RFR: 8257967: JFR: Events for loaded agents [v14]
Markus Grönlund
mgronlun at openjdk.org
Thu Mar 30 19:23:20 UTC 2023
On Thu, 30 Mar 2023 19:20:11 GMT, Markus Grönlund <mgronlun at openjdk.org> wrote:
>> Greetings,
>>
>> We are adding support to let JFR report on Agents.
>>
>> #### Design
>>
>> An Agent is a library that uses any instrumentation or profiling APIs. Most agents are started and initialized on the command line, but agents can also be loaded dynamically during runtime. Because command line agents initialize during the VM startup sequence, they add to the overall startup time latency in getting the VM ready. The events will report on the time the agent took to initialize.
>>
>> A JavaAgent is an agent written in the Java programming language, using the APIs in the package [java.lang.instrument](https://docs.oracle.com/en/java/javase/19/docs/api/java.instrument/java/lang/instrument/package-summary.html)
>>
>> A JavaAgent is sometimes called a JPLIS agent, where the acronym JPLIS stands for Java Programming Language Instrumentation Services.
>>
>> To report on JavaAgents, JFR will add the new event type jdk.JavaAgent and events will look similar to these two examples:
>>
>> // Command line
>> jdk.JavaAgent {
>> startTime = 12:31:19.789 (2023-03-08)
>> name = "JavaAgent.jar"
>> options = "foo=bar"
>> dynamic = false
>> initialization = 12:31:15.574 (2023-03-08)
>> initializationTime = 172 ms
>> }
>>
>> // Dynamic load
>> jdk.JavaAgent {
>> startTime = 12:31:31.158 (2023-03-08)
>> name = "JavaAgent.jar"
>> options = "bar=baz"
>> dynamic = true
>> initialization = 12:31:31.037 (2023-03-08)
>> initializationTime = 64,1 ms
>> }
>>
>> The jdk.JavaAgent event type is a JFR periodic event that iterates over running Java agents.
>>
>> For a JavaAgent event, the agent's name will be the specific .jar file containing the instrumentation code. The options will be the specific options passed to the .jar file as part of launching the agent, for example, on the command line: -javaagent: JavaAgent.jar=foo=bar.
>>
>> The "dynamic" field denotes if the agent was loaded via the command line (dynamic = false) or dynamically (dynamic = true)
>>
>> "initialization" is the timestamp the JVM invoked the initialization method, and "initializationTime" is the duration of executing the initialization method.
>>
>> "startTime" represents the time the JFR framework issued the periodic event; hence "initialization" will be earlier than "startTime".
>>
>> An agent can also be written in a native programming language using the [JVM Tools Interface (JVMTI)](https://docs.oracle.com/en/java/javase/19/docs/specs/jvmti.html). This kind of agent, sometimes called a native agent, is a platform-specific binary, sometimes referred to as a library, but here it means a .so or .dll file.
>>
>> To report on native agents, JFR will add the new event type jdk.NativeAgent and events will look similar to this example:
>>
>> jdk.NativeAgent {
>> startTime = 12:31:40.398 (2023-03-08)
>> name = "jdwp"
>> options = "transport=dt_socket,server=y,address=any,onjcmd=y"
>> dynamic = false
>> initialization = 12:31:36.142 (2023-03-08)
>> initializationTime = 0,00184 ms
>> path = "c:\ade\github\openjdk\jdk\build\windows-x86_64-server-slowdebug\jdk\bin\jdwp.dll"
>> }
>>
>> The layout of the event type is very similar to the jdk.JavaAgent event, but here the path to the native library is reported.
>>
>> The initialization of a native agent is performed by invoking an agent-specified callback routine. The "initialization" is when the JVM sent or would have sent the JVMTI VMInit event to a specified callback. "initializationTime" is the duration to execute that specific callback. If no callback is specified for the JVMTI VMInit event, the "initializationTime" will be 0.
>>
>> #### Implementation
>>
>> There has not existed a reification of a JavaAgent directly in the JVM, as these are built on top of the JDK native library, "instrument", using a many-to-one mapping. At the level of the JVM, the only representation of agents after startup is through JvmtiEnv's, which agents request from the JVM during startup and initialization — as such, mapping which JvmtiEnv belongs to what JavaAgent was not possible before.
>>
>> Using implementation details of how the JDK native library "instrument" interacts with the JVM, we can build this mapping to track what JvmtiEnv's "belong" to what JavaAgent. This mapping now lets us report the Java-relevant context (name, options) and measure the time it takes for the JavaAgent to initialize.
>>
>> When implementing this capability, it was necessary to refactor the code used to represent agents, AgentLibrary. The previous implementation was located primarily in arguments.cpp, and threads.cpp but also jvmtiExport.cpp.
>>
>> The refactoring isolates the relevant logic into two new modules, prims/agent.hpp and prims/agentList.hpp. Breaking out this code from their older places will help reduce the sizes of oversized arguments.cpp and threads.cpp.
>>
>> The previous two lists that maintained "agents" (JVMTI) and "libraries" (Xrun) were not thread-safe for concurrent iterations. A single list that allows for concurrent iterations is therefore introduced.
>>
>> Testing: jdk_jfr, tier 1 - 6
>>
>> Thanks
>> Markus
>
> Markus Grönlund has updated the pull request incrementally with one additional commit since the last revision:
>
> restore misssing frees
> Hm, not sure how helpful the events are, but if you want them to be informative, how about adding the path of the jar file or maybe the class names?
It has been considered. The full path of the Java .jar might not be that interesting, and it adds much more complexity to resolve it, as most are relative to the classpath. ClassName will be whatever class exports the prremain or agentmain.
We discussed this internally and decided that if there is an actual demand for it, we can add a "path" field to the JavaAgent event type.
-------------
PR Comment: https://git.openjdk.org/jdk/pull/12923#issuecomment-1490811900
More information about the serviceability-dev
mailing list