Fully featured low overhead profiler for Java EE and Java SE platforms.
Ultimate profiling and monitoring solution for Gradle, Maven, Ant, JUnit and TestNG.
Easy to use performance and memory profiler for .NET framework.

Register Custom yourkit java probe using on startup option

Moderators: Vladimir Kondratyev, Anton Katilin

Register Custom yourkit java probe using on startup option

Postby epro » Mon Mar 30, 2015 1:11 am

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,
epro
 
Posts: 3
Joined: Mon Mar 30, 2015 12:24 am

Re: Register Custom yourkit java probe using on startup opti

Postby Anton Katilin » Mon Mar 30, 2015 10:02 am

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
Anton Katilin
 
Posts: 5576
Joined: Wed Aug 11, 2004 8:37 am

Re: Register Custom yourkit java probe using on startup opti

Postby epro » Mon Mar 30, 2015 10:56 am

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
epro
 
Posts: 3
Joined: Mon Mar 30, 2015 12:24 am

Re: Register Custom yourkit java probe using on startup opti

Postby Anton Katilin » Mon Mar 30, 2015 11:16 am

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
Anton Katilin
 
Posts: 5576
Joined: Wed Aug 11, 2004 8:37 am

Re: Register Custom yourkit java probe using on startup opti

Postby epro » Mon Mar 30, 2015 12:31 pm

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$.
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.
epro
 
Posts: 3
Joined: Mon Mar 30, 2015 12:24 am

Re: Register Custom yourkit java probe using on startup opti

Postby Anton Katilin » Mon Mar 30, 2015 1:34 pm

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.
Anton Katilin
 
Posts: 5576
Joined: Wed Aug 11, 2004 8:37 am


Return to Java Profiler

Who is online

Users browsing this forum: Bing [Bot], Google [Bot] and 6 guests