-
Bug
-
Resolution: Fixed
-
P4
-
None
-
None
-
None
-
$ uname -a Linux leo.home 6.6.6-200.fc39.x86_64 #1 SMP PREEMPT_DYNAMIC Mon Dec 11 17:29:08 UTC 2023 x86_64 GNU/Linux
I've been doing this with latest JMH master:
# JMH version: 1.38-SNAPSHOT
$ git log --topo-order --pretty=format:"$_git_log_oneline_format" 6d6ce631 7903696: JMH: Add xctrace-based perfasm profiler for macOS (HEAD -> master, upstream/master)
$ uname -a Linux leo.home 6.6.6-200.fc39.x86_64 #1 SMP PREEMPT_DYNAMIC Mon Dec 11 17:29:08 UTC 2023 x86_64 GNU/Linux I've been doing this with latest JMH master: # JMH version: 1.38-SNAPSHOT $ git log --topo-order --pretty=format: "$_git_log_oneline_format" 6d6ce631 7903696: JMH: Add xctrace-based perfasm profiler for macOS (HEAD -> master, upstream/master)
{code}
/home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java -jar /home/g/1/jmh/jmh-samples/target/benchmarks.jar JMHSample_01 -f 1 -i 1 -r 10 -wi 1 -w 10 -prof perf:events=instructions -v EXTRA
...
Forking using command: [perf, stat, --log-fd, 2, --detailed, --detailed, --detailed, --delay, 11000, -e, instructions, /home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java, -XX:+UnlockDiagnosticVMOptions, -XX:+UnlockExperimentalVMOptions, -DcompilerBlackholesEnabled=true, -XX:CompileCommandFile=/tmp/jmh64043897194948902compilecommand, -cp, /home/g/1/jmh/jmh-samples/target/benchmarks.jar, org.openjdk.jmh.runner.ForkedMain, 127.0.0.1, 35829]
# Fork: 1 of 1
# Preparing profilers: LinuxPerfProfiler
Events disabled
# Warmup Iteration 1: 2460681904.610 ops/s
Iteration 1: Events enabled
2449719593.732 ops/s
Performance counter stats for '/home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java -XX:+UnlockDiagnosticVMOptions -XX:+UnlockExperimentalVMOptions -DcompilerBlackholesEnabled=true -XX:CompileCommandFile=/tmp/jmh64043897194948902compilecommand -cp /home/g/1/jmh/jmh-samples/target/benchmarks.jar org.openjdk.jmh.runner.ForkedMain 127.0.0.1 35829':
137,154,006,885 instructions (50.00%)
68,562,705,632 L1-dcache-loads (50.01%)
2,199,968 L1-dcache-load-misses # 0.00% of all L1-dcache accesses (50.02%)
<not supported> LLC-loads
<not supported> LLC-load-misses
46,754,639 L1-icache-loads (50.04%)
1,133,224 L1-icache-load-misses # 2.42% of all L1-icache accesses (50.11%)
364,940 dTLB-loads (50.07%)
122,019 dTLB-load-misses # 33.44% of all dTLB cache accesses (50.06%)
73,954 iTLB-loads (50.03%)
11,945 iTLB-load-misses # 16.15% of all iTLB cache accesses (49.99%)
586,628 L1-dcache-prefetches (49.96%)
<not supported> L1-dcache-prefetch-misses
9.342746225 seconds time elapsed
20.609231000 seconds user
0.105270000 seconds sys
{code}
One would expect to only see instructions, e.g.
{code}
$ perf stat -e instructions sleep 1
Performance counter stats for 'sleep 1':
1,705,471 instructions
1.001887415 seconds time elapsed
0.000000000 seconds user
0.001356000 seconds sys
{code}
{code}
$ perf stat --log-fd 2 --detailed --detailed --detailed --delay 11000 -e instructions /home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java --version
Events disabled
openjdk 21.0.4-internal 2024-07-16
OpenJDK Runtime Environment (build 21.0.4-internal-adhoc.g.jdk21u-dev)
OpenJDK 64-Bit Server VM (build 21.0.4-internal-adhoc.g.jdk21u-dev, mixed mode)
Events enabled
Performance counter stats for '/home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java --version':
<not counted> instructions
<not counted> L1-dcache-loads
<not counted> L1-dcache-load-misses
<not supported> LLC-loads
<not supported> LLC-load-misses
<not counted> L1-icache-loads
<not counted> L1-icache-load-misses
<not counted> dTLB-loads
<not counted> dTLB-load-misses
<not counted> iTLB-loads
<not counted> iTLB-load-misses
<not counted> L1-dcache-prefetches
<not supported> L1-dcache-prefetch-misses
0.000002170 seconds time elapsed
0.000000000 seconds user
0.000000000 seconds sys
Some events weren't counted. Try disabling the NMI watchdog:
echo 0 > /proc/sys/kernel/nmi_watchdog
perf stat ...
echo 1 > /proc/sys/kernel/nmi_watchdog
{code}
It seems the `perf stat` parameter construction is not right.
/home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java -jar /home/g/1/jmh/jmh-samples/target/benchmarks.jar JMHSample_01 -f 1 -i 1 -r 10 -wi 1 -w 10 -prof perf:events=instructions -v EXTRA
...
Forking using command: [perf, stat, --log-fd, 2, --detailed, --detailed, --detailed, --delay, 11000, -e, instructions, /home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java, -XX:+UnlockDiagnosticVMOptions, -XX:+UnlockExperimentalVMOptions, -DcompilerBlackholesEnabled=true, -XX:CompileCommandFile=/tmp/jmh64043897194948902compilecommand, -cp, /home/g/1/jmh/jmh-samples/target/benchmarks.jar, org.openjdk.jmh.runner.ForkedMain, 127.0.0.1, 35829]
# Fork: 1 of 1
# Preparing profilers: LinuxPerfProfiler
Events disabled
# Warmup Iteration 1: 2460681904.610 ops/s
Iteration 1: Events enabled
2449719593.732 ops/s
Performance counter stats for '/home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java -XX:+UnlockDiagnosticVMOptions -XX:+UnlockExperimentalVMOptions -DcompilerBlackholesEnabled=true -XX:CompileCommandFile=/tmp/jmh64043897194948902compilecommand -cp /home/g/1/jmh/jmh-samples/target/benchmarks.jar org.openjdk.jmh.runner.ForkedMain 127.0.0.1 35829':
137,154,006,885 instructions (50.00%)
68,562,705,632 L1-dcache-loads (50.01%)
2,199,968 L1-dcache-load-misses # 0.00% of all L1-dcache accesses (50.02%)
<not supported> LLC-loads
<not supported> LLC-load-misses
46,754,639 L1-icache-loads (50.04%)
1,133,224 L1-icache-load-misses # 2.42% of all L1-icache accesses (50.11%)
364,940 dTLB-loads (50.07%)
122,019 dTLB-load-misses # 33.44% of all dTLB cache accesses (50.06%)
73,954 iTLB-loads (50.03%)
11,945 iTLB-load-misses # 16.15% of all iTLB cache accesses (49.99%)
586,628 L1-dcache-prefetches (49.96%)
<not supported> L1-dcache-prefetch-misses
9.342746225 seconds time elapsed
20.609231000 seconds user
0.105270000 seconds sys
{code}
One would expect to only see instructions, e.g.
{code}
$ perf stat -e instructions sleep 1
Performance counter stats for 'sleep 1':
1,705,471 instructions
1.001887415 seconds time elapsed
0.000000000 seconds user
0.001356000 seconds sys
{code}
{code}
$ perf stat --log-fd 2 --detailed --detailed --detailed --delay 11000 -e instructions /home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java --version
Events disabled
openjdk 21.0.4-internal 2024-07-16
OpenJDK Runtime Environment (build 21.0.4-internal-adhoc.g.jdk21u-dev)
OpenJDK 64-Bit Server VM (build 21.0.4-internal-adhoc.g.jdk21u-dev, mixed mode)
Events enabled
Performance counter stats for '/home/g/1/jdk21u-dev/build/release-linux-x86_64/jdk/bin/java --version':
<not counted> instructions
<not counted> L1-dcache-loads
<not counted> L1-dcache-load-misses
<not supported> LLC-loads
<not supported> LLC-load-misses
<not counted> L1-icache-loads
<not counted> L1-icache-load-misses
<not counted> dTLB-loads
<not counted> dTLB-load-misses
<not counted> iTLB-loads
<not counted> iTLB-load-misses
<not counted> L1-dcache-prefetches
<not supported> L1-dcache-prefetch-misses
0.000002170 seconds time elapsed
0.000000000 seconds user
0.000000000 seconds sys
Some events weren't counted. Try disabling the NMI watchdog:
echo 0 > /proc/sys/kernel/nmi_watchdog
perf stat ...
echo 1 > /proc/sys/kernel/nmi_watchdog
{code}
It seems the `perf stat` parameter construction is not right.
- links to
-
Commit(master) openjdk/jmh/fedf7639
-
Review(master) openjdk/jmh/133