#!/usr/sbin/dtrace -s /* * querystat.d - Show MySQL query statistics * * Tim.Cook@sun.com, 17 Sep 2009 * * NOTES: * If you have no query cache hits (or misses), you will not see * matching statistics. Similarly for pre-empted queries. * * If the query cache is disabled, you will only see statistics * for "query cache not used". */ #pragma D option quiet dtrace:::BEGIN { printf("Tracing started at %Y\n", walltimestamp); self->in_query = 0; } mysql$target:::query-start { self->in_query = 1; /* self->query = copyinstr(arg0); */ /* self->connid = arg1; */ self->querystart = timestamp; self->preempted = "WAS NOT"; self->qc_mode = "not used"; } mysql$target:::query-cache-hit /self->in_query/ { self->qc_mode = "hit"; } mysql$target:::query-cache-miss /self->in_query/ { self->qc_mode = "miss"; } mysql$target:::query-done { @qps = count(); self->elapsed = (timestamp - self->querystart) / 1000; @hit_or_miss[self->qc_mode] = count(); @latency = avg(self->elapsed); @lat_by_cache[self->qc_mode] = avg(self->elapsed); @lat_hist = quantize(self->elapsed); @lat_hist_by_cache[self->qc_mode] = quantize(self->elapsed); @lat_by_preempt[self->preempted] = avg(self->elapsed); self->in_query = 0; } sched:::off-cpu /self->in_query/ { self->preempted = "WAS"; @preemptor[stringof(args[1]->pr_fname)] = count(); } profile:::tick-3s { printf("%Y ", walltimestamp); printa("throughput %@lu queries/sec\n", @qps); trunc(@qps); } END { printf("Tracing ended at %Y\n", walltimestamp); printa("Average latency, all queries: %@ld us\n", @latency); printa("Latency distribution, all queries (us): %@ld", @lat_hist); printf("Query cache statistics:\n"); printa(" count %8s: %@lu\n", @hit_or_miss); printa(" avg latency %8s: %@ld (us)\n", @lat_by_cache); printa("Latency distribution, for query cache %s (us): %@ld", @lat_hist_by_cache); printa("Average latency when query %7s pre-empted: %@ld us\n", @lat_by_preempt); printf("Pre-emptors:\n"); printa(" %-30s %@12lu\n", @preemptor); }