Overly brief stack traces for Java/linux ?


Bradley Schatz
 

Hi,

 

I’m just starting to come to grips with bcc & perf-map-agent for introspecting java on linux, with the goal of identifying what appears to be an off-heap memory leak (using memleak).

 

I appear to be getting reliable stack decoding for jvm library code and for jit’ed java methods (see below for an example of the former). However I am seeing some very short stack traces which don’t seem to decode (the latter three stacks of below).

 

It’s looking to me like the frame starting with “jna…” is likely the native JNI shared library for the FFI library “JNA”.

 

Any suggestions as to why these latter three are so brief and/or how I can increase the resolution?

 

Apologies if this is the wrong place for such a question. Thank you for your help.

 

Kind regards,

Bradley

 

 

 

 

       119408 bytes in 71 allocations from stack

              os::malloc(unsigned long, MemoryType, NativeCallStack const&)+0xb5 [libjvm.so]

              CodeBlob::set_oop_maps(OopMapSet*) [clone .part.5]+0x75 [libjvm.so]

              CodeBlob::CodeBlob(char const*, CodeBuffer*, int, int, int, int, OopMapSet*)+0xe3 [libjvm.so]

              nmethod::nmethod(Method*, int, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x4d [libjvm.so]

              nmethod::new_nmethod(methodHandle, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x219 [libjvm.so]

              ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int, bool, bool, RTMState)+0x1b1 [libjvm.so]

              Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool)+0xe60 [libjvm.so]

              C2Compiler::compile_method(ciEnv*, ciMethod*, int)+0xa3 [libjvm.so]

              CompileBroker::invoke_compiler_on_method(CompileTask*)+0x808 [libjvm.so]

              CompileBroker::compiler_thread_loop()+0x6d8 [libjvm.so]

              JavaThread::thread_main_inner()+0x1c7 [libjvm.so]

              JavaThread::run()+0x2fa [libjvm.so]

              java_start(Thread*)+0x102 [libjvm.so]

              start_thread+0xf3 [libpthread-2.28.so]

       34603008 bytes in 33 allocations from stack

              [unknown] [jna9005484735610534564.tmp (deleted)]

              [unknown] [perf-31566.map]

       96468992 bytes in 92 allocations from stack

              [unknown] [jna9005484735610534564.tmp (deleted)]

              [unknown] [perf-31566.map]

       295698432 bytes in 282 allocations from stack

              [unknown] [jna9005484735610534564.tmp (deleted)]

              [unknown] [perf-31566.map]

 


Yonghong Song
 

On Wed, Mar 31, 2021 at 11:25 PM Bradley Schatz
<bradley@schatzforensic.com> wrote:

Hi,



I’m just starting to come to grips with bcc & perf-map-agent for introspecting java on linux, with the goal of identifying what appears to be an off-heap memory leak (using memleak).



I appear to be getting reliable stack decoding for jvm library code and for jit’ed java methods (see below for an example of the former). However I am seeing some very short stack traces which don’t seem to decode (the latter three stacks of below).



It’s looking to me like the frame starting with “jna…” is likely the native JNI shared library for the FFI library “JNA”.



Any suggestions as to why these latter three are so brief and/or how I can increase the resolution?
I can see the file has been marked as deleted.

34603008 bytes in 33 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

96468992 bytes in 92 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

So the file has been removed in userspace and current bcc won't be
pass to parse it since it takes the file name as
"jna9005484735610534564.tmp (deleted)"
The file name is actually taken from /proc/<pid>/maps.

I am not sure whether you can hack to parse "jna9005484735610534564.tmp" or not.
But I would consider it is unsafe to do that as the original file
related info may just
exist in kernel and there is a reference to it. For user space, it is
either gone or
could be replaced by something else. So the safest way is to find a place to
do symbolization before file is gone or keep tmp file a little bit longer.



Apologies if this is the wrong place for such a question. Thank you for your help.



Kind regards,

Bradley









119408 bytes in 71 allocations from stack

os::malloc(unsigned long, MemoryType, NativeCallStack const&)+0xb5 [libjvm.so]

CodeBlob::set_oop_maps(OopMapSet*) [clone .part.5]+0x75 [libjvm.so]

CodeBlob::CodeBlob(char const*, CodeBuffer*, int, int, int, int, OopMapSet*)+0xe3 [libjvm.so]

nmethod::nmethod(Method*, int, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x4d [libjvm.so]

nmethod::new_nmethod(methodHandle, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x219 [libjvm.so]

ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int, bool, bool, RTMState)+0x1b1 [libjvm.so]

Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool)+0xe60 [libjvm.so]

C2Compiler::compile_method(ciEnv*, ciMethod*, int)+0xa3 [libjvm.so]

CompileBroker::invoke_compiler_on_method(CompileTask*)+0x808 [libjvm.so]

CompileBroker::compiler_thread_loop()+0x6d8 [libjvm.so]

JavaThread::thread_main_inner()+0x1c7 [libjvm.so]

JavaThread::run()+0x2fa [libjvm.so]

java_start(Thread*)+0x102 [libjvm.so]

start_thread+0xf3 [libpthread-2.28.so]

34603008 bytes in 33 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

96468992 bytes in 92 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

295698432 bytes in 282 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]




Bradley Schatz
 

Thanks for the suggestion. I found a tunable to keep the JNI shared library in memory after loading. As you can see below, it is no longer showing as deleted.

13238272 bytes in 404 allocations from stack
[unknown] [jna2576903844543447777.tmp]
[unknown] [perf-18047.map]

No improvement in granularity though.

In the VM I'm using -XX:+PreserveFramePointer -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints. In perf_maps_agent, I'm using "unfoldall"

Any other suggestions?

Thanks!




On 3/4/21, 2:42 am, "Y Song" <ys114321@gmail.com> wrote:

On Wed, Mar 31, 2021 at 11:25 PM Bradley Schatz
<bradley@schatzforensic.com> wrote:
>
> Hi,
>
>
>
> I’m just starting to come to grips with bcc & perf-map-agent for introspecting java on linux, with the goal of identifying what appears to be an off-heap memory leak (using memleak).
>
>
>
> I appear to be getting reliable stack decoding for jvm library code and for jit’ed java methods (see below for an example of the former). However I am seeing some very short stack traces which don’t seem to decode (the latter three stacks of below).
>
>
>
> It’s looking to me like the frame starting with “jna…” is likely the native JNI shared library for the FFI library “JNA”.
>
>
>
> Any suggestions as to why these latter three are so brief and/or how I can increase the resolution?

I can see the file has been marked as deleted.

34603008 bytes in 33 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

96468992 bytes in 92 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

So the file has been removed in userspace and current bcc won't be
pass to parse it since it takes the file name as
"jna9005484735610534564.tmp (deleted)"
The file name is actually taken from /proc/<pid>/maps.

I am not sure whether you can hack to parse "jna9005484735610534564.tmp" or not.
But I would consider it is unsafe to do that as the original file
related info may just
exist in kernel and there is a reference to it. For user space, it is
either gone or
could be replaced by something else. So the safest way is to find a place to
do symbolization before file is gone or keep tmp file a little bit longer.
>
>
>
> Apologies if this is the wrong place for such a question. Thank you for your help.
>
>
>
> Kind regards,
>
> Bradley
>
>
>
>
>
>
>
>
>
> 119408 bytes in 71 allocations from stack
>
> os::malloc(unsigned long, MemoryType, NativeCallStack const&)+0xb5 [libjvm.so]
>
> CodeBlob::set_oop_maps(OopMapSet*) [clone .part.5]+0x75 [libjvm.so]
>
> CodeBlob::CodeBlob(char const*, CodeBuffer*, int, int, int, int, OopMapSet*)+0xe3 [libjvm.so]
>
> nmethod::nmethod(Method*, int, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x4d [libjvm.so]
>
> nmethod::new_nmethod(methodHandle, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x219 [libjvm.so]
>
> ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int, bool, bool, RTMState)+0x1b1 [libjvm.so]
>
> Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool)+0xe60 [libjvm.so]
>
> C2Compiler::compile_method(ciEnv*, ciMethod*, int)+0xa3 [libjvm.so]
>
> CompileBroker::invoke_compiler_on_method(CompileTask*)+0x808 [libjvm.so]
>
> CompileBroker::compiler_thread_loop()+0x6d8 [libjvm.so]
>
> JavaThread::thread_main_inner()+0x1c7 [libjvm.so]
>
> JavaThread::run()+0x2fa [libjvm.so]
>
> java_start(Thread*)+0x102 [libjvm.so]
>
> start_thread+0xf3 [libpthread-2.28.so]
>
> 34603008 bytes in 33 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
> 96468992 bytes in 92 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
> 295698432 bytes in 282 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
>
>
>


Yonghong Song
 

On Mon, Apr 5, 2021 at 10:08 PM Bradley Schatz
<bradley@schatzforensic.com> wrote:

Thanks for the suggestion. I found a tunable to keep the JNI shared library in memory after loading. As you can see below, it is no longer showing as deleted.

13238272 bytes in 404 allocations from stack
[unknown] [jna2576903844543447777.tmp]
[unknown] [perf-18047.map]
I have no experience with perf-map-agent, but the following is what I guess:
[perf-18047.map] is used to find the mapping between address and symbol.
What does '[unknown] [perf-18047.map]' mean? Does this mean
perf-18047.map is not found? If the perf-<pid>.map file cannot be found,
symbolization won't be possible. Maybe you want to double check this?


No improvement in granularity though.

In the VM I'm using -XX:+PreserveFramePointer -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints. In perf_maps_agent, I'm using "unfoldall"

Any other suggestions?

Thanks!




On 3/4/21, 2:42 am, "Y Song" <ys114321@gmail.com> wrote:

On Wed, Mar 31, 2021 at 11:25 PM Bradley Schatz
<bradley@schatzforensic.com> wrote:
>
> Hi,
>
>
>
> I’m just starting to come to grips with bcc & perf-map-agent for introspecting java on linux, with the goal of identifying what appears to be an off-heap memory leak (using memleak).
>
>
>
> I appear to be getting reliable stack decoding for jvm library code and for jit’ed java methods (see below for an example of the former). However I am seeing some very short stack traces which don’t seem to decode (the latter three stacks of below).
>
>
>
> It’s looking to me like the frame starting with “jna…” is likely the native JNI shared library for the FFI library “JNA”.
>
>
>
> Any suggestions as to why these latter three are so brief and/or how I can increase the resolution?

I can see the file has been marked as deleted.

34603008 bytes in 33 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

96468992 bytes in 92 allocations from stack

[unknown] [jna9005484735610534564.tmp (deleted)]

[unknown] [perf-31566.map]

So the file has been removed in userspace and current bcc won't be
pass to parse it since it takes the file name as
"jna9005484735610534564.tmp (deleted)"
The file name is actually taken from /proc/<pid>/maps.

I am not sure whether you can hack to parse "jna9005484735610534564.tmp" or not.
But I would consider it is unsafe to do that as the original file
related info may just
exist in kernel and there is a reference to it. For user space, it is
either gone or
could be replaced by something else. So the safest way is to find a place to
do symbolization before file is gone or keep tmp file a little bit longer.
>
>
>
> Apologies if this is the wrong place for such a question. Thank you for your help.
>
>
>
> Kind regards,
>
> Bradley
>
>
>
>
>
>
>
>
>
> 119408 bytes in 71 allocations from stack
>
> os::malloc(unsigned long, MemoryType, NativeCallStack const&)+0xb5 [libjvm.so]
>
> CodeBlob::set_oop_maps(OopMapSet*) [clone .part.5]+0x75 [libjvm.so]
>
> CodeBlob::CodeBlob(char const*, CodeBuffer*, int, int, int, int, OopMapSet*)+0xe3 [libjvm.so]
>
> nmethod::nmethod(Method*, int, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x4d [libjvm.so]
>
> nmethod::new_nmethod(methodHandle, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x219 [libjvm.so]
>
> ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int, bool, bool, RTMState)+0x1b1 [libjvm.so]
>
> Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool)+0xe60 [libjvm.so]
>
> C2Compiler::compile_method(ciEnv*, ciMethod*, int)+0xa3 [libjvm.so]
>
> CompileBroker::invoke_compiler_on_method(CompileTask*)+0x808 [libjvm.so]
>
> CompileBroker::compiler_thread_loop()+0x6d8 [libjvm.so]
>
> JavaThread::thread_main_inner()+0x1c7 [libjvm.so]
>
> JavaThread::run()+0x2fa [libjvm.so]
>
> java_start(Thread*)+0x102 [libjvm.so]
>
> start_thread+0xf3 [libpthread-2.28.so]
>
> 34603008 bytes in 33 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
> 96468992 bytes in 92 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
> 295698432 bytes in 282 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
>
>
>


Bradley Schatz
 

What does '[unknown] [perf-18047.map]' mean? Does this mean
perf-18047.map is not found? If the perf-<pid>.map file cannot be found,
symbolization won't be possible. Maybe you want to double check this?
The file perf-18047.map is there and from other parts of the stack trace I can see it being used to successfully resolve symbols.

Thanks!



On 7/4/21, 4:44 am, "Y Song" <ys114321@gmail.com> wrote:

On Mon, Apr 5, 2021 at 10:08 PM Bradley Schatz
<bradley@schatzforensic.com> wrote:
>
> Thanks for the suggestion. I found a tunable to keep the JNI shared library in memory after loading. As you can see below, it is no longer showing as deleted.
>
> 13238272 bytes in 404 allocations from stack
> [unknown] [jna2576903844543447777.tmp]
> [unknown] [perf-18047.map]

I have no experience with perf-map-agent, but the following is what I guess:
[perf-18047.map] is used to find the mapping between address and symbol.
What does '[unknown] [perf-18047.map]' mean? Does this mean
perf-18047.map is not found? If the perf-<pid>.map file cannot be found,
symbolization won't be possible. Maybe you want to double check this?

>
> No improvement in granularity though.
>
> In the VM I'm using -XX:+PreserveFramePointer -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints. In perf_maps_agent, I'm using "unfoldall"
>
> Any other suggestions?
>
> Thanks!
>
>
>
>
> On 3/4/21, 2:42 am, "Y Song" <ys114321@gmail.com> wrote:
>
> On Wed, Mar 31, 2021 at 11:25 PM Bradley Schatz
> <bradley@schatzforensic.com> wrote:
> >
> > Hi,
> >
> >
> >
> > I’m just starting to come to grips with bcc & perf-map-agent for introspecting java on linux, with the goal of identifying what appears to be an off-heap memory leak (using memleak).
> >
> >
> >
> > I appear to be getting reliable stack decoding for jvm library code and for jit’ed java methods (see below for an example of the former). However I am seeing some very short stack traces which don’t seem to decode (the latter three stacks of below).
> >
> >
> >
> > It’s looking to me like the frame starting with “jna…” is likely the native JNI shared library for the FFI library “JNA”.
> >
> >
> >
> > Any suggestions as to why these latter three are so brief and/or how I can increase the resolution?
>
> I can see the file has been marked as deleted.
>
> 34603008 bytes in 33 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
> 96468992 bytes in 92 allocations from stack
>
> [unknown] [jna9005484735610534564.tmp (deleted)]
>
> [unknown] [perf-31566.map]
>
> So the file has been removed in userspace and current bcc won't be
> pass to parse it since it takes the file name as
> "jna9005484735610534564.tmp (deleted)"
> The file name is actually taken from /proc/<pid>/maps.
>
> I am not sure whether you can hack to parse "jna9005484735610534564.tmp" or not.
> But I would consider it is unsafe to do that as the original file
> related info may just
> exist in kernel and there is a reference to it. For user space, it is
> either gone or
> could be replaced by something else. So the safest way is to find a place to
> do symbolization before file is gone or keep tmp file a little bit longer.
> >
> >
> >
> > Apologies if this is the wrong place for such a question. Thank you for your help.
> >
> >
> >
> > Kind regards,
> >
> > Bradley
> >
> >
> >
> >
> >
> >
> >
> >
> >
> > 119408 bytes in 71 allocations from stack
> >
> > os::malloc(unsigned long, MemoryType, NativeCallStack const&)+0xb5 [libjvm.so]
> >
> > CodeBlob::set_oop_maps(OopMapSet*) [clone .part.5]+0x75 [libjvm.so]
> >
> > CodeBlob::CodeBlob(char const*, CodeBuffer*, int, int, int, int, OopMapSet*)+0xe3 [libjvm.so]
> >
> > nmethod::nmethod(Method*, int, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x4d [libjvm.so]
> >
> > nmethod::new_nmethod(methodHandle, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x219 [libjvm.so]
> >
> > ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int, bool, bool, RTMState)+0x1b1 [libjvm.so]
> >
> > Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool)+0xe60 [libjvm.so]
> >
> > C2Compiler::compile_method(ciEnv*, ciMethod*, int)+0xa3 [libjvm.so]
> >
> > CompileBroker::invoke_compiler_on_method(CompileTask*)+0x808 [libjvm.so]
> >
> > CompileBroker::compiler_thread_loop()+0x6d8 [libjvm.so]
> >
> > JavaThread::thread_main_inner()+0x1c7 [libjvm.so]
> >
> > JavaThread::run()+0x2fa [libjvm.so]
> >
> > java_start(Thread*)+0x102 [libjvm.so]
> >
> > start_thread+0xf3 [libpthread-2.28.so]
> >
> > 34603008 bytes in 33 allocations from stack
> >
> > [unknown] [jna9005484735610534564.tmp (deleted)]
> >
> > [unknown] [perf-31566.map]
> >
> > 96468992 bytes in 92 allocations from stack
> >
> > [unknown] [jna9005484735610534564.tmp (deleted)]
> >
> > [unknown] [perf-31566.map]
> >
> > 295698432 bytes in 282 allocations from stack
> >
> > [unknown] [jna9005484735610534564.tmp (deleted)]
> >
> > [unknown] [perf-31566.map]
> >
> >
> >
> >
>