Java method profiling saved in JFR format, no corresponding event found

[qsLI]

async profiler version

➜  async-profiler-2.8-macos ./profiler.sh -v
Async-profiler 2.8 built on May  9 2022
Copyright 2016-2021 Andrei Pangin

Java Method Profiling

jfr output

./profiler.sh -e java.lang.Thread.sleep -f p.jfr -d 120 51286

jfr summary:

no execution samples

html output

Native Method Profiling

➜  async-profiler-2.8-macos ./profiler.sh -e JavaThread::sleep  -f p.html -d 120 51286
[ERROR] PerfEvents are unsupported on macOS

since macos does not support perf, we use linux instead

-e JavaThread::sleep -d 60 -f p.jfr

jfr summary:

➜  performance jfr summary p.jfr | grep " jdk.ExecutionSample"
 jdk.ExecutionSample                                   20           659

event content:

render into html:

simple dig

method instrumented

source code

event_type is BCI_INSTRUMENT

void JNICALL Instrument::recordSample(JNIEnv* jni, jobject unused) {
    if (!_enabled) return;

    if (_interval <= 1 || ((atomicInc(_calls) + 1) % _interval) == 0) {
        ExecutionEvent event;
        Profiler::instance()->recordSample(NULL, _interval, BCI_INSTRUMENT, &event);
    }
}

when record event, BCI_INSTRUMENT is ignored

void FlightRecorder::recordEvent(int lock_index, int tid, u32 call_trace_id,
                                 int event_type, Event* event, u64 counter) {
    if (_rec != NULL) {
        Buffer* buf = _rec->buffer(lock_index);
        switch (event_type) {
            case 0:
                _rec->recordExecutionSample(buf, tid, call_trace_id, (ExecutionEvent*)event);
                break;
            case BCI_ALLOC:
                _rec->recordAllocationInNewTLAB(buf, tid, call_trace_id, (AllocEvent*)event);
                break;
            case BCI_ALLOC_OUTSIDE_TLAB:
                _rec->recordAllocationOutsideTLAB(buf, tid, call_trace_id, (AllocEvent*)event);
                break;
            case BCI_LOCK:
                _rec->recordMonitorBlocked(buf, tid, call_trace_id, (LockEvent*)event);
                break;
            case BCI_PARK:
                _rec->recordThreadPark(buf, tid, call_trace_id, (LockEvent*)event);
                break;
        }
        _rec->flushIfNeeded(buf);
        _rec->addThread(tid);
    }
}

Expection

java method profiling via instrument is recorded in jfr events

[qsLI]

seems rewrite in latest code

https://github.com/async-profiler/async-profiler/blob/5da01c0a44e16710e388115cdbcc5c00545d6e3c/src/instrument.cpp#L617C1-L624C2

void JNICALL Instrument::recordSample(JNIEnv* jni, jobject unused) {
    if (!_enabled) return;

    if (_interval <= 1 || ((atomicInc(_calls) + 1) % _interval) == 0) {
        ExecutionEvent event;
        Profiler::instance()->recordSample(NULL, _interval, INSTRUMENTED_METHOD, &event);
    }
}

https://github.com/async-profiler/async-profiler/blob/5da01c0a44e16710e388115cdbcc5c00545d6e3c/src/flightRecorder.cpp#L1430C1-L1461C2

void FlightRecorder::recordEvent(int lock_index, int tid, u32 call_trace_id,
                                 EventType event_type, Event* event) {
    if (_rec != NULL) {
        Buffer* buf = _rec->buffer(lock_index);
        switch (event_type) {
            case PERF_SAMPLE:
            case EXECUTION_SAMPLE:
            case INSTRUMENTED_METHOD:
                _rec->recordExecutionSample(buf, tid, call_trace_id, (ExecutionEvent*)event);
                break;
            case ALLOC_SAMPLE:
                _rec->recordAllocationInNewTLAB(buf, tid, call_trace_id, (AllocEvent*)event);
                break;
            case ALLOC_OUTSIDE_TLAB:
                _rec->recordAllocationOutsideTLAB(buf, tid, call_trace_id, (AllocEvent*)event);
                break;
            case LIVE_OBJECT:
                _rec->recordLiveObject(buf, tid, call_trace_id, (LiveObject*)event);
                break;
            case LOCK_SAMPLE:
                _rec->recordMonitorBlocked(buf, tid, call_trace_id, (LockEvent*)event);
                break;
            case PARK_SAMPLE:
                _rec->recordThreadPark(buf, tid, call_trace_id, (LockEvent*)event);
                break;
            case PROFILING_WINDOW:
                _rec->recordWindow(buf, tid, (ProfilingWindow*)event);
                break;
        }
        _rec->flushIfNeeded(buf);
        _rec->addThread(tid);
    }
}

[qsLI]

Will this be backported?

[apangin]

I verified that Java method profiling works fine with JFR with the master version of async-profiler:

$ asprof -e java.lang.Thread.sleep -f p.jfr -d 120 jps
Profiling for 120 seconds
Done

$ jfr summary p.jfr

 Version: 2.0
 Chunks: 1
 Start: 2023-12-14 14:20:00 (UTC)
 Duration: 120 s

 Event Type                          Count  Size (bytes)
=========================================================
 jdk.CPULoad                           120          2400
 jdk.ActiveSetting                      21           662
 jdk.NativeLibrary                      18          1300
 jdk.InitialSystemProperty              15           844
 jdk.ExecutionSample                     4            52
                                       ^^^

[apangin]

Will this be backported?

We typically maintain only the latest version of async-profiler.
Is there any reason why you can't use the latest version? It is mostly backward compatible, except for minor details.

[qsLI]

Will this be backported?

We typically maintain only the latest version of async-profiler. Is there any reason why you can't use the latest version? It is mostly backward compatible, except for minor details.

Alright, I got it, thank you. We will test the latest version.