1 #!/usr/sbin/dtrace -Zs 2 /* 3 * Copyright (c) 2006, Oracle and/or its affiliates. All rights reserved. 4 * 5 * Redistribution and use in source and binary forms, with or without 6 * modification, are permitted provided that the following conditions 7 * are met: 8 * 9 * - Redistributions of source code must retain the above copyright 10 * notice, this list of conditions and the following disclaimer. 11 * 12 * - Redistributions in binary form must reproduce the above copyright 13 * notice, this list of conditions and the following disclaimer in the 14 * documentation and/or other materials provided with the distribution. 15 * 16 * - Neither the name of Oracle nor the names of its 17 * contributors may be used to endorse or promote products derived 18 * from this software without specific prior written permission. 19 * 20 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS 21 * IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, 22 * THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR 23 * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR 24 * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, 25 * EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, 26 * PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR 27 * PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF 28 * LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING 29 * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS 30 * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. 31 */ 32 33 /* 34 */ 35 36 /* 37 * Usage: 38 * 1. gc_time_stat.d -c "java ..." INTERVAL_SECS 39 * 2. gc_time_stat.d -p JAVA_PID INTERVAL_SECS 40 * 41 * This script measures the duration of a time spent in GC. The duration is 42 * measured for every memory pool every INTERVAL_SECS seconds. If 43 * INTERVAL_SECS is not set then 10 seconds interval is used. 44 * 45 */ 46 47 #pragma D option quiet 48 #pragma D option destructive 49 #pragma D option defaultargs 50 #pragma D option aggrate=100ms 51 52 53 string TEST_NAME; 54 self char *str_ptr; 55 self string mgr_name; 56 self string pool_name; 57 58 int INTERVAL_SECS; 59 60 :::BEGIN 61 { 62 SAMPLE_NAME = "hotspot GC tracing"; 63 64 START_TIME = timestamp; 65 gc_total_time = 0; 66 gc_total_count = 0; 67 68 INTERVAL_SECS = $1 ? $1 : 10; 69 SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull; 70 71 LINE_SEP = "--------------------------------------------------------"; 72 73 printf("BEGIN %s\n\n", SAMPLE_NAME); 74 } 75 76 77 /* 78 * hotspot:::gc-begin 79 * arg0: uintptr_t, boolean value which indicates 80 * if this is to be a full GC or not 81 */ 82 hotspot$target:::gc-begin 83 { 84 self->gc_ts = timestamp; 85 printf("\nGC started: %Y\n", walltimestamp); 86 printf("%20s | %-20s | %10s\n", "manager", "pool", "time (ms)"); 87 printf(" %s\n", LINE_SEP); 88 } 89 90 hotspot$target:::gc-end 91 /self->gc_ts/ 92 { 93 self->time = (timestamp - self->gc_ts) / 1000; 94 95 printf(" %s\n", LINE_SEP); 96 printf(" %40s | %10d\n", "GC total", self->time); 97 98 gc_total_time += self->time; 99 gc_total_count ++; 100 self->gc_ts = 0; 101 } 102 103 /* 104 * hotspot:::mem-pool-gc-begin, hotspot:::mem-pool-gc-end 105 * arg0: char*, a pointer to mUTF-8 string data which contains the name 106 * of the manager which manages this memory pool 107 * arg1: uintptr_t, the length of the manager name (in bytes 108 * arg2: char*, a pointer to mUTF-8 string data which contains the name 109 * of the memory pool 110 * arg3: uintptr_t, the length of the memory pool name (in bytes) 111 * arg4: uintptr_t, the initial size of the memory pool (in bytes) 112 * arg5: uintptr_t, the amount of memory in use in the memory pool 113 * (in bytes) 114 * arg6: uintptr_t, the the number of committed pages in the memory pool 115 * arg7: uintptr_t, the the maximum size of the memory pool 116 */ 117 hotspot$target:::mem-pool-gc-begin 118 { 119 self->str_ptr = (char*) copyin(arg0, arg1+1); 120 self->str_ptr[arg1] = '\0'; 121 self->mgr_name = (string) self->str_ptr; 122 123 self->str_ptr = (char*) copyin(arg2, arg3+1); 124 self->str_ptr[arg3] = '\0'; 125 self->pool_name = (string) self->str_ptr; 126 127 self->mem_pool_ts[self->mgr_name, self->pool_name] = timestamp; 128 } 129 130 hotspot$target:::mem-pool-gc-end 131 { 132 self->str_ptr = (char*) copyin(arg0, arg1+1); 133 self->str_ptr[arg1] = '\0'; 134 self->mgr_name = (string) self->str_ptr; 135 136 self->str_ptr = (char*) copyin(arg2, arg3+1); 137 self->str_ptr[arg3] = '\0'; 138 self->pool_name = (string) self->str_ptr; 139 140 self->time = 141 (timestamp - self->mem_pool_ts[self->mgr_name, self->pool_name]) / 1000; 142 143 printf( 144 "%20s | %-20s | %10d\n", self->mgr_name, self->pool_name, self->time); 145 146 @mem_pool_total_time[self->mgr_name, self->pool_name] = sum(self->time); 147 self->mem_pool_ts[self->mgr_name, self->pool_name] = 0; 148 149 @mem_pool_count[self->mgr_name, self->pool_name] = count(); 150 } 151 152 tick-1sec 153 /timestamp > SAMPLING_TIME/ 154 { 155 trace_time = (timestamp - START_TIME) / 1000; 156 157 printf(" %s\n", LINE_SEP); 158 printf("\nGC statistics, time: %Y\n\n", walltimestamp); 159 printf("%20s | %-20s | %10s\n", "manager", "pool", "total time"); 160 printf(" %s\n", LINE_SEP); 161 printa("%20s | %-20s | %10@d\n", @mem_pool_total_time); 162 printf(" %s\n", LINE_SEP); 163 printf(" %40s | %10d\n", "total", gc_total_time); 164 165 printf("\n"); 166 printf("%20s | %-20s | %10s\n", "manager", "pool", "# of calls"); 167 printf(" %s\n", LINE_SEP); 168 printa("%20s | %-20s | %10@d\n", @mem_pool_count); 169 printf(" %s\n", LINE_SEP); 170 printf(" %40s | %10d\n", "total", gc_total_count); 171 172 SAMPLING_TIME = timestamp + INTERVAL_SECS * 1000000000ull; 173 } 174 175 :::END 176 { 177 trace_time = (timestamp - START_TIME) / 1000; 178 179 printf(" %s\n", LINE_SEP); 180 printf("\nGC statistics, time: %Y\n\n", walltimestamp); 181 printf("%20s | %-20s | %10s\n", "manager", "pool", "total time"); 182 printf(" %s\n", LINE_SEP); 183 printa("%20s | %-20s | %10@d\n", @mem_pool_total_time); 184 printf(" %s\n", LINE_SEP); 185 printf(" %40s | %10d\n", "total", gc_total_time); 186 187 printf("\n"); 188 printf("%20s | %-20s | %10s\n", "manager", "pool", "# of calls"); 189 printf(" %s\n", LINE_SEP); 190 printa("%20s | %-20s | %10@d\n", @mem_pool_count); 191 printf(" %s\n", LINE_SEP); 192 printf(" %40s | %10d\n", "total", gc_total_count); 193 194 195 printf("\nEND of %s\n", SAMPLE_NAME); 196 } 197 198 syscall::rexit:entry, 199 syscall::exit:entry 200 /pid == $target/ 201 { 202 exit(0); 203 } 204