Tracing all method calls in Play framework

Play Framework
1

I want to get a log about all called methods inside my Play project (using Intellij Idea) including full package description and timestamp. It should be the same as writing Java code like

Logger.trace("{} <package>.<methodname>",Instant.now());

at the beginning of every method - or at least something similar where I can extract those information.

I tried a few methods listed in https://stackoverflow.com/questions/29382231/how-do-i-trace-methods-calls-in-java but they did not fit my needs or i used them wrong. I’d be glad to get some advice how to use them in combination with Play to get the desired results.

  • Tracer: I could only find inTrace (the others seem no longer supported) but it was not started when running the Project (no error message or similar)

  • Visual VM just gives me “Not supported for this JVM”

  • Integrated Java tools: jstack delivers me the stacktrace but without the actual method names or full package descriptions. The other tools seem not to deliver any information i could use for my usecase.

I’d also appreciate other tools or methods to track all method calls.

[This question is a copy from https://stackoverflow.com/posts/50346346]

2

Saw this post, found it interesting.

I got it to work. In order to add java arguments to sbt, you need to prepend the regular argument with -J.

So for instance, this: sbt -J-noverify -J-javaagent:./intrace-agent.jar run

EDIT: added the -J-noverify to suppress all those VerificationError prints. It’s a flag that was added in JDK8, I found it after a quick google.

Got something like this in the UI: https://i.imgur.com/MZtT2fF.png

Though in the UI, you have to go to “Classes” and enter the classes you want to see. Apparently, it doesn’t default to *.

Sadly, with *, the application I tried it on crashed not much later with this output:

Caught Throwable when trying to instrument: java.util.function.BinaryOperator
java.lang.ArrayIndexOutOfBoundsException: 16128
	at org.intrace.internal.objectweb.asm.ClassReader.readClass(ClassReader.java:2015)
	at org.intrace.internal.objectweb.asm.ClassReader.accept(ClassReader.java:469)
	at org.intrace.internal.objectweb.asm.ClassReader.accept(ClassReader.java:425)
	at org.intrace.agent.ClassTransformer.getInstrumentedClassBytes(ClassTransformer.java:109)
	at org.intrace.agent.ClassTransformer.transform(ClassTransformer.java:275)
	at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
	at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
	at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
	at sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:144)
	at org.intrace.agent.ClassTransformer.instrumentKlasses(ClassTransformer.java:659)
	at org.intrace.agent.ClassTransformer.getResponse(ClassTransformer.java:525)
	at org.intrace.agent.server.AgentClientConnection.runMethod(AgentClientConnection.java:118)
	at org.intrace.output.InstruRunnable.run(InstruRunnable.java:18)
	at java.lang.Thread.run(Thread.java:748)
java.lang.VerifyError
	at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
	at sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:144)
	at org.intrace.agent.ClassTransformer.instrumentKlasses(ClassTransformer.java:659)
	at org.intrace.agent.ClassTransformer.getResponse(ClassTransformer.java:525)
	at org.intrace.agent.server.AgentClientConnection.runMethod(AgentClientConnection.java:118)
	at org.intrace.output.InstruRunnable.run(InstruRunnable.java:18)
	at java.lang.Thread.run(Thread.java:748)
java.lang.VerifyError(repeats some 50 times)

Ending in this:

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007fd3122dfc0c, pid=3732, tid=0x00007fd274583700
#
# JRE version: Java(TM) SE Runtime Environment (8.0_171-b11) (build 1.8.0_171-b11)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.171-b11 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# V  [libjvm.so+0xa36c0c]  Symbol::as_C_string() const+0xc
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# An error report file with more information is saved as:
# /home/myuser/<EDITTED>/hs_err_pid3732.log
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#
/usr/share/sbt/bin/sbt-launch-lib.bash: line 58:  3732 Aborted                 (core dumped) "$@"

And Ubuntu telling me “the application java has stopped unexpectedly.”. First time I’ve ever seen that happen.

So limiting your classes to be instrumented, is recommended.