Kubernetes Linux perf for OpenJ9 Java Recipe
- Restart the pod with additional JVM options to enable the
perfmapping file either with-XX:+PerfToolfor newer Java or-Xjit:perfToolfor older Java as well as-Xdump:system:events=user2,request=exclusive+prepwalkfor easier collection of OS core dumps:- For IBM Java >= 8.0.7.20 or IBM Semeru Runtimes >= v8.0.352 /
11.0.17.0 / 17.0.5.0, restart the Java process with
-XX:+PerfTool - For older versions of IBM Java or IBM Semeru Runtimes, restart the
Java process with
-Xjit:perfToolwhile making sure to combine with commas with any pre-existing-Xjitoptions. - For example, a common approach to add the options is using a JVM
environment variable such as
JAVA_TOOL_OPTIONSin aDeployment(making sure to combine envars of the same name if they're already present):spec: template: spec: containers: - name: ... env: - name: JAVA_TOOL_OPTIONS value: -XX:+PerfTool -Xdump:system:events=user2,request=exclusive+prepwalk
- For IBM Java >= 8.0.7.20 or IBM Semeru Runtimes >= v8.0.352 /
11.0.17.0 / 17.0.5.0, restart the Java process with
- For each pod of interest, open a terminal and ensure there are
/tmp/perf-$PID.mapfiles and note down the container process ID(s) from the file names. For example:$ kubectl exec -it liberty1-846f7c48c4-ltcvq -- sh -c "ls /tmp/perf*map" /tmp/perf-1021.map /tmp/perf-1059.map /tmp/perf-1.map /tmp/perf-82.map- In some cases, there may be perf map files for Java processes that no longer exist as they were transient.
- For each pod, find the worker node the pod is on and the container
ID; for example:
$ kubectl get pod liberty1-846f7c48c4-ltcvq -o jsonpath='{.spec.nodeName}{"\n"}{.status.containerStatuses[*].containerID}{"\n"}' itz-bn7nf2-worker-3 cri-o://fedce1715892cef7a360566f588fd006d343eb7e243d16402cf47c48167e1d54 - As a user with
cluster-adminpermissions, start a debug pod on the worker node (replace $NODE with the worker node name in the previous step and replace thefedoraimage with another general purpose image if needed). Note that older versions ofkubectldon't require--profile=sysadmin.kubectl debug node/$NODE --profile=sysadmin -it --image=fedora -- bash- Switch to the worker node filesystem:
chroot /host - Display the distribution and version of the worker node which may be
needed later if you need to build a container with
perf; for example:cat /etc/os-release - Find the main PID of the container given the container ID from the
steps above (excluding the URI prefix); for example:
# crictl inspect fedce1715892cef7a360566f588fd006d343eb7e243d16402cf47c48167e1d54 | jq '.info.pid' 41647 - Check if this main PID is the PID of Java by seeing if the container
PID (3rd column) matches the initial steps above finding the Java PIDs
in the container:
# grep NSpid /proc/41647/status NSpid: 41647 1 - If the main PID is not Java, or if there are multiple Java PIDs of
interest, then find all worker node PIDs of the Java processes:
- Find the PID namespace from the main container PID; for example:
# readlink /proc/41647/ns/pid pid:[4026535300] - List all worker node PIDs in that namespace; for example:
sh-5.1# lsns 4026535300 PID PPID USER COMMAND 41647 41645 1000870000 /opt/java/openjdk/bin/java ... 86373 86371 1000870000 sh 88294 86373 1000870000 `-java ConsumeCPU 30 - For each worker node PID, find the matching container PID (third
column); for example:
# grep NSpid /proc/41647/status NSpid: 41647 1 # grep NSpid /proc/88294/status NSpid: 88294 1059
- Find the PID namespace from the main container PID; for example:
- Check if
perfis installed. Normally,perfis not installed and you'll get the following error.$ perf -v sh: perf: command not found
- Switch to the worker node filesystem:
- If the worker node doesn't have
perfand if you don't already have another available container image withperfinstalled, then create your own:- Create a
Containerfilethat installsperf, matching or approximately matching the container distribution to that of the worker node found above; for example:FROM fedora RUN dnf install -y perf runc procps-ng binutils less lsof psmisc sysstat vim zip util-linux fatrace && dnf clean all - Build the image locally; for example:
podman build --platform linux/amd64 -t perfcontainer . - Publish the image to your cluster image registry.
- Create a
- Run a debug pod with an image that has
perf; for example:kubectl debug node/$NODE --profile=sysadmin -it --image=image-registry.svc:5000/perfimage/perfcontainer -- bash - Check if
perf topworks:
If it works, typeperf top -zqto exit. If there are errors, some permission errors may be resolved with dynamic (and temporary) kernel configuration changes:sysctl -w kernel.perf_event_paranoid=-1 sysctl -w kernel.kptr_restrict=0 - Create symbolic links for all the Java perf maps using the container
PIDs and the worker node PIDs found above; for example:
Create symbolic links in the worker node filesystem as well; for example:ln -s /host/proc/41647/root/tmp/perf-1.map /tmp/perf-41647.map ln -s /host/proc/41647/root/tmp/perf-1059.map /tmp/perf-88294.mapchroot /host/ ln -s /proc/41647/root/tmp/perf-1.map /tmp/perf-41647.map ln -s /proc/41647/root/tmp/perf-1059.map /tmp/perf-88294.map exit - Start the perf collection in the background:
cd /tmp/ nohup sh -c "date +'%Y-%m-%d %H:%M:%S.%N %Z' >> diag_perfdata_starttimes.txt; cat /proc/uptime >> diag_perfdata_starttimes.txt; perf record --call-graph dwarf,65528 -T -F 19 -o perf.data -a -g -- sleep infinity" & - Ensure there were no errors starting
perf:cat nohup.out - Start a loop that continuously prints the size of the
perf.datafile to the screen to avoid some cases where lack of interaction causes termination of the debug pod and you can also monitor disk usage to ensure no exhaustion:while true; do date; ls -lh /tmp/perf.data; df -h /tmp; echo ""; sleep 8; done - Leave the debug pod window open.
- Reproduce the problem.
- After the problem is reproduced, stop the data collection by going
back to the debug pod window and
Ctrl^Cout of the while loop. Then, end theperfexecution:kill -TERM %1 - Execute the
jobscommand until you see the "Terminated" output:# jobs [1]+ Running nohup sh -c "date +'%Y-%m-%d %H:%M:%S.%N %Z' >> diag_perfdata_starttimes.txt; cat /proc/uptime >> diag_perfdata_starttimes.txt; perf record --call-graph dwarf,65528 -T -F 19 -o perf.data -a -g -- sleep infinity" & # jobs [1]+ Running nohup sh -c "date +'%Y-%m-%d %H:%M:%S.%N %Z' >> diag_perfdata_starttimes.txt; cat /proc/uptime >> diag_perfdata_starttimes.txt; perf record --call-graph dwarf,65528 -T -F 19 -o perf.data -a -g -- sleep infinity" & # jobs [1]+ Terminated nohup sh -c "date +'%Y-%m-%d %H:%M:%S.%N %Z' >> diag_perfdata_starttimes.txt; cat /proc/uptime >> diag_perfdata_starttimes.txt; perf record --call-graph dwarf,65528 -T -F 19 -o perf.data -a -g -- sleep infinity" - Run the following commands:
perf script -i perf.data --symfs=/host --kallsyms=/host/proc/kallsyms --header -I -f -F comm,cpu,pid,tid,time,event,ip,sym,dso,symoff > diag_perfscript_${HOSTNAME}_$(date +%Y%m%d_%H%M%S_%N).stdout.txt 2> diag_perfscript_${HOSTNAME}_$(date +%Y%m%d_%H%M%S_%N).stderr.txt perf report -i perf.data --symfs=/host --kallsyms=/host/proc/kallsyms -n --show-cpu-utilization -v --stdio > diag_perfreport_${HOSTNAME}_$(date +%Y%m%d_%H%M%S_%N).stdout.txt 2> diag_perfreport_${HOSTNAME}_$(date +%Y%m%d_%H%M%S_%N).stderr.txt - Delete the perf symlinks in the worker node filesystem; for example:
rm -f /host/tmp/perf-41647.map rm -f /host/tmp/perf-88294.map - Compress all the files:
tar chzvf diag_perfoutput_${HOSTNAME}_$(date +%Y%m%d_%H%M%S_%N).tar.gz perf* diag* nohup.out - List the full file name for later:
$ ls diag_perfoutput* diag_perfoutput_itz-bn7nf2-worker-3_20260806_213742_673730815.tar.gz - Start a loop to keep this debug pod active:
while true; do date; sleep 8; done - In another window, open a terminal to the pod.
- First check where OS core dumps will go:
cat /proc/sys/kernel/core_pattern - If the output starts with
|, then they will go to the specified program on the worker node. - If the output starts with
/, they will attempt to be written to the specified directory. If this doesn't exist or the user doesn't have permissions to write to it, creating the core will fail. You may either try creating the directory dynamically, or temporarily change thecore_patternsetting on the worker node through a debug pod:$ sysctl kernel.core_pattern # Print the current setting for later reversion kernel.core_pattern = /core.%e.%p.%t $ sysctl -w "kernel.core_pattern=/tmp/core" # Dynamically update the setting - Otherwise, they will go to the current working directory in the
container (find with
ls -l /proc/$PID/ | grep cwd).
- First check where OS core dumps will go:
- Request a non-destructive OS core dump of the relevant Java
processes (replace $PID with the container process ID; in the above
example, it was 1 and 1059):
kill -USR2 $PID - Exit the pod terminal and now find the running debug pod; for
example:
$ kubectl get pods -A | grep -e NAMESPACE -e -debug- NAMESPACE NAME READY STATUS RESTARTS AGE debug-x54bw itz-bn7nf2-worker-3-debug-bxgdm 1/1 Running 0 164m - Download the perfoutput tar from the debug pod (replace the full tar
file name from above twice):
kubectl cp -n debug-x54bw itz-bn7nf2-worker-3-debug-bxgdm:/tmp/diag_perfoutput_FILE.tar.gz diag_perfoutput_FILE.tar.gz - Download the OS core dumps from the pod or the worker node:
- For example, if
core_patternshows the following:# cat /proc/sys/kernel/core_pattern |/usr/lib/systemd/systemd-coredump %P %u %g %s %t %c %h - Then download cores through the debug pod with:
kubectl cp -n debug-x54bw itz-bn7nf2-worker-3-debug-bxgdm:/host/var/lib/systemd/coredump/ coredumps
- For example, if
- Upload
diag_perfoutput*.tar.gz,coredumps, all relevant logs from the pods, and any OS core dumps. - If you made any temporary kernel changes above using
sysctl, then revert those.
Notes:
- Some other commands that may be useful to start after starting
perf record(and then stop these after the problem is reproduced):- strace:
nohup strace -f -T -tt -s 256 -p $PID1 -p $PID2 -o diag_strace_${HOSTNAME}_$(date +%Y%m%d_%H%M%S_%N).stdout.txt 2> diag_strace_${HOSTNAME}_$(date +%Y%m%d_%H%M%S_%N).stderr.txt & - fatrace:
nohup fatrace -t -f CROW > diag_fatrace_${HOSTNAME}_$(date +%Y%m%d_%H%M%S).txt 2> diag_fatrace_${HOSTNAME}_$(date +%Y%m%d_%H%M%S).stderr.txt &
- strace:
- Only
perf reportoutput seems to be useful. It's unclear why, butperf scriptcan't seem to evaluate JITted methods even with access to/tmp/perf-$PID.mapeither within the debug pod or the host with--symfs=/host; strace suggests some sort of issue calling libunwind with the perf map (unwind: failed with 'not a valid ELF file'):
For example, despite the rawopenat(AT_FDCWD, "/host///tmp/perf-211133.map", O_RDONLY) = 37 fcntl(37, F_GETFD) = 0 fstat(37, {st_mode=S_IFREG|0640, st_size=110045, ...}) = 0 mmap(NULL, 110045, PROT_READ|PROT_WRITE, MAP_PRIVATE, 37, 0) = 0x7f035a3c0000 munmap(0x7f035a3c0000, 110045) = 0 close(37) = 0 write(2, "unwind: failed with 'not a valid ELF file'\n", 43) = 43 write(1, "main 211133/211134 [001] 11013.555344: cpu/cycles/P: \n\n", 57) = 57perf script -Dshowing an instruction pointer0x7f7d1ab53d18:
Which maps to the1 11013660434443 0x70aa50 [0xfff8]: PERF_RECORD_SAMPLE(IP, 0x2): 211133/211134: 0x7f7d1ab53d18 period: 163762576 addr: 0perf-211133.mapfor the range0x7F7D1AB53940 - 0x7F7D1AB56C75:
Yet00007F7D1AB53940 3335 com/sun/crypto/provider/AESCrypt.makeSessionKey([B)V_scorchingperf scriptdoesn't show this top stack frame at all, let alone unwinding beyond it.perf reportbehaves differently.