[dtrace-discuss] "dtrace -c" and HotSpot extended probes
Ekaterina Pavlova
Ekaterina.Pavlova at Sun.COM
Thu Aug 17 10:14:32 PDT 2006
Waw, you are right!
I didn't note that in class_loading_stat.d I use argN and in
object_allocation_stat.d I use args[N].
That was the problem. I rewrote object_allocation_stat.d to use argN and
now it works.
Thanks a lot Adam and Chip for so quick problem resolution!
-katya
Adam Leventhal wrote:
>Ah, in this case, the probes aren't created until some time after the
>process has started when the libjvm.so object is opened. When the dtrace(1M)
>command starts, there are no probes matching the probe specifier so there's
>no way to infer the typed arguments.
>
>Adam
>
>On Thu, Aug 17, 2006 at 01:09:52PM +0400, Ekaterina Pavlova wrote:
>
>>yes, you are right.
>>But I cann't get '-l' option work with '-c' option for Hotspot probes.
>>I mean that the probes definitions are not yet loaded at the time dtrace
>>attaches to the java process and as result I get:
>>
>>
>>>dtrace -P hotspot\$target -l -c "java -XX:+ExtendedDTraceProbes -version"
>>>
>> ID PROVIDER MODULE FUNCTION NAME
>> dtrace: failed to match hotspot7073:::: No probe matches description
>>
>>
>>I can do only this:
>>
>>>dtrace -Z -qc "java -XX:+ExtendedDTraceProbes -version" -n
>>>
>>'hotspot\$target:::object-alloc{printf("%s:%s:%s:%s\n", probeprov,
>>probemod,
>> probefunc, probename);}' |sort |uniq
>>
>>java version "1.6.0-rc"
>>Java(TM) SE Runtime Environment (build 1.6.0-rc-b95)
>>Java HotSpot(TM) Client VM (build 1.6.0-rc-b95, mixed mode, sharing)
>>
>>hotspot7168:libjvm.so:__1cNSharedRuntimeYdtrace_object_alloc_base6FpnGThread_pnHoopDesc__i_:object-alloc
>>
>>
>>-katya
>>
>>Chip Bennett wrote:
>>
>>
>>>Hi Katya,
>>>
>>>If I understood you correctly, you said in your first post that if you
>>>attached the D program to an existing process, you didn't get the
>>>error. Don't you need to add the "-l" flag to the one where you used
>>>"-c" to start the program?
>>>
>>>Chip
>>>
>>>Ekaterina Pavlova wrote:
>>>
>>>
>>>>Hmm, I don't think we have multiple probes here.
>>>>'dtrace -l' also shows only one object-alloc probe:
>>>>
>>>>
>>>>>./object_allocation_stat.d -p 6934 -l
>>>>>
>>>> ID PROVIDER MODULE FUNCTION NAME
>>>> 1 dtrace
>>>>BEGIN
>>>>36258 hotspot6934 libjvm.so
>>>>__1cNSharedRuntimeYdtrace_object_alloc_base6FpnGThread_pnHoopDesc__i_
>>>>object-alloc
>>>>38856 profile
>>>>tick-1sec
>>>> 6 syscall rexit
>>>>entry
>>>> 2 dtrace END
>>>>
>>>>
>>>>-katya
>>>>
>>>>Adam Leventhal wrote:
>>>>
>>>>
>>>>>Hi Katya,
>>>>>
>>>>>As Chip mentioned, if an enabling is associated with multiple probes
>>>>>(in this particular case there are apparently several probes in
>>>>>different
>>>>>locations that match) the args[] array can't work since different
>>>>>probes
>>>>>might have different arguments. The argN variable are always available.
>>>>>
>>>>>We've done some work towards addressing this issue, but there's more
>>>>>work to be done.
>>>>>
>>>>>Adam
>>>>>
>>>>>On Wed, Aug 16, 2006 at 08:28:05PM +0400, Ekaterina Pavlova wrote:
>>>>>
>>>>>
>>>>>
>>>>>>Hello,
>>>>>>
>>>>>>We have strange problems with using dtrace '-c' option.
>>>>>>
>>>>>>I have very simple object_allocation_stat.d script (attached) which
>>>>>>trace hotspot:::object-alloc.
>>>>>>These probes are part of HotSpot JVM (JDK 6.0).
>>>>>>When I try to run it I observe following error:
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>>object_allocation_stat.d -c "JDK6/bin/java
>>>>>>>-XX:+ExtendedDTraceProbes -version"
>>>>>>>
>>>>>>>
>>>>>>dtrace: failed to compile script
>>>>>>./hotspot/object_allocation_stat.d: line 53: args[ ] may not be
>>>>>>referenced because probe description hotspot5226:::object-alloc
>>>>>>matches an unstable set of probes
>>>>>>
>>>>>>
>>>>>>However, if I attach object_allocation_stat.d to already running
>>>>>>Java process no any errors are happening.
>>>>>>
>>>>>>At the same time I have similar script called class_loading_stat.d
>>>>>>which trace hotspot:::class-[un]loaded probes.
>>>>>>When I try to run it I don't have any errors:
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>>class_loading_stat.d -c "JDK6/bin/java -XX:+ExtendedDTraceProbes
>>>>>>>-version"
>>>>>>>
>>>>>>>
>>>>>>Loaded classes by package:
>>>>>> 1 java/lang/annotation
>>>>>> 1 java/nio/charset/spi
>>>>>> 1 sun/net/www
>>>>>> 1 sun/net/www/protocol/file
>>>>>> 1 sun/net/www/protocol/jar
>>>>>> ...
>>>>>>
>>>>>>The only difference between hotspot:::object-alloc and
>>>>>>hotspot:::class-[un]loaded probes is that hotspot:::object-alloc are
>>>>>>available only if ExtendedDTraceProbes flag is present
>>>>>>(-XX:+ExtendedDTraceProbes).
>>>>>>
>>>>>>Also, entire hotspot provider, probes, and args are all marked as
>>>>>>'evolving', not stable,
>>>>>>but that doesn't explain why it works for some of the scripts or
>>>>>>when we pause and attach.
>>>>>>
>>>>>>
>>>>>>Does anybody have any ideas why "...matches an unstable set of
>>>>>>probes" error is thrown?
>>>>>>
>>>>>>Thanks a lot,
>>>>>>-katya
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>>>#!/usr/sbin/dtrace -Zs
>>>>>>
>>>>>>#pragma D option quiet
>>>>>>#pragma D option destructive
>>>>>>#pragma D option defaultargs
>>>>>>#pragma D option aggrate=100ms
>>>>>>
>>>>>>/*
>>>>>>* Usage:
>>>>>>* 1. class_loading_stat.d -c "java ..." INTERVAL_SECS
>>>>>>* 2. class_loading_stat.d -p JAVA_PID INTERVAL_SECS
>>>>>>*
>>>>>>* This script collects statistics about loaded and
>>>>>>* unloaded Java classes and dump current state to stdout every
>>>>>>INTERVAL_SECS seconds.
>>>>>>* If INTERVAL_SECS is not set then 10 seconds interval is used.
>>>>>>*
>>>>>>*/
>>>>>>
>>>>>>self char *str_ptr;
>>>>>>self string class_name;
>>>>>>self string package_name;
>>>>>>
>>>>>>int INTERVAL_SECS;
>>>>>>
>>>>>>:::BEGIN
>>>>>>{
>>>>>> printf("BEGIN Java classes loading tracing\n");
>>>>>>
>>>>>> INTERVAL_SECS = $1 ? $1 : 10;
>>>>>> SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull;
>>>>>>
>>>>>> LOADED_CLASSES_CNT = 0;
>>>>>> UNLOADED_CLASSES_CNT = 0;
>>>>>>}
>>>>>>
>>>>>>/*
>>>>>>* hotspot:::class-loaded, hotspot:::class-unloaded probe arguments:
>>>>>>* arg0: char*, class name passed as mUTF8 string
>>>>>>* arg1: uintptr_t, class name length
>>>>>>* arg2: void*, class loader ID, which is unique identifier for
>>>>>>* a class loader in the VM.
>>>>>>* arg3: uintptr_t, class is shared or not
>>>>>>*/
>>>>>>hotspot$target:::class-loaded
>>>>>>{
>>>>>> LOADED_CLASSES_CNT ++;
>>>>>>
>>>>>> self->str_ptr = (char*) copyin(arg0, arg1+1);
>>>>>> self->str_ptr[arg1] = '\0';
>>>>>> self->class_name = (string) self->str_ptr;
>>>>>>
>>>>>> self->package_name = dirname(self->class_name);
>>>>>>
>>>>>> /* printf("class-loaded: class=%s, loader=%x\n",
>>>>>>self->class_name, arg2); */
>>>>>>
>>>>>> @classes_loaded[self->package_name] = count();
>>>>>>}
>>>>>>
>>>>>>hotspot$target:::class-unloaded
>>>>>>{
>>>>>> UNLOADED_CLASSES_CNT ++;
>>>>>>
>>>>>> self->str_ptr = (char*) copyin(arg0, arg1+1);
>>>>>> self->str_ptr[arg1] = '\0';
>>>>>> self->class_name = (string) self->str_ptr;
>>>>>>
>>>>>> self->package_name = dirname(self->class_name);
>>>>>>
>>>>>> @classes_unloaded[self->package_name] = count();
>>>>>>}
>>>>>>
>>>>>>hotspot$target:::vm-shutdown
>>>>>>{
>>>>>> exit(0);
>>>>>>}
>>>>>>
>>>>>>syscall::rexit:entry,
>>>>>>syscall::exit:entry
>>>>>>/pid == $target/
>>>>>>{
>>>>>> exit(0);
>>>>>>}
>>>>>>
>>>>>>tick-1sec
>>>>>>/ timestamp > SAMPLING_TIME /
>>>>>>{
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>> printf("%Y\n", walltimestamp);
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>>
>>>>>> printf("Loaded classes by package:\n");
>>>>>> printa("%10 at d %s\n", @classes_loaded);
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Unloaded classes by package:\n");
>>>>>> printa("%10 at d %s\n", @classes_unloaded);
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Number of loaded classes: %10d\n", LOADED_CLASSES_CNT);
>>>>>> printf("Number of unloaded classes: %10d\n", UNLOADED_CLASSES_CNT);
>>>>>>
>>>>>> SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull;
>>>>>>}
>>>>>>
>>>>>>
>>>>>>:::END
>>>>>>{
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>> printf("%Y\n", walltimestamp);
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>>
>>>>>> printf("Loaded classes by package:\n");
>>>>>> printa("%10 at d %s\n", @classes_loaded);
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Unloaded classes by package:\n");
>>>>>> printa("%10 at d %s\n", @classes_unloaded);
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Number of loaded classes: %10d\n", LOADED_CLASSES_CNT);
>>>>>> printf("Number of unloaded classes: %10d\n", UNLOADED_CLASSES_CNT);
>>>>>>
>>>>>> printf("\nEND hotspot tracing.\n");
>>>>>>}
>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>>>#!/usr/sbin/dtrace -Zs
>>>>>>
>>>>>>#pragma D option quiet
>>>>>>#pragma D option destructive
>>>>>>#pragma D option defaultargs
>>>>>>#pragma D option bufsize=16m
>>>>>>#pragma D option aggrate=100ms
>>>>>>
>>>>>>/*
>>>>>>* Usage:
>>>>>>* 1. object_allocation_stat.d -c "java ..." TOP_RESULTS_COUNT
>>>>>>INTERVAL_SECS
>>>>>>* 2. object_allocation_stat.d -p JAVA_PID TOP_RESULTS_COUNT
>>>>>>INTERVAL_SECS
>>>>>>*
>>>>>>* This script collects statistics about TOP_RESULTS_COUNT (default
>>>>>>is 25) object allocations
>>>>>>* every INTERVAL_SECS (default is 60) seconds.
>>>>>>*
>>>>>>* Notes:
>>>>>>* - these probes are available only with
>>>>>>'-XX:+ExtendedDTraceProbes' option,
>>>>>>* so pass this option too.
>>>>>>* - This script SLOWS DOWN your java application. So, not be
>>>>>>surprised :)
>>>>>>*
>>>>>>*/
>>>>>>
>>>>>>self char *str_ptr;
>>>>>>self string class_name;
>>>>>>
>>>>>>long long ALLOCATED_OBJECTS_CNT;
>>>>>>
>>>>>>int INTERVAL_SECS;
>>>>>>
>>>>>>:::BEGIN
>>>>>>{
>>>>>> TOP_RESULTS_COUNT = $1 ? $1 : 25;
>>>>>> INTERVAL_SECS = $2 ? $2 : 60;
>>>>>>
>>>>>> ALLOCATED_OBJECTS_CNT = 0;
>>>>>>
>>>>>> SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull;
>>>>>>}
>>>>>>
>>>>>>/*
>>>>>>* hotspot:::object-alloc probe arguments:
>>>>>>* arg0: uintptr_t, Java thread id
>>>>>>* arg1: char*, a pointer to mUTF-8 string containing the
>>>>>>name of
>>>>>>* the class of the object being allocated
>>>>>>* arg2: uintptr_t, the length of the class name (in bytes)
>>>>>>* arg3: uintptr_t, the size of the object being allocated
>>>>>>*/
>>>>>>hotspot$target:::object-alloc
>>>>>>{
>>>>>> ALLOCATED_OBJECTS_CNT ++;
>>>>>>
>>>>>> self->str_ptr = (char*) copyin(arg1, args[2]+1);
>>>>>> self->str_ptr[args[2]] = '\0';
>>>>>> self->class_name = (string) self->str_ptr;
>>>>>>
>>>>>>
>>>>>> @allocs_count[self->class_name] = count();
>>>>>> @allocs_size[self->class_name] = sum(args[3]);
>>>>>>
>>>>>>/*
>>>>>> printf("%s:\t[%u] class_name=%s (len=%u), size=%u\n",
>>>>>> probename, args[0], self->class_name, args[2], args[3]);
>>>>>>*/
>>>>>>}
>>>>>>
>>>>>>tick-1sec
>>>>>>/ timestamp > SAMPLING_TIME /
>>>>>>{
>>>>>> printf("\n");
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>> printf("%Y\n", walltimestamp);
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Top %d allocations by size:\n", TOP_RESULTS_COUNT);
>>>>>> trunc(@allocs_size, TOP_RESULTS_COUNT);
>>>>>> printa("%10 at d %s\n", @allocs_size);
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Top %d allocations by count:\n", TOP_RESULTS_COUNT);
>>>>>> trunc(@allocs_count, TOP_RESULTS_COUNT);
>>>>>> printa("%10 at d %s\n", @allocs_count);
>>>>>>
>>>>>> printf("\nTotal number of allocated objects: %d\n",
>>>>>>ALLOCATED_OBJECTS_CNT);
>>>>>>
>>>>>> SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull;
>>>>>>}
>>>>>>
>>>>>>
>>>>>>syscall::rexit:entry,
>>>>>>syscall::exit:entry
>>>>>>/pid == $target/
>>>>>>{
>>>>>> exit(0);
>>>>>>}
>>>>>>
>>>>>>:::END
>>>>>>{
>>>>>> printf("\n");
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>> printf("%Y\n", walltimestamp);
>>>>>>
>>>>>>printf("------------------------------------------------------------------------\n");
>>>>>>
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Top %d allocations by size:\n", TOP_RESULTS_COUNT);
>>>>>> trunc(@allocs_size, TOP_RESULTS_COUNT);
>>>>>> printa("%10 at d %s\n", @allocs_size);
>>>>>>
>>>>>> printf("\n");
>>>>>> printf("Top %d allocations by count:\n", TOP_RESULTS_COUNT);
>>>>>> trunc(@allocs_count, TOP_RESULTS_COUNT);
>>>>>> printa("%10 at d %s\n", @allocs_count);
>>>>>>
>>>>>> printf("\nTotal number of allocated objects: %d\n",
>>>>>>ALLOCATED_OBJECTS_CNT);
>>>>>>}
>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>>>_______________________________________________
>>>>>>dtrace-discuss mailing list
>>>>>>dtrace-discuss at opensolaris.org
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>>
>>--
>>Ekaterina Pavlova,
>>VMSQE Team, St. Petersburg.
>>http://blogs.sun.com/roller/page/vmrobot
>>
>
--
Ekaterina Pavlova,
VMSQE Team, St. Petersburg.
http://blogs.sun.com/roller/page/vmrobot
More information about the dtrace-discuss
mailing list