Register Custom yourkit java probe using on startup option

Questions about YourKit Java Profiler
Post Reply
epro
Posts: 3
Joined: Mon Mar 30, 2015 12:24 am

Register Custom yourkit java probe using on startup option

Post by epro »

Hi,

I am trying to register a custom YourKit java probe using on startup option in eclipse. I tried using a simple @param example code from the documentation. I specified probe_on, probeclasspath and probebootclasspath on eclipse another startup option. However, the probe does not appears on Events recorded by probes; also the manage probe options is inactive.

Could you please point me what I missed here, it been more than a week while I stuck here.

Than You,
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Register Custom yourkit java probe using on startup opti

Post by Anton Katilin »

Hi,

Could you please provide:
1. The full source code of the probe you tried to apply.
2. The agent log file <user home>/.yjp/log/<session name>-<pid>.log

Best regards,
Anton
epro
Posts: 3
Joined: Mon Mar 30, 2015 12:24 am

Re: Register Custom yourkit java probe using on startup opti

Post by epro »

Hi Anton,

Thank you for your swift reply.

The probe source code is snippet code from Parameter annotation @Param Doc example, just used to try the registration process.

Here is the code

Code: Select all

package myProf;

import com.yourkit.probes.*;

@MethodPattern("des.main.SimObject:restoreFrom(Object)")
public class MyYourKitProf {

	  public static void onEnter(@Param(1) Object obj) {
	    System.out.println("myProf object before: " + obj); // will print original 'obj'
	  }

	  public static void onExit(
	    @Param(1) Object obj
	  ){
	    System.out.println("myProf object after: " + obj); // will print original 'obj' (not null)
	  }
}
The agent log file
14124 - 0.009: Command line:
C:\Program Files (x86)\Java\jre7\bin\javaw.exe
-agentpath:C:\ProgramData\YourKit\yjpagent_14124_32_8398371B.dll=tracing,sessionname=DES,profiler_dir=YJPQUOTED433a5c50726f6772616d2046696c65732028783836295c596f75724b6974204a6176612050726f66696c65722032303134206275696c64203134313234,ideport=51403,probe_on=myProf.MyYourKitProf,probeclasspath=E:\ApplicationProfiling\DES\bin\myProf\,onexit=snapshot
-Dfile.encoding=Cp1252
-classpath
E:\ApplicationProfiling\DES\bin;C:\Users\kasspro\Downloads\Galois-2.0p1\Galois-2.0\lib\trove-3.0.0a1.jar;C:\Program Files (x86)\YourKit Java Profiler 2014 build 14124\lib\yjp.jar
des.main.Main
E:\ApplicationProfiling\DES\EventdrivenSimulation\runA\input\csaArray16.net
14124 - 0.009: Executable: C:\Program Files (x86)\Java\jre7\bin\javaw.exe
14124 - 0.009: Windows 7; version 6.1; 32-bit process
14124 - 0.009: Today is 20150330
14124 - 0.010: Build stamp: 201503271511
14124 - 0.010: Agent_OnLoad: orig_options=tracing,sessionname=DES,profiler_dir=YJPQUOTED433a5c50726f6772616d2046696c65732028783836295c596f75724b6974204a6176612050726f66696c65722032303134206275696c64203134313234,ideport=51403,probe_on=myProf.MyYourKitProf,probeclasspath=E:\ApplicationProfiling\DES\bin\myProf\,onexit=snapshot
full_options=,tracing,sessionname=DES,profiler_dir=YJPQUOTED433a5c50726f6772616d2046696c65732028783836295c596f75724b6974204a6176612050726f66696c65722032303134206275696c64203134313234,ideport=51403,probe_on=myProf.MyYourKitProf,probeclasspath=E:\ApplicationProfiling\DES\bin\myProf\,onexit=snapshot,
14124 - 0.010: phase: 1
14124 - 0.010: jvmtiVersion: 30010201
14124 - 0.010: vendor: Oracle Corporation
14124 - 0.010: version: 24.51-b03
14124 - 0.010: info: mixed mode, sharing
14124 - 0.010: probeSystemClassPath: E:\ApplicationProfiling\DES\bin\myProf\
14124 - 0.015: line_method: 1
14124 - 0.039: Reusing existing jar file: C:\Users\kasspro\AppData\Local\Temp\yjp201503271511.jar
14124 - 0.041: JVMTI 30010201; 24.51-b03; Oracle Corporation; mixed mode, sharing; JR=0; I=0
14124 - 0.434:
Error: probe class myProf.MyYourKitProf: class not found
14124 - 0.616: agentStart: 1
14124 - 0.617: agentStart: 2
14124 - 0.620: agentStart: OK
14124 - 1.082: agentInit: 1
14124 - 1.084: agentInit: Core loaded
14124 - 1.105: setTriggers:

14124 - 1.269: setTriggers: to unregister: 0
14124 - 1.270: setTriggers: method listeners to register: 0
14124 - 1.270: setTriggers: OK
14124 - 1.271: shmem: Global\YOURKIT SHARE5 G: NULL (1)
14124 - 1.271: shmem: Local\YOURKIT SHARE5 L: OK, isFirst=0
14124 - 1.278: shmem: Global\YOURKIT SHARE2 G: NULL (1)
14124 - 1.278: shmem: Local\YOURKIT SHARE2 L: OK, isFirst=0
14124 - 1.631: Profiler agent is listening on port 10001
14124 - 1.631: agentInit: Core.init() called
14124 - 1.632: agentInit: OK
14124 - 1.632: startProfiling: 1
14124 - 1.632: CPU tracing calibration will start now...
14124 - 1.641: Launching profiler UI (C:\Program Files (x86)\YourKit Java Profiler 2014 build 14124\bin\profiler.exe)
14124 - 1.667: Calibration: starting...
14124 - 1.667: Events from Auto probes cleared:

14124 - 1.724: socket timeout: 30000
14124 - 1.910: SP: gc #0 0 ms=93 sz=4115 p=0 t=0
14124 - 2.050: f_t_a_d: #3 trn=15 conv=0/0 ms=1
14124 - 2.299: SP: pinned java.lang.NoSuchFieldException
14124 - 2.407: SP: pinned java.lang..
14124 - 2.868: SP: pinned java.lang.ClassNotFoundException
14124 - 5.149: Events from Auto probes cleared:

14124 - 5.149: TracingSettings:
filter=*
filter=+com.yourkit.runtime.Calibration

-------------------------
adaptive = 1
adaptive_min_method_invocation_count = 20000
adaptive_max_average_method_time_ns = 1000
adaptive_min_method_time_percent = 0.100
14124 - 5.383: No probes with activity mode 'Auto' found - nothing to retransform
14124 - 9.475: No probes with activity mode 'Auto' found - nothing to retransform
14124 - 12.365: Events from Auto probes cleared:

14124 - 12.365: TracingSettings:
filter=*
filter=+com.yourkit.runtime.Calibration

-------------------------
adaptive = 1
adaptive_min_method_invocation_count = 20000
adaptive_max_average_method_time_ns = 1000
adaptive_min_method_time_percent = 0.100
14124 - 12.558: No probes with activity mode 'Auto' found - nothing to retransform
14124 - 15.176: No probes with activity mode 'Auto' found - nothing to retransform
14124 - 15.177: Events from Auto probes cleared:

14124 - 15.177: Calibration: completed ( 5928038000/7737744=766 5850037500/967218=6048 5282)
14124 - 15.177: CPU tracing calibration performed: 5282
14124 - 15.178: Events from Auto probes cleared:

14124 - 15.178: TracingSettings:
walltime=*
adaptive=true
adaptive_min_method_invocation_count=20000
adaptive_max_average_method_time_ns=1000
adaptive_min_method_time_percent=0.1

-------------------------
adaptive = 1
adaptive_min_method_invocation_count = 20000
adaptive_max_average_method_time_ns = 1000
adaptive_min_method_time_percent = 0.100
14124 - 15.425: No probes with activity mode 'Auto' found - nothing to retransform
14124 - 15.425: CPU tracing started: walltime=*
adaptive=true
adaptive_min_method_invocation_count=20000
adaptive_max_average_method_time_ns=1000
adaptive_min_method_time_percent=0.1

14124 - 15.425: startProfiling: OK
14124 - 15.731: SP: pinned java.io.FileNotFoundException
14124 - 21.045: adaptive_filter: method #11082: galois.objects.graph.SerialHashMorphObjectGraph$EdgeGraphNode.getData(byte, byte)
cnt=20000 avg_ns=997 time_ns=19957069 (0.340% at tracing_time_ms=5867)
14124 - 90.161: vmDeath: 1
14124 - 90.161: vmDeath: 2
14124 - 90.161: vmDeath: 3
14124 - 90.223: [m: 71 49] WSN: starting...
14124 - 90.306: [m: 72 50] WSN: tables written
14124 - 90.306: [m: 72 50] WSN: heap segment closed
14124 - 90.311: [m: 71 49] WSN: map done
14124 - 90.408: SP: gc #1 4 ms=97 sz=7977 p=4 t=0
14124 - 90.409: [m: 71 49] WSN: done
14124 - 90.409: Snapshot captured: C:\Users\kasspro\Snapshots\DES-2015-03-30-shutdown(9).snapshot
14124 - 90.409: vmDeath: 4
14124 - 90.409: vmDeath: OK
Thank you
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Register Custom yourkit java probe using on startup opti

Post by Anton Katilin »

The agent options you've specified (I'll split them by space for clarity):

tracing
sessionname=DES
profiler_dir=...
ideport=51403
probe_on=myProf.MyYourKitProf
probeclasspath=E:\ApplicationProfiling\DES\bin\myProf\
onexit=snapshot

All seems OK.

However, the log contains an error:
14124 - 0.434: Error: probe class myProf.MyYourKitProf: class not found
Does the file E:\ApplicationProfiling\DES\bin\myProf\myProf\MyYourKitProf.class exist?

(Please note the double "myProf".)

Best regards,
Anton
epro
Posts: 3
Joined: Mon Mar 30, 2015 12:24 am

Re: Register Custom yourkit java probe using on startup opti

Post by epro »

Hi Anton,

No, the class exist on the directory E:\ApplicationProfiling\DES\bin\myProf (single “myProf”). In “probe_on” option, I include my “myProf”, since it said fully qualified class name.

When I tried without “myProf” package name in my probe_on option.
I got
Error: no probes found in classes:
However, when I use the fully qualified class name and “E:\ApplicationProfiling\DES\bin\” directory in probeclasspath (just to remove the redundancy of “myProf”),
my probe registered successfully (Registered: myProf.MyYourKitProf).

However, on the Events lists/table, myProbe does not appear. Where should I expect the output of myProbe?

Thank you very much for your help, I really appreciate your swift help.

In case if the log file need, here is it (the one that successfully registered custom probe)
14124 - 0.007: Command line:
C:\Program Files (x86)\Java\jre7\bin\javaw.exe
-agentpath:C:\ProgramData\YourKit\yjpagent_14124_32_8398371B.dll=tracing,sessionname=DES,profiler_dir=YJPQUOTED433a5c50726f6772616d2046696c65732028783836295c596f75724b6974204a6176612050726f66696c65722032303134206275696c64203134313234,ideport=51859,probe_on=myProf.MyYourKitProf,probeclasspath=E:\ApplicationProfiling\DES\bin\,onexit=snapshot
-Dfile.encoding=Cp1252
-classpath
E:\ApplicationProfiling\DES\bin;C:\Users\kasspro\Downloads\Galois-2.0p1\Galois-2.0\lib\trove-3.0.0a1.jar;C:\Program Files (x86)\YourKit Java Profiler 2014 build 14124\lib\yjp.jar
des.main.Main
E:\ApplicationProfiling\DES\EventdrivenSimulation\runA\input\csaArray16.net
14124 - 0.007: Executable: C:\Program Files (x86)\Java\jre7\bin\javaw.exe
14124 - 0.007: Windows 7; version 6.1; 32-bit process
14124 - 0.008: Today is 20150330
14124 - 0.008: Build stamp: 201503271511
14124 - 0.008: Agent_OnLoad: orig_options=tracing,sessionname=DES,profiler_dir=YJPQUOTED433a5c50726f6772616d2046696c65732028783836295c596f75724b6974204a6176612050726f66696c65722032303134206275696c64203134313234,ideport=51859,probe_on=myProf.MyYourKitProf,probeclasspath=E:\ApplicationProfiling\DES\bin\,onexit=snapshot
full_options=,tracing,sessionname=DES,profiler_dir=YJPQUOTED433a5c50726f6772616d2046696c65732028783836295c596f75724b6974204a6176612050726f66696c65722032303134206275696c64203134313234,ideport=51859,probe_on=myProf.MyYourKitProf,probeclasspath=E:\ApplicationProfiling\DES\bin\,onexit=snapshot,
14124 - 0.008: phase: 1
14124 - 0.008: jvmtiVersion: 30010201
14124 - 0.008: vendor: Oracle Corporation
14124 - 0.008: version: 24.51-b03
14124 - 0.008: info: mixed mode, sharing
14124 - 0.008: probeSystemClassPath: E:\ApplicationProfiling\DES\bin\
14124 - 0.014: line_method: 1
14124 - 0.039: Reusing existing jar file: C:\Users\kasspro\AppData\Local\Temp\yjp201503271511.jar
14124 - 0.041: JVMTI 30010201; 24.51-b03; Oracle Corporation; mixed mode, sharing; JR=0; I=0
14124 - 0.408: Successfully registered probe classes: 121
Registered: .AWTEvents$EventQueue_dispatchEvent_Probe
Registered: .AgentLoadingSupport$JBoss
Registered: .AgentLoadingSupport$OSGi1
Registered: .AgentLoadingSupport$OSGi2
Registered: .AgentLoadingSupport$OSGi3
Registered: .Databases$Connection_close_Probe
Registered: .Databases$Connection_createStatement_Probe
Registered: .Databases$Connection_prepareStatement_Probe
Registered: .Databases$DataSource_getConnection_Probe
Registered: .Databases$DataSource_setName_Probe
Registered: .Databases$DriverManager_getConnection_Probe
Registered: .Databases$Driver_connect_Probe
Registered: .Databases$InitialContext_lookup_Probe
Registered: .Databases$PooledConnection_getConnection_Probe
Registered: .Databases$PreparedStatement_addBatch_Probe
Registered: .Databases$PreparedStatement_clearBatch_Probe
Registered: .Databases$PreparedStatement_execute_Probe
Registered: .Databases$Statement_addBatch_Probe
Registered: .Databases$Statement_clearBatch_Probe
Registered: .Databases$Statement_close_Probe
Registered: .Databases$Statement_executeBatch_Probe
Registered: .Databases$Statement_execute_Probe
Registered: .DatabasesLW$Connection_close_Probe
Registered: .DatabasesLW$Connection_createStatement_Probe
Registered: .DatabasesLW$Connection_prepareStatement_Probe
Registered: .DatabasesLW$DataSource_getConnection_Probe
Registered: .DatabasesLW$DriverManager_getConnection_Probe
Registered: .DatabasesLW$Driver_connect_Probe
Registered: .DatabasesLW$PooledConnection_getConnection_Probe
Registered: .DatabasesLW$PreparedStatement_execute_Probe
Registered: .DatabasesLW$Statement_close_Probe
Registered: .DatabasesLW$Statement_execute_Probe1
Registered: .DatabasesLW$Statement_execute_Probe2
Registered: .Files$FileChannel_read_Probe
Registered: .Files$FileChannel_write_Probe
Registered: .Files$FileInputStream_close_Probe
Registered: .Files$FileInputStream_open_Probe
Registered: .Files$FileInputStream_readBytes_Probe
Registered: .Files$FileInputStream_read_Probe
Registered: .Files$FileOutputStream_close_Probe
Registered: .Files$FileOutputStream_open_Probe
Registered: .Files$FileOutputStream_writeBytes_Probe
Registered: .Files$FileOutputStream_write_Probe
Registered: .Files$GetChannel_Probe
Registered: .Files$RandomAccessFile_close_Probe
Registered: .Files$RandomAccessFile_open_Probe
Registered: .Files$RandomAccessFile_readBytes_Probe
Registered: .Files$RandomAccessFile_read_Probe
Registered: .Files$RandomAccessFile_writeBytes_Probe
Registered: .Files$RandomAccessFile_write_Probe
Registered: .FilesLW$FileChannelsTelemetry$FileChannel_read_Probe
Registered: .FilesLW$FileChannelsTelemetry$FileChannel_write_Probe
Registered: .FilesLW$FileChannelsTelemetry$GetChannel_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileInputStream_close_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileInputStream_open_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileInputStream_readBytes_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileInputStream_read_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileOutputStream_close_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileOutputStream_open_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileOutputStream_writeBytes_Probe
Registered: .FilesLW$FileStreamsTelemetry$FileOutputStream_write_Probe
Registered: .FilesLW$RandomAccessFilesTelemetry$RandomAccessFile_close_Probe
Registered: .FilesLW$RandomAccessFilesTelemetry$RandomAccessFile_open_Probe
Registered: .FilesLW$RandomAccessFilesTelemetry$RandomAccessFile_readBytes_Probe
Registered: .FilesLW$RandomAccessFilesTelemetry$RandomAccessFile_read_Probe
Registered: .FilesLW$RandomAccessFilesTelemetry$RandomAccessFile_writeBytes_Probe
Registered: .FilesLW$RandomAccessFilesTelemetry$RandomAccessFile_write_Probe
Registered: .JNDI$DirContext_1
Registered: .JNDI$DirContext_2
Registered: .JNDI$NamingContext_1
Registered: .JNDI$NamingContext_2
Registered: .JUnitTests$Old_Run_Probe
Registered: .JUnitTests$Old_SetUp_Probe
Registered: .JUnitTests$Old_TearDown_Probe
Registered: .JUnitTests$Run_Probe
Registered: .JUnitTests$SetUp_Probe
Registered: .JUnitTests$TearDown_Probe
Registered: .Processes$FileOutputStream_writeBytes_Probe
Registered: .Processes$FileOutputStream_write_Probe
Registered: .Processes$InputStream_readBytes_Probe
Registered: .Processes$InputStream_read_Probe
Registered: .Processes$ProcessImpl_getErrorStream_Probe
Registered: .Processes$ProcessImpl_getInputStream_Probe
Registered: .Processes$ProcessImpl_getOutputStream_Probe
Registered: .Processes$ProcessImpl_start_Probe
Registered: .Processes$ProcessImpl_waitFor_Probe
Registered: .Processes$UnixProcess_._Probe
Registered: .Servlets$Filter_doFilter_Probe
Registered: .Servlets$HttpJspPage_jspService_Probe
Registered: .Servlets$Servlet_service_Probe
Registered: .ServletsLW$Filter_doFilter_Probe
Registered: .ServletsLW$HttpJspPage_jspService_Probe
Registered: .ServletsLW$Servlet_service_Probe
Registered: .Sockets$ServerSocketChannel_accept_Probe
Registered: .Sockets$ServerSocket_accept_Probe
Registered: .Sockets$SocketChannel_close_Probe
Registered: .Sockets$SocketChannel_connect_Probe
Registered: .Sockets$SocketChannel_read_Probe
Registered: .Sockets$SocketChannel_write_Probe
Registered: .Sockets$SocketInputStream_read_Probe
Registered: .Sockets$SocketOutputStream_write_Probe
Registered: .Sockets$Socket_close_Probe
Registered: .Sockets$Socket_connect_Probe
Registered: .Sockets$Socket_getInputStream_Probe
Registered: .Sockets$Socket_getOutputStream_Probe
Registered: .SocketsLW$ServerSocketChannel_accept_Probe
Registered: .SocketsLW$ServerSocket_accept_Probe
Registered: .SocketsLW$SocketChannel_close_Probe
Registered: .SocketsLW$SocketChannel_connect_Probe
Registered: .SocketsLW$SocketChannel_read_Probe
Registered: .SocketsLW$SocketChannel_write_Probe
Registered: .SocketsLW$SocketInputStream_read_Probe
Registered: .SocketsLW$SocketOutputStream_write_Probe
Registered: .SocketsLW$Socket_close_Probe
Registered: .SocketsLW$Socket_connect_Probe
Registered: .TestNG$Test_Probe
Registered: .Threads$Thread_constructor_Probe
Registered: .Threads$Thread_run_Probe
Registered: .Threads$Thread_setName_Probe
Registered: .Threads$Thread_start_Probe
Registered: myProf.MyYourKitProf
14124 - 0.661: agentStart: 1
14124 - 0.661: agentStart: 2
14124 - 0.665: agentStart: OK
14124 - 1.115: agentInit: 1
14124 - 1.118: agentInit: Core loaded
14124 - 1.139: setTriggers:

14124 - 1.294: setTriggers: to unregister: 0
14124 - 1.294: setTriggers: method listeners to register: 0
14124 - 1.294: setTriggers: OK
14124 - 1.294: shmem: Global\YOURKIT SHARE5 G: NULL (1)
14124 - 1.295: shmem: Local\YOURKIT SHARE5 L: OK, isFirst=0
14124 - 1.300: shmem: Global\YOURKIT SHARE2 G: NULL (1)
14124 - 1.300: shmem: Local\YOURKIT SHARE2 L: OK, isFirst=0
14124 - 1.633: Profiler agent is listening on port 10001
14124 - 1.634: socket timeout: 30000
14124 - 1.634: agentInit: Core.init() called
14124 - 1.635: Launching profiler UI (C:\Program Files (x86)\YourKit Java Profiler 2014 build 14124\bin\profiler.exe)
14124 - 1.650: agentInit: OK
14124 - 1.650: startProfiling: 1
14124 - 1.651: CPU tracing calibration will start now...
14124 - 1.671: Calibration: starting...
14124 - 1.674: Events from Auto probes cleared:

14124 - 1.898: SP: gc #0 0 ms=112 sz=4170 p=0 t=0
14124 - 2.250: SP: pinned java.lang.NoSuchFieldException
14124 - 2.350: SP: pinned java.lang..
14124 - 2.867: SP: pinned java.lang.ClassNotFoundException
14124 - 4.822: Events from Auto probes cleared:

14124 - 4.822: TracingSettings:
filter=*
filter=+com.yourkit.runtime.Calibration

-------------------------
adaptive = 1
adaptive_min_method_invocation_count = 20000
adaptive_max_average_method_time_ns = 1000
adaptive_min_method_time_percent = 0.100
14124 - 5.023: retransformProbes: loaded classes: 1057 probeClassNames: 53
14124 - 5.031: Probe classes to retransform: 3
com.yourkit.probes.builtin.Files$FileInputStream_close_Probe
com.yourkit.probes.builtin.Files$FileInputStream_open_Probe
com.yourkit.probes.builtin.Files$FileInputStream_readBytes_Probe
14124 - 5.036: Probe classes retransform completed
14124 - 8.739: retransformProbes: loaded classes: 1093 probeClassNames: 53
14124 - 8.744: Probe classes to retransform: 9
com.yourkit.probes.builtin.Files$FileInputStream_close_Probe
com.yourkit.probes.builtin.Files$FileInputStream_open_Probe
com.yourkit.probes.builtin.Files$FileInputStream_readBytes_Probe
com.yourkit.probes.builtin.Sockets$ServerSocket_accept_Probe
com.yourkit.probes.builtin.Sockets$SocketInputStream_read_Probe
com.yourkit.probes.builtin.Sockets$SocketOutputStream_write_Probe
com.yourkit.probes.builtin.Sockets$Socket_close_Probe
com.yourkit.probes.builtin.Sockets$Socket_getInputStream_Probe
com.yourkit.probes.builtin.Sockets$Socket_getOutputStream_Probe
14124 - 8.761: Probe classes retransform completed
14124 - 11.443: Events from Auto probes cleared:
#39 Socket
#40 Read
#41 Write
#42 Channel Read
#43 Channel Write
#44 Close

14124 - 11.444: TracingSettings:
filter=*
filter=+com.yourkit.runtime.Calibration

-------------------------
adaptive = 1
adaptive_min_method_invocation_count = 20000
adaptive_max_average_method_time_ns = 1000
adaptive_min_method_time_percent = 0.100
14124 - 11.659: retransformProbes: loaded classes: 1107 probeClassNames: 53
14124 - 11.664: Probe classes to retransform: 9
com.yourkit.probes.builtin.Files$FileInputStream_close_Probe
com.yourkit.probes.builtin.Files$FileInputStream_open_Probe
com.yourkit.probes.builtin.Files$FileInputStream_readBytes_Probe
com.yourkit.probes.builtin.Sockets$ServerSocket_accept_Probe
com.yourkit.probes.builtin.Sockets$SocketInputStream_read_Probe
com.yourkit.probes.builtin.Sockets$SocketOutputStream_write_Probe
com.yourkit.probes.builtin.Sockets$Socket_close_Probe
com.yourkit.probes.builtin.Sockets$Socket_getInputStream_Probe
com.yourkit.probes.builtin.Sockets$Socket_getOutputStream_Probe
14124 - 11.678: Probe classes retransform completed
14124 - 14.086: retransformProbes: loaded classes: 1107 probeClassNames: 53
14124 - 14.091: Probe classes to retransform: 9
com.yourkit.probes.builtin.Files$FileInputStream_close_Probe
com.yourkit.probes.builtin.Files$FileInputStream_open_Probe
com.yourkit.probes.builtin.Files$FileInputStream_readBytes_Probe
com.yourkit.probes.builtin.Sockets$ServerSocket_accept_Probe
com.yourkit.probes.builtin.Sockets$SocketInputStream_read_Probe
com.yourkit.probes.builtin.Sockets$SocketOutputStream_write_Probe
com.yourkit.probes.builtin.Sockets$Socket_close_Probe
com.yourkit.probes.builtin.Sockets$Socket_getInputStream_Probe
com.yourkit.probes.builtin.Sockets$Socket_getOutputStream_Probe
14124 - 14.106: Probe classes retransform completed
14124 - 14.106: Events from Auto probes cleared:
#39 Socket
#40 Read
#41 Write
#42 Channel Read
#43 Channel Write
#44 Close

14124 - 14.106: Calibration: completed ( 5616036000/7737744=725 5584835800/967218=5774 5049)
14124 - 14.107: CPU tracing calibration performed: 5049
14124 - 14.107: Events from Auto probes cleared:
#39 Socket
#40 Read
#41 Write
#42 Channel Read
#43 Channel Write
#44 Close

14124 - 14.108: TracingSettings:
walltime=*
adaptive=true
adaptive_min_method_invocation_count=20000
adaptive_max_average_method_time_ns=1000
adaptive_min_method_time_percent=0.1

-------------------------
adaptive = 1
adaptive_min_method_invocation_count = 20000
adaptive_max_average_method_time_ns = 1000
adaptive_min_method_time_percent = 0.100
14124 - 14.300: retransformProbes: loaded classes: 1107 probeClassNames: 53
14124 - 14.312: Probe classes to retransform: 9
com.yourkit.probes.builtin.Files$FileInputStream_close_Probe
com.yourkit.probes.builtin.Files$FileInputStream_open_Probe
com.yourkit.probes.builtin.Files$FileInputStream_readBytes_Probe
com.yourkit.probes.builtin.Sockets$ServerSocket_accept_Probe
com.yourkit.probes.builtin.Sockets$SocketInputStream_read_Probe
com.yourkit.probes.builtin.Sockets$SocketOutputStream_write_Probe
com.yourkit.probes.builtin.Sockets$Socket_close_Probe
com.yourkit.probes.builtin.Sockets$Socket_getInputStream_Probe
com.yourkit.probes.builtin.Sockets$Socket_getOutputStream_Probe
14124 - 14.332: Probe classes retransform completed
14124 - 14.332: CPU tracing started: walltime=*
adaptive=true
adaptive_min_method_invocation_count=20000
adaptive_max_average_method_time_ns=1000
adaptive_min_method_time_percent=0.1

14124 - 14.332: startProfiling: OK
14124 - 14.850: SP: pinned java.io.FileNotFoundException
14124 - 15.221: adaptive_filter: method #3804: sun.nio.cs.SingleByte$Decoder.decode(int)
cnt=20000 avg_ns=952 time_ns=19056494 (1.711% at tracing_time_ms=1113)
14124 - 16.529: adaptive_filter: method #4236: java.lang.CharacterDataLatin1.getProperties(int)
cnt=20000 avg_ns=969 time_ns=19385394 (0.800% at tracing_time_ms=2421)
14124 - 19.916: adaptive_filter: method #11127: galois.objects.graph.SerialHashMorphObjectGraph$EdgeGraphNode.getData(byte, byte)
cnt=20000 avg_ns=963 time_ns=19263627 (0.332% at tracing_time_ms=5809)
14124 - 85.130: vmDeath: 1
14124 - 85.130: vmDeath: 2
14124 - 85.130: vmDeath: 3
14124 - 85.211: [m: 72 51] WSN: starting...
14124 - 85.288: [m: 73 52] WSN: tables written
14124 - 85.288: [m: 73 52] WSN: heap segment closed
14124 - 85.289: [m: 72 51] WSN: map done
14124 - 85.379: SP: gc #1 4 ms=90 sz=8524 p=4 t=137
14124 - 85.379: [m: 72 51] WSN: done
14124 - 85.379: Snapshot captured: C:\Users\kasspro\Snapshots\DES-2015-03-30-shutdown(12).snapshot
14124 - 85.379: vmDeath: 4
14124 - 85.380: vmDeath: OK
Once again, thank you very much.
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Register Custom yourkit java probe using on startup opti

Post by Anton Katilin »

probeclasspath works like Java's classpath: it requires the "root" directory where the default package classes reside.
In your case, it should be the directory where myProf resides, i.e. E:\ApplicationProfiling\DES\bin

And this makes the probe registered, and it's fine.
The message
Registered: ... myProf.MyYourKitProf
means that the class was accepted as a probe.
However, on the Events lists/table, myProbe does not appear.
Correct, since all what it does is System.out.println().
Where should I expect the output of myProbe?
In the profiled application's stdout.

The Event list is populated only when the probe creates a table:
https://www.yourkit.com/docs/java/help/data_storage.jsp

I can suggest to consider a tigger on method invocation instead of probes:
https://www.yourkit.com/docs/java/help/triggers.jsp

Technically, they are based on probes, i.e. when you create a trigger a probe is created basing on a template.

Triggers are much easier to start working with, and they allow to explicitly target the output to a table (will be seen in the Event tree), to a file, to console, or to the agent log.
Post Reply