I have experiments that I collected while running a Java application under the Java Microbenchmark Harness (JMH). JMH forks new JVM's so that the harness does not affect the benchmark, and can serially fork multiple
JVM to measure run-to-run variation, startup time, etc.
I am seeing an infinite loop in the
gprofng display gui, I think while reading an experiment. I am using my own build of the
https://savannah.gnu.org/projects/gprofng-gui/ repo that I built on an Ampere Altra running Fedora 36, and using the standard OpenJDK build of jdk-17.0.4.1 to run the
gprofng display gui application.
I have tried up to 5 forks under JMH and
gprofng display text seems to be able to handle them all. Here's a run with 1 fork showing the process view:
Altra $ /home/pkessler/Work/GProfNG-GUI/Repos/INSTALL/bin/gprofng display text
forks-1.er -processes
Warning: History and command editing is not supported on this system.
Objects sorted by metric: Exclusive Total CPU Time
Excl. Total Name
CPU
sec. %
2.642 100.00 <Total>
1.631 61.74 java, Process 4, PID 1195111
0.961 36.36 java, Process 1, PID 1195043
0.030 1.14 java, Process 2, PID 1195068
0.020 0.76 java, Process 3, PID 1195090
My benchmark is process 4, that takes around 1.6 seconds. Here is a run with 5 forks:
Altra $ /home/pkessler/Work/GProfNG-GUI/Repos/INSTALL/bin/gprofng display text
forks-5.er -processes
Warning: History and command editing is not supported on this system.
Objects sorted by metric: Exclusive Total CPU Time
Excl. Total Name
CPU
sec. %
9.176 100.00 <Total>
1.651 17.99 java, Process 5, PID 1195779
1.631 17.78 java, Process 4, PID 1195751
1.581 17.23 java, Process 6, PID 1195808
1.561 17.01 java, Process 8, PID 1195865
1.551 16.90 java, Process 7, PID 1195837
1.161 12.65 java, Process 1, PID 1195684
0.020 0.22 java, Process 2, PID 1195708
0.020 0.22 java, Process 3, PID 1195730
If I try to look at the same experiments with
gprofng display gui it usually hangs reading the experiment.
Altra $ /home/pkessler/Work/GProfNG-GUI/Repos/INSTALL/bin/gprofng display gui \
--jdkhome "/home/pkessler/Deployed/OpenJDK/jdk-17.0.4.1" \
forks-1.er
fdhome: /home/pkessler/Work/GProfNG-GUI/Repos/INSTALL
gp-display-text: /home/pkessler/Work/GProfNG-GUI/Repos/INSTALL/bin/gp-display-text
That run hung with the progress bar bouncing back and forth saying
Loading CallStack Data: _x1_x1.er
until I used File/Exit to quit and then it produced the exception stack trace
Exception in thread "IPCReader" java.lang.StringIndexOutOfBoundsException: offset 18, count 16842752, length 54
at java.base/java.lang.String.checkBoundsOffCount(String.java:4589)
at java.base/java.lang.String.<init>(String.java:523)
at java.base/java.lang.String.<init>(String.java:1415)
at org.gprofng.mpmt.ipc.IPCProtocol.decodeSVal(IPCProtocol.java:109)
at org.gprofng.mpmt.ipc.IPCResult.progress(IPCResult.java:197)
at org.gprofng.mpmt.ipc.IPCResult.fireResponse(IPCResult.java:220)
at org.gprofng.mpmt.ipc.IPCReader.run(IPCReader.java:228)
at java.base/java.lang.Thread.run(Thread.java:833)
Trying the same thing again (because :-) worked flawlessly, allowing me to export the Process view
ExperimentIDs sorted by metric: Exclusive Total CPU Time
Exclusive
Total CPU Time Name
sec.
2.642 (100.00%) <Total>
1.631 ( 61.74%) java, Process 4, PID 1195111
0.961 ( 36.36%) java, Process 1, PID 1195043
0.030 ( 1.14%) java, Process 2, PID 1195068
0.020 ( 0.76%) java, Process 3, PID 1195090
matching the gprofng display text shown above, with subtle formatting differences.
When
gprofng display gui hangs on input (80% (?) of the time with my forks-1.er, 100% of the time with my forks-5.er), the status bar in the lower right shows different stages. Here are a bunch of attempts to display the 5 fork experiment
Altra $ /home/pkessler/Work/GProfNG-GUI/Repos/INSTALL/bin/gprofng display gui \
--jdkhome "/home/pkessler/Deployed/OpenJDK/jdk-17.0.4.1" \
forks-5.er
which produced the status bars
Loading Profile Data: _x2_x1.er
Loading CallStack Data: _x1_x1.er
Loading CallStack Data: _x2_x1.er
Loading CallStack Data: _x6_x1.er
Loading CallStack Data: _x6_x1.er 34%
Loading CallStack Data: _x3_x1.er
Loading CallStack Data: _x4_x1.er
Loading CallStack Data: _x4_x1.er 69%
Loading CallStack Data: _x5_x1.er
Loading CallStack Data: _x4_x1.er 34%
Loading CallStack Data: _x6_x1.er 52%
Processing Load Object Data
I have tried letting it run (for hours) and it never finishes loading the experiment. But sometimes it just works: loading the experiment (forks-1.er) essentially instantly. (Fortunately, the one time I was demoing
it to my manager! :-) I hate intermittent bugs.
When I have to use File/Exit to quit the GUI, it always reports the same exception stack trace shown above. The
count 16842752 argument looks distinctly
wrong. (!(offset < 0) and !(count < 0), but (offset
> length - count)). Maybe
count is an uninitialized variable? Maybe the looping behavior is because someone is catching the exception (or a superclass) but not fixing the cause and trying again. I shouldn't speculate.
The experiments are too large to attach to an email. I could send you the code if you have Maven and can download JMH and try to reproduce it yourself. Or, if you know how to write JMH benchmarks, you might be
able to reproduce the problem on your own. Let me know if you want me to send you anything that will help you debug this issue.
... peter