javaeclipsetraceopenj9

How to dump the content of method argument with OpenJ9 Xtrace Option

Background:

I want to log user activities on Eclipse, for example, what git repositories the users cloned, when did merge conflicts happened, and so on.

I came up with using the OpenJ9 -Xtrace option. First, to test the OpenJ9 -Xtrace option capabilities, I made the following options with OpenJ9: Xtrace Option Builder, and add these options to eclipse.ini to log cloned git repositories.

-Xtrace:none,maximal={mt{entry},mt{exit},mt{exception}},methods={org/eclipse/jgit/api/CloneCommand.setURI(),org/eclipse/jgit/api/CloneCommand.call()},output="C:\tmp\mytrace.trc"
-Xjit:exclude={org/eclipse/jgit/api/CloneCommand.setURI*|org/eclipse/jgit/api/CloneCommand.call*}

Then I launched Eclipse with -clean option, clone a repository, and exit Eclipse. I converted mytrace.trc with traceformat command, and got this output in mytrace.trc.fmt:

                Trace Formatted Data 

Time (UTC)          Thread ID          Tracepoint ID       Type        Tracepoint Data
07:56:41.541990300 *0x0000000001fafe00 mt.0                Entry      >org/eclipse/jgit/api/CloneCommand.setURI(Ljava/lang/String;)Lorg/eclipse/jgit/api/CloneCommand; bytecode method, this = 0x7f9788a98
07:56:41.541991900  0x0000000001fafe00 mt.6                Exit       <org/eclipse/jgit/api/CloneCommand.setURI(Ljava/lang/String;)Lorg/eclipse/jgit/api/CloneCommand; bytecode method
07:56:41.542010000  0x0000000001fafe00 mt.0                Entry      >org/eclipse/jgit/api/CloneCommand.call()Lorg/eclipse/jgit/api/Git; bytecode method, this = 0x7f9788a98
07:56:46.512616000  0x0000000001fafe00 mt.6                Exit       <org/eclipse/jgit/api/CloneCommand.call()Lorg/eclipse/jgit/api/Git; bytecode method
07:56:47.631399600  0x0000000001fafe00 dg.262              Debug       ***** Thread termination - trace purged *****

This output shows setURI() method has an argument (Ljava/lang/String;), but there is no URI that JGit cloned.

Question:

How can I dump the content of method argument with OpenJ9 Xtrace option?

Solution

  • How can I dump the content of method argument with OpenJ9 Xtrace option?

    Your option only enables entry, exit, and exception method trace tracepoints. Method arguments are printed under a different tracepoint. If you use this option instead you should see the additional trace entries containing the arguments.

    However, while the values of primitive arguments are shown in the trace, when the argument is an object you will only see the address of the object on the Java heap. For example, when tracing calls to *.println() you will see something like this:

    15:31:13.710 0x33acc00              mt.18       - this: java/io/PrintStream@00000000FFF04AE0 method arguments: (java/lang/String@00000000E0002768)

    My understanding is that the limitation is due to the architecture of the Xtrace engine, and the performance impact of resolving objects such as Strings and storing them in the trace buffers.

    While addresses can be extremely useful for locating objects of interest in the Java heap, for example when using Eclipse Memory Analyzer to look at an associated system dump, Xtrace cannot provide the functionality you are aiming for.

    A alternative approach would be to use a Java agent to modify (instrument) the org/eclipse/jgit/api/CloneCommand class at runtime to add logging code to the .setURI() method.