[DEV] Reach DeadLock even if using writeLock()

Question

[DEV] Reach DeadLock even if using writeLock()

totetmatt opened this issue 3 years ago · 3 comments

Context

I'm developping new version of twitter streaming importer. I can build from netbeans, run it and it looks to "works" on the sense that I can generate new entities (nodes & edges) from a stream.

However, somehow the program can enter into a deadlock.

How to reproduce

(Might be difficult as it asks for a configured twitter app)

Using this fork https://github.com/totetmatt/gephi-plugins/tree/twitter_v2

Build and Start gephi with plugin.
Get credential and have some search registered.
Run any network (user network usualy lock faster)
Node > Size Node >Ranking > Choose Degree from 1 to 50, Link & Auto Execute
Run FA2 with
Display label with font size based on node size
Wait an undetermined amount of time

I didn't manage to understand when and why it enter the states, therefore it might take sometime or few seconds before the application freeze (graph not updated, UI unresponsive)

Looks like it only have issue when using the Auto resize by degree (see thread dump after and I tried same process without auto resize, no isse detected)

Pre-investigation

Thread dump from jvisualvm gives this :

Found one Java-level deadlock:
=============================
"DataLaboratoryGraphObservers":
  waiting for ownable synchronizer 0x0000000605711110, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
  which is held by "Appearance Auto Transformer"
"Appearance Auto Transformer":
  waiting for ownable synchronizer 0x00000006052373a8, (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync),
  which is held by "Twitter Streaming Importer v2 : TweetsListenersExecutor"
"Twitter Streaming Importer v2 : TweetsListenersExecutor":
  waiting for ownable synchronizer 0x0000000605711110, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
  which is held by "Appearance Auto Transformer"

Java stack information for the threads listed above:
===================================================
"DataLaboratoryGraphObservers":
        at jdk.internal.misc.Unsafe.park(java.base@11.0.13/Native Method)
        - parking to wait for  <0x0000000605711110> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.13/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.13/AbstractQueuedSynchronizer.java:885)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.13/AbstractQueuedSynchronizer.java:917)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.13/AbstractQueuedSynchronizer.java:1240)
        at java.util.concurrent.locks.ReentrantLock.lock(java.base@11.0.13/ReentrantLock.java:267)
        at org.gephi.graph.impl.TableLockImpl.lock(TableLockImpl.java:31)
        at org.gephi.graph.impl.ColumnStore.lock(ColumnStore.java:356)
        at org.gephi.graph.impl.ColumnStore$ColumnStoreIterator.<init>(ColumnStore.java:405)
        at org.gephi.graph.impl.ColumnStore.deepHashCode(ColumnStore.java:458)
        at org.gephi.graph.impl.TableImpl.deepHashCode(TableImpl.java:259)
        at org.gephi.graph.impl.TableObserverImpl.hasTableChanged(TableObserverImpl.java:44)
        - locked <0x0000000605792528> (a org.gephi.graph.impl.TableObserverImpl)
        at org.gephi.desktop.filters.WorkspaceColumnsObservers.processTableObseverChanges(WorkspaceColumnsObservers.java:100)
        at org.gephi.desktop.filters.WorkspaceColumnsObservers.hasChanges(WorkspaceColumnsObservers.java:93)
        at org.gephi.desktop.filters.FiltersTopComponent$2.run(FiltersTopComponent.java:165)
        at java.util.TimerThread.mainLoop(java.base@11.0.13/Timer.java:556)
        at java.util.TimerThread.run(java.base@11.0.13/Timer.java:506)
"Appearance Auto Transformer":
        at jdk.internal.misc.Unsafe.park(java.base@11.0.13/Native Method)
        - parking to wait for  <0x00000006052373a8> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.13/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.13/AbstractQueuedSynchronizer.java:885)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.13/AbstractQueuedSynchronizer.java:1009)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.13/AbstractQueuedSynchronizer.java:1324)
        at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.13/ReentrantReadWriteLock.java:738)
        at org.gephi.graph.impl.GraphLockImpl.readLock(GraphLockImpl.java:37)
        at org.gephi.graph.impl.NodeStore.readLock(NodeStore.java:489)
        at org.gephi.graph.impl.NodeStore$NodeStoreIterator.<init>(NodeStore.java:627)
        at org.gephi.graph.impl.NodeStore.iterator(NodeStore.java:166)
        at org.gephi.graph.impl.NodeStore.iterator(NodeStore.java:31)
        at org.gephi.graph.impl.DegreeNoIndexImpl.getMinValue(DegreeNoIndexImpl.java:82)
        at org.gephi.graph.impl.DegreeNoIndexImpl.getMinValue(DegreeNoIndexImpl.java:13)
        at org.gephi.graph.impl.IndexImpl.getMinValue(IndexImpl.java:116)
        at org.gephi.appearance.DegreeRankingImpl.getMinValue(DegreeRankingImpl.java:72)
        at org.gephi.appearance.FunctionImpl.transformAll(FunctionImpl.java:118)
        at org.gephi.appearance.AppearanceControllerImpl.transform(AppearanceControllerImpl.java:122)
        at org.gephi.desktop.appearance.AppearanceUIController.transform(AppearanceUIController.java:167)
        at org.gephi.desktop.appearance.AutoAppyTransformer.run(AutoAppyTransformer.java:81)
        at java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.13/Executors.java:515)
        at java.util.concurrent.FutureTask.runAndReset(java.base@11.0.13/FutureTask.java:305)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@11.0.13/ScheduledThreadPoolExecutor.java:305)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.13/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.13/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.13/Thread.java:834)
"Twitter Streaming Importer v2 : TweetsListenersExecutor":
        at jdk.internal.misc.Unsafe.park(java.base@11.0.13/Native Method)
        - parking to wait for  <0x0000000605711110> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.13/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.13/AbstractQueuedSynchronizer.java:885)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.13/AbstractQueuedSynchronizer.java:917)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.13/AbstractQueuedSynchronizer.java:1240)
        at java.util.concurrent.locks.ReentrantLock.lock(java.base@11.0.13/ReentrantLock.java:267)
        at org.gephi.graph.impl.TableLockImpl.lock(TableLockImpl.java:31)
        at org.gephi.graph.impl.ColumnStore.lock(ColumnStore.java:356)
        at org.gephi.graph.impl.ColumnStore.getColumnByIndex(ColumnStore.java:205)
        at org.gephi.graph.impl.ElementImpl.setLabel(ElementImpl.java:88)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.createNode(Networklogic.java:149)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.createUser(Networklogic.java:212)
        at fr.totetmatt.gephi.twitter.networklogics.UserNetwork.onStatus(UserNetwork.java:57)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.actionOnTweetsStream(Networklogic.java:52)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.actionOnTweetsStream(Networklogic.java:29)
        at fr.totetmatt.gephi.twitter.utils.listener.filtered.TweetsStreamListenersExecutor$TweetsListenersExecutor.processTweets(TweetsStreamListenersExecutor.java:97)
        at fr.totetmatt.gephi.twitter.utils.listener.filtered.TweetsStreamListenersExecutor$TweetsListenersExecutor.run(TweetsStreamListenersExecutor.java:85)

Found 1 deadlock.

Code explain in the plugin

The library, twitter-api-java-sdk , doesn't have yet a listener version for stream of tweet so most of the technical code is based on example from the library with minor adjustment.

When starting the stream 2 threads are created :

One that manage the input stream and at each line push the result into a queue : https://github.com/totetmatt/gephi-plugins/blob/twitter_v2/modules/TwitterV2/src/main/java/fr/totetmatt/gephi/twitter/utils/listener/filtered/TweetsStreamListenersExecutor.java#L106-L133
One that pop from this queue and dispatch it to any listener : https://github.com/totetmatt/gephi-plugins/blob/twitter_v2/modules/TwitterV2/src/main/java/fr/totetmatt/gephi/twitter/utils/listener/filtered/TweetsStreamListenersExecutor.java#L81-L103

The listener is defined by the interface TweetsStreamListener<T> that my abstract class Networklogic implements for all kind of network generation https://github.com/totetmatt/gephi-plugins/blob/twitter_v2/modules/TwitterV2/src/main/java/fr/totetmatt/gephi/twitter/networklogics/Networklogic.java#L36-L56

And here actionOnTweetsStream is mainly a wrapper that do the graph.writeLock / writeUnlock around onStatus that do the work for creating node and edges.

I don't really see where the lock could come from as on the plugin the writeLock / writeUnlock should appears before and after any graph change.

Answer 1 · 2022-05-27T11:29:54.000Z

Thanks @totetmatt for the detailed report. Seems like the issue is related to the Appearance Module, which its core was rewritten for 0.9.3 so it's possible some sync issues were created. Just to confirm, when you say "Auto resize by degree" you mean using the default "auto-apply" feature in Appearance? Let me dig into it and I'll let you know what I find.

Answer 2 · 2022-05-27T12:25:47.000Z

you mean using the default "auto-apply"
Yes exactly

Answer 3 · 2022-05-31T17:14:32.000Z

Manage to find another deadlock, while running ,just simply applying a new Size by degree (1 - 50) generates this dead lock

Found one Java-level deadlock:
=============================
"AWT-EventQueue-0":
  waiting for ownable synchronizer 0x000000060772f150, (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync),
  which is held by "Twitter Streaming Importer v2 : TweetsListenersExecutor"
"Twitter Streaming Importer v2 : TweetsListenersExecutor":
  waiting for ownable synchronizer 0x0000000607d5e278, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
  which is held by "AWT-EventQueue-0"

Java stack information for the threads listed above:
===================================================
"AWT-EventQueue-0":
        at jdk.internal.misc.Unsafe.park(java.base@11.0.13/Native Method)
        - parking to wait for  <0x000000060772f150> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.13/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.13/AbstractQueuedSynchronizer.java:885)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.13/AbstractQueuedSynchronizer.java:1009)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.13/AbstractQueuedSynchronizer.java:1324)
        at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.13/ReentrantReadWriteLock.java:738)
        at org.gephi.graph.impl.GraphLockImpl.readLock(GraphLockImpl.java:37)
        at org.gephi.graph.impl.NodeStore.readLock(NodeStore.java:489)
        at org.gephi.graph.impl.NodeStore$NodeStoreIterator.<init>(NodeStore.java:627)
        at org.gephi.graph.impl.NodeStore.iterator(NodeStore.java:166)
        at org.gephi.graph.impl.NodeStore.iterator(NodeStore.java:31)
        at org.gephi.graph.impl.DegreeNoIndexImpl.getMinValue(DegreeNoIndexImpl.java:82)
        at org.gephi.graph.impl.DegreeNoIndexImpl.getMinValue(DegreeNoIndexImpl.java:13)
        at org.gephi.graph.impl.IndexImpl.getMinValue(IndexImpl.java:116)
        at org.gephi.appearance.DegreeRankingImpl.getMinValue(DegreeRankingImpl.java:72)
        at org.gephi.appearance.FunctionImpl.transformAll(FunctionImpl.java:118)
        at org.gephi.appearance.AppearanceControllerImpl.transform(AppearanceControllerImpl.java:122)
        at org.gephi.desktop.appearance.AppearanceUIController.transform(AppearanceUIController.java:167)
        at org.gephi.desktop.appearance.AppearanceTopComponent$8.actionPerformed(AppearanceTopComponent.java:414)
        at javax.swing.AbstractButton.fireActionPerformed(java.desktop@11.0.13/AbstractButton.java:1967)
        at javax.swing.AbstractButton$Handler.actionPerformed(java.desktop@11.0.13/AbstractButton.java:2308)
        at javax.swing.DefaultButtonModel.fireActionPerformed(java.desktop@11.0.13/DefaultButtonModel.java:405)
        at javax.swing.DefaultButtonModel.setPressed(java.desktop@11.0.13/DefaultButtonModel.java:262)
        at javax.swing.plaf.basic.BasicButtonListener.mouseReleased(java.desktop@11.0.13/BasicButtonListener.java:279)
        at java.awt.AWTEventMulticaster.mouseReleased(java.desktop@11.0.13/AWTEventMulticaster.java:297)
        at java.awt.Component.processMouseEvent(java.desktop@11.0.13/Component.java:6635)
        at javax.swing.JComponent.processMouseEvent(java.desktop@11.0.13/JComponent.java:3342)
        at java.awt.Component.processEvent(java.desktop@11.0.13/Component.java:6400)
        at java.awt.Container.processEvent(java.desktop@11.0.13/Container.java:2263)
        at java.awt.Component.dispatchEventImpl(java.desktop@11.0.13/Component.java:5011)
        at java.awt.Container.dispatchEventImpl(java.desktop@11.0.13/Container.java:2321)
        at java.awt.Component.dispatchEvent(java.desktop@11.0.13/Component.java:4843)
        at java.awt.LightweightDispatcher.retargetMouseEvent(java.desktop@11.0.13/Container.java:4918)
        at java.awt.LightweightDispatcher.processMouseEvent(java.desktop@11.0.13/Container.java:4547)
        at java.awt.LightweightDispatcher.dispatchEvent(java.desktop@11.0.13/Container.java:4488)
        at java.awt.Container.dispatchEventImpl(java.desktop@11.0.13/Container.java:2307)
        at java.awt.Window.dispatchEventImpl(java.desktop@11.0.13/Window.java:2772)
        at java.awt.Component.dispatchEvent(java.desktop@11.0.13/Component.java:4843)
        at java.awt.EventQueue.dispatchEventImpl(java.desktop@11.0.13/EventQueue.java:772)
        at java.awt.EventQueue$4.run(java.desktop@11.0.13/EventQueue.java:721)
        at java.awt.EventQueue$4.run(java.desktop@11.0.13/EventQueue.java:715)
        at java.security.AccessController.doPrivileged(java.base@11.0.13/Native Method)
        at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(java.base@11.0.13/ProtectionDomain.java:85)
        at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(java.base@11.0.13/ProtectionDomain.java:95)
        at java.awt.EventQueue$5.run(java.desktop@11.0.13/EventQueue.java:745)
        at java.awt.EventQueue$5.run(java.desktop@11.0.13/EventQueue.java:743)
        at java.security.AccessController.doPrivileged(java.base@11.0.13/Native Method)
        at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(java.base@11.0.13/ProtectionDomain.java:85)
        at java.awt.EventQueue.dispatchEvent(java.desktop@11.0.13/EventQueue.java:742)
        at org.netbeans.core.TimableEventQueue.dispatchEvent(TimableEventQueue.java:136)
        at java.awt.EventDispatchThread.pumpOneEventForFilters(java.desktop@11.0.13/EventDispatchThread.java:203)
        at java.awt.EventDispatchThread.pumpEventsForFilter(java.desktop@11.0.13/EventDispatchThread.java:124)
        at java.awt.EventDispatchThread.pumpEventsForHierarchy(java.desktop@11.0.13/EventDispatchThread.java:113)
        at java.awt.EventDispatchThread.pumpEvents(java.desktop@11.0.13/EventDispatchThread.java:109)
        at java.awt.EventDispatchThread.pumpEvents(java.desktop@11.0.13/EventDispatchThread.java:101)
        at java.awt.EventDispatchThread.run(java.desktop@11.0.13/EventDispatchThread.java:90)
"Twitter Streaming Importer v2 : TweetsListenersExecutor":
        at jdk.internal.misc.Unsafe.park(java.base@11.0.13/Native Method)
        - parking to wait for  <0x0000000607d5e278> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.13/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.13/AbstractQueuedSynchronizer.java:885)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.13/AbstractQueuedSynchronizer.java:917)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.13/AbstractQueuedSynchronizer.java:1240)
        at java.util.concurrent.locks.ReentrantLock.lock(java.base@11.0.13/ReentrantLock.java:267)
        at org.gephi.graph.impl.TableLockImpl.lock(TableLockImpl.java:31)
        at org.gephi.graph.impl.ColumnStore.lock(ColumnStore.java:356)
        at org.gephi.graph.impl.ColumnStore.getColumnByIndex(ColumnStore.java:205)
        at org.gephi.graph.impl.ElementImpl.setLabel(ElementImpl.java:88)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.createNode(Networklogic.java:162)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.createUser(Networklogic.java:211)
        at fr.totetmatt.gephi.twitter.networklogics.UserNetwork.generateUsers(UserNetwork.java:60)
        at fr.totetmatt.gephi.twitter.networklogics.UserNetwork.onStatus(UserNetwork.java:108)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.actionOnTweetsStream(Networklogic.java:61)
        - locked <0x00000006065952f8> (a fr.totetmatt.gephi.twitter.networklogics.UserNetwork)
        at fr.totetmatt.gephi.twitter.networklogics.Networklogic.actionOnTweetsStream(Networklogic.java:33)
        at fr.totetmatt.gephi.twitter.utils.listener.filtered.TweetsStreamListenersExecutor$TweetsListenersExecutor.processTweets(TweetsStreamListenersExecutor.java:97)
        at fr.totetmatt.gephi.twitter.utils.listener.filtered.TweetsStreamListenersExecutor$TweetsListenersExecutor.run(TweetsStreamListenersExecutor.java:85)

Found 1 deadlock.

I'm using Graph graph = graphModel.getGraph(); write and read lock. Is there other lock to acquire actually ?