В моих предыдущих двух блогах из этой серии, часть 1 и часть 2 , я демонстрировал, как создать кусок плохого кода, который блокируется, а затем использовал этот код, чтобы показать три способа получения дампа потока. В этом блоге я собираюсь проанализировать дамп потока, чтобы выяснить, что не так.
Обсуждение ниже относится как к классам Account
и к классам DeadlockDemo
из первой части этой серии, в которой содержатся полные списки кодов.
Первое, что мне нужно, это дамп потока из приложения DeadlockDemo
, так как в Blue Peter говорили: «Вот тот, который я подготовил ранее».
001
002
003
004
005
006
007
008
009
010
011
012
013
014
015
016
017
018
019
020
021
022
023
024
025
026
027
028
029
030
031
032
033
034
035
036
037
038
039
040
041
042
043
044
045
046
047
048
049
050
051
052
053
054
055
056
057
058
059
060
061
062
063
064
065
066
067
068
069
070
071
072
073
074
075
076
077
078
079
080
081
082
083
084
085
086
087
088
089
090
091
092
093
094
095
096
097
098
099
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
|
2012-10-16 13:37:03 Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.10-b01-428 mixed mode): "DestroyJavaVM" prio=5 tid=7f9712001000 nid=0x110247000 waiting on condition [00000000] java.lang.Thread.State: RUNNABLE "Thread-21" prio=5 tid=7f9712944000 nid=0x118d76000 waiting for monitor entry [118d75000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366f58> (a threads.deadlock.Account) - locked <7f3366ee0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-20" prio=5 tid=7f971216c000 nid=0x118c73000 waiting for monitor entry [118c72000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e98> (a threads.deadlock.Account) - locked <7f3366f58> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-19" prio=5 tid=7f9712943800 nid=0x118b70000 waiting for monitor entry [118b6f000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366f40> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-18" prio=5 tid=7f9712942800 nid=0x118a6d000 waiting for monitor entry [118a6c000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366f40> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-17" prio=5 tid=7f9712942000 nid=0x11896a000 waiting for monitor entry [118969000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366ec8> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-16" prio=5 tid=7f9712941000 nid=0x118867000 waiting for monitor entry [118866000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366ec8> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-15" prio=5 tid=7f9712940800 nid=0x118764000 waiting for monitor entry [118763000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366ef8> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-14" prio=5 tid=7f971293f800 nid=0x118661000 waiting for monitor entry [118660000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366f28> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-13" prio=5 tid=7f97129ae000 nid=0x11855e000 waiting for monitor entry [11855d000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366eb0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-12" prio=5 tid=7f97129ad000 nid=0x11845b000 waiting for monitor entry [11845a000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366f40> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-11" prio=5 tid=7f97129ac800 nid=0x118358000 waiting for monitor entry [118357000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366f58> (a threads.deadlock.Account) - locked <7f3366eb0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-10" prio=5 tid=7f97129ab800 nid=0x118255000 waiting for monitor entry [118254000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366eb0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-9" prio=5 tid=7f97129ab000 nid=0x118152000 waiting for monitor entry [118151000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e98> (a threads.deadlock.Account) - locked <7f3366ec8> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-8" prio=5 tid=7f97129aa000 nid=0x11804f000 waiting for monitor entry [11804e000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366eb0> (a threads.deadlock.Account) - locked <7f3366f28> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-7" prio=5 tid=7f97129a9800 nid=0x117f4c000 waiting for monitor entry [117f4b000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366eb0> (a threads.deadlock.Account) - locked <7f3366e80> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-6" prio=5 tid=7f97129a8800 nid=0x117e49000 waiting for monitor entry [117e48000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366e80> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-5" prio=5 tid=7f97128a1800 nid=0x117d46000 waiting for monitor entry [117d45000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:81) - waiting to lock <7f3366f28> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-4" prio=5 tid=7f97121af800 nid=0x117c43000 waiting for monitor entry [117c42000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e80> (a threads.deadlock.Account) - locked <7f3366e98> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-3" prio=5 tid=7f97121ae800 nid=0x117b40000 waiting for monitor entry [117b3f000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e80> (a threads.deadlock.Account) - locked <7f3366ef8> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-2" prio=5 tid=7f971224a000 nid=0x117a3d000 waiting for monitor entry [117a3c000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366eb0> (a threads.deadlock.Account) - locked <7f3366f40> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "RMI TCP Accept-0" daemon prio=5 tid=7f97128fd800 nid=0x117837000 runnable [117836000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:408) - locked <7f32ee740> (a java.net.SocksSocketImpl) at java.net.ServerSocket.implAccept(ServerSocket.java:462) at java.net.ServerSocket.accept(ServerSocket.java:430) at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:34) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341) at java.lang.Thread.run(Thread.java:680) "Poller SunPKCS11-Darwin" daemon prio=1 tid=7f97128fd000 nid=0x117734000 waiting on condition [117733000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread. sleep (Native Method) at sun.security.pkcs11.SunPKCS11$TokenPoller.run(SunPKCS11.java:692) at java.lang.Thread.run(Thread.java:680) "Low Memory Detector" daemon prio=5 tid=7f971209e000 nid=0x1173ec000 runnable [00000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=9 tid=7f971209d000 nid=0x1172e9000 waiting on condition [00000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=9 tid=7f971209c800 nid=0x1171e6000 waiting on condition [00000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=9 tid=7f971209b800 nid=0x1170e3000 waiting on condition [00000000] java.lang.Thread.State: RUNNABLE "Surrogate Locker Thread (Concurrent GC)" daemon prio=5 tid=7f971209a800 nid=0x116fe0000 waiting on condition [00000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=8 tid=7f971209a000 nid=0x116d1c000 in Object.wait() [116d1b000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <7f3001300> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118) - locked <7f3001300> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159) "Reference Handler" daemon prio=10 tid=7f9712099000 nid=0x116c19000 in Object.wait() [116c18000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <7f30011d8> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:485) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) - locked <7f30011d8> (a java.lang.ref.Reference$Lock) "VM Thread" prio=9 tid=7f9712096800 nid=0x116b16000 runnable "Gang worker#0 (Parallel GC Threads)" prio=9 tid=7f9712002800 nid=0x1135c7000 runnable "Gang worker#1 (Parallel GC Threads)" prio=9 tid=7f9712003000 nid=0x1136ca000 runnable "Concurrent Mark-Sweep GC Thread" prio=9 tid=7f971204d800 nid=0x116790000 runnable "VM Periodic Task Thread" prio=10 tid=7f97122d4000 nid=0x11793a000 waiting on condition "Exception Catcher Thread" prio=10 tid=7f9712001800 nid=0x1103ef000 runnable JNI global references: 1037 Found one Java-level deadlock: ============================= "Thread-21" : waiting to lock monitor 7f97118bd560 (object 7f3366f58, a threads.deadlock.Account), which is held by "Thread-20" "Thread-20" : waiting to lock monitor 7f97118bc108 (object 7f3366e98, a threads.deadlock.Account), which is held by "Thread-4" "Thread-4" : waiting to lock monitor 7f9711834360 (object 7f3366e80, a threads.deadlock.Account), which is held by "Thread-7" "Thread-7" : waiting to lock monitor 7f97118b9708 (object 7f3366eb0, a threads.deadlock.Account), which is held by "Thread-11" "Thread-11" : waiting to lock monitor 7f97118bd560 (object 7f3366f58, a threads.deadlock.Account), which is held by "Thread-20" Java stack information for the threads listed above: =================================================== "Thread-21" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366f58> (a threads.deadlock.Account) - locked <7f3366ee0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-20" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e98> (a threads.deadlock.Account) - locked <7f3366f58> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-4" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e80> (a threads.deadlock.Account) - locked <7f3366e98> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-7" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366eb0> (a threads.deadlock.Account) - locked <7f3366e80> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-11" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366f58> (a threads.deadlock.Account) - locked <7f3366eb0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) Found 1 deadlock. Heap par new generation total 19136K, used 11590K [7f3000000, 7f44c0000, 7f44c0000) eden space 17024K, 68% used [7f3000000, 7f3b51ac0, 7f40a0000) from space 2112K, 0% used [7f40a0000, 7f40a0000, 7f42b0000) to space 2112K, 0% used [7f42b0000, 7f42b0000, 7f44c0000) concurrent mark-sweep generation total 63872K, used 0K [7f44c0000, 7f8320000, 7fae00000) concurrent-mark-sweep perm gen total 21248K, used 8268K [7fae00000, 7fc2c0000, 800000000) |
Быстро просматривая, вы можете видеть, что этот дамп потока разделен на четыре части. Эти:
- Полный список всех потоков приложения
- Список заблокированных тем
- Небольшой стек следов заблокированных потоков
- Резюме кучи приложения
Список тем
Список потоков в пункте один выше представляет собой список всех потоков приложения и их текущего состояния. Отсюда видно, что приложение состоит из целого ряда потоков, которые можно условно разделить на две части. Во-первых, это фоновые темы. Это те, которые есть в каждом приложении, и они справляются со всеми грязными задачами, о которых нам, как прикладным программистам, обычно не нужно беспокоиться. Они имеют такие имена, как: « DestroyJavaVM
», Low Memory Detector, Finalizer, Exception Catcher Thread and Concurrent Mark-Sweep GC Thread
DestroyJavaVM
Low Memory Detector, Finalizer, Exception Catcher Thread and Concurrent Mark-Sweep GC Thread
DestroyJavaVM
, DestroyJavaVM
Low Memory Detector, Finalizer, Exception Catcher Thread and Concurrent Mark-Sweep GC Thread
DestroyJavaVM
. Во-вторых, есть потоки, которые вы или я можем создать как часть нашего кода. Обычно они имеют имена, состоящие из слова Thread
за которым следует число. Например: Thread-3, Thread-6 and Thread-20.
1
2
3
4
5
6
|
"Thread-20" prio=5 tid=7f971216c000 nid=0x118c73000 waiting for monitor entry [118c72000] java.lang.Thread.State: BLOCKED (on object monitor) at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:82) - waiting to lock <7f3366e98> (a threads.deadlock.Account) - locked <7f3366f58> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:58) |
Более подробно рассмотрев информацию, приведенную в теме 20, вы увидите, что ее можно разбить на несколько частей. Эти:
<td> Thread-20 <td> Имя потока, как описано выше. <tr> <td> prio = 5 <td> Приоритет потока. Число от 1 до 10, где 1 — самый низкий, а 10 — самый высокий приоритет. <tr> <tr> <td> tid = 7f971216c000 <td> Идентификатор потока. Уникальный номер, возвращаемый вызовом Thread.getId (). <tr> <td> nid = 0x118c73000 <td> Идентификатор собственного потока. Это соответствует платформо-зависимому идентификатору потока. <tr> <td> ожидает записи монитора [118c72000]
java.lang.Thread.State: BLOCKED (на объектном мониторе) <td> Это состояние потока; в этом случае он заблокирован. Также включена трассировка стека, в которой указано, где поток заблокирован.
Обратите внимание, что поток также может быть помечен как демон. Например:
Демон «RMI TCP Accept-0» prio = 5 tid = 7f97128fd800 nid = 0x117837000 runnable [117836000] java.lang.Thread.State: RUNNABLE
Потоки демона являются потоками фоновых задач, такими как поток RMI TCP Accept-0, перечисленный выше. Поток демона — это поток, который не препятствует выходу JVM. JVM выйдет или закроется, когда останутся только потоки демона.
Тем не менее, список потоков на самом деле не помогает отследить причину тупика, поэтому быстро продвигаться вперед …
Список тупиковых тем
Этот раздел дампа потока содержит список всех потоков, которые вовлечены в тупик.
01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
17
|
Found one Java-level deadlock: ============================= "Thread-21" : waiting to lock monitor 7f97118bd560 (object 7f3366f58, a threads.deadlock.Account), which is held by "Thread-20" "Thread-20" : waiting to lock monitor 7f97118bc108 (object 7f3366e98, a threads.deadlock.Account), which is held by "Thread-4" "Thread-4" : waiting to lock monitor 7f9711834360 (object 7f3366e80, a threads.deadlock.Account), which is held by "Thread-7" "Thread-7" : waiting to lock monitor 7f97118b9708 (object 7f3366eb0, a threads.deadlock.Account), which is held by "Thread-11" "Thread-11" : waiting to lock monitor 7f97118bd560 (object 7f3366f58, a threads.deadlock.Account), which is held by "Thread-20" |
Из приведенного выше сегмента видно, что все пять потоков блокируют экземпляры класса threads.deadlock.Account
Оставляя в стороне идентификаторы монитора и экземпляры учетной записи, вы можете видеть, что «Thread-21» ожидает «Thread-20», который ожидает «Thread-4», который, в свою очередь, ожидает «Thread-7». «Thread-7» ожидает «Thread-11», который ожидает «Thread-20»: тупиковая петля, как показано на рисунке ниже:
Следы стека тупика
Последним фрагментом головоломки является список трассировок стека заблокированных нитей, как показано ниже:
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
|
Java stack information for the threads listed above: =================================================== "Thread-21" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366f58> (a threads.deadlock.Account) - locked <7f3366ee0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-20" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e98> (a threads.deadlock.Account) - locked <7f3366f58> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-4" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366e80> (a threads.deadlock.Account) - locked <7f3366e98> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-7" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366eb0> (a threads.deadlock.Account) - locked <7f3366e80> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-11" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f3366f58> (a threads.deadlock.Account) - locked <7f3366eb0> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) |
Из предыдущего раздела мы знаем, что Thread-20
через обходной маршрут ожидает Thread-11
а Thread-11
ожидает Thread-20
. Это наш тупик.
Следующий шаг — привязать этот тупик к строкам кода, используя трассировку стека потоков выше, и я упростил это на диаграмме ниже.
На приведенной выше диаграмме для ясности я удалил префикс 7f3366
из идентификаторов объектов; следовательно, объект 7f3366f58
теперь является f58
. Из этой диаграммы видно, что объект f58
заблокирован f58
Thread-20
в строке 59 и ожидает блокировки объекта e98
в строке 86. Следуя стрелкам вниз, вы можете видеть, что Thread-7
ожидает блокировки в eb0
в строке 86, которая, в свою очередь, заблокирована eb0
Thread-11
в строке 59. Thread-11
ожидает блокировки на f58
в строке 86, которая, f58
цикл, блокируется в строке 58 Thread-20
.
Итак, где эти строки кода? Ниже показана строка 59:
… а это строка 86:
Каждый иногда получает сюрпризы, и трассировка стека выше удивила меня. Я ожидал, что замки будут на линиях 85 и 86; однако они были на 59 и 86. Поскольку строка 59 не содержит синхронизированного ключевого слова, я предполагаю, что компилятор выполнил некоторую оптимизацию первого синхронизированного ключевого слова метода Transfer (…).
Из этого можно сделать вывод, что код, который случайным образом выбирает два объекта Account
из списка, блокирует их в неправильном порядке в строках 59 и 86. Так в чем же проблема? Подробнее об этом в следующий раз; Тем не менее, есть один последний момент, на который следует обратить внимание: составление взаимоблокировки может быть разным при каждом создании дампа потока в программе. После повторного запуска программы DeadlockDemo
и использования kill -3
PID для получения дампа другого потока я получил следующие результаты:
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
|
Found one Java-level deadlock: ============================= "Thread-20" : waiting to lock monitor 7fdc7c802508 (object 7f311a530, a threads.deadlock.Account), which is held by "Thread-3" "Thread-3" : waiting to lock monitor 7fdc7a83d008 (object 7f311a518, a threads.deadlock.Account), which is held by "Thread-11" "Thread-11" : waiting to lock monitor 7fdc7c802508 (object 7f311a530, a threads.deadlock.Account), which is held by "Thread-3" Java stack information for the threads listed above: =================================================== "Thread-20" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:86) - waiting to lock <7f311a530> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-3" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:87) - waiting to lock <7f311a518> (a threads.deadlock.Account) - locked <7f311a530> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) "Thread-11" : at threads.deadlock.DeadlockDemo$BadTransferOperation.transfer(DeadlockDemo.java:87) - waiting to lock <7f311a530> (a threads.deadlock.Account) - locked <7f311a518> (a threads.deadlock.Account) at threads.deadlock.DeadlockDemo$BadTransferOperation.run(DeadlockDemo.java:59) Found 1 deadlock. |
В этом дампе потока в тупик вовлечено меньшее количество потоков, но если вы проанализируете его, вы сможете сделать те же выводы, что и в моем первом примере.
В следующий раз: исправление кода …
Для получения дополнительной информации см. Другие блоги в этой серии.
Весь исходный код для этого и других блогов из этой серии доступен на Github по адресу: gitub.com/roghughe/captaindebug.git.
Ссылка: Исследование тупиков — Часть 3: Анализ дампа потоков от нашего партнера по JCG Роджера Хьюза в блоге Captain Debug’s Blog .