Latency Profiling enhancements #1499

fandreuz · 2025-09-19T15:15:47Z

Description

Removed --latency in favor of --trace
Format examples:
- --trace A.B: latency=0, wildcard signature
- --trace A.B(JJ)V: latency=0
- --trace A.B(JJ)V+10ms: latency=10ms
- --trace A.B+10ms: latency=10ms, wildcard signature
--trace can appear multiple times in the arguments
--trace can target multiple methods in the same or different classes
--trace takes one independent latency threshold for each target
event=A.B will always perform "old" instrumentation
Latency profiling can run in parallel with other profiling modes
args._include/exclude now use std::vector

Related issues

#1421

Motivation and context

This feature is nice to have for users, latency profiling should not exclude other profiling modes.

How has this been tested?

New tests.

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

src/profiler.cpp

src/arguments.h

Makefile

docs/ProfilerOptions.md

src/arguments.cpp

src/profiler.cpp

src/arguments.cpp

src/instrument.cpp

fandreuz · 2025-09-29T14:34:06Z

Hi team, thanks for the feedback. This PR currently does a bit more than what I was expecting:

enable method tracing in parallel with other engines
enable multiple methods to be traced

I'll need some more changes to get the following:

enable multiple methods to be traced in the same class (won't work at the moment)
per-method latency
per-method interval

I see two ways to move forward:

keep this PR open a bit more and add all the required features (I think 1# is needed, 2# is nice, 3# is lower-priority);
we add checks to report an appropriate failure when user tries to do 1#, merge this PR, and follow-up later.

Any thoughts @apangin ?

src/arguments.cpp

src/instrument.cpp

docs/ProfilerOptions.md

src/arguments.cpp

src/instrument.cpp

src/main/main.cpp

src/arguments.h

src/arguments.cpp

src/instrument.cpp

fandreuz · 2025-09-30T13:35:35Z

I propose the following action table:

trace=A.B(50ms)	event=NULL	event=cpu	event=C.D	latency=100ms	Result
yes	yes	no	no	yes	Error: unexpected argument `latency`
yes	no	yes	no	yes	Error: unexpected argument `latency`
yes	no	no	yes	yes	Trace `A.B` with latency=50ms, trace `C.D` with latency=100ms
yes	yes	no	no	no	Trace `A.B` with latency=50ms
yes	no	yes	no	no	Trace `A.B` with latency=50ms, and cpu sampling
yes	no	no	yes	no	Trace `A.B` with latency=50ms, old instrumentation on `C.D`
no	yes	no	no	yes	Error: unexpected argument `latency`
no	no	yes	no	yes	Error: unexpected argument `latency`
no	no	no	yes	yes	Trace `C.D` with latency=100ms
no	yes	no	no	no	Cpu sampling
no	no	yes	no	no	Cpu sampling
no	no	no	yes	no	Old instrumentation on `C.D`

Q:

Is it ok to let --latency refer only to event=C.D, not to --trace?
- Consequence: --trace=A.B will fail, --trace=A.B(50ms) is expected
- Alternative: --trace=A.B will do old instrumentation rather than method tracing
  - If we do this, then we should probably reconsider the name --trace as it won't only do method tracing
Do we want to support row 3# ?

fandreuz · 2025-09-30T14:23:27Z

Discussed offline, we'll remove --latency. New table:

trace=A.B(50ms)	event=NULL	event=cpu	event=C.D	Result
yes	yes	no	no	Trace `A.B` with latency=50ms
yes	no	yes	no	Trace `A.B` with latency=50ms, and cpu sampling
yes	no	no	yes	Trace `A.B` with latency=50ms, old instrumentation on `C.D`
no	yes	no	no	Cpu sampling
no	no	yes	no	Cpu sampling
no	no	no	yes	Old instrumentation on `C.D`

github-actions

⚠️ Clang-Tidy found issue(s) with the introduced code (1/1)

src/instrument.cpp

github-actions

⚠️ Clang-Tidy found issue(s) with the introduced code (1/1)

src/instrument.cpp

This reverts commit 12b4ce7.

fandreuz · 2025-10-14T08:40:31Z

This PR is already very large and not easy to review as is. I think we should take every chance to refactor bits out that can be merged in smaller PRs.

@fandreuz I think the commit should be pushed into a separate PR

Are there other candidates to refactor out into new smaller PRs, in addition to this?

Not really, all these changes should go together as they don't really make sense without each other now. I proposed to split them here, but my comment did not receive any reaction.

I reverted 12b4ce7 in d49d41a.

src/instrument.cpp

apangin · 2025-10-14T21:16:11Z

src/instrument.cpp

+        // Make sure the class is rewritten, constant pool reconstitution
+        // doesn't always work (JDK-8216547)


How is JDK-8216547 related here?

When I have if (name == NULL) return in the ClassFileLoadHook i get a segfault with this stacktrace:

V [libjvm.so+0xa9a409] Symbol::as_C_string() const+0x9 V [libjvm.so+0x4e6cd1] ConstantPool::copy_cpool_bytes(int, SymbolHashMap*, unsigned char*)+0x191 V [libjvm.so+0x75d83c] JvmtiClassFileReconstituter::write_class_file_format()+0x2cc V [libjvm.so+0x7b4f5f] JvmtiEnv::RetransformClasses(int, _jclass* const*)+0x78f V [libjvm.so+0x7600a6] jvmti_RetransformClasses+0x136 C [libasyncProfiler.so+0xea53] VM::RetransformClassesHook(_jvmtiEnv*, int, _jclass* const*)+0x23 C [libasyncProfiler.so+0x1ea6d] Instrument::retransformMatchedClasses(_jvmtiEnv*) [clone .constprop.0]+0xcd C [libasyncProfiler.so+0x1ecbf] Instrument::stop()+0x2f C [libasyncProfiler.so+0x4b61d] Profiler::stop(bool)+0xbd C [libasyncProfiler.so+0x5468f] Profiler::runInternal(Arguments&, Writer&)+0x14f C [libasyncProfiler.so+0x55326] Profiler::run(Arguments&)+0xc6 C [libasyncProfiler.so+0x5605e] VM::VMDeath(_jvmtiEnv*, JNIEnv_*)+0x4e V [libjvm.so+0x7c1b69] JvmtiExport::post_vm_death()+0x1f9 V [libjvm.so+0x69dfbf] before_exit(JavaThread*)+0x12f V [libjvm.so+0xae450b] Threads::destroy_vm()+0x34b V [libjvm.so+0x7110cf] jni_DestroyJavaVM+0x7f C [libjli.so+0x8618] JavaMain+0x5c8 C [libc.so.6+0x891f5]

My impression is that the class data is corrupted somehow and needs to be copied from the original version, which is more or less what is happening in the ticket. I could investigate more if you want to understand the root cause, but it only affects jdk8 and I figured it's not a priority.

This works fine:

if (name == NULL) { VM::jvmti()->Allocate(class_data_len, new_class_data); memcpy(*new_class_data, class_data, class_data_len); *new_class_data_len = class_data_len; return; }

but does not support the request you had the other day, that we should support the feature even when name == NULL by getting the name from class_data.

apangin · 2025-10-14T21:32:49Z

src/instrument.cpp

+            u16 name_idx = _cpool[i]->info();
+            const auto& it = _targets->find(_cpool[name_idx]->as_string());
+            if (it == _targets->end()) {
+                _target_methods = &EMPTY_METHOD_TARGETS;


EMPTY_METHOD_TARGETS does not make sense to me.
If there is nothing to rewrite, return immediately.
If returning NULL from ClassFileLoadHook does not work for some reason (I still don't understand why), you can just copy _src to _dst, and that's it.

If returning NULL from ClassFileLoadHook does not work for some reason (I still don't understand why),

See here

just copy _src to _dst, and that's it.

Check Result::ABORTED: 5696577

src/instrument.cpp

test/test/instrument/InstrumentTests.java

src/frameName.cpp

docs/ProfilingModes.md

src/arguments.h

src/instrument.cpp

This reverts commit a85ddd5.

src/instrument.cpp

Signed-off-by: Andrei Pangin <1749416+apangin@users.noreply.github.com>

fandreuz commented Sep 19, 2025

View reviewed changes

src/profiler.cpp Outdated Show resolved Hide resolved

fandreuz commented Sep 19, 2025

View reviewed changes

src/arguments.h Outdated Show resolved Hide resolved

fandreuz changed the title ~~Enable CPU sampling and latency profiling to run together~~ Enable CPU sampling and method tracing to run together Sep 19, 2025

apangin reviewed Sep 19, 2025

View reviewed changes

Makefile Outdated Show resolved Hide resolved

docs/ProfilerOptions.md Outdated Show resolved Hide resolved

src/arguments.cpp Outdated Show resolved Hide resolved

src/profiler.cpp Outdated Show resolved Hide resolved

Baraa-Hasheesh reviewed Sep 22, 2025

View reviewed changes

src/arguments.cpp Outdated Show resolved Hide resolved

src/arguments.cpp Outdated Show resolved Hide resolved

src/instrument.cpp Outdated Show resolved Hide resolved

fandreuz mentioned this pull request Sep 24, 2025

Clean up EventMask usages #1507

Merged

fandreuz marked this pull request as draft September 26, 2025 13:18

fandreuz marked this pull request as ready for review September 29, 2025 14:34

Baraa-Hasheesh reviewed Sep 29, 2025

View reviewed changes

fandreuz marked this pull request as draft September 29, 2025 15:26

github-actions bot reviewed Oct 1, 2025

View reviewed changes

src/instrument.cpp Outdated Show resolved Hide resolved

github-actions bot reviewed Oct 1, 2025

View reviewed changes

src/instrument.cpp Outdated Show resolved Hide resolved

src/instrument.cpp Outdated Show resolved Hide resolved

fandreuz force-pushed the latency-and-cpu branch from 0e983bf to a50dd59 Compare October 1, 2025 21:53

do stuff

e01247e

fandreuz force-pushed the latency-and-cpu branch from e264b07 to e01247e Compare October 1, 2025 22:08

fandreuz added 10 commits October 1, 2025 22:28

add targets to jfr

519af04

check latency

8aefb57

fix test

e48e316

nn

f486ff1

no plus

be3a9d6

ops

46427ed

ops

054fed8

rename

7f572c7

u64

811f356

err

ad47a04

fandreuz marked this pull request as ready for review October 2, 2025 08:46

fandreuz changed the title ~~Enable CPU sampling and method tracing to run together~~ Latency profiling enhancements Oct 2, 2025

fandreuz added 4 commits October 13, 2025 22:58

lower bound

f732971

tests

00e3fd3

fix

c9a97d0

Revert "jvm_dying"

d49d41a

This reverts commit 12b4ce7.

fandreuz added 4 commits October 14, 2025 08:46

trigger

cc4510b

-ea nn

cb20e14

Merge branch 'master' into latency-and-cpu

4311c17

rename

9dde23b

apangin reviewed Oct 14, 2025

View reviewed changes

test/test/instrument/InstrumentTests.java Show resolved Hide resolved

review

2542eb5

Baraa-Hasheesh reviewed Oct 15, 2025

View reviewed changes

src/frameName.cpp Show resolved Hide resolved

docs/ProfilingModes.md Show resolved Hide resolved

src/arguments.h Show resolved Hide resolved

src/instrument.cpp Outdated Show resolved Hide resolved

fandreuz added 6 commits October 15, 2025 09:52

ABORTED

5696577

rename

4b5bbf3

cc test

2f9e8a9

insert

a85ddd5

Revert "insert"

0a65747

This reverts commit a85ddd5.

no interval when cpu

cccbd14

fandreuz commented Oct 15, 2025

View reviewed changes

src/instrument.cpp Outdated Show resolved Hide resolved

apangin reviewed Oct 15, 2025

View reviewed changes

src/instrument.cpp Outdated Show resolved Hide resolved

src/instrument.cpp Outdated Show resolved Hide resolved

src/instrument.cpp Show resolved Hide resolved

src/instrument.cpp Outdated Show resolved Hide resolved

fandreuz and others added 7 commits October 15, 2025 18:39

latency type

be3cd36

common func for method_targets

99bc734

Merge branch 'master' into latency-and-cpu

aeb767a

nn

7d6e477

comment

c00f7a2

Minor formatting

8e8c3b7

Merge branch 'master' into latency-and-cpu

4e4e7c3

Signed-off-by: Andrei Pangin <1749416+apangin@users.noreply.github.com>

apangin merged commit fc2a9b9 into async-profiler:master Oct 15, 2025
7 checks passed

		// Make sure the class is rewritten, constant pool reconstitution
		// doesn't always work (JDK-8216547)

Latency Profiling enhancements #1499

Latency Profiling enhancements #1499

Uh oh!

Conversation

fandreuz commented Sep 19, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Related issues

Motivation and context

How has this been tested?

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

fandreuz commented Sep 29, 2025

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

fandreuz commented Sep 30, 2025

Uh oh!

fandreuz commented Sep 30, 2025

Uh oh!

github-actions bot left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

github-actions bot left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

fandreuz commented Oct 14, 2025

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

apangin Oct 14, 2025

Choose a reason for hiding this comment

Uh oh!

fandreuz Oct 15, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

fandreuz Oct 15, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

apangin Oct 14, 2025

Choose a reason for hiding this comment

Uh oh!

fandreuz Oct 15, 2025

Choose a reason for hiding this comment

Uh oh!

fandreuz Oct 15, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

fandreuz commented Sep 19, 2025 •

edited

Loading

fandreuz Oct 15, 2025 •

edited

Loading

fandreuz Oct 15, 2025 •

edited

Loading