add support for user JFR events #1223

arielb1 · 2025-04-08T14:18:09Z

This adds an (unstable) profiler.UserEvent JFR event, that can be emitted by user native code and contain custom data.

Using T_STRING for the data instead of T_BYTE/F_ARRAY due to a bug in jfr print:

java.lang.NullPointerException
        at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printValue(PrettyWriter.java:357)
        at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printArray(PrettyWriter.java:281)
        at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printValue(PrettyWriter.java:325)
        at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printFieldValue(PrettyWriter.java:273)
        at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.print(PrettyWriter.java:213)
        at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.print(PrettyWriter.java:76)
        at jdk.jfr/jdk.jfr.internal.tool.EventPrintWriter.print(EventPrintWriter.java:79)
        at jdk.jfr/jdk.jfr.internal.tool.Print.execute(Print.java:165)
        at jdk.jfr/jdk.jfr.internal.tool.Main.main(Main.java:84)

The relevant code is at
https://github.com/openjdk/jdk/blob/965e330cb4a972fd96ff04e149029d1ee0561940/src/jdk.jfr/share/classes/jdk/jfr/internal/tool/PrettyWriter.java#L357

printArray calls printValue with a null field, and printValue only supports a null field with a value of type Byte.

Description

Related issues

Motivation and context

How has this been tested?

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

apangin · 2025-04-09T22:56:50Z

src/asprof.cpp

    return ThreadLocalData::getThreadLocalData();
 }
+
+DLLEXPORT asprof_user_jfr_key asprof_create_user_jfr_key(const char *name) {


type* name everywhere

apangin · 2025-04-09T23:00:34Z

src/asprof.cpp

+    return UserEvents::registerEvent(name);
+}
+
+DLLEXPORT int asprof_emit_user_jfr(asprof_user_jfr_key key, const uint8_t *data, size_t len) {


Will it ever be needed to record events with stack traces?
I initially thought event will have a bitmask of standard fields that should be recorded along with user-provided data. These fields may include threadId and stackTrace.

(It's more like a question for discussion, not necessarily for this PR).

Adding a flags parameter in case someone wants to add flags for this.

The thread id is currently included in all cases, I don't see a reason not to include thread id / timestamp always.

apangin · 2025-04-09T23:14:03Z

src/asprof.h

 typedef asprof_thread_local_data* (*asprof_get_thread_local_data_t)(void);

+
+typedef int asprof_user_jfr_key;


Maybe unsigned int?

Also, I'm not fully happy with "user" in this and other identifiers in this API (who is user?)
WDYT about asprof_event_tag? Alternative suggestions are welcome.

It can be -1 in case of failure, like in "normal" C functions.

user = the user of async-profiler (as opposed to the developer of async profiler = you).

apangin · 2025-04-09T23:20:26Z

src/flightRecorder.cpp

        writePackages(buf, &lookup);
        writeSymbols(buf, &lookup);
        writeLogLevels(buf);
+        writeUserEventTypes(buf);


Write them before log levels. There is no difference for parsing, but it will be easier to spot visually if JFR file is complete or truncated, since valid JFR will always end with predefined recognizable list of log levels.

apangin · 2025-04-09T23:20:48Z

src/flightRecorder.cpp

+        writePoolHeader(buf, T_USER_EVENT_TYPE, events.size());
+        for (std::map<u32, const char*>::const_iterator it = events.begin(); it != events.end(); ++it) {
+            flushIfNeeded(buf, RECORDING_BUFFER_LIMIT - MAX_STRING_LENGTH);
+            buf->putVar64(it->first);


apangin · 2025-04-09T23:24:29Z

src/jfrMetadata.cpp

+                << field("string", T_STRING, "String"))
+
+            << (type("profiler.UserEvent", T_USER_EVENT, "User Event")
+                << category("Java Virtual Machine", "Profiling")


It's not really about Java Virtual Machine. I'd put it in category("Profiler")

apangin · 2025-04-09T23:27:51Z

src/jfrMetadata.cpp

                << field("stackTrace", T_STACK_TRACE, "Stack Trace", F_CPOOL)
                << field("address", T_LONG, "Address", F_ADDRESS))

+            << (type("profiler.UserEventType", T_USER_EVENT_TYPE, "User Event Type", true)


Move it up next to other data types and give it a name in "profiler.types." namespace.

apangin · 2025-04-09T23:28:53Z

src/jfrMetadata.cpp

+            << (type("profiler.UserEvent", T_USER_EVENT, "User Event")
+                << category("Java Virtual Machine", "Profiling")
+                << field("startTime", T_LONG, "Start Time", F_TIME_TICKS)
+                << field("sampledThread", T_THREAD, "Thread", F_CPOOL)


"eventThread" for consistency with other non-sampled events.

apangin · 2025-04-09T23:31:41Z

src/jfrMetadata.h

    T_WALL_CLOCK_SAMPLE = 118,
    T_MALLOC = 119,
    T_FREE = 120,
+    T_USER_EVENT_TYPE = 121,


If ID is between 100 and 199, a class will inherit jdk.jfr.Event, which is not correct. Data types should have IDs below 100.

apangin · 2025-04-09T23:39:32Z

src/userEvents.cpp

+Mutex UserEvents::_state_lock;
+
+int UserEvents::registerEvent(const char *event) {
+    MutexLocker locker(_state_lock);


Dictionary is thread-safe.
Note, however, that numeric keys that Dictionary issues are not sequential, which is probably fine for your purpose. But if for some reason you prefer sequential keys, use std::unordered_map or something.

apangin · 2025-04-14T15:08:02Z

src/asprof.cpp

+    return UserEvents::registerEvent(name);
+}
+
+DLLEXPORT int asprof_emit_user_jfr(asprof_user_jfr_key type, const uint8_t* data, size_t len, uint64_t _flags) {


I'm not sure if flags should be included here or in create_key function, since all events of the same type must have the same structure.
Let's just go without flags now and add them when needed.

apangin · 2025-04-14T15:10:32Z

src/flightRecorder.cpp

        for (std::map<u32, const char*>::const_iterator it = symbols.begin(); it != symbols.end(); ++it) {
            flushIfNeeded(buf, RECORDING_BUFFER_LIMIT - MAX_STRING_LENGTH);
-            buf->putVar64(it->first | _base_id);
+            buf->putVar32(it->first | _base_id);


You've changed it in a wrong place.

apangin · 2025-04-14T15:17:59Z

src/jfrMetadata.cpp

                << field("name", T_STRING, "Name"))

+            << (type("profiler.types.UserEventType", T_USER_EVENT_TYPE, "User-Defined Event Type", true)
+                << category("Profiler")


Category is used for events - it reflects a tree node where JMC groups events of this type.
Category does not make sense for types.

apangin · 2025-04-14T15:18:59Z

src/jfrMetadata.cpp

+                << field("startTime", T_LONG, "Start Time", F_TIME_TICKS)
+                << field("eventThread", T_THREAD, "Event Thread", F_CPOOL)
+                << field("type", T_USER_EVENT_TYPE, "User Event Type", F_CPOOL)
+                // Using T_STRING with a Latin-1 string to encode raw bytes as user data.q


apangin · 2025-04-14T15:32:52Z

src/flightRecorder.cpp


+    void putByteString(const uint8_t* v, size_t len) {
+        put8(5); // STRING_ENCODING_LATIN1_BYTE_ARRAY
+        u32 truncated_len = len < MAX_STRING_LENGTH ? len : MAX_STRING_LENGTH;


All events written during a profiling session (except for prologue events) are rather small; async-profiler currently reserves 4096 bytes at the end of a buffer to accommodate such events. Either reserved size should be revised, or maximum length of a user event needs to be decreased. Alternatively, recordUserEvent should do an extra flushIfNeeded call in the beginning, although it's less preferable to me.

src/asprof.cpp

This adds an (unstable) `profiler.UserEvent` JFR event, that can be emitted by user native code and contain custom data. Using T_STRING for the data instead of T_BYTE/F_ARRAY due to a bug in `jfr print`: ``` java.lang.NullPointerException at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printValue(PrettyWriter.java:357) at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printArray(PrettyWriter.java:281) at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printValue(PrettyWriter.java:325) at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.printFieldValue(PrettyWriter.java:273) at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.print(PrettyWriter.java:213) at jdk.jfr/jdk.jfr.internal.tool.PrettyWriter.print(PrettyWriter.java:76) at jdk.jfr/jdk.jfr.internal.tool.EventPrintWriter.print(EventPrintWriter.java:79) at jdk.jfr/jdk.jfr.internal.tool.Print.execute(Print.java:165) at jdk.jfr/jdk.jfr.internal.tool.Main.main(Main.java:84) ``` The relevant code is at https://github.com/openjdk/jdk/blob/965e330cb4a972fd96ff04e149029d1ee0561940/src/jdk.jfr/share/classes/jdk/jfr/internal/tool/PrettyWriter.java#L357 `printArray` calls `printValue` with a `null` `field`, and `printValue` only supports a `null` `field` with a value of type `Byte`.

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

arielb1 force-pushed the app-jfr branch 2 times, most recently from de97888 to 50aaf13 Compare April 8, 2025 15:29

apangin reviewed Apr 9, 2025

View reviewed changes

arielb1 force-pushed the app-jfr branch from 1114fe7 to ae913a8 Compare April 10, 2025 11:36

apangin reviewed Apr 14, 2025

View reviewed changes

Ariel Ben-Yehuda added 3 commits April 15, 2025 10:59

address review comments

3164a54

address review comments

cb3fd5a

arielb1 force-pushed the app-jfr branch from ae913a8 to cb3fd5a Compare April 15, 2025 10:59

Ariel Ben-Yehuda and others added 3 commits April 15, 2025 11:10

add size assertion

101c6fc

Naming & formatting

8031ce5

Naming & formatting

a79a943

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

apangin merged commit 164eac4 into async-profiler:master Apr 15, 2025
7 of 10 checks passed

apangin mentioned this pull request Apr 18, 2025

Allow some way of emitting events from native code #1107

Closed

2 tasks

		typedef asprof_thread_local_data* (*asprof_get_thread_local_data_t)(void);


		typedef int asprof_user_jfr_key;

add support for user JFR events #1223

add support for user JFR events #1223

Uh oh!

Conversation

arielb1 commented Apr 8, 2025

Description

Related issues

Motivation and context

How has this been tested?

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

apangin Apr 9, 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!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

apangin Apr 9, 2025 •

edited

Loading