#!/usr/sbin/dtrace -Zs
/*
* Copyright (c) 2006, Oracle and/or its affiliates. All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
* are met:
*
* - Redistributions of source code must retain the above copyright
* notice, this list of conditions and the following disclaimer.
*
* - Redistributions in binary form must reproduce the above copyright
* notice, this list of conditions and the following disclaimer in the
* documentation and/or other materials provided with the distribution.
*
* - Neither the name of Oracle nor the names of its
* contributors may be used to endorse or promote products derived
* from this software without specific prior written permission.
*
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS
* IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
* THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
* PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR
* CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
* EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
* PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
* PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
* LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
* NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
* SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/
/*
*/
/*
* Usage:
* 1. gc_time_stat.d -c "java ..." INTERVAL_SECS
* 2. gc_time_stat.d -p JAVA_PID INTERVAL_SECS
*
* This script measures the duration of a time spent in GC. The duration is
* measured for every memory pool every INTERVAL_SECS seconds. If
* INTERVAL_SECS is not set then 10 seconds interval is used.
*
*/
#pragma D option quiet
#pragma D option destructive
#pragma D option defaultargs
#pragma D option aggrate=100ms
string TEST_NAME;
self char *str_ptr;
self string mgr_name;
self string pool_name;
int INTERVAL_SECS;
:::BEGIN
{
SAMPLE_NAME = "hotspot GC tracing";
START_TIME = timestamp;
gc_total_time = 0;
gc_total_count = 0;
INTERVAL_SECS = $1 ? $1 : 10;
SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull;
LINE_SEP = "--------------------------------------------------------";
printf("BEGIN %s\n\n", SAMPLE_NAME);
}
/*
* hotspot:::gc-begin
* arg0: uintptr_t, boolean value which indicates
* if this is to be a full GC or not
*/
hotspot$target:::gc-begin
{
self->gc_ts = timestamp;
printf("\nGC started: %Y\n", walltimestamp);
printf("%20s | %-20s | %10s\n", "manager", "pool", "time (ms)");
printf(" %s\n", LINE_SEP);
}
hotspot$target:::gc-end
/self->gc_ts/
{
self->time = (timestamp - self->gc_ts) / 1000;
printf(" %s\n", LINE_SEP);
printf(" %40s | %10d\n", "GC total", self->time);
gc_total_time += self->time;
gc_total_count ++;
self->gc_ts = 0;
}
/*
* hotspot:::mem-pool-gc-begin, hotspot:::mem-pool-gc-end
* arg0: char*, a pointer to mUTF-8 string data which contains the name
* of the manager which manages this memory pool
* arg1: uintptr_t, the length of the manager name (in bytes
* arg2: char*, a pointer to mUTF-8 string data which contains the name
* of the memory pool
* arg3: uintptr_t, the length of the memory pool name (in bytes)
* arg4: uintptr_t, the initial size of the memory pool (in bytes)
* arg5: uintptr_t, the amount of memory in use in the memory pool
* (in bytes)
* arg6: uintptr_t, the the number of committed pages in the memory pool
* arg7: uintptr_t, the the maximum size of the memory pool
*/
hotspot$target:::mem-pool-gc-begin
{
self->str_ptr = (char*) copyin(arg0, arg1+1);
self->str_ptr[arg1] = '\0';
self->mgr_name = (string) self->str_ptr;
self->str_ptr = (char*) copyin(arg2, arg3+1);
self->str_ptr[arg3] = '\0';
self->pool_name = (string) self->str_ptr;
self->mem_pool_ts[self->mgr_name, self->pool_name] = timestamp;
}
hotspot$target:::mem-pool-gc-end
{
self->str_ptr = (char*) copyin(arg0, arg1+1);
self->str_ptr[arg1] = '\0';
self->mgr_name = (string) self->str_ptr;
self->str_ptr = (char*) copyin(arg2, arg3+1);
self->str_ptr[arg3] = '\0';
self->pool_name = (string) self->str_ptr;
self->time =
(timestamp - self->mem_pool_ts[self->mgr_name, self->pool_name]) / 1000;
printf(
"%20s | %-20s | %10d\n", self->mgr_name, self->pool_name, self->time);
@mem_pool_total_time[self->mgr_name, self->pool_name] = sum(self->time);
self->mem_pool_ts[self->mgr_name, self->pool_name] = 0;
@mem_pool_count[self->mgr_name, self->pool_name] = count();
}
tick-1sec
/timestamp > SAMPLING_TIME/
{
trace_time = (timestamp - START_TIME) / 1000;
printf(" %s\n", LINE_SEP);
printf("\nGC statistics, time: %Y\n\n", walltimestamp);
printf("%20s | %-20s | %10s\n", "manager", "pool", "total time");
printf(" %s\n", LINE_SEP);
printa("%20s | %-20s | %10@d\n", @mem_pool_total_time);
printf(" %s\n", LINE_SEP);
printf(" %40s | %10d\n", "total", gc_total_time);
printf("\n");
printf("%20s | %-20s | %10s\n", "manager", "pool", "# of calls");
printf(" %s\n", LINE_SEP);
printa("%20s | %-20s | %10@d\n", @mem_pool_count);
printf(" %s\n", LINE_SEP);
printf(" %40s | %10d\n", "total", gc_total_count);
SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull;
}
:::END
{
trace_time = (timestamp - START_TIME) / 1000;
printf(" %s\n", LINE_SEP);
printf("\nGC statistics, time: %Y\n\n", walltimestamp);
printf("%20s | %-20s | %10s\n", "manager", "pool", "total time");
printf(" %s\n", LINE_SEP);
printa("%20s | %-20s | %10@d\n", @mem_pool_total_time);
printf(" %s\n", LINE_SEP);
printf(" %40s | %10d\n", "total", gc_total_time);
printf("\n");
printf("%20s | %-20s | %10s\n", "manager", "pool", "# of calls");
printf(" %s\n", LINE_SEP);
printa("%20s | %-20s | %10@d\n", @mem_pool_count);
printf(" %s\n", LINE_SEP);
printf(" %40s | %10d\n", "total", gc_total_count);
printf("\nEND of %s\n", SAMPLE_NAME);
}
syscall::rexit:entry,
syscall::exit:entry
/pid == $target/
{
exit(0);
}