user/kernel space c++ method tracing
Trace the 2nd argument of JNIEXPORT jint JNICALL Agent_OnAttach(JavaVM* vm, char *args, void * reserved)
download perf-tools from https://github.com/brendangregg/perf-tools/
$ sudo bin/uprobe 'p:/usr/java/jdk1.8.0_144/jre/lib/amd64/libinstrument.so:Agent_OnAttach args=+0(%si):string'
Tracing uprobe Agent_OnAttach (p:Agent_OnAttach /usr/java/jdk1.8.0_144/jre/lib/amd64/libinstrument.so:0x27b0 args=+0(%si):string). Ctrl-C to end.
<...>-61491 [012] d... 8823844.123721: Agent_OnAttach: (0x7f0f63df87b0) args="/home/ec2-user/.greys/lib/1.7.6.6/greys/greys-agent.jar=/home/ec2-user/.greys/lib/1.7.6.6/greys/greys-core.jar;;targetIp=127.0.0.1;greysCore=/home/ec2-user/.greys/lib/1.7.6.6/greys/greys-core.jar;greysAgent=/home/ec2-user/.greys/lib/1.7.6.6/greys/greys-agent.jar;connectTimeout=6000;targetPort=3658;javaPid=61228;"
For more complex parameters, like struct pointer, object pointer. Dumping the object layout first, this can be done through clang. https://eli.thegreenplace.net/2012/12/17/dumping-a-c-objects-memory-layout-with-clang
$ objdump -tTC $JAVA_HOME/jre/lib/amd64/server/libjvm.so | grep GCCause::to_string
00000000005d2fd0 l F .text 00000000000001c9 .hidden GCCause::to_string(GCCause::Cause)
$ sudo perf probe -x $JAVA_HOME/jre/lib/amd64/server/libjvm.so '0x00000000005d2fd0%return +0($retval):string'
Added new event:
probe_libjvm:abs_5d2fd0 (on 0x00000000005d2fd0%return in $omit_java_home/jre/lib/amd64/server/libjvm.so with +0($retval):string)
You can now use it in all perf tools, such as:
perf record -e probe_libjvm:abs_5d2fd0 -aR sleep 1
$ sudo perf record -e probe_libjvm:abs_5d2fd0 -a
$ sudo perf script
java 5260 [000] 2190542.672893: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce9144f4d) arg1="No GC"
java 5260 [000] 2190542.672898: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce9144f61) arg1="Allocation Failure"
java 5260 [000] 2190542.672903: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce8b0464d) arg1="Allocation Failure"
java 5260 [000] 2190542.672906: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce8b04663) arg1="Allocation Failure"
java 5260 [000] 2190542.672930: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce8c6825c) arg1="Allocation Failure"
java 5260 [000] 2190542.672962: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce8fbf214) arg1="Allocation Failure"
java 5260 [000] 2190542.692693: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce8b046bf) arg1="Allocation Failure"
java 5260 [000] 2190542.692697: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce8b046d3) arg1="Allocation Failure"
java 5260 [000] 2190542.692699: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce9144f9f) arg1="Allocation Failure"
java 5260 [000] 2190542.692701: probe_libjvm:abs_5d2fd0: (7f0ce8c4ffd0 <- 7f0ce9144fb3) arg1="No GC"
Oracle hotspot jvm 1.8.0u144
$ sudo perf probe -v -x /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so --funcs | head -n 10
(anonymous namespace)::get_global()
ASConcurrentMarkSweepGeneration::cms_size_policy() const
ASConcurrentMarkSweepGeneration::gc_adaptive_policy_counters()
ASConcurrentMarkSweepGeneration::kind()
ASConcurrentMarkSweepGeneration::resize(unsigned long, unsigned long)
ASConcurrentMarkSweepGeneration::short_name() const
ASConcurrentMarkSweepGeneration::shrink_by(unsigned long)
ASConcurrentMarkSweepGeneration::update_counters()
ASConcurrentMarkSweepGeneration::update_counters(unsigned long)
ASConcurrentMarkSweepPolicy::initialize_gc_policy_counters()
function to be traced -- jint JvmtiExport::load_agent_library(AttachOperation* op, outputStream* st)
Check existence
$ sudo perf probe -v -x /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so --funcs | grep load_agent
JvmtiExport::load_agent_library(AttachOperation*, outputStream*)
First attempt to add probe
sudo perf probe -x /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so --add 'JvmtiExport::load_agent_library(AttachOperation*, outputStream*)'
Semantic error :There is non-digit char in line number.
...
Try mangled symbol instead
$ readelf -s --wide /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so | grep load_agen
39207: 000000000079cd00 1389 FUNC LOCAL HIDDEN 13 _ZN11JvmtiExport18load_agent_libraryEP15AttachOperationP12outputStream
$ sudo perf probe -x /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so --add '_ZN11JvmtiExport18load_agent_libraryEP15AttachOperationP12outputStream'
Failed to find symbol _ZN11JvmtiExport18load_agent_libraryEP15AttachOperationP12outputStream in /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so
Error: Failed to add events.
3rd attempt, add probe through function address. The address got from readelf
or objdump
$ objdump -tT /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so | grep _ZN11JvmtiExport18load_agent_libraryEP15AttachOperationP12outputStream | awk '{print $1}'
000000000079cd00
$ sudo perf probe -x /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so --add '0x000000000079cd00'
Added new event:
probe_libjvm:abs_79cd00 (on 0x000000000079cd00 in /usr/java/jdk1.8.0_144/jre/lib/amd64/server/libjvm.so)
You can now use it in all perf tools, such as:
perf record -e probe_libjvm:abs_79cd00 -aR sleep 1
Now try this event
$ sudo perf record -e probe_libjvm:abs_79cd00 -a -g
Lowering default frequency rate to 750.
Please consider tweaking /proc/sys/kernel/perf_event_max_sample_rate.
sudo perf report --stdio
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 2 of event 'probe_libjvm:abs_79cd00'
# Event count (approx.): 2
#
# Children Self Trace output
# ........ ........ ..............
#
100.00% 100.00% (7f304aad6d00)
|
---start_thread
java_start
JavaThread::run
JavaThread::thread_main_inner
JvmtiExport::load_agent_library
sudo perf probe 'vfs_read file->f_path.dentry->d_name.name:string'