gephi / gephi-plugins

Repository for Gephi Plugins maintained by the team. Each plugin has it's branch.
269 stars 620 forks source link

[DEV] Reach DeadLock even if using writeLock() #250

Closed totetmatt closed 2 years ago

totetmatt commented 2 years ago

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

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 :

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/ writeUnlockshould appears before and after any graph change.

mbastian commented 2 years ago

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.

totetmatt commented 2 years ago

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

totetmatt commented 2 years ago

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 ?