Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

support pns style flamegraph #886

Closed
qsLI opened this issue Feb 2, 2024 · 5 comments
Closed

support pns style flamegraph #886

qsLI opened this issue Feb 2, 2024 · 5 comments
Labels

Comments

@qsLI
Copy link

qsLI commented Feb 2, 2024

The pns function is a debug function in jvm debug version,it gives more details:

help info:

(gdb) call help()

"Executing help"
basic
  pp(void* p)   - try to make sense of p
  ps()          - print current thread stack
  pss()         - print all thread stacks
  pm(int pc)    - print Method* given compiled PC
  findm(intptr_t pc) - finds Method*
  find(intptr_t x)   - finds & prints nmethod/stub/bytecode/oop based on pointer into it
  pns(void* sp, void* fp, void* pc)  - print native (i.e. mixed) stack trace. E.g.
                   pns($sp, $rbp, $pc) on Linux/amd64 or
                   pns($sp, $ebp, $pc) on Linux/x86 or
                   pns($sp, $fp, $pc)  on Linux/AArch64 or
                   pns($sp, 0, $pc)    on Linux/ppc64 or
                   pns($sp, $s8, $pc)  on Linux/mips or
                 - in gdb do 'set overload-resolution off' before calling pns()
                 - in dbx do 'frame 1' before calling pns()
misc.
  flush()       - flushes the log file
  events()      - dump events from ring buffers
compiler debugging
  debug()       - to set things up for compiler debugging
  ndebug()      - undo debug

for example:

V  [libjvm.so+0xdceef3]  LinkResolver::resolve_invokestatic(CallInfo&, constantPoolHandle const&, int, JavaThread*)+0x2f
V  [libjvm.so+0xdceae1]  LinkResolver::resolve_invoke(CallInfo&, Handle, constantPoolHandle const&, int, Bytecodes::Code, JavaThread*)+0x91
V  [libjvm.so+0xaebf3b]  InterpreterRuntime::resolve_invoke(JavaThread*, Bytecodes::Code)+0x307
V  [libjvm.so+0xaec926]  InterpreterRuntime::resolve_from_cache(JavaThread*, Bytecodes::Code)+0xbe
j  com.kuaishou.alwayson.profiler.ProfilerAgentInstaller.lambda$initJFR$1()V+14
j  com.kuaishou.alwayson.profiler.ProfilerAgentInstaller$$Lambda$434+0x00000008004b3ce0.run()V+0
j  com.github.phantomthief.util.MoreFunctions.lambda$runCatching$1(Lcom/github/phantomthief/util/ThrowableRunnable;)Ljava/lang/Object;+1
j  com.github.phantomthief.util.MoreFunctions$$Lambda$100+0x000000080016e630.call()Ljava/lang/Object;+4
j  com.github.phantomthief.util.MoreFunctions.catching(Ljava/util/concurrent/Callable;Lcom/github/phantomthief/util/ThrowableConsumer;)Ljava/lang/Object;+1
j  com.github.phantomthief.util.MoreFunctions.runCatching(Lcom/github/phantomthief/util/ThrowableRunnable;)V+11
j  com.kuaishou.alwayson.profiler.ProfilerAgentInstaller.initJFR()V+5
j  com.kuaishou.alwayson.profiler.PerfInsightProfiler$$Lambda$431+0x00000008004b2f70.run()V+0
j  com.kuaishou.alwayson.profiler.PerfInsightProfiler.lambda$static$2(Ljava/lang/Runnable;)Lcom/kuaishou/alwayson/profiler/ProfilerLifeCycle;+1
j  com.kuaishou.alwayson.profiler.PerfInsightProfiler$$Lambda$432+0x00000008004b31a0.get()Ljava/lang/Object;+4
j  com.kuaishou.alwayson.profiler.PerfInsightProfiler.lambda$profileForAgent$4(Ljava/lang/String;Lcom/kuaishou/alwayson/profiler/PerfConfig;Ljava/util/function/Supplier;Lcom/kuaishou/alwayson/profiler/config/constants/ProfileSource;)V+172
j  com.kuaishou.alwayson.profiler.PerfInsightProfiler$$Lambda$433+0x00000008004b3aa8.run()V+16
J 2632 c1 java.util.concurrent.Executors$RunnableAdapter.call()Ljava/lang/Object; java.base (14 bytes) @ 0x00007fffe1a91434 [0x00007fffe1a91300+0x0000000000000134]
J 2830 c1 java.util.concurrent.FutureTask.run()V java.base (123 bytes) @ 0x00007fffe1b0d524 [0x00007fffe1b0ccc0+0x0000000000000864]
j  java.util.concurrent.ThreadPoolExecutor.runWorker(Ljava/util/concurrent/ThreadPoolExecutor$Worker;)V+92 java.base
j  java.util.concurrent.ThreadPoolExecutor$Worker.run()V+5 java.base
j  java.lang.Thread.run()V+11 java.base
v  ~StubRoutines::call_stub
V  [libjvm.so+0xaf76bd]  JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x595
V  [libjvm.so+0xfc8160]  os::os_exception_wrapper(void (*)(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*), JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x36
V  [libjvm.so+0xaf7124]  JavaCalls::call(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x3a
V  [libjvm.so+0xaf61a0]  JavaCalls::call_virtual(JavaValue*, Klass*, Symbol*, Symbol*, JavaCallArguments*, JavaThread*)+0x19a
V  [libjvm.so+0xaf62ad]  JavaCalls::call_virtual(JavaValue*, Handle, Klass*, Symbol*, Symbol*, JavaThread*)+0x95
V  [libjvm.so+0xbfa5a5]  thread_entry(JavaThread*, JavaThread*)+0x8e
V  [libjvm.so+0x1281b5a]  JavaThread::thread_main_inner()+0x14c
V  [libjvm.so+0x1281a06]  JavaThread::run()+0x11e
V  [libjvm.so+0x127f316]  Thread::call_run()+0x180
V  [libjvm.so+0xfbe8e7]  thread_native_entry(Thread*)+0x18f

jstack and async get call trace seems just ignored the native call between java calls:

void JavaThread::print_stack_on(outputStream* st) {
  if (!has_last_Java_frame()) return;

  Thread* current_thread = Thread::current();
  ResourceMark rm(current_thread);
  HandleMark hm(current_thread);

  RegisterMap reg_map(this);
  vframe* start_vf = last_java_vframe(&reg_map);
  start_vf->fr().print_on(tty);
  int count = 0;
  for (vframe* f = start_vf; f != NULL; f = f->sender()) {
    if (f->is_java_frame()) {
      javaVFrame* jvf = javaVFrame::cast(f);
      java_lang_Throwable::print_stack_element(st, jvf->method(), jvf->bci());

      // Print out lock information
      if (JavaMonitorsInStackTrace) {
        jvf->print_lock_info_on(st, count);
      }
    } else {
      // Ignore non-Java frames
    }

    // Bail-out case for too deep stacks if MaxJavaStackTraceDepth > 0
    count++;
    if (MaxJavaStackTraceDepth > 0 && MaxJavaStackTraceDepth == count) return;
  }
}

The detail information is import for investigate problem like class deadlock init.

Can async profiler support pns style flamegraph?

@apangin
Copy link
Collaborator

apangin commented Feb 2, 2024

Have you tried --cstack vm ?

See #795 for the details.

@qsLI
Copy link
Author

qsLI commented Feb 4, 2024

Have you tried --cstack vm ?

See #795 for the details.

This mode appears to be exactly what I need, but in some cases, it fails to capture the Java method stack.

enviroment

$ java -version
openjdk version "17-internal" 2021-09-14
OpenJDK Runtime Environment (slowdebug build 17-internal+0-adhoc.kk.openjdk)
OpenJDK 64-Bit Server VM (slowdebug build 17-internal+0-adhoc.kk.openjdk, mixed mode)

$ uname -a
Linux staging-liqisheng-02.dev.kwaidc.com 3.10.0-1160.11.1.el7.x86_64 #1 SMP Fri Dec 18 16:34:56 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

test code

code from chatgpt

import java.lang.Throwable;
public class InitLockTest {

	public static class Test1 {
    static {
        // 初始化块
        System.out.println(Thread.currentThread().getName() + " initializing Test1 class...");
        Test2.test();
        System.out.println(Thread.currentThread().getName() + " Test1 class initialized.");
    }

    public static void test() {
        System.out.println(Thread.currentThread().getName() + " in Test1 test method.");
    }
}

public static class Test2 {
    static {
        // 初始化块
        System.out.println(Thread.currentThread().getName() + " initializing Test2 class...");
        Test1.test();
        System.out.println(Thread.currentThread().getName() + " Test2 class initialized.");
    }

    public static void test() {
        System.out.println(Thread.currentThread().getName() + " in Test2 test method.");
    }
}

    public static void main(String[] args) {
        new Thread(() -> Test1.test()).start();
        new Thread(() -> Test2.test()).start();
    }


}

cstack=vm

command

java -agentpath:/tools/async-profiler-3.0-linux-x64/lib/libasyncProfiler.so=start,event=cpu,file=profile.html,timeout=60,cstack=vm InitLockTest

result:

image

call_stub is not parsed correctly,so there’s no java method

cstack=fp

java -agentpath:/tools/async-profiler-3.0-linux-x64/lib/libasyncProfiler.so=start,event=cpu,file=profile.html,timeout=60,cstack=fp InitLockTest
image

@apangin
Copy link
Collaborator

apangin commented Feb 4, 2024

cstack=vm does not currently work on slowdebug builds. It works fine with product JVM though:
cstack-vm

@apangin
Copy link
Collaborator

apangin commented Feb 6, 2024

I added support for cstack=vm for slowdebug JVM builds.
Please check if it helps.

@apangin apangin added the bug label Feb 6, 2024
@apangin apangin closed this as completed Feb 7, 2024
@qsLI
Copy link
Author

qsLI commented Feb 19, 2024

I added support for cstack=vm for slowdebug JVM builds. Please check if it helps.

Awesome! Thanks very much.

image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants