util/dtrace/locktimes.d

   1 #!/usr/sbin/dtrace -qs
   2 /*
   3  * Copyright (c) 2011, 2012 Oracle and/or its affiliates.  All rights reserved.
   4  *
   5  * locktimesid.d - Display lock wait times grouped by filename.
   6  *
   7  * This script graphs the time spent waiting for DB page locks.
   8  *
   9  * The optional integer maxcount parameter directs the script to exit once that
  10  * many page lock waits have been measured.
  11  *
  12  * usage: locktimes.d { -p <pid> | -c "<program> [<args]" } [maxcount]
  13  *
  14  * The result times in nanoseconds are grouped by (filename, pgno, lock_mode).
  15  *
  16  * Static probes used:
  17  *      lock-suspend(DBT *lockobj, db_lockmode_t lock_ mode)
  18  *      lock-resume(DBT *lockobj, db_lockmode_t mode)
  19  *      db-open(char *file, char *db, uint32_t flags, uint8_t fileid[20])
  20  *      db-cursor(char *file, char *db, unsigned txnid, unsigned flags,
  21  *              uint8_t fileid[20])
  22  *
  23  *      The DBT locates the locked object in shared memory.  As long as
  24  *      application-specific locks are not being used, the DBT points to
  25  *      a DB_ILOCK:
  26  *              db_pgno_t       pgno;
  27  *              u_int8_t        fileid[20];
  28  *              u_int32_t       type;
  29  *      Type is 1 for handle, 2 for page, 3 for a queue's record number.
  30  *      The mode paramteris the enum db_lockmode_t
  31  *              notgranted,read,write,wait,iread,iwrite,iwr,read_unc,wwrite
  32  *
  33  *      This script may display unexpected results when application-specific
  34  *      locks are present.
  35  *
  36  */
  37 #pragma D option defaultargs
  38
  39 typedef D`uint32_t db_pgno_t;
  40
  41 /* A DBT for the DB API */
  42 typedef struct __db_dbt {
  43         uintptr_t       data;                   /* Key/data */
  44         uint32_t        size;                   /* key/data length */
  45
  46         uint32_t        ulen;                   /* RO: length of user buffer. */
  47         uint32_t        dlen;                   /* RO: get/put record length. */
  48         uint32_t        doff;                   /* RO: get/put record offset. */
  49
  50         uintptr_t       app_data;
  51         uint32_t        flags;
  52 } DBT;
  53
  54 /* A DBT in shared memory */
  55
  56 /*
  57  * DB fileids are actually uint8_t fileid[20]; in D it is easier to handle them
  58  * as a struct of 5 four-byte integers.
  59  */
  60 typedef struct fileid
  61 {
  62         uint32_t id1;
  63         uint32_t id2;
  64         uint32_t id3;
  65         uint32_t id4;
  66         uint32_t id5;
  67 } FILEID;
  68
  69 typedef struct __db_ilock {
  70         uint32_t        pgno;
  71         FILEID          fileid;
  72         uint32_t        type;
  73 } DB_ILOCK;
  74
  75 this DBT *dbt;
  76 this DB_ILOCK *ilock;
  77 this FILEID *fileid;
  78 this string filename;
  79
  80 string filenames[unsigned, unsigned, unsigned, unsigned, unsigned];
  81
  82 self int suspend;
  83
  84 dtrace:::BEGIN
  85 {
  86         maxcount = $1 != 0 ? $1 : -1;
  87         lockcount = 0;
  88         printf("DB lock wait times by (file, pgno) for process %d\n", $target);
  89         printf("Interrupt to display summary\n");
  90         modes[0] = "NOTGRANTED";
  91         modes[1] = "READ";
  92         modes[2] = "WRITE";
  93         modes[3] = "WAIT";
  94         modes[4] = "INTENT_WRITE";
  95         modes[5] = "INTENT_READ";
  96         modes[6] = "INTENT_WR";
  97         modes[7] = "READ_UNCOMMITTED";
  98         modes[8] = "WAS_WRITE";
  99
 100 }
 101
 102 /* lock-suspend(DBT *lockobj, int lock_mode) */
 103 bdb$target:::lock-suspend
 104 {
 105         self->suspend = timestamp;
 106 }
 107
 108
 109 /* lock-resume(DBT *lockobj, int lock_mode) */
 110 bdb$target:::lock-resume
 111 /self->suspend > 0/
 112 {
 113         this->duration = timestamp - self->suspend;
 114         self->suspend = 0;
 115         this->dbt = copyin(arg0, sizeof(DBT));
 116         this->ilock = copyin(this->dbt->data, sizeof(DB_ILOCK));
 117         this->filename = filenames[this->ilock->fileid.id1,
 118             this->ilock->fileid.id2, this->ilock->fileid.id3,
 119             this->ilock->fileid.id4, this->ilock->fileid.id5];
 120         @locktimes[this->filename, this->ilock->pgno, modes[arg1]] =
 121             quantize(this->duration);
 122         lockcount++;
 123 }
 124
 125 bdb$target:::lock-resume
 126 /lockcount == maxcount/
 127 {
 128         exit(0);
 129 }
 130
 131 /* db-open(char *file, char *db, uint32_t flags, uint8_t fileid[20])
 132  *
 133  * Watch db-open probes in order to get the fileid -> file name mapping.
 134  */
 135 bdb$target:::db-open
 136 /arg0 != 0/
 137 {
 138         this->filename = copyinstr(arg0);
 139         this->fileid = (FILEID *) copyin(arg3, 20);
 140         filenames[this->fileid->id1, this->fileid->id2, this->fileid->id3,
 141             this->fileid->id4, this->fileid->id5] = this->filename;
 142 }
 143
 144 /* db-cursor(char *file, char *db, unsigned txnid, unsigned flags, uint8_t fileid[20])
 145  *
 146  * Watch cursor creation probes in order to get the fileid -> file name mapping.
 147  */
 148 bdb$target:::db-cursor
 149 /arg0 != 0/
 150 {
 151         this->filename = (string) copyinstr(arg0);
 152         this->fileid = (FILEID *) copyin(arg4, 20);
 153         filenames[this->fileid->id1, this->fileid->id2, this->fileid->id3,
 154             this->fileid->id4, this->fileid->id5] = this->filename;
 155 }
 156
 157 dtrace:::END
 158 {
 159         printa("Wait time for file %s page %u %s locks in nanoseconds %@a\n", @locktimes);
 160 }