Это тематическое исследование также продемонстрирует важность овладения навыками анализа Thread Dump; в том числе для формата IBM JVM Thread Dump.
Спецификации окружающей среды
— Сервер Java EE: Oracle Weblogic Server 11g & Spring 2.0.5 — ОС: AIX 5.3 — Java VM: IBM JRE 1.6.0 — Тип платформы: Портал и приложение для заказа
Инструменты мониторинга и устранения неполадок
— Дамп потока JVM (формат IBM JVM) — Compuware Server Vantage (мониторинг и оповещение Weblogic JMX)
Обзор проблемы
Компания Compuware Server Vantage наблюдала и сообщала о серьезной проблеме с застрявшими потоками, которая затрагивала 2 наших производственных управляемых сервера Weblogic 11g, вызывая влияние на приложения и время ожидания у наших конечных пользователей.
Сбор и проверка фактов
Как обычно, исследование проблемы Java EE требует сбора технических и нетехнических фактов, чтобы мы могли либо получить другие факты и / или сделать вывод о первопричине. Перед применением корректирующих мер факты, приведенные ниже, были проверены, чтобы сделать вывод о первопричине:
· Какое влияние оказывает клиент? СРЕДНЯЯ (только 2 управляемых сервера / JVM затронуты из 16) · Недавнее изменение уязвимой платформы? Да (новый асинхронный компонент, связанный с JMS). • Увеличение трафика в последнее время на уязвимую платформу? Нет · Как эта проблема проявляется? Наблюдалось внезапное увеличение потоков, приводящее к быстрому истощению потоков. Решил ли проблему перезапуск управляемого сервера Weblogic? Да, но проблема возвращается через несколько часов (непредсказуемый и прерывистый характер)
— Вывод № 1 :
Проблема связана с периодическим поведением застрявших потоков, затрагивающим только несколько управляемых серверов Weblogic в то время
— Вывод № 2 :
Поскольку проблема носит неустойчивый характер, глобальная первопричина, такая как не реагирующая нисходящая система, маловероятна
Анализ дампа потока — первый проход
Первое, что нужно сделать при решении проблем с застрявшими потоками, — создать дамп потока JVM. Это золотое правило независимо от спецификаций вашей среды и контекста проблемы. Снимок дампа потоков JVM предоставляет вам важную информацию об активных потоках и типах обработки / задач, которые они выполняют в это время.
Теперь вернемся к нашему примеру: был создан дамп потока IBM JVM (формат javacore.xyz), который обнаружил следующее условие взаимоблокировки потока Java ниже:
|
01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
|
1LKDEADLOCK Deadlock detected !!! NULL --------------------- NULL 2LKDEADLOCKTHR Thread '[STUCK] ExecuteThread: '8' for queue: 'weblogic.kernel.Default (self-tuning)'' (0x000000012CC08B00) 3LKDEADLOCKWTR is waiting for: 4LKDEADLOCKMON sys_mon_t:0x0000000126171DF8 infl_mon_t: 0x0000000126171E38: 4LKDEADLOCKOBJ weblogic/jms/frontend/FESession@0x07000000198048C0/0x07000000198048D8: 3LKDEADLOCKOWN which is owned by: 2LKDEADLOCKTHR Thread '[STUCK] ExecuteThread: '10' for queue: 'weblogic.kernel.Default (self-tuning)'' (0x000000012E560500) 3LKDEADLOCKWTR which is waiting for: 4LKDEADLOCKMON sys_mon_t:0x000000012884CD60 infl_mon_t: 0x000000012884CDA0: 4LKDEADLOCKOBJ weblogic/jms/frontend/FEConnection@0x0700000019822F08/0x0700000019822F20: 3LKDEADLOCKOWN which is owned by: 2LKDEADLOCKTHR Thread '[STUCK] ExecuteThread: '8' for queue: 'weblogic.kernel.Default (self-tuning)'' (0x000000012CC08B00) |
Эта тупиковая ситуация может быть переведена как ниже:
— Weblogic Thread # 8 ожидает получения блокировки монитора объектов, принадлежащей Weblogic Thread # 10
— Weblogic Thread # 10 ожидает получения блокировки монитора объектов, принадлежащей Weblogic Thread # 8
Вывод: оба потока Weblogic # 8 и # 10 ждут друг друга; навсегда!
Теперь, прежде чем углубляться в анализ первопричин, позвольте мне дать вам общий обзор тупиков Java Thread.
Обзор тупиковых ситуаций Java Thread
Большинство из вас, вероятно, знакомы с принципами взаимоблокировки Java Thread, но действительно ли вы столкнулись с настоящей проблемой взаимоблокировки?
Исходя из моего опыта, реальные взаимоблокировки Java встречаются редко, и я видел только ~ 5 случаев за последние 10 лет. Причина заключается в том, что большинство проблем, связанных с застрявшими потоками, возникают из-за зависания потоков (ожидание при удаленном вызове ввода-вывода и т. Д.), Но не связаны с истинным тупиком с другими потоками.
Взаимная блокировка потока Java — это ситуация, например, когда поток A ожидает получения блокировки монитора объекта, удерживаемой потоком B, который сам ожидает получения блокировки монитора объекта, удерживаемой потоком A. Оба этих потока будут ждать друг друга вечно. Эта ситуация может быть визуализирована согласно диаграмме ниже:
Подтверждена тупиковая ситуация … что теперь можно сделать?
После подтверждения взаимоблокировки ( большинство реализаций JVM Thread Dump выделят ее для вас ), следующим шагом будет выполнение более глубокого анализа погружения путем анализа каждого потока, участвующего в ситуации взаимоблокировки, наряду с их текущей задачей и условием ожидания.
Найдите ниже частичную трассировку стека потоков из нашего проблемного случая для каждого потока, вовлеченного в условие взаимоблокировки:
** Обратите внимание, что реальное имя пакета Java приложения было переименовано в целях конфиденциальности **
Веблогическая Тема № 8
|
01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
|
'[STUCK] ExecuteThread: '8' for queue: 'weblogic.kernel.Default (self-tuning)'' J9VMThread:0x000000012CC08B00, j9thread_t:0x00000001299E5100, java/lang/Thread:0x070000001D72EE00, state:B, prio=1 (native thread ID:0x111200F, native priority:0x1, native policy:UNKNOWN) Java callstack: at weblogic/jms/frontend/FEConnection.stop(FEConnection.java:671(Compiled Code)) at weblogic/jms/frontend/FEConnection.invoke(FEConnection.java:1685(Compiled Code)) at weblogic/messaging/dispatcher/Request.wrappedFiniteStateMachine(Request.java:961(Compiled Code)) at weblogic/messaging/dispatcher/DispatcherImpl.syncRequest(DispatcherImpl.java:184(Compiled Code)) at weblogic/messaging/dispatcher/DispatcherImpl.dispatchSync(DispatcherImpl.java:212(Compiled Code)) at weblogic/jms/dispatcher/DispatcherAdapter.dispatchSync(DispatcherAdapter.java:43(Compiled Code)) at weblogic/jms/client/JMSConnection.stop(JMSConnection.java:863(Compiled Code)) at weblogic/jms/client/WLConnectionImpl.stop(WLConnectionImpl.java:843) at org/springframework/jms/connection/SingleConnectionFactory.closeConnection(SingleConnectionFactory.java:342) at org/springframework/jms/connection/SingleConnectionFactory.<strong>resetConnection</strong>(SingleConnectionFactory.java:296) at org/app/JMSReceiver.receive() …………………………………………………………………… |
Веблогическая Тема № 10
|
01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
|
'[STUCK] ExecuteThread: '10' for queue: 'weblogic.kernel.Default (self-tuning)'' J9VMThread:0x000000012E560500, j9thread_t:0x000000012E35BCE0, java/lang/Thread:0x070000001ECA9200, state:B, prio=1 (native thread ID:0x4FA027, native priority:0x1, native policy:UNKNOWN) Java callstack: at weblogic/jms/frontend/<strong>FEConnection</strong>.getPeerVersion(FEConnection.java:1381(Compiled Code)) at weblogic/jms/frontend/FESession.setUpBackEndSession(FESession.java:755(Compiled Code)) at weblogic/jms/frontend/FESession.consumerCreate(FESession.java:1025(Compiled Code)) at weblogic/jms/frontend/FESession.invoke(FESession.java:2995(Compiled Code)) at weblogic/messaging/dispatcher/Request.wrappedFiniteStateMachine(Request.java:961(Compiled Code)) at weblogic/messaging/dispatcher/DispatcherImpl.syncRequest(DispatcherImpl.java:184(Compiled Code)) at weblogic/messaging/dispatcher/DispatcherImpl.dispatchSync(DispatcherImpl.java:212(Compiled Code)) at weblogic/jms/dispatcher/DispatcherAdapter.dispatchSync(DispatcherAdapter.java:43(Compiled Code)) at weblogic/jms/client/JMSSession.consumerCreate(JMSSession.java:2982(Compiled Code)) at weblogic/jms/client/JMSSession.setupConsumer(JMSSession.java:2749(Compiled Code)) at weblogic/jms/client/JMSSession.createConsumer(JMSSession.java:2691(Compiled Code)) at weblogic/jms/client/JMSSession.createReceiver(JMSSession.java:2596(Compiled Code)) at weblogic/jms/client/WLSessionImpl.createReceiver(WLSessionImpl.java:991(Compiled Code)) at org/springframework/jms/core/JmsTemplate102.createConsumer(JmsTemplate102.java:204(Compiled Code)) at org/springframework/jms/core/JmsTemplate.doReceive(JmsTemplate.java:676(Compiled Code)) at org/springframework/jms/core/JmsTemplate$10.doInJms(JmsTemplate.java:652(Compiled Code)) at org/springframework/jms/core/JmsTemplate.execute(JmsTemplate.java:412(Compiled Code)) at org/springframework/jms/core/JmsTemplate.receiveSelected(JmsTemplate.java:650(Compiled Code)) at org/springframework/jms/core/JmsTemplate.receiveSelected(JmsTemplate.java:641(Compiled Code)) at org/app/JMSReceiver.receive() …………………………………………………………… |
Как вы можете видеть из приведенных выше трассировок Thread Strack, такая тупиковая ситуация возникла из кода нашего приложения, использующего API-интерфейс Spring для реализации потребителя JMS (очень полезно, когда не используются MDB). Трассировки стеков довольно интересны и показывают, что оба Потока находятся в состоянии гонки с одним и тем же сеансом / подключением потребителя Weblogic JMS и приводят к тупиковой ситуации:
— Поток Weblogic # 8 пытается сбросить и закрыть текущее соединение JMS — Поток Weblogic # 10 пытается использовать то же соединение / сеанс JMS для создания нового потребителя JMS — Запущена взаимоблокировка потока!
Основная причина: не потокобезопасная реализация Spring JMS SingleConnectionFactory
Обзор кода и быстрое исследование из базы данных ошибок Spring JIRA выявили следующий дефект безопасного потока ниже с идеальной корреляцией с вышеупомянутым анализом:
# SingleConnectionFactory resetConnection вызывает взаимные блокировки с базовым JMS-соединением OracleAQ https://jira.springsource.org/browse/SPR-5987
В 2009 году было выпущено исправление для Spring SingleConnectionFactory, которое включало добавление правильного синхронизированного блока {} для предотвращения взаимоблокировки потоков в случае операции сброса соединения JMS:
|
01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
17
18
19
|
synchronized (connectionMonitor) { //if condition added to avoid possible deadlocks when trying to reset the target connection if (!started) { this.target.start(); started = true; } } |
Решение
В настоящее время наша команда планирует внедрить этот патч Spring в нашу производственную среду. Начальные тесты, выполненные в нашей тестовой среде, являются положительными.
Вывод
Я надеюсь, что это исследование помогло понять реальную проблему взаимоблокировки Java Thread и то, как правильные навыки анализа дампа Thread могут помочь вам быстро определить причину застрявших проблем, связанных с Thread, на уровне кода. Пожалуйста, не стесняйтесь оставлять комментарии или вопросы.
Ссылка: тупик Java Thread — тематическое исследование от нашего партнера по JCG Пьера-Хьюга Шарбонно в блоге, посвященном шаблонам поддержки Java EE и учебному пособию по Java .