Recording the java stack-trace when a specific system call is made?

Question

The Context: I am working on a Java based network server that accidentally leaks pipes. Every few days it hits its limit of 40,000 file descriptors and dies. Using lsof on the server prior to death shows it is choked with pipes. The pipes connect to itself, rather than another process.

No part of the codebase creates or uses pipes - that we can see.

Some older version of the JVM have created & leaked a pipe when creating a socket, however this exhibits on java 1.7.0_75 which I believe does not suffer that bug.

My question is: Using the modern Linux toolchain, (such as perf) is it possible to snapshot the process when it calls the pipe(2) system call - which I believe is the only way pipes are created. Furthermore, is it possible then to retrieve a Java stack-trace from that?

Given this information it should be possible to answer the question "Who is creating pipes, and why?"

Answer 1

On java 1.7.0_75 (or pre- java 8 update 60) you can only get limited information from perf on the call stack of an event because the stack will be truncated (see below).

You can get systemwide tracepoint events on sys calls to pipe and close with the following perf command, or similar.

perf record -e 'syscalls:sys_enter_pipe*' -e 'syscalls:sys_enter_close' -ag -- sleep 10

To get the full stack :

1. Test on a test system before running in production.
2. Install Java 8 update 60 or later
3. Run java with -XX:+PreserveFramePointer to avoid truncated stacks
4. Optionally (as is it is not production ready code) install and run perf-map-agent from Github to resolve Java JIT symbols for perf's use
5. Run the above "perf record" or similar when the issue is occurring
6. Run "perf script" to output the tracepoint events and associated stack traces

A truncated stack will be one that does not have thread start function at the bottom for example:

java 19575 [018] 10600910.346655: syscalls:sys_enter_pipe: fildes: 0x7f353b9f7f80
        7f3809cff0b7 __pipe (/usr/lib64/libc-2.17.so)
        7f37f59aecb9 [unknown] (/tmp/perf-19375.map)
        7f37f5e83150 [unknown] (/tmp/perf-19375.map)
    edb4639ef8034082 [unknown] ([unknown])

A full stack may look more like:

java 21553 [009] 10601254.522385: syscalls:sys_enter_pipe: fildes: 0x7f545322f340
        7f54527180b7 __pipe (/usr/lib64/libc-2.17.so)
        7f543d007760 [unknown] (/tmp/perf-21552.map)
        7f543d0007a7 [unknown] (/tmp/perf-21552.map)
        7f5451ce1be6 JavaCalls::call_helper (/usr/java/jdk1.8.0_60/jre/lib/amd64/server/libjvm.so)
        7f5451fe7b27 Reflection::invoke (/usr/java/jdk1.8.0_60/jre/lib/amd64/server/libjvm.so)
        7f5451feb237 Reflection::invoke_method (/usr/java/jdk1.8.0_60/jre/lib/amd64/server/libjvm.so)
        7f5451d705fb JVM_InvokeMethod (/usr/java/jdk1.8.0_60/jre/lib/amd64/server/libjvm.so)
        7f543da669ed [unknown] (/tmp/perf-21552.map)
        7f543d0007a7 [unknown] (/tmp/perf-21552.map)
        7f5451ce1be6 JavaCalls::call_helper (/usr/java/jdk1.8.0_60/jre/lib/amd64/server/libjvm.so)
        7f5451d23182 jni_invoke_static (/usr/java/jdk1.8.0_60/jre/lib/amd64/server/libjvm.so)
        7f5451d3fb8a jni_CallStaticVoidMethod (/usr/java/jdk1.8.0_60/jre/lib/amd64/server/libjvm.so)
        7f5452bfcbcc JavaMain (/usr/java/jdk1.8.0_60/jre/lib/amd64/jli/libjli.so)
        7f5452e12df5 start_thread (/usr/lib64/libpthread-2.17.so)

Run with perf-map-agent to allow perf to resolve the JITted [unknown] functions to java methods.

There are various other guides on how to do this including Brendan Gregg's work http://techblog.netflix.com/2015/07/java-in-flames.html