Open vitalyd opened 5 years ago
So the recording/your app has 7000 threads?
// Klara
On 30 May 2019, at 20:46, vitalyd notifications@github.com wrote:
Not sure if this is the right channel to report this, but what the heck - I'll try it :).
Analyzing a Java 11 recorded .jfr using Zulu Mission Control 7 EA, which is (to my understanding) merely a packaging of the open JMC project, shows an extremely high UI lag (freeze) - in the 10s of seconds - when switching to the Threads view. I captured the stacktrace of JMC during the UI freeze, and it's almost always something along these lines:
"main" #1 prio=6 os_prio=0 cpu=133712.13ms elapsed=502.88s tid=0x000000000093e000 nid=0x5632 runnable [0x00007f0c242dc000] java.lang.Thread.State: RUNNABLE at java.util.stream.Sink$ChainedReference.cancellationRequested(java.base@11.0.3/Sink.java:263) at java.util.stream.Sink$ChainedReference.cancellationRequested(java.base@11.0.3/Sink.java:263) at java.util.stream.Sink$ChainedReference.cancellationRequested(java.base@11.0.3/Sink.java:263) at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(java.base@11.0.3/StreamSpliterators.java:206) at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(java.base@11.0.3/StreamSpliterators.java:169) at java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(java.base@11.0.3/StreamSpliterators.java:300) at java.util.stream.ReferencePipeline$7$1.accept(java.base@11.0.3/ReferencePipeline.java:278) at java.util.Spliterators$ArraySpliterator.tryAdvance(java.base@11.0.3/Spliterators.java:958) at java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(java.base@11.0.3/StreamSpliterators.java:294) at java.util.stream.StreamSpliterators$WrappingSpliterator$$Lambda$509/0x00000008007bf040.getAsBoolean(java.base@11.0.3/Unknown Source) at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(java.base@11.0.3/StreamSpliterators.java:206) at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(java.base@11.0.3/StreamSpliterators.java:169) at java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(java.base@11.0.3/StreamSpliterators.java:300) at java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(java.base@11.0.3/StreamSpliterators.java:294) at java.util.stream.StreamSpliterators$WrappingSpliterator$$Lambda$509/0x00000008007bf040.getAsBoolean(java.base@11.0.3/Unknown Source) at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(java.base@11.0.3/StreamSpliterators.java:206) at java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(java.base@11.0.3/StreamSpliterators.java:161) at java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(java.base@11.0.3/StreamSpliterators.java:300) at java.util.Spliterators$1Adapter.hasNext(java.base@11.0.3/Spliterators.java:681) at org.openjdk.jmc.flightrecorder.ui.common.ThreadGraphLanes.threadRanges(ThreadGraphLanes.java:167) at org.openjdk.jmc.flightrecorder.ui.common.ThreadGraphLanes.buildThreadRenderer(ThreadGraphLanes.java:145) at org.openjdk.jmc.flightrecorder.ui.pages.ThreadsPage$ThreadsPageUi.lambda$2(ThreadsPage.java:202) at org.openjdk.jmc.flightrecorder.ui.pages.ThreadsPage$ThreadsPageUi$$Lambda$703/0x0000000800882040.apply(Unknown Source) at org.openjdk.jmc.flightrecorder.ui.common.ItemHistogram$HistogramSelection.lambda$2(ItemHistogram.java:223) at org.openjdk.jmc.flightrecorder.ui.common.ItemHistogram$HistogramSelection$$Lambda$704/0x0000000800882440.apply(Unknown Source) at java.util.stream.ReferencePipeline$3$1.accept(java.base@11.0.3/ReferencePipeline.java:195) at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(java.base@11.0.3/ArrayList.java:1654) at java.util.stream.AbstractPipeline.copyInto(java.base@11.0.3/AbstractPipeline.java:484) at java.util.stream.AbstractPipeline.wrapAndCopyInto(java.base@11.0.3/AbstractPipeline.java:474) at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(java.base@11.0.3/ReduceOps.java:913) at java.util.stream.AbstractPipeline.evaluate(java.base@11.0.3/AbstractPipeline.java:234) at java.util.stream.ReferencePipeline.collect(java.base@11.0.3/ReferencePipeline.java:578) at org.openjdk.jmc.flightrecorder.ui.pages.ThreadsPage$ThreadsPageUi.getChartRenderer(ThreadsPage.java:203) at org.openjdk.jmc.flightrecorder.ui.pages.ChartAndTableUI.buildChart(ChartAndTableUI.java:207) at org.openjdk.jmc.flightrecorder.ui.pages.ChartAndTableUI.lambda$0(ChartAndTableUI.java:116) at org.openjdk.jmc.flightrecorder.ui.pages.ChartAndTableUI$$Lambda$587/0x000000080082e040.selectionChanged(Unknown Source) at org.eclipse.jface.viewers.Viewer$1.run(Viewer.java:155) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42) at org.eclipse.ui.internal.JFaceUtil.lambda$0(JFaceUtil.java:44) at org.eclipse.ui.internal.JFaceUtil$$Lambda$136/0x000000080033e840.run(Unknown Source) at org.eclipse.jface.util.SafeRunnable.run(SafeRunnable.java:173) at org.eclipse.jface.viewers.Viewer.fireSelectionChanged(Viewer.java:152) at org.eclipse.jface.viewers.StructuredViewer.updateSelection(StructuredViewer.java:2179) at org.eclipse.jface.viewers.StructuredViewer.setSelection(StructuredViewer.java:1716) at org.eclipse.jface.viewers.TableViewer.setSelection(TableViewer.java:162) at org.eclipse.jface.viewers.Viewer.setSelection(Viewer.java:380) at org.openjdk.jmc.ui.column.ColumnManager.setSelectionState(ColumnManager.java:599) at org.openjdk.jmc.flightrecorder.ui.pages.ThreadsPage$ThreadsPageUi.
(ThreadsPage.java:173) at org.openjdk.jmc.flightrecorder.ui.pages.ThreadsPage.display(ThreadsPage.java:256) at org.openjdk.jmc.flightrecorder.ui.JfrEditor.displayPage(JfrEditor.java:232) at org.openjdk.jmc.flightrecorder.ui.JfrEditor.navigateTo(JfrEditor.java:216) at org.openjdk.jmc.flightrecorder.ui.JfrOutlinePage.selectionChanged(JfrOutlinePage.java:449) at org.eclipse.jface.viewers.Viewer$1.run(Viewer.java:155) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42) at org.eclipse.ui.internal.JFaceUtil.lambda$0(JFaceUtil.java:44) at org.eclipse.ui.internal.JFaceUtil$$Lambda$136/0x000000080033e840.run(Unknown Source) at org.eclipse.jface.util.SafeRunnable.run(SafeRunnable.java:173) at org.eclipse.jface.viewers.Viewer.fireSelectionChanged(Viewer.java:152) at org.eclipse.jface.viewers.StructuredViewer.updateSelection(StructuredViewer.java:2179) at org.eclipse.jface.viewers.StructuredViewer.handleSelect(StructuredViewer.java:1222) at org.eclipse.jface.viewers.StructuredViewer$4.widgetSelected(StructuredViewer.java:1251) at org.eclipse.jface.util.OpenStrategy.fireSelectionEvent(OpenStrategy.java:240) at org.eclipse.jface.util.OpenStrategy.access$4(OpenStrategy.java:235) at org.eclipse.jface.util.OpenStrategy$1.handleEvent(OpenStrategy.java:400) at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:86) at org.eclipse.swt.widgets.Display.sendEvent(Display.java:5686) at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1370) at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:4940) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4518) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$5.run(PartRenderingEngine.java:1170) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:336) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:1059) at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:153) at org.eclipse.ui.internal.Workbench.lambda$3(Workbench.java:667) at org.eclipse.ui.internal.Workbench$$Lambda$168/0x00000008003ba840.run(Unknown Source) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:336) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:597) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:148) at org.openjdk.jmc.rcp.application.Application.start(Application.java:64) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:134) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:104) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:388) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:243) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.3/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.3/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.3/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.3/Method.java:566) at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:656) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:592) at org.eclipse.equinox.launcher.Main.run(Main.java:1498) at org.eclipse.equinox.launcher.Main.main(Main.java:1471) JMC was being run on AdoptOpenJDK 11.0.3 on Linux. Has anyone seen/experienced something similar? Exporting the Threads view to a csv, once loaded, yields about 7000 rows. The JFR file itself is a few hundred MB. I don't remember the old JMC (bundled with Oracle JDK), up to Java 8, having similar problems.
I'm happy to provide any additional info.
Thanks!
— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.
@klaraward, the application, over its lifetime/recording, has about that many, yeah. Note that the recording also has a bunch of JIT compiler threads in there. For example, things like this repeated many times, for the same compiler thread but also for other CompilerThreadN
values:
"C2 CompilerThread2";"system";"7";"1558386372660149229 epochns";"1558386373162779876 epochns";"502630647 ns"
"C2 CompilerThread2";"system";"7";"1558386377510162906 epochns";"1558386377777291571 epochns";"267128665 ns"
"C2 CompilerThread2";"system";"7";"1558386378359235820 epochns";"1558386378466345096 epochns";"107109276 ns"
"C2 CompilerThread2";"system";"7";"1558387053910552778 epochns";"1558387054262061196 epochns";"351508418 ns"
"C2 CompilerThread2";"system";"7";"1558387054810979195 epochns";"1558387055530752680 epochns";"719773485 ns"
"C2 CompilerThread2";"system";"7";"1558387056173090833 epochns";"1558387057685824514 epochns";"1512733681 ns"
"C2 CompilerThread2";"system";"7";"1558387057757533056 epochns";"1558387058961464222 epochns";"1203931166 ns"
"C2 CompilerThread2";"system";"7";"1558387058992014237 epochns";"1558387064148112006 epochns";"5156097769 ns"
"C2 CompilerThread2";"system";"7";"1558397353074622060 epochns";"1558397360836368400 epochns";"7761746340 ns"
"C2 CompilerThread2";"system";"7";"1558389071385798048 epochns";"1558389073600594775 epochns";"2214796727 ns"
"C2 CompilerThread2";"system";"7";"1558401766567525345 epochns";"1558401767674502750 epochns";"1106977405 ns"
"C2 CompilerThread2";"system";"7";"1558395783172116354 epochns";"1558395784563664272 epochns";"1391547918 ns"
"C2 CompilerThread2";"system";"7";"1558387069050283267 epochns";"1558387070493018880 epochns";"1442735613 ns"
"C2 CompilerThread2";"system";"7";"1558386000618425257 epochns";"1558386001808956132 epochns";"1190530875 ns"
"C2 CompilerThread2";"system";"7";"1558398217280748435 epochns";"1558398227000986453 epochns";"9720238018 ns"
"C2 CompilerThread2";"system";"7";"1558388248137855911 epochns";"1558388248449831829 epochns";"311975918 ns"
"C2 CompilerThread2";"system";"7";"1558387591293538025 epochns";"1558387595292277763 epochns";"3998739738 ns"
"C2 CompilerThread2";"system";"7";"1558386399300392182 epochns";"1558386400157819299 epochns";"857427117 ns"
"C2 CompilerThread2";"system";"7";"1558389117317875363 epochns";"1558389118060282036 epochns";"742406673 ns"
"C2 CompilerThread2";"system";"7";"1558402470990379604 epochns";"1558402471261724016 epochns";"271344412 ns"
"C2 CompilerThread2";"system";"7";"1558398247518566606 epochns";"1558398249669863773 epochns";"2151297167 ns"
"C2 CompilerThread2";"system";"7";"1558386003979485998 epochns";"1558386004309901152 epochns";"330415154 ns"
"C2 CompilerThread2";"system";"7";"1558403219206697206 epochns";"1558403220106626615 epochns";"899929409 ns"
"C2 CompilerThread2";"system";"7";"1558386004776622810 epochns";"1558386005402641190 epochns";"626018380 ns"
"C2 CompilerThread2";"system";"7";"1558390257396673124 epochns";"1558390257720240193 epochns";"323567069 ns"
Granted, this is the csv
export from JMC but I suspect the .jfr
file just has similar information in its binary format.
Any chance you're on a paid support plan from Azul, Red Hat or Oracle?
@thegreystone, unfortunately not at the moment.
So I noticed Azul had released a new version, 7.0.0.49. Wanted to try it out, but looks a bit bleeding edge for the machine I have available: apparently the version of Eclipse that's built on uses a newer SWT version, which in turn needs a newer GTK+ than I have:
!ENTRY org.eclipse.osgi 4 0 2019-06-19 16:25:14.345
!MESSAGE Application error
!STACK 1
java.lang.UnsatisfiedLinkError: Could not load SWT library. Reasons:
no swt-pi4-gtk-4924r25 in java.library.path
no swt-pi4-gtk in java.library.path
Can't load library: /home/vitaly/.swt/lib/linux/x86_64/libswt-pi4-gtk-4924r25.so
Can't load library: /home/vitaly/.swt/lib/linux/x86_64/libswt-pi4-gtk.so
at org.eclipse.swt.internal.Library.loadLibrary(Library.java:329)
at org.eclipse.swt.internal.Library.loadLibrary(Library.java:241)
at org.eclipse.swt.internal.gtk.OS.<clinit>(OS.java:88)
at org.eclipse.swt.internal.Converter.wcsToMbcs(Converter.java:209)
at org.eclipse.swt.internal.Converter.wcsToMbcs(Converter.java:155)
at org.eclipse.swt.widgets.Display.<clinit>(Display.java:159)
at org.eclipse.ui.internal.Workbench.createDisplay(Workbench.java:749)
at org.eclipse.ui.PlatformUI.createDisplay(PlatformUI.java:162)
at org.openjdk.jmc.rcp.application.Application.start(Application.java:52)
at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:203)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:137)
at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:107)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:400)
at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:255)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:661)
at org.eclipse.equinox.launcher.Main.basicRun(Main.java:597)
at org.eclipse.equinox.launcher.Main.run(Main.java:1476)
at org.eclipse.equinox.launcher.Main.main(Main.java:1449)
@thegreystone, do you know when the "stock" (i.e. not Azul's ZMC) JMC7 will be released? I saw it was delayed, but haven't found the latest status. Thanks!
Hi there! Still no news about the Oracle release of JMC 7. @guruhb - any news?
Not sure if this is the right channel to report this, but what the heck - I'll try it :).
Analyzing a Java 11 recorded
.jfr
using Zulu Mission Control 7 EA, which is (to my understanding) merely a packaging of the open JMC project, shows an extremely high UI lag (freeze) - in the 10s of seconds - when switching to the Threads view. I captured the stacktrace of JMC during the UI freeze, and it's almost always something along these lines:JMC was being run on AdoptOpenJDK 11.0.3 on Linux.
Has anyone seen/experienced something similar? Exporting the Threads view to a csv, once loaded, yields about 7000 rows. The JFR file itself is a few hundred MB. I don't remember the old JMC (bundled with Oracle JDK), up to Java 8, having similar problems.
I'm happy to provide any additional info.
Thanks!