Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Problem cancelling loading huge session #115

Open
olegs opened this issue Apr 21, 2020 · 2 comments
Open

Problem cancelling loading huge session #115

olegs opened this issue Apr 21, 2020 · 2 comments
Labels
bug Something isn't working

Comments

@olegs
Copy link
Contributor

olegs commented Apr 21, 2020

Original report by Roman Chernyatchik

  1. Load big session
  2. Press Cancel
  3. Menus actions are disabled (AWT thread still working)
020-04-21 21:38:39,765 INFO [AWT-EventQueue-0] o.j.b.b.f.Session [Session.kt:172] Navigate: 1:138655775-154233939
2020-04-21 21:38:39,765 INFO [ForkJoinPool-9-worker-13] o.j.b.b.GenomeBrowser [LoggerExtensions.kt:35] Preprocessing track 'repeats_hg19_LINE.bed': [CANCELED] after 15.18 s
2020-04-21 21:38:39,766 INFO [AWT-EventQueue-0] o.j.b.b.f.Session [Session.kt:222] Session /Users/romeo/work/aging-wgbs/_playground/_wgbs_dmrs/_sessions_/y2020_rrbs_paper_vs_pipeline.yaml loaded
2020-04-21 21:38:39,766 INFO [ForkJoinPool-9-worker-7] o.j.b.b.GenomeBrowser [LoggerExtensions.kt:35] Preprocessing track 'repeats_hg19_SINE.bed': [CANCELED] after 14.81 s
2020-04-21 21:38:39,767 INFO [Thread-7] o.j.b.b.GenomeBrowser [ProgressDialog.kt:175] [CANCELED] Opening session: y2020_rrbs_paper_vs_pipeline.yaml

jstack utility shows that AWT thread is processing dialog, looks like cancellation failed and JBR tries to load all tracks in background on AWT

AWT-EventQueue-0" #18 prio=6 os_prio=31 cpu=125330.93ms elapsed=161.87s tid=0x00007ffb9f318000 nid=0x10b03 runnable  [0x00007000105f7000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.String.regionMatches([email protected]/Unknown Source)
	at kotlin.text.StringsKt__StringsJVMKt.regionMatches(StringsJVM.kt:533)
	at kotlin.text.StringsKt__StringsKt.findAnyOf$StringsKt__StringsKt(Strings.kt:905)
	at kotlin.text.StringsKt__StringsKt.access$findAnyOf(Strings.kt:1)
	at kotlin.text.StringsKt__StringsKt$rangesDelimitedBy$4.invoke(Strings.kt:1167)
	at kotlin.text.StringsKt__StringsKt$rangesDelimitedBy$4.invoke(Strings.kt)
	at kotlin.text.DelimitedRangesSequence$iterator$1.calcNext(Strings.kt:1095)
	at kotlin.text.DelimitedRangesSequence$iterator$1.hasNext(Strings.kt:1124)
	at kotlin.sequences.TransformingSequence$iterator$1.hasNext(Sequences.kt:176)
	at kotlin.sequences.SequencesKt___SequencesKt.toCollection(_Sequences.kt:702)
	at kotlin.sequences.SequencesKt___SequencesKt.toMutableList(_Sequences.kt:732)
	at kotlin.sequences.SequencesKt___SequencesKt.toList(_Sequences.kt:723)
	at kotlin.text.StringsKt__StringsKt.lines(Strings.kt:1287)
	at org.jetbrains.bio.browser.desktop.dialogs.ProgressDialog$1$append$1.run(ProgressDialog.kt:61)
	at java.awt.event.InvocationEvent.dispatch([email protected]/Unknown Source)
	at java.awt.EventQueue.dispatchEventImpl([email protected]/Unknown Source)
	at java.awt.EventQueue$4.run([email protected]/Unknown Source)
	at java.awt.EventQueue$4.run([email protected]/Unknown Source)
	at java.security.AccessController.doPrivileged([email protected]/Native Method)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege([email protected]/Unknown Source)
	at java.awt.EventQueue.dispatchEvent([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpOneEventForFilters([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForFilter([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.run([email protected]/Unknown Source)
@olegs olegs added the bug Something isn't working label Apr 21, 2020
@iromeo
Copy link
Contributor

iromeo commented Apr 21, 2020

In my case noticeable ui freeze noticed on 2-nd attempt to open large session, 1st seems to be ok and UI was responsive.

@iromeo
Copy link
Contributor

iromeo commented Apr 21, 2020

full trace

2020-04-21 21:40:30
Full thread dump OpenJDK 64-Bit Server VM (11.0.6+10-LTS mixed mode):

Threads class SMR info:
_java_thread_list=0x0000600003633e80, length=18, elements={
0x00007ffb9f808800, 0x00007ffba080c000, 0x00007ffba081b800, 0x00007ffba081c800,
0x00007ffb9e007800, 0x00007ffb9e01a800, 0x00007ffb9f018800, 0x00007ffb9f019000,
0x00007ffba096c000, 0x00007ffba0969000, 0x00007ffb9e19f800, 0x00007ffb9f2fd000,
0x00007ffb9f318000, 0x00007ffba0e15000, 0x00007ffba0a03000, 0x00007ffb9f128800,
0x00007ffb9f93d000, 0x00007ffba700d000
}

"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=2262.34ms elapsed=163.00s tid=0x00007ffb9f808800 nid=0x3e03 waiting on condition  [0x000070000eeab000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList([email protected]/Native Method)
	at java.lang.ref.Reference.processPendingReferences([email protected]/Unknown Source)
	at java.lang.ref.Reference$ReferenceHandler.run([email protected]/Unknown Source)

"Finalizer" #3 daemon prio=8 os_prio=31 cpu=4.36ms elapsed=163.00s tid=0x00007ffba080c000 nid=0x4003 in Object.wait()  [0x000070000efae000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait([email protected]/Native Method)
	- waiting on <no object reference available>
	at java.lang.ref.ReferenceQueue.remove([email protected]/Unknown Source)
	- waiting to re-lock in wait() <0x0000000783d0ad80> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove([email protected]/Unknown Source)
	at java.lang.ref.Finalizer$FinalizerThread.run([email protected]/Unknown Source)

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=0.34ms elapsed=162.99s tid=0x00007ffba081b800 nid=0x5603 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=31 cpu=12913.74ms elapsed=162.99s tid=0x00007ffba081c800 nid=0xa503 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C1 CompilerThread0" #8 daemon prio=9 os_prio=31 cpu=2714.15ms elapsed=162.99s tid=0x00007ffb9e007800 nid=0xa303 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"Sweeper thread" #9 daemon prio=9 os_prio=31 cpu=80.06ms elapsed=162.99s tid=0x00007ffb9e01a800 nid=0xa003 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Service Thread" #10 daemon prio=9 os_prio=31 cpu=0.05ms elapsed=162.96s tid=0x00007ffb9f018800 nid=0x9e03 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Common-Cleaner" #11 daemon prio=8 os_prio=31 cpu=8.38ms elapsed=162.95s tid=0x00007ffb9f019000 nid=0x9a03 in Object.wait()  [0x000070000f6c3000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait([email protected]/Native Method)
	- waiting on <no object reference available>
	at java.lang.ref.ReferenceQueue.remove([email protected]/Unknown Source)
	- waiting to re-lock in wait() <0x0000000783d0d110> (a java.lang.ref.ReferenceQueue$Lock)
	at jdk.internal.ref.CleanerImpl.run([email protected]/Unknown Source)
	at java.lang.Thread.run([email protected]/Unknown Source)
	at jdk.internal.misc.InnocuousThread.run([email protected]/Unknown Source)

"AppKit Thread" #12 daemon prio=5 os_prio=31 cpu=5319.58ms elapsed=162.62s tid=0x00007ffba096c000 nid=0x307 runnable  [0x00007ffee4009000]
   java.lang.Thread.State: RUNNABLE
	at sun.lwawt.macosx.LWCToolkit.doAWTRunLoopImpl([email protected]/Native Method)
	at sun.lwawt.macosx.LWCToolkit.doAWTRunLoop([email protected]/Unknown Source)
	at sun.lwawt.macosx.LWCToolkit.invokeAndWait([email protected]/Unknown Source)
	at com.apple.laf.ScreenMenu.invokeOpenLater([email protected]/Unknown Source)

"AWT-Shutdown" #13 prio=5 os_prio=31 cpu=2.18ms elapsed=162.57s tid=0x00007ffba0969000 nid=0x6a03 in Object.wait()  [0x000070000fad2000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait([email protected]/Native Method)
	- waiting on <no object reference available>
	at java.lang.Object.wait([email protected]/Unknown Source)
	at sun.awt.AWTAutoShutdown.run([email protected]/Unknown Source)
	- waiting to re-lock in wait() <0x0000000783d0b098> (a java.lang.Object)
	at java.lang.Thread.run([email protected]/Unknown Source)

"Java2D Queue Flusher" #15 daemon prio=10 os_prio=31 cpu=207.14ms elapsed=162.15s tid=0x00007ffb9e19f800 nid=0xda07 in Object.wait()  [0x000070000fde1000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait([email protected]/Native Method)
	- waiting on <no object reference available>
	at sun.java2d.opengl.OGLRenderQueue$QueueFlusher.run([email protected]/Unknown Source)
	- waiting to re-lock in wait() <0x0000000783d0b640> (a sun.java2d.opengl.OGLRenderQueue$QueueFlusher)
	at java.lang.Thread.run([email protected]/Unknown Source)

"Java2D Disposer" #16 daemon prio=10 os_prio=31 cpu=121.87ms elapsed=162.09s tid=0x00007ffb9f2fd000 nid=0xe90b in Object.wait()  [0x000070000fee4000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait([email protected]/Native Method)
	- waiting on <no object reference available>
	at java.lang.ref.ReferenceQueue.remove([email protected]/Unknown Source)
	- waiting to re-lock in wait() <0x0000000783d0d3f0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove([email protected]/Unknown Source)
	at sun.java2d.Disposer.run([email protected]/Unknown Source)
	at java.lang.Thread.run([email protected]/Unknown Source)

"AWT-EventQueue-0" #18 prio=6 os_prio=31 cpu=125330.93ms elapsed=161.87s tid=0x00007ffb9f318000 nid=0x10b03 runnable  [0x00007000105f7000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.String.regionMatches([email protected]/Unknown Source)
	at kotlin.text.StringsKt__StringsJVMKt.regionMatches(StringsJVM.kt:533)
	at kotlin.text.StringsKt__StringsKt.findAnyOf$StringsKt__StringsKt(Strings.kt:905)
	at kotlin.text.StringsKt__StringsKt.access$findAnyOf(Strings.kt:1)
	at kotlin.text.StringsKt__StringsKt$rangesDelimitedBy$4.invoke(Strings.kt:1167)
	at kotlin.text.StringsKt__StringsKt$rangesDelimitedBy$4.invoke(Strings.kt)
	at kotlin.text.DelimitedRangesSequence$iterator$1.calcNext(Strings.kt:1095)
	at kotlin.text.DelimitedRangesSequence$iterator$1.hasNext(Strings.kt:1124)
	at kotlin.sequences.TransformingSequence$iterator$1.hasNext(Sequences.kt:176)
	at kotlin.sequences.SequencesKt___SequencesKt.toCollection(_Sequences.kt:702)
	at kotlin.sequences.SequencesKt___SequencesKt.toMutableList(_Sequences.kt:732)
	at kotlin.sequences.SequencesKt___SequencesKt.toList(_Sequences.kt:723)
	at kotlin.text.StringsKt__StringsKt.lines(Strings.kt:1287)
	at org.jetbrains.bio.browser.desktop.dialogs.ProgressDialog$1$append$1.run(ProgressDialog.kt:61)
	at java.awt.event.InvocationEvent.dispatch([email protected]/Unknown Source)
	at java.awt.EventQueue.dispatchEventImpl([email protected]/Unknown Source)
	at java.awt.EventQueue$4.run([email protected]/Unknown Source)
	at java.awt.EventQueue$4.run([email protected]/Unknown Source)
	at java.security.AccessController.doPrivileged([email protected]/Native Method)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege([email protected]/Unknown Source)
	at java.awt.EventQueue.dispatchEvent([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpOneEventForFilters([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForFilter([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.pumpEvents([email protected]/Unknown Source)
	at java.awt.EventDispatchThread.run([email protected]/Unknown Source)

"Timer-0" #20 daemon prio=5 os_prio=31 cpu=2.56ms elapsed=159.38s tid=0x00007ffba0e15000 nid=0xff1b in Object.wait()  [0x0000700010a05000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait([email protected]/Native Method)
	- waiting on <no object reference available>
	at java.lang.Object.wait([email protected]/Unknown Source)
	at java.util.TimerThread.mainLoop([email protected]/Unknown Source)
	- waiting to re-lock in wait() <0x000000078563a4b0> (a java.util.TaskQueue)
	at java.util.TimerThread.run([email protected]/Unknown Source)

"TimerQueue" #32 daemon prio=5 os_prio=31 cpu=3.85ms elapsed=156.75s tid=0x00007ffba0a03000 nid=0x1ee07 waiting on condition  [0x000070001121d000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
	- parking to wait for  <0x0000000791663f78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park([email protected]/Unknown Source)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await([email protected]/Unknown Source)
	at java.util.concurrent.DelayQueue.take([email protected]/Unknown Source)
	at javax.swing.TimerQueue.run([email protected]/Unknown Source)
	at java.lang.Thread.run([email protected]/Unknown Source)

"ForkJoinPool-3-worker-3" #33 daemon prio=6 os_prio=31 cpu=464.28ms elapsed=156.75s tid=0x00007ffb9f128800 nid=0x1ed03 waiting on condition  [0x0000700011320000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
	- parking to wait for  <0x000000079169bb58> (a java.util.concurrent.ForkJoinPool)
	at java.util.concurrent.locks.LockSupport.park([email protected]/Unknown Source)
	at java.util.concurrent.ForkJoinPool.runWorker([email protected]/Unknown Source)
	at java.util.concurrent.ForkJoinWorkerThread.run([email protected]/Unknown Source)

"DestroyJavaVM" #34 prio=5 os_prio=31 cpu=3258.71ms elapsed=156.67s tid=0x00007ffb9f93d000 nid=0x2e03 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" #90 daemon prio=9 os_prio=31 cpu=0.69ms elapsed=0.20s tid=0x00007ffba700d000 nid=0xfb0f waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"VM Thread" os_prio=31 cpu=198.14ms elapsed=163.01s tid=0x00007ffb9f01a800 nid=0x4303 runnable

"GC Thread#0" os_prio=31 cpu=2998.33ms elapsed=163.03s tid=0x00007ffba101e800 nid=0x3503 runnable

"GC Thread#1" os_prio=31 cpu=2995.36ms elapsed=161.98s tid=0x00007ffba0a84000 nid=0xec17 runnable

"GC Thread#2" os_prio=31 cpu=3044.18ms elapsed=161.98s tid=0x00007ffba0a90800 nid=0xed03 runnable

"GC Thread#3" os_prio=31 cpu=3011.46ms elapsed=161.98s tid=0x00007ffb9f302000 nid=0x11203 runnable

"GC Thread#4" os_prio=31 cpu=3014.28ms elapsed=161.98s tid=0x00007ffb9f302800 nid=0x11103 runnable

"GC Thread#5" os_prio=31 cpu=2994.01ms elapsed=161.98s tid=0x00007ffb9f304800 nid=0xf003 runnable

"GC Thread#6" os_prio=31 cpu=2841.74ms elapsed=157.21s tid=0x00007ffb9f3da000 nid=0x1fa07 runnable

"GC Thread#7" os_prio=31 cpu=2787.07ms elapsed=150.39s tid=0x00007ffba2057000 nid=0x17c0b runnable

"G1 Main Marker" os_prio=31 cpu=5.68ms elapsed=163.03s tid=0x00007ffba103e800 nid=0x3603 runnable

"G1 Conc#0" os_prio=31 cpu=26771.28ms elapsed=163.03s tid=0x00007ffba103f800 nid=0x3903 runnable

"G1 Conc#1" os_prio=31 cpu=26803.47ms elapsed=159.52s tid=0x00007ffba09de800 nid=0xfe3f runnable

"G1 Refine#0" os_prio=31 cpu=373.68ms elapsed=163.02s tid=0x00007ffba10e0000 nid=0x3a03 runnable

"G1 Refine#1" os_prio=31 cpu=108.98ms elapsed=157.82s tid=0x00007ffba1287800 nid=0x1f80b runnable

"G1 Refine#2" os_prio=31 cpu=60.70ms elapsed=157.80s tid=0x00007ffba0946000 nid=0x16007 runnable

"G1 Refine#3" os_prio=31 cpu=36.01ms elapsed=157.80s tid=0x00007ffb9e851800 nid=0x16607 runnable

"G1 Refine#4" os_prio=31 cpu=25.29ms elapsed=157.80s tid=0x00007ffb9e384000 nid=0x1f307 runnable

"G1 Refine#5" os_prio=31 cpu=10.56ms elapsed=157.80s tid=0x00007ffb9f478000 nid=0x16507 runnable

"G1 Refine#6" os_prio=31 cpu=1.89ms elapsed=157.80s tid=0x00007ffba21e7800 nid=0x15c07 runnable

"G1 Young RemSet Sampling" os_prio=31 cpu=81.68ms elapsed=163.02s tid=0x00007ffba10e1000 nid=0x3b03 runnable
"VM Periodic Task Thread" os_prio=31 cpu=75.55ms elapsed=162.96s tid=0x00007ffba10ff000 nid=0x9d03 waiting on condition

JNI global refs: 225, weak refs: 165

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants