Back-End

2 abr, 2013

Investigando Deadlocks – Parte 3: analisando dump de thread

Publicidade

Nos meus dois artigos anteriores desta série, parte 1 e parte 2, eu demonstrei como criar uma parte de código inválido, os deadlocks, e depois usei esse código para mostrar três maneiras de pegar um dump de thread. Neste artigo, vou analisar o dump de thread para descobrir o que deu errado.

A discussão a seguir refere-se tanto às classes Account e DeadlockDemo da parte 1 desta série, que contêm listagens de código completo.

A primeira coisa de que preciso é um dump de thread do aplicativo DeadlockDemo. Aqui está um que havia preparado mais cedo.

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)

Ao fazer uma varredura rápida, você pode ver que esse dump de thread é dividido em quatro partes. Aqui estão:

  1. Uma lista completa de todas as threads do aplicativo
  2. Uma lista de threads com deadlock
  3. Um pequeno rastreamento de pilha de threads com deadlock
  4. Sumário da aplicação heap

A lista de threads

A lista de thread no ponto um, mencionado acima, é uma lista de todos as threads do aplicativo e seu status atual. A partir disso, você pode ver que um aplicativo consiste em um monte de threads, que você pode dividir em aproximadamente duas. Em primeiro lugar, há das threads de background. Elas são aquelas que todo aplicativo possui, que ficam com todos os trabalhos sujos que nós, como programadores de aplicativos, geralmente não precisamos nos preocupar. Elas têm nomes como: “DestroyJavaVM”, Low Memory Detector, Finalizer, Exception Catcher Thread e Concurrent Mark-Sweep GC Thread. Em segundo lugar, há as threads que você ou eu podemos criar como parte de nosso código. Elas geralmente têm nomes que consistem da palavra Thread seguida de um número. Por exemplo: Thread-3, Thread-6-e Thread-20.

"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)

Analisando as informações fornecidas na Thread-20 com mais detalhes, você pode ver que isso pode ser dividido em várias partes. Aqui estão elas:

 

Thread-20 Nome da thread, tal como descrito acima.
prio=5 A prioridade da thread. Um número de 1 a 10, em que 1 é a menor e 10 é a maior prioridade.
tid=7f971216c000 A ID da thread. Um único número que é retornado por uma chamada Thread.getId().
nid=0x118c73000 A ID nativa da thread. Isso mapeia para uma ID da thread dependente de plataforma.
waiting for monitor entry [118c72000]
java.lang.Thread.State: BLOCKED (on object monitor)
Este é o estado da thread; nesse caso, está BLOCKED. Também está incluído um stacktrace que define onde A thread está bloqueada.

Observe que uma thread também pode ser marcada como um daemon. Por exemplo:

“RMI TCP Accept-0” daemon prio=5 tid=7f97128fd800 nid=0x117837000 runnable [117836000]
   java.lang.Thread.State: RUNNABLE

As threads daemon são threads de tarefa de background, como a thread RMI TCP Accept-0 listada acima. Uma thread daemon é uma thread que não impede a JVM de sair. A JVM vai sair, ou fechar, quando apenas as threads daemon permanecem.

No entanto, a lista de threads realmente não ajuda a localizar a causa de um deadlock, movendo-se rapidamente…

A lista de threads deadlock

Esta seção do dump de thread contém uma lista de todos as threads que estão envolvidas no deadlock.

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"
<span style="font-family: Georgia, 'Times New Roman', 'Bitstream Charter', Times, serif; font-size: 13px; line-height: 19px;">A partir do segmento acima, você pode ver que existem cinco threads de bloqueio em todas as instâncias da classe </span><em style="font-family: Georgia, 'Times New Roman', 'Bitstream Charter', Times, serif; font-size: 13px; line-height: 19px;">threads.deadlock.Account</em><span style="font-family: Georgia, 'Times New Roman', 'Bitstream Charter', Times, serif; font-size: 13px; line-height: 19px;">.</span>

Deixando de lado os ids do monitor e as instâncias Account, você pode ver que “Thread-21” está esperando por “Thread-20”, que está esperando por “Thread-4”, que por sua vez está esperando por “Thread-7”. “Thread-7” está esperando por “Thread-11”, que está esperando por “Thread-20”: um loop de deadlock, como mostrado no diagrama abaixo:

deadlock3

O Deadlock Stack Traces

A última peça do quebra-cabeça é a lista de threads deadlocked thread stack como mostrado abaixo:

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)

Da seção anterior, sabemos que Thread-20 está esperando, através de um caminho tortuoso, por Thread-11, e Thread-11 está esperando por Thread-20. Esse é o nosso deadlock.

O próximo passo é amarrar esse deadlock até as linhas de código usando o rastreamento da pilha de thread acima, e eu simplifiquei isso no diagrama abaixo.

skitch2

No diagrama acima, eu removi o prefixo 7f3366 das ids de objetos para maior clareza, portanto, o objeto 7f3366f58 agora é f58. A partir desse diagrama, você pode ver que o objeto f58 está bloqueado por Thread-20 na linha 59 e está esperando por um bloqueio no objeto e98 na linha 86. Seguindo as setas para baixo, você pode ver que Thread-7 está esperando por um bloqueio em eb0 na linha 86, que por sua vez está bloqueado por Thread-11 na linha 59. Thread-11 está esperando por um bloqueio no f58 na linha 86, que, ao voltar-se, está bloqueado na linha 58 por Thread-20.

Então, onde estão essas linhas de código? A imagem abaixo mostra a linha 59:

code1

… e esta é a linha 86:

code2

Todo mundo fica surpreso às vezes, e o rastreamento de pilha acima me surpreendeu. Eu estava esperando que os bloqueios estivessem nas linhas 85 e 86; no entanto, eles estavam nas 59 e 86. Uma vez que a linha 59 não contém a palavra-chave synchronized, eu estou supondo que o compilador realizou alguma otimização na primeira palavra-chave synchronized do método transfer(…).

A conclusão que se pode tirar disso é que o código, que escolhe aleatoriamente dois objetos Account de uma lista, está bloqueando-os na ordem errada nas linhas 59 e 86. Então qual é a solução? Falaremos mais sobre isso na próxima vez, no entanto, há um último ponto a se notar, que é que a confecção de um deadlock não pode ser o mesma cada vez que você gerar um dump de thread em um programa. Após executar o programa DeadlockDemo novamente e usando kill -3 PID para se apossar de outro dump de thread, obtive estes resultados:

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.

 

Neste dump de thread, um número menor de threads está envolvido no deadlock, mas se você analisá-lo pode tirar a mesma conclusão do meu primeiro exemplo.

***

Artigo traduzido pela Redação iMasters, com autorização do autor. Publicado originalmente em http://www.captaindebug.com/2012/10/investigating-deadlocks-part-3.html#.UU_NQRyzeSr