Skip to content

weixingsun/jBProF

Repository files navigation

JVM eBPF profiler

JVM profiling tool on linux: low overhead, robust, accurate. 
Consistent with perf top/record
Automatically resolve symbols
Hardware breakpoint sampling, counting, timing, and perform rule-based actions dynamically 

Features:

Agent:   java -agentpath:./libprof.so=$OPTS
Attach:  jcmd $pid JVMTI.agent_load ./libprof.so $OPTS
Binary:  ./jbprof $pid `pwd`/libprof.so $OPT

WHERE $OPTS equals to:

1.Flamegraph: flame.svg [root]

"sample_duration=3;frequency=49;log_file=cpu.log"
./flamegraph.pl cpu.log > flame.svg

2.Thread Sampling: thread.log [root]

"sample_duration=3;frequency=49;sample_thread=4;log_file=thread.log"

pid 	tid 	count	pct 	name
8876	8879	790 	51.13	ParGC Thread#1
8876	8878	742 	48.03	ParGC Thread#0
8876	8880	8   	0.52	VM Thread
8876	8877	5   	0.32	java

3.Method Sampling: method.log [root]

"sample_duration=3;sample_method=9;log_file=method.log"
"sample_duration=3;sample_method=9;log_file=method.log;monitor_duration=1;count_top=3"
"sample_duration=3;sample_method=9;log_file=method.log;monitor_duration=2;lat_top=1"
"sample_duration=3;sample_method=9;log_file=method.log;monitor_duration=3;lat_name=sleep"

Top methods for 3 seconds:
samples	 method_addr	 method_name
 354	 7f9264d26310 -> 7f9264ec3514	 __pthread_mutex_unlock_usercnt
 231	 7f925c023c50 -> 7f925c023c50	 __pthread_mutex_unlock_usercnt
 168	 7f921fa3d2ec -> 7f92457ed3ab	 Interpreter
 110	 7f92640066d2 -> 7f9263ffe740	 __pthread_cond_timedwait
  69	 7f9264ec3440 -> 7f9264a0dea7	 JavaThread::sleep(long)
  66	 7f9236450219 -> 7f926545d4a5	 [UNKNOWN]
  42	 7f9264a0dcc0 -> 7f924d387764	 JVM_Sleep
  38	 7f92640066c2 -> 7f9263ffe730	 __pthread_cond_timedwait
  29	 7f9264ec1430 -> 7f9264ec349d	 java_lang_Thread::interrupted(oopDesc*)
  28	 7f924d3876c8 -> 7f924d38cdc8	 java.lang.Thread.sleep

(2) latency for method: (7f9264ec3440 -> 7f9264a0dea7)	"JavaThread::sleep(long)"
nsecs    	     count
>1048576     	 21	 
>2097152     	 2756	 

(2) latency for method: (7f924d3876c8 -> 7f924d38cdc8)	"java.lang.Thread.sleep"
nsecs    	     count
>1048576     	 11	 
>2097152     	 2752

4.Memory sampling: alloc.log

"sample_duration=5;sample_alloc=4;alloc_class_size=java.lang.String;sample_alloc_interval=10m;log_file=alloc.log"
 Counts	Method(Class)
 293	java.lang.Integer.toString(byte)
 305	java.lang.Integer.toString(java.lang.String)
 206	java.lang.Integer.valueOf(java.lang.Integer)
 374	java.util.HashMap.newNode(java.util.HashMap$Node)
 Class java.lang.String size:
 Counts	Size
 305	24

5.Tuning: tune.log [root]

 "sample_duration=3;sample_method=9;log_file=method.log;rule_cfg=tune.cfg;action_n=3;start_until=PROF%start"
   
 |***************************************|
    perf map: /tmp/perf-1314.map
    sample_duration=3
    sample_method=9
    log_file=method.log
    rule: java.util.HashMap.resize		java.util.HashMap$I^DEFAULT_INITIAL_CAPACITY 	x4<1024
    rule: java.util.HashMap.resize		Main$()V^IncreaseMapInitSize()
    rule: java.util.HashMap.resize>1s	        Main$()V^IncreaseMapInitSize()
    rule: java.util.ArrayList.grow		java.util.ArrayList$I^DEFAULT_CAPACITY       	x2<2048
    rule: java.util.HashMap.getNode		java.util.HashMap$F^DEFAULT_LOAD_FACTOR      	-0.05>0.2
    action_n=3
    start_until=PROF%start
 |***************************************|
 |************* sleep 0s **************|
 found text=start in PROF
 Start BPF
 attached fn:do_perf_event_method to pid:1314 perf event 
 BPF sampling 3 seconds
 sampled 329 methods
 java/util/HashMap.DEFAULT_INITIAL_CAPACITY: 16 -> 64
   
 Initialized BPF(4)
 attached fn:do_perf_event_method to pid:1314 perf event 
 BPF sampling 3 seconds
 sampled 298 methods
 java/util/HashMap.DEFAULT_INITIAL_CAPACITY: 64 -> 256

 Initialized BPF(4)
 attached fn:do_perf_event_method to pid:1314 perf event 
 BPF sampling 3 seconds
 sampled 349 methods
 java/util/HashMap.DEFAULT_INITIAL_CAPACITY: 256 -> 1024
 Done.

Install:

1.install BCC & dependencies
2.install clang
3.install JDK (OpenJDK 10,11,12,13,14 tested)
4.run.sh

Todo || Issues:

1. sometimes there may be duplicated method, it usually caused by JIT recompilation.
2. add feature to get instance level variable values, like ArrayList.size, HashMap.size, from JVMTI api
3. add feature to report on factors which selected by bayes.