[BUG]a dead lock case #170

a8156268 · 2021-07-13T15:42:35Z

Describe the bug
A dead lock occured. And then cause download blocked.

Dead lock reason:
cleaner thread acquired connectionLock then try acquiring EventBus Lock
collector thread acquired EventBus Lock then try acquiring connectionLock

stack of ConnectionPool Cleaner thread

"6891.bt.net.pool.cleaner" #480 daemon prio=5 os_prio=0 tid=0x000000000af38800 nid=0xd9fb waiting for monitor entry [0x00007f56e4ef2000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at bt.event.EventBus.firePeerDisconnected(EventBus.java:76)
        - waiting to lock <0x00000001330a6c18> (a bt.event.EventBus)
        at bt.net.PeerConnectionPool.purgeConnection(PeerConnectionPool.java:263)
        at bt.net.PeerConnectionPool.access$200(PeerConnectionPool.java:48)
        at bt.net.PeerConnectionPool$Cleaner.lambda$run$0(PeerConnectionPool.java:239)
        at bt.net.PeerConnectionPool$Cleaner$$Lambda$796/158316397.accept(Unknown Source)
        at bt.net.Connections$$Lambda$797/128473136.accept(Unknown Source)
        at java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4707)
        at bt.net.Connections.visitConnections(PeerConnectionPool.java:332)
        at bt.net.PeerConnectionPool$Cleaner.run(PeerConnectionPool.java:237)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

stack of peer-collector thread

"6891.bt.peer.peer-collector" #482 daemon prio=5 os_prio=0 tid=0x0000000008379800 nid=0xd9fd waiting on condition [0x00007f56e4e6f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000001330a7e08> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
        at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
        at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
        at bt.net.PeerConnectionPool.getConnection(PeerConnectionPool.java:87)
        at bt.net.ConnectionSource.getExistingOrPendingConnection(ConnectionSource.java:169)
        at bt.net.ConnectionSource.getConnectionAsync(ConnectionSource.java:89)
        at bt.torrent.messaging.TorrentWorker.onPeerDiscovered(TorrentWorker.java:415)
        - locked <0x000000012f000ba8> (a bt.torrent.messaging.TorrentWorker)
        at bt.torrent.messaging.TorrentWorker.lambda$new$0(TorrentWorker.java:108)
        at bt.torrent.messaging.TorrentWorker$$Lambda$698/90086491.accept(Unknown Source)
        at bt.event.EventBus.lambda$addListener$3(EventBus.java:246)
        at bt.event.EventBus$$Lambda$599/292545143.accept(Unknown Source)
        at bt.event.EventBus.doFireEvent(EventBus.java:180)
        at bt.event.EventBus.fireEvent(EventBus.java:163)
        at bt.event.EventBus.firePeerDiscovered(EventBus.java:61)
        - locked <0x00000001330a6c18> (a bt.event.EventBus)
        at bt.peer.PeerRegistry.addPeer(PeerRegistry.java:214)
        at bt.peer.PeerRegistry.queryPeerSource(PeerRegistry.java:194)
        at bt.peer.PeerRegistry.lambda$null$2(PeerRegistry.java:137)
        at bt.peer.PeerRegistry$$Lambda$727/1689179593.accept(Unknown Source)
        at java.lang.Iterable.forEach(Iterable.java:75)
        at bt.peer.PeerRegistry.lambda$collectAndVisitPeers$3(PeerRegistry.java:136)
        at bt.peer.PeerRegistry$$Lambda$681/315981216.accept(Unknown Source)
        at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
        at java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1080)
        at bt.peer.PeerRegistry.collectAndVisitPeers(PeerRegistry.java:104)
        at bt.peer.PeerRegistry$$Lambda$679/1839725766.run(Unknown Source)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

The text was updated successfully, but these errors were encountered:

a8156268 · 2021-07-13T15:43:08Z

Dose EventBus really need a sync lock?

a8156268 · 2021-07-13T15:49:31Z

data.worker still been blocked on EventBus


"6891.bt.torrent.data.worker-01" #547 daemon prio=5 os_prio=0 tid=0x000000000c879800 nid=0xda3e waiting for monitor entry [0x00007f56e39bf000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at bt.event.EventBus.nextId(EventBus.java:151)
        - waiting to lock <0x00000001330a6c18> (a bt.event.EventBus)
        at bt.event.EventBus.firePieceVerified(EventBus.java:126)
        at bt.torrent.messaging.PieceConsumer.lambda$null$0(PieceConsumer.java:119)
        at bt.torrent.messaging.PieceConsumer$$Lambda$815/1020742529.accept(Unknown Source)
        at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760)
        at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736)
        at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
        at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1595)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

a8156268 · 2021-07-15T13:20:40Z

Another deadlock:

=============================
"6881.bt.net.pool.connection-worker-49":
  waiting for ownable synchronizer 0x0000000151000040, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
  which is held by "6881.bt.net.pool.cleaner"
"6881.bt.net.pool.cleaner":
  waiting to lock monitor 0x0000000014c5eef8 (object 0x0000000151001fb0, a bt.torrent.messaging.TorrentWorker),
  which is held by "6881.bt.peer.peer-collector"
"6881.bt.peer.peer-collector":
  waiting for ownable synchronizer 0x0000000151000040, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
  which is held by "6881.bt.net.pool.cleaner"
  
===================================================
"6881.bt.net.pool.connection-worker-49":
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x0000000151000040> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
        at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
        at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
        at bt.net.PeerConnectionPool.addConnectionIfAbsent(PeerConnectionPool.java:131)
        at bt.net.IncomingConnectionListener.lambda$establishConnection$2(IncomingConnectionListener.java:89)
        at bt.net.IncomingConnectionListener$$Lambda$755/135765622.run(Unknown Source)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
		
"6881.bt.net.pool.cleaner":
        at bt.torrent.messaging.TorrentWorker.onPeerDisconnected(TorrentWorker.java:430)
        - waiting to lock <0x0000000151001fb0> (a bt.torrent.messaging.TorrentWorker)
        at bt.torrent.messaging.TorrentWorker.lambda$new$2(TorrentWorker.java:112)
        at bt.torrent.messaging.TorrentWorker$$Lambda$699/1957213216.accept(Unknown Source)
        at bt.event.EventBus.lambda$addListener$3(EventBus.java:248)
        at bt.event.EventBus$$Lambda$599/1570015850.accept(Unknown Source)
        at bt.event.EventBus.doFireEvent(EventBus.java:182)
        at bt.event.EventBus.fireEvent(EventBus.java:165)
        at bt.event.EventBus.firePeerDisconnected(EventBus.java:80)
        at bt.net.PeerConnectionPool.purgeConnection(PeerConnectionPool.java:265)
        at bt.net.PeerConnectionPool.access$200(PeerConnectionPool.java:48)
        at bt.net.PeerConnectionPool$Cleaner.lambda$run$0(PeerConnectionPool.java:241)
        at bt.net.PeerConnectionPool$Cleaner$$Lambda$792/3405922.accept(Unknown Source)
        at bt.net.Connections$$Lambda$793/250877460.accept(Unknown Source)
        at java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4707)
        at bt.net.Connections.visitConnections(PeerConnectionPool.java:334)
        at bt.net.PeerConnectionPool$Cleaner.run(PeerConnectionPool.java:239)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
		
		
"6881.bt.peer.peer-collector":
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x0000000151000040> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
        at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
        at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
        at bt.net.PeerConnectionPool.getConnection(PeerConnectionPool.java:87)
        at bt.net.ConnectionSource.getExistingOrPendingConnection(ConnectionSource.java:169)
        at bt.net.ConnectionSource.getConnectionAsync(ConnectionSource.java:89)
        at bt.torrent.messaging.TorrentWorker.onPeerDiscovered(TorrentWorker.java:412)
        - locked <0x0000000151001fb0> (a bt.torrent.messaging.TorrentWorker)
        at bt.torrent.messaging.TorrentWorker.lambda$new$0(TorrentWorker.java:108)
        at bt.torrent.messaging.TorrentWorker$$Lambda$695/415660731.accept(Unknown Source)
        at bt.event.EventBus.lambda$addListener$3(EventBus.java:248)
        at bt.event.EventBus$$Lambda$599/1570015850.accept(Unknown Source)
        at bt.event.EventBus.doFireEvent(EventBus.java:182)
        at bt.event.EventBus.fireEvent(EventBus.java:165)
        at bt.event.EventBus.firePeerDiscovered(EventBus.java:62)
        at bt.peer.PeerRegistry.addPeer(PeerRegistry.java:214)
        at bt.peer.PeerRegistry.queryPeerSource(PeerRegistry.java:194)
        at bt.peer.PeerRegistry.lambda$null$2(PeerRegistry.java:137)
        at bt.peer.PeerRegistry$$Lambda$720/999371603.accept(Unknown Source)
        at java.lang.Iterable.forEach(Iterable.java:75)
        at bt.peer.PeerRegistry.lambda$collectAndVisitPeers$3(PeerRegistry.java:136)
        at bt.peer.PeerRegistry$$Lambda$678/1741590285.accept(Unknown Source)
        at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
        at java.util.Collections$UnmodifiableCollection.forEach(Collections.java:1080)
        at bt.peer.PeerRegistry.collectAndVisitPeers(PeerRegistry.java:104)
        at bt.peer.PeerRegistry$$Lambda$676/355874953.run(Unknown Source)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

atomashpolskiy · 2021-07-15T21:02:40Z

Thanks for reporting! This needs some additional thought. Seems like the culprit here is not the EventBus but rather the TorrentWorker's synchronized methods (onPeerDiscovered and onPeerDisconnected in the cases that you've encountered, with onPeerDisconnected being the only method that is used by the pool cleaner). I'm not sure why these methods were marked synchronized at the moment they were added (61abc06) -- most probably to enforce the hard limit on the number of peers -- but there's a good chance that things that they do can be done in a different way that would not need lock- or monitor-based synchronization. And onPeerDisconnected method in particular looks like it does not need to be synchronized at all...

a8156268 · 2021-07-16T02:45:57Z

Yes, both EventBus and TorrentWorker have this issue.
Since EventBus also has synchronized methods(firePeerDiscovered and firePeerConnected and firePeerDisconnected) that same with TorrentWorker(onPeerDiscovered and onPeerDisconnected and onPeerDisconnected)

atomashpolskiy · 2021-07-16T07:24:16Z

I'm not 100% sure, but to me it looks like the problem is with TorrentWorker.onPeerDisconnected, because the deadlock involves the pool cleaner. The fact that the EventBus is synchronized only has the effect that events are processed one at a time, effectively turning it into a synchronous blocking queue with guaranteed order of event ids, which is probably intended. I'm not saying that this is a good design or that it can't lead to problems in other places, but the one that you're running into should be solved by making TorrentWorker.onPeerDisconnected not synchronized. It will create a race condition, but the limit on the number of peers should still hold.

…

On Fri, 16 Jul 2021, 04:46 maomao, ***@***.***> wrote: Yes, both EventBus and TorrentWorker have this issue. Since EventBus also has synchronized methods(firePeerDiscovered and firePeerConnected and firePeerDisconnected) that same with TorrentWorker(onPeerDiscovered and onPeerDisconnected and onPeerDisconnected) — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#170 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AA4TJBTQ6HSHXWUM35WNPJTTX6MPBANCNFSM5AJNF4YA> .

a8156268 · 2021-07-16T08:14:57Z

EventBus has 8 fireXXX methods, but only the 3 fireXXX methods marked as synchronized.
From git history, the 3 methods is original first 3 methods, and other 5 was added by flowing commits.
That is, events are processed one at a time is not 100% guaranteed.

atomashpolskiy · 2021-07-16T09:20:37Z

Ok, I will look into it and your PR in more detail in the nearest time

…

On Fri, 16 Jul 2021, 10:15 maomao, ***@***.***> wrote: EventBus has 8 fireXXX methods, but only the 3 fireXXX methods marked as synchronized. From git history, the 3 methods is original first 3 methods, and other 5 was added by flowing commits. That is, events are processed one at a time is not 100% guaranteed. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#170 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AA4TJBQL5YBTCLXRQUDDEVDTX7TAXANCNFSM5AJNF4YA> .

…iy#170

pyckle · 2021-07-18T10:35:44Z

Please also see the above pull request too. It uses lockfree algorithms to remove synchronization from TorrentWorker while ensuring that the limits set in the configuration are exactly adhered to.

…iy#170

Update comment, fix more race conditions related to Bug: #170

a8156268 added the bug label Jul 13, 2021

a8156268 mentioned this issue Jul 14, 2021

remove sync lock on EventBus #177

Closed

pyckle added a commit to pyckle/bt that referenced this issue Jul 16, 2021

Use lockfree algorithms for PeerConnection limiting Bug: atomashpolsk…

20921a7

…iy#170

atomashpolskiy added a commit that referenced this issue Jul 19, 2021

Use lockfree algorithms for PeerConnection limiting Bug: #170

622fea0

atomashpolskiy added this to the 1.10 milestone Jul 19, 2021

atomashpolskiy linked a pull request Jul 19, 2021 that will close this issue

Use lockfree algorithms for PeerConnection limiting Bug: #170 #179

Merged

atomashpolskiy closed this as completed Jul 19, 2021

pyckle added a commit to pyckle/bt that referenced this issue Jul 20, 2021

Update comment, fix more race conditions related to Bug: atomashpolsk…

8ac1b8a

…iy#170

pyckle added a commit to pyckle/bt that referenced this issue Jul 20, 2021

Update comment, fix more race conditions related to Bug: atomashpolsk…

3add77c

…iy#170

atomashpolskiy added a commit that referenced this issue Jul 20, 2021

Merge pull request #180 from pyckle/connsource_locking

0f94c34

Update comment, fix more race conditions related to Bug: #170

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[BUG]a dead lock case #170

[BUG]a dead lock case #170

a8156268 commented Jul 13, 2021

a8156268 commented Jul 13, 2021 •

edited

Loading

a8156268 commented Jul 13, 2021

a8156268 commented Jul 15, 2021

atomashpolskiy commented Jul 15, 2021

a8156268 commented Jul 16, 2021

atomashpolskiy commented Jul 16, 2021 via email

a8156268 commented Jul 16, 2021

atomashpolskiy commented Jul 16, 2021 via email

pyckle commented Jul 18, 2021

[BUG]a dead lock case #170

[BUG]a dead lock case #170

Comments

a8156268 commented Jul 13, 2021

a8156268 commented Jul 13, 2021 • edited Loading

a8156268 commented Jul 13, 2021

a8156268 commented Jul 15, 2021

atomashpolskiy commented Jul 15, 2021

a8156268 commented Jul 16, 2021

atomashpolskiy commented Jul 16, 2021 via email

a8156268 commented Jul 16, 2021

atomashpolskiy commented Jul 16, 2021 via email

pyckle commented Jul 18, 2021

a8156268 commented Jul 13, 2021 •

edited

Loading