dtracelio.d
Note: if you will do copy/paste you will probably need to process the file with dos2unix before execution
#!/usr/sbin/dtrace -CZs
/********************************************************************************************/
/* */
/* File Name: dtracelio.d */
/* Version: 2.01 */
/* Authors: Alexander Anokhin ( http://alexanderanokhin.com ) */
/* Andrey Nikolaev ( http://andreynikolaev.wordpress.com ) */
/* Dated: Mar 2012 */
/* Purpose: The script shows calls of the functions */
/* performing logical I/O in Oracle. */
/* */
/* Usage: dtracelio.d <PID> [show_each_call] [interval] */
/* PID: unix process ID */
/* show_each_call - Bitmask determining how functions calls will be shown */
/* 1st bit - logical I/O functions */
/* 2nd bit - buffer pinning */
/* Examples: */
/* 0: output of each call will be disabled */
/* 1: logical I/O functions will be shown */
/* 3: logical I/O and buffer pinning functions */
/* will be shown */
/* Default value: 1 */
/* interval - Specifies the number of seconds over which */
/* Summary form with cumulative figures will be shown. */
/* Works only when show_each_call is disabled. */
/* */
/* Other: Some bits of info in 8103.1 */
/* Note that data structures definitions are not full */
/* in current version of the script */
/* */
/********************************************************************************************/
#pragma D option quiet
#pragma D option defaultargs
#pragma D option switchrate=10Hz
/* 0. Several standard oratype.h declarations */
typedef unsigned long long ub8; /* unsigned int of length 8 */
typedef unsigned int ub4;
typedef unsigned short ub2;
typedef unsigned char ub1;
typedef int sb4;
/* */
typedef sb4 kobjd;
typedef sb4 kobjn;
typedef ub4 ktsn;
typedef ub4 krdba;
/* definition from MOS note 8103.1 */
typedef struct kdbafr /* full relative dba */
{
ktsn tsn_kdbafr; /* a tablespace number */
krdba dba_kdbafr; /* a relative dba */
} kdbafr;
typedef struct ktid /* relative dba + objd */
{
struct kdbafr dbr_ktid; /* a relative dba */
kobjd objd_ktid; /* data object number */
kobjn objn_ktid; /* dictionary object number */
} ktid;
typedef struct kcbds
{
struct ktid kcbdstid; /* full relative DBA plus object number */
/* Here unknown (yet ;-)) part of the structure */
} kcbds;
BEGIN
{
show_each_call = ($$2 == NULL) ? 1:$2;
tick_time_interval = ($$3 == NULL) ? 0:$3;
trace_logical_io = 1;
trace_buf_pinning = 1;
show_lio_calls = show_each_call & 1;
show_buf_pins_calls = show_each_call & 2;
printf("\nDynamic tracing of Oracle logical I/O v2.0 by Alexander Anokhin ( https://alexanderanokhin.wordpress.com )\n\n");
}
pid$1::kcbgtcr:entry,
pid$1::kcbgcur:entry,
pid$1::kcbnew:entry,
pid$1::kcbrls:entry,
pid$1::kcbispnd:entry,
pid$1::kcbldrget:entry,
pid$1::kcbget:entry
{
blk = ((kcbds *) copyin(arg0, sizeof(kcbds)));
tsn = blk->kcbdstid.dbr_ktid.tsn_kdbafr;
rdba = blk->kcbdstid.dbr_ktid.dba_kdbafr;
objd = blk->kcbdstid.objd_ktid;
objn = blk->kcbdstid.objn_ktid;
rdba_file = rdba >> 22; /* for smallfile tablespaces */
rdba_block = rdba & 0x3FFFFF;
}
pid$1::kcbgtcr:entry
/trace_logical_io/
{
stat = "cr";
where = arg2&0xFFFF;
mode_held = "";
@func[probefunc,stat,objn,objd,mode_held,where] = count();
@bufs[probefunc,stat,objn,objd,mode_held,where] = sum(1);
@obj_cr[objn,objd] = sum(1);
@total_cr = sum(1);
@obj_lio[objn,objd] = sum(1);
@total_lio = sum(1);
}
pid$1::kcbgtcr:entry
/trace_logical_io && show_lio_calls/
{
printf("%s(0x%X,%d,%d,%d) [tsn: %d rdba: 0x%x (%d/%d) obj: %d dobj: %d] where: %d\n",probefunc,arg0,arg1,arg2,arg3,tsn, rdba,rdba_file,rdba_block,objn, objd, where);
}
pid$1::kcbldrget:entry
/trace_logical_io/
{
stat = "cr (d)";
where = 0;
mode_held = "";
@func[probefunc,stat,objn,objd,mode_held,where] = count();
@bufs[probefunc,stat,objn,objd,mode_held,where] = sum(1);
@obj_cr_d[objn,objd] = sum(1);
@total_cr_d = sum(1);
@obj_cr[objn,objd] = sum(-1);
@total_cr = sum(-1);
/* commented because incremented in kcbgtcr yet
@obj_lio[objn,objd] = sum(1);
@total_lio = sum(1);
*/
}
pid$1::kcbldrget:entry
/trace_logical_io && show_lio_calls/
{
printf("%s(0x%X,%d,%d,%d)\n",probefunc,arg0,arg1,arg2,arg3);
}
pid$1::kcbgcur:entry,
pid$1::kcbget:entry
/trace_logical_io/
{
stat = "cu";
where = arg2&0xFFFF;
mode_held = lltostr(arg1);
@func[probefunc,stat,objn,objd,mode_held,where] = count();
@bufs[probefunc,stat,objn,objd,mode_held,where] = sum(1);
@obj_cu[objn,objd] = sum(1);
@total_cu = sum(1);
@obj_lio[objn,objd] = sum(1);
@total_lio = sum(1);
}
pid$1::kcbgcur:entry,
pid$1::kcbget:entry
/trace_logical_io && show_lio_calls/
{
printf("%s(0x%X,%d,%d,%d) [tsn: %d rdba: 0x%x (%d/%d) obj: %d dobj: %d] where: %d mode_held: %s\n",probefunc,arg0,arg1,arg2,arg3,tsn, rdba,rdba_file,rdba_block,objn, objd, where, mode_held);
}
pid$1::kcbnew:entry
/trace_logical_io/
{
stat = "cu";
where = arg2&0xFFFF;
mode_held = "";
blocks = arg1;
@func[probefunc,stat,objn,objd,mode_held,where] = count();
@bufs[probefunc,stat,objn,objd,mode_held,where] = sum(blocks);
@obj_cu[objn,objd] = sum(blocks);
@total_cu = sum(blocks);
@obj_lio[objn,objd] = sum(blocks);
@total_lio = sum(blocks);
}
pid$1::kcbnew:entry
/trace_logical_io && show_lio_calls/
{
printf("%s(0x%X,%d,%d,%d) [tsn: %d rdba: 0x%x (%d/%d) obj: %d dobj: %d] where: %d mode_held: %s blocks: %d\n",probefunc,arg0,arg1,arg2,arg3,tsn, rdba,rdba_file,rdba_block,objn, objd, where, mode_held, blocks);
}
pid$1::kcblnb:entry, pid$1::kcblnb_dscn:entry
/trace_logical_io/
{
stat = "cu (d)";
@func[probefunc,stat,0,0,"",0] = count();
@bufs[probefunc,stat,0,0,"",0] = sum(1);
@obj_cu[objn,objd] = sum(1);
@total_cu = sum(1);
@obj_cu_d[objn,objd] = sum(1);
@total_cu_d = sum(1);
@obj_lio[objn,objd] = sum(1);
@total_lio = sum(1);
}
pid$1::kcblnb:entry, pid$1::kcblnb_dscn:entry
/trace_logical_io && show_lio_calls/
{
printf("%s(0x%X,%d,%d,%d)\n",probefunc,arg0,arg1,arg2,arg3);
}
/* buffer pinning */
pid$1::kcbispnd:entry
/trace_buf_pinning && show_buf_pins_calls/
{
printf("%s(0x%X,%d,%d,%d) [tsn: %d rdba: 0x%x (%d/%d) obj: %d dobj: %d]: ",probefunc,arg0,arg1,arg2,arg3,tsn, rdba,rdba_file,rdba_block,objn,objd);
}
pid$1::kcbispnd:return
/trace_buf_pinning && arg1 == 0/
{
@obj_is_not_pnd[objn,objd] = sum(1);
@total_is_not_pnd = sum(1);
}
pid$1::kcbispnd:return
/trace_buf_pinning && arg1 == 1/
{
@obj_is_pnd[objn,objd] = sum(1);;
@total_is_pnd = sum(1);
}
pid$1::kcbispnd:return
/trace_buf_pinning && show_buf_pins_calls/
{
printf("%d\n",arg1);
}
pid$1::kcbrls:entry
/trace_buf_pinning/
{
@obj_pinrls[objn,objd] = sum(1);
@total_pinrls = sum(1);
}
pid$1::kcbrls:entry
/trace_buf_pinning && show_buf_pins_calls/
{
printf("%s(0x%X,%d,%d,%d) [tsn: %d rdba: 0x%x (%d/%d) obj: %d dobj: %d]\n",probefunc,arg0,arg1,arg2,arg3,tsn, rdba,rdba_file,rdba_block,objn,objd);
}
tick-1sec
/show_each_call == 0 && tick_time_interval > 0 && ++ticks >= tick_time_interval/
{
printf("\n\n");
printf("================================= Logical I/O Summary (grouped by object) ================================\n");
printf(" object_id data_object_id lio cr cr (d) cu cu (d) ispnd (Y) ispnd (N) pin rls\n");
printf("---------- --------------- --------- --------- --------- --------- --------- --------- --------- ---------\n");
printa("%10d %15d %9@d %9@d %9@d %9@d %9@d %9@d %9@d %9@d\n",
@obj_lio, @obj_cr, @obj_cr_d, @obj_cu, @obj_cu_d, @obj_is_pnd, @obj_is_not_pnd, @obj_pinrls);
printf("---------- --------------- --------- --------- --------- --------- --------- --------- --------- ---------\n");
printa(" total %25@d %9@d %9@d %9@d %9@d %9@d %9@d %9@d\n", @total_lio, @total_cr, @total_cr_d, @total_cu, @total_cu_d, @total_is_pnd, @total_is_not_pnd, @total_pinrls);
printf("==========================================================================================================\n");
ticks = 0;
}
END
{
printf("\n============================= Logical I/O Summary (grouped by object/function) ===========================\n");
printf(" function stat object_id data_object_id mode_held where bufs calls\n");
printf("--------- ------- ----------- ---------------- ----------- ------- -------- ---------\n");
printa("%9s %7s %11d %16d %11s %7d %@8d %@9d\n", @bufs, @func);
printf("==========================================================================================================\n");
}
END
{
printf("\n================================= Logical I/O Summary (grouped by object) ================================\n");
printf(" object_id data_object_id lio cr cr (d) cu cu (d) ispnd (Y) ispnd (N) pin rls\n");
printf("---------- --------------- --------- --------- --------- --------- --------- --------- --------- ---------\n");
printa("%10d %15d %9@d %9@d %9@d %9@d %9@d %9@d %9@d %9@d\n",
@obj_lio, @obj_cr, @obj_cr_d, @obj_cu, @obj_cu_d, @obj_is_pnd, @obj_is_not_pnd, @obj_pinrls);
printf("---------- --------------- --------- --------- --------- --------- --------- --------- --------- ---------\n");
printa(" total %25@d %9@d %9@d %9@d %9@d %9@d %9@d %9@d\n", @total_lio, @total_cr, @total_cr_d, @total_cu, @total_cu_d, @total_is_pnd, @total_is_not_pnd, @total_pinrls);
printf("==========================================================================================================\n");
}
Comments (0)
Trackbacks (3)
Leave a comment
Trackback
-
November 13, 2011 at 3:01 amDynamic tracing of Oracle logical I/O « Alexander Anokhin
-
December 20, 2011 at 2:49 pmIndex Full Scan and array of changes in DML « Alexander Anokhin
-
March 19, 2012 at 3:44 pmDtrace LIO: new features « Alexander Anokhin
Alexander Anokhin 