search

eclipse-equinox / equinox

equinox
Eclipse Public License 2.0
33 stars 66 forks source link

Deadlock at startup with Build id: I20221031-1800 #148

Closed vogella closed 1 year ago

vogella commented 2 years ago

Latest Eclipse takes very long to start, see below for a stack trace.

It recovers after multiple minutes and starts Eclipse.

2022-11-01 10:06:39 Full thread dump OpenJDK 64-Bit Server VM (17.0.3+7 mixed mode, sharing):

Threads class SMR info: _java_thread_list=0x00007f1ae0001890, length=23, elements={ 0x00007f1b28024a00, 0x00007f1b28192ee0, 0x00007f1b281942c0, 0x00007f1b281999e0, 0x00007f1b2819ad90, 0x00007f1b2819c1a0, 0x00007f1b2819db50, 0x00007f1b2819f080, 0x00007f1b281a84e0, 0x00007f1b281b3be0, 0x00007f1b281f2740, 0x00007f1b284d8980, 0x00007f1b283ae4f0, 0x00007f1b2881f6f0, 0x00007f1a7002e460, 0x00007f1a7032a970, 0x00007f1a70692210, 0x00007f1a7c0ff4a0, 0x00007f1b2881beb0, 0x00007f1b28e60830, 0x00007f1b28f4be70, 0x00007f1b28f58880, 0x00007f1ae0000eb0 }

"main" #1 prio=6 os_prio=0 cpu=1079.89ms elapsed=54.93s tid=0x00007f1b28024a00 nid=0x2790 waiting on condition [0x00007f1b2db43000] java.lang.Thread.State: TIMED_WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@17.0.3/Native Method)

"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=0.65ms elapsed=54.89s tid=0x00007f1b28192ee0 nid=0x2797 waiting on condition [0x00007f1b0c7c3000] java.lang.Thread.State: RUNNABLE at java.lang.ref.Reference.waitForReferencePendingList(java.base@17.0.3/Native Method) at java.lang.ref.Reference.processPendingReferences(java.base@17.0.3/Reference.java:253) at java.lang.ref.Reference$ReferenceHandler.run(java.base@17.0.3/Reference.java:215)

"Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.52ms elapsed=54.89s tid=0x00007f1b281942c0 nid=0x2798 in Object.wait() [0x00007f1b0c6c3000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.29ms elapsed=54.89s tid=0x00007f1b281999e0 nid=0x2799 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE

"Service Thread" #5 daemon prio=9 os_prio=0 cpu=0.37ms elapsed=54.89s tid=0x00007f1b2819ad90 nid=0x279a runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE

"Monitor Deflation Thread" #6 daemon prio=9 os_prio=0 cpu=2.31ms elapsed=54.89s tid=0x00007f1b2819c1a0 nid=0x279b runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #7 daemon prio=9 os_prio=0 cpu=1022.38ms elapsed=54.89s tid=0x00007f1b2819db50 nid=0x279c waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE No compile task

"C1 CompilerThread0" #10 daemon prio=9 os_prio=0 cpu=859.60ms elapsed=54.89s tid=0x00007f1b2819f080 nid=0x279d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE No compile task

"Sweeper thread" #11 daemon prio=9 os_prio=0 cpu=3.33ms elapsed=54.89s tid=0x00007f1b281a84e0 nid=0x279e runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE

"Common-Cleaner" #12 daemon prio=8 os_prio=0 cpu=0.57ms elapsed=54.88s tid=0x00007f1b281b3be0 nid=0x279f in Object.wait() [0x00007f1afdefe000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"Notification Thread" #13 daemon prio=9 os_prio=0 cpu=0.04ms elapsed=54.87s tid=0x00007f1b281f2740 nid=0x27a1 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE

"Active Thread: Equinox Container: 155c388c-4a71-49ba-867b-426763faabcc" #15 prio=5 os_prio=0 cpu=1.10ms elapsed=54.56s tid=0x00007f1b284d8980 nid=0x27b4 waiting on condition [0x00007f1aa6eeb000] java.lang.Thread.State: TIMED_WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@17.0.3/Native Method)

"Framework Event Dispatcher: Equinox Container: 155c388c-4a71-49ba-867b-426763faabcc" #17 daemon prio=5 os_prio=0 cpu=74.47ms elapsed=54.47s tid=0x00007f1b283ae4f0 nid=0x27b5 in Object.wait() [0x00007f1aa6deb000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"Start Level: Equinox Container: 155c388c-4a71-49ba-867b-426763faabcc" #18 daemon prio=5 os_prio=0 cpu=595.80ms elapsed=54.47s tid=0x00007f1b2881f6f0 nid=0x27b6 in Object.wait() [0x00007f1aa6ceb000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"SCR Component Actor" #19 daemon prio=5 os_prio=0 cpu=10.77ms elapsed=54.46s tid=0x00007f1a7002e460 nid=0x27b7 waiting on condition [0x00007f1aa6b63000] java.lang.Thread.State: TIMED_WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@17.0.3/Native Method)

"Bundle File Closer" #21 daemon prio=5 os_prio=0 cpu=10.44ms elapsed=54.24s tid=0x00007f1a7032a970 nid=0x27b9 in Object.wait() [0x00007f1aa6965000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"Worker-JM" #23 prio=5 os_prio=0 cpu=0.10ms elapsed=53.92s tid=0x00007f1a70692210 nid=0x27ba in Object.wait() [0x00007f1aa5ffe000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"EMF Reference Cleaner" #24 daemon prio=5 os_prio=0 cpu=0.19ms elapsed=53.83s tid=0x00007f1a7c0ff4a0 nid=0x27bd in Object.wait() [0x00007f1aa5cfa000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"Gogo shell" #26 prio=5 os_prio=0 cpu=6.49ms elapsed=53.77s tid=0x00007f1b2881beb0 nid=0x27be waiting on condition [0x00007f1aa5bfa000] java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@17.0.3/Native Method)

"Worker-0" #30 prio=5 os_prio=0 cpu=0.27ms elapsed=52.44s tid=0x00007f1b28e60830 nid=0x27e1 in Object.wait() [0x00007f1aa59fa000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"BC Entropy Daemon" #31 daemon prio=6 os_prio=0 cpu=0.62ms elapsed=52.37s tid=0x00007f1b28f4be70 nid=0x27e2 waiting on condition [0x00007f1aa5afa000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(java.base@17.0.3/Native Method) at org.bouncycastle.jcajce.provider.drbg.DRBG$EntropyDaemon.run(Unknown Source) at java.lang.Thread.run(java.base@17.0.3/Thread.java:833)

"Git Repository Closer" #32 daemon prio=6 os_prio=0 cpu=0.13ms elapsed=52.36s tid=0x00007f1b28f58880 nid=0x27e3 in Object.wait() [0x00007f1a4c2fa000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@17.0.3/Native Method)

"Attach Listener" #33 daemon prio=9 os_prio=0 cpu=0.63ms elapsed=19.81s tid=0x00007f1ae0000eb0 nid=0x282c waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE

"VM Thread" os_prio=0 cpu=30.20ms elapsed=54.90s tid=0x00007f1b2818ee90 nid=0x2796 runnable

"GC Thread#0" os_prio=0 cpu=13.00ms elapsed=54.91s tid=0x00007f1b28081650 nid=0x2791 runnable

"GC Thread#1" os_prio=0 cpu=13.90ms elapsed=54.58s tid=0x00007f1af4005cd0 nid=0x27ab runnable

"GC Thread#2" os_prio=0 cpu=14.55ms elapsed=54.58s tid=0x00007f1af4006740 nid=0x27ac runnable

"GC Thread#3" os_prio=0 cpu=15.91ms elapsed=54.58s tid=0x00007f1af40071b0 nid=0x27ad runnable

"GC Thread#4" os_prio=0 cpu=11.49ms elapsed=54.58s tid=0x00007f1af4008010 nid=0x27ae runnable

"GC Thread#5" os_prio=0 cpu=12.68ms elapsed=54.58s tid=0x00007f1af4008e90 nid=0x27af runnable

"GC Thread#6" os_prio=0 cpu=1.90ms elapsed=53.88s tid=0x00007f1af400f020 nid=0x27bb runnable

"GC Thread#7" os_prio=0 cpu=4.23ms elapsed=53.88s tid=0x00007f1af40123d0 nid=0x27bc runnable

"G1 Main Marker" os_prio=0 cpu=0.60ms elapsed=54.91s tid=0x00007f1b28092c50 nid=0x2792 runnable

"G1 Conc#0" os_prio=0 cpu=15.01ms elapsed=54.91s tid=0x00007f1b28093bb0 nid=0x2793 runnable

"G1 Conc#1" os_prio=0 cpu=15.90ms elapsed=52.48s tid=0x00007f1b00000eb0 nid=0x27de runnable

"G1 Refine#0" os_prio=0 cpu=6.71ms elapsed=54.91s tid=0x00007f1b28160fc0 nid=0x2794 runnable

"G1 Refine#1" os_prio=0 cpu=4.62ms elapsed=54.58s tid=0x00007f1af8000eb0 nid=0x27b0 runnable

"G1 Refine#2" os_prio=0 cpu=3.44ms elapsed=54.58s tid=0x00007f1a88000eb0 nid=0x27b1 runnable

"G1 Refine#3" os_prio=0 cpu=2.11ms elapsed=54.58s tid=0x00007f1a8c000eb0 nid=0x27b2 runnable

"G1 Refine#4" os_prio=0 cpu=0.03ms elapsed=54.58s tid=0x00007f1a80000eb0 nid=0x27b3 runnable

"G1 Service" os_prio=0 cpu=13.76ms elapsed=54.91s tid=0x00007f1b28161eb0 nid=0x2795 runnable

"VM Periodic Task Thread" os_prio=0 cpu=48.97ms elapsed=54.87s tid=0x00007f1b281f40b0 nid=0x27a2 waiting on condition

JNI global refs: 82, weak refs: 0

Found one Java-level deadlock:

"main": waiting for ownable synchronizer 0x000000008d6d8a38, (a java.util.concurrent.locks.ReentrantLock$NonfairSync), which is held by "SCR Component Actor"

"SCR Component Actor": waiting for ownable synchronizer 0x0000000080202560, (a java.util.concurrent.locks.ReentrantLock$NonfairSync), which is held by "main"

Java stack information for the threads listed above:

"main": at jdk.internal.misc.Unsafe.park(java.base@17.0.3/Native Method)

Found 1 deadlock.

vogella commented 2 years ago

cc @iloveeclipse @jukzi @HannesWell @laeubi

jukzi commented 2 years ago

does not look like a deadlock. rather like a module with a slow state change. for a performance problem sampling results would help more then single stacktrace

HannesWell commented 2 years ago

The analysis says it is a deadlock and I can see the look for which the threads are waiting from the lock, but I cannot see when the two involved threads start to hold the involved locks. Or it is just not displayed.

github-actions[bot] commented 1 year ago

This issue has been inactive for 180 days and is therefore labeled as stale. If this issue became irrelevant in the meantime please close it as completed. If it is still relevant and you think it should be fixed some possibilities are listed below. Please read https://github.com/eclipse-equinox/.github/blob/main/CONTRIBUTING.md#contributing-to-eclipse-equinox for ways to influence development.