summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--support-files/dtrace/locktime.d49
-rw-r--r--support-files/dtrace/query-execandqc.d36
-rw-r--r--support-files/dtrace/query-filesort-time.d47
-rw-r--r--support-files/dtrace/query-network-time.d63
-rw-r--r--support-files/dtrace/query-parse-time.d23
-rw-r--r--support-files/dtrace/query-rowops.d66
-rw-r--r--support-files/dtrace/query-time.d25
-rw-r--r--support-files/dtrace/statement-time.d45
-rw-r--r--support-files/dtrace/statement-type-aggregate.d46
9 files changed, 400 insertions, 0 deletions
diff --git a/support-files/dtrace/locktime.d b/support-files/dtrace/locktime.d
new file mode 100644
index 00000000000..c9b509ca61e
--- /dev/null
+++ b/support-files/dtrace/locktime.d
@@ -0,0 +1,49 @@
+#!/usr/sbin/dtrace -s
+#
+# Shows the time that an individual lock is applied to a database and table
+# Shows the time to achieve the lock, and the time the table was locked
+
+o#pragma D option quiet
+
+mysql*:::handler-rdlock-start
+{
+ self->rdlockstart = timestamp;
+ this->lockref = strjoin(copyinstr(arg0),strjoin("@",copyinstr(arg1)));
+ self->lockmap[this->lockref] = self->rdlockstart;
+ printf("Start: Lock->Read %s.%s\n",copyinstr(arg0),copyinstr(arg1));
+}
+
+mysql*:::handler-wrlock-start
+{
+ self->wrlockstart = timestamp;
+ this->lockref = strjoin(copyinstr(arg0),strjoin("@",copyinstr(arg1)));
+ self->lockmap[this->lockref] = self->rdlockstart;
+ printf("Start: Lock->Write %s.%s\n",copyinstr(arg0),copyinstr(arg1));
+}
+
+mysql*:::handler-unlock-start
+{
+ self->unlockstart = timestamp;
+ this->lockref = strjoin(copyinstr(arg0),strjoin("@",copyinstr(arg1)));
+ printf("Start: Lock->Unlock %s.%s (%d ms lock duration)\n",
+ copyinstr(arg0),copyinstr(arg1),
+ (timestamp - self->lockmap[this->lockref])/1000000);
+}
+
+mysql*:::handler-rdlock-done
+{
+ printf("End: Lock->Read %d ms\n",
+ (timestamp - self->rdlockstart)/1000000);
+}
+
+mysql*:::handler-wrlock-done
+{
+ printf("End: Lock->Write %d ms\n",
+ (timestamp - self->wrlockstart)/1000000);
+}
+
+mysql*:::handler-unlock-done
+{
+ printf("End: Lock->Unlock %d ms\n",
+ (timestamp - self->unlockstart)/1000000);
+}
diff --git a/support-files/dtrace/query-execandqc.d b/support-files/dtrace/query-execandqc.d
new file mode 100644
index 00000000000..64599223f55
--- /dev/null
+++ b/support-files/dtrace/query-execandqc.d
@@ -0,0 +1,36 @@
+#!/usr/sbin/dtrace -s
+#
+# Show query execution times, indicating whether the query-cache was used
+
+#pragma D option quiet
+
+dtrace:::BEGIN
+{
+ printf("%-20s %-20s %-40s %2s %-9s\n", "Who", "Database", "Query", "QC", "Time(ms)");
+}
+
+mysql*:::query-start
+{
+ self->query = copyinstr(arg0);
+ self->connid = arg1;
+ self->db = copyinstr(arg2);
+ self->who = strjoin(copyinstr(arg3),strjoin("@",copyinstr(arg4)));
+ self->querystart = timestamp;
+ self->qc = 0;
+}
+
+mysql*:::query-cache-hit
+{
+ self->qc = 1;
+}
+
+mysql*:::query-cache-miss
+{
+ self->qc = 0;
+}
+
+mysql*:::query-done
+{
+ printf("%-20s %-20s %-40s %-2s %-9d\n",self->who,self->db,self->query,(self->qc ? "Y" : "N"),
+ (timestamp - self->querystart) / 1000000);
+}
diff --git a/support-files/dtrace/query-filesort-time.d b/support-files/dtrace/query-filesort-time.d
new file mode 100644
index 00000000000..425ed3863aa
--- /dev/null
+++ b/support-files/dtrace/query-filesort-time.d
@@ -0,0 +1,47 @@
+#!/usr/sbin/dtrace -s
+#
+# Show the time taken for a query, including the time taken to
+# sort the results using filesort
+
+#pragma D option quiet
+
+dtrace:::BEGIN
+{
+ printf("%-2s %-10s %-10s %9s %18s %-s \n",
+ "St", "Who", "DB", "ConnID", "Dur microsec", "Query");
+}
+
+mysql*:::query-start
+{
+ self->query = copyinstr(arg0);
+ self->who = strjoin(copyinstr(arg3),strjoin("@",copyinstr(arg4)));
+ self->db = copyinstr(arg2);
+ self->connid = arg1;
+ self->querystart = timestamp;
+ self->filesort = 0;
+ self->fsdb = "";
+ self->fstable = "";
+}
+
+mysql*:::filesort-start
+{
+ self->filesort = timestamp;
+ self->fsdb = copyinstr(arg0);
+ self->fstable = copyinstr(arg1);
+}
+
+mysql*:::filesort-done
+{
+ this->elapsed = (timestamp - self->filesort) /1000;
+ printf("%2d %-10s %-10s %9d %18d Filesort on %s\n",
+ arg0, self->who, self->fsdb,
+ self->connid, this->elapsed, self->fstable);
+}
+
+mysql*:::query-done
+{
+ this->elapsed = (timestamp - self->querystart) /1000;
+ printf("%2d %-10s %-10s %9d %18d %s\n",
+ arg0, self->who, self->db,
+ self->connid, this->elapsed, self->query);
+}
diff --git a/support-files/dtrace/query-network-time.d b/support-files/dtrace/query-network-time.d
new file mode 100644
index 00000000000..f0483778fb0
--- /dev/null
+++ b/support-files/dtrace/query-network-time.d
@@ -0,0 +1,63 @@
+#!/usr/sbin/dtrace -s
+#
+# Show the time taken to execute a query, include the bytes and time taken
+# to transfer the information over the network to/from the client
+
+#pragma D option quiet
+#pragma D option dynvarsize=4m
+
+dtrace:::BEGIN
+{
+ printf("%-2s %-30s %-10s %9s %18s %-s \n",
+ "St", "Who", "DB", "ConnID", "Dur microsec", "Query");
+}
+
+mysql*:::query-start
+{
+ self->query = copyinstr(arg0);
+ self->who = strjoin(copyinstr(arg3),strjoin("@",copyinstr(arg4)));
+ self->db = copyinstr(arg2);
+ self->connid = arg1;
+ self->querystart = timestamp;
+ self->netwrite = 0;
+ self->netwritecum = 0;
+ self->netwritebase = 0;
+ self->netread = 0;
+ self->netreadcum = 0;
+ self->netreadbase = 0;
+}
+
+mysql*:::net-write-start
+{
+ self->netwrite += arg0;
+ self->netwritebase = timestamp;
+}
+
+mysql*:::net-write-done
+{
+ self->netwritecum += (timestamp - self->netwritebase);
+ self->netwritebase = 0;
+}
+
+mysql*:::net-read-start
+{
+ self->netreadbase = timestamp;
+}
+
+mysql*:::net-read-done
+{
+ self->netread += arg1;
+ self->netreadcum += (timestamp - self->netreadbase);
+ self->netreadbase = 0;
+}
+
+mysql*:::query-done
+{
+ this->elapsed = (timestamp - self->querystart) /1000000;
+ printf("%2d %-30s %-10s %9d %18d %s\n",
+ arg0, self->who, self->db,
+ self->connid, this->elapsed, self->query);
+ printf("Net read: %d bytes (%d ms) write: %d bytes (%d ms)\n",
+ self->netread, (self->netreadcum/1000000),
+ self->netwrite, (self->netwritecum/1000000));
+}
diff --git a/support-files/dtrace/query-parse-time.d b/support-files/dtrace/query-parse-time.d
new file mode 100644
index 00000000000..31fe1275e1a
--- /dev/null
+++ b/support-files/dtrace/query-parse-time.d
@@ -0,0 +1,23 @@
+#!/usr/sbin/dtrace -s
+#
+# Shows time take to actually parse the query statement
+
+#pragma D option quiet
+
+mysql*:::query-parse-start
+{
+ self->parsestart = timestamp;
+ self->parsequery = copyinstr(arg0);
+}
+
+mysql*:::query-parse-done
+/arg0 == 0/
+{
+ printf("Parsing %s: %d microseconds\n", self->parsequery,((timestamp - self->parsestart)/1000));
+}
+
+mysql*:::query-parse-done
+/arg0 != 0/
+{
+ printf("Error parsing %s: %d microseconds\n", self->parsequery,((timestamp - self->parsestart)/1000));
+}
diff --git a/support-files/dtrace/query-rowops.d b/support-files/dtrace/query-rowops.d
new file mode 100644
index 00000000000..a16f3df90f4
--- /dev/null
+++ b/support-files/dtrace/query-rowops.d
@@ -0,0 +1,66 @@
+#!/usr/sbin/dtrace -s
+#
+# Calculates the time (and operations) for accessing data from individual
+# rows for each query
+
+#pragma D option quiet
+
+dtrace:::BEGIN
+{
+ printf("%-2s %-10s %-10s %9s %9s %-s \n",
+ "St", "Who", "DB", "ConnID", "Dur ms", "Query");
+}
+
+mysql*:::query-start
+{
+ self->query = copyinstr(arg0);
+ self->who = strjoin(copyinstr(arg3),strjoin("@",copyinstr(arg4)));
+ self->db = copyinstr(arg2);
+ self->connid = arg1;
+ self->querystart = timestamp;
+ self->rowdur = 0;
+}
+
+mysql*:::query-done
+{
+ this->elapsed = (timestamp - self->querystart) /1000000;
+ printf("%2d %-10s %-10s %9d %9d %s\n",
+ arg0, self->who, self->db,
+ self->connid, this->elapsed, self->query);
+}
+
+mysql*:::query-done
+/ self->rowdur /
+{
+ printf("%34s %9d %s\n", "", (self->rowdur/1000000), "-> Row ops");
+}
+
+mysql*:::insert-row-start
+{
+ self->rowstart = timestamp;
+}
+
+mysql*:::delete-row-start
+{
+ self->rowstart = timestamp;
+}
+
+mysql*:::update-row-start
+{
+ self->rowstart = timestamp;
+}
+
+mysql*:::insert-row-done
+{
+ self->rowdur += (timestamp-self->rowstart);
+}
+
+mysql*:::delete-row-done
+{
+ self->rowdur += (timestamp-self->rowstart);
+}
+
+mysql*:::update-row-done
+{
+ self->rowdur += (timestamp-self->rowstart);
+}
diff --git a/support-files/dtrace/query-time.d b/support-files/dtrace/query-time.d
new file mode 100644
index 00000000000..9983a73b7e5
--- /dev/null
+++ b/support-files/dtrace/query-time.d
@@ -0,0 +1,25 @@
+#!/usr/sbin/dtrace -s
+#
+# Shows basic query execution time, who execute the query, and on what database
+
+#pragma D option quiet
+
+dtrace:::BEGIN
+{
+ printf("%-20s %-20s %-40s %-9s\n", "Who", "Database", "Query", "Time(ms)");
+}
+
+mysql*:::query-start
+{
+ self->query = copyinstr(arg0);
+ self->connid = arg1;
+ self->db = copyinstr(arg2);
+ self->who = strjoin(copyinstr(arg3),strjoin("@",copyinstr(arg4)));
+ self->querystart = timestamp;
+}
+
+mysql*:::query-done
+{
+ printf("%-20s %-20s %-40s %-9d\n",self->who,self->db,self->query,
+ (timestamp - self->querystart) / 1000000);
+}
diff --git a/support-files/dtrace/statement-time.d b/support-files/dtrace/statement-time.d
new file mode 100644
index 00000000000..d00fc10348d
--- /dev/null
+++ b/support-files/dtrace/statement-time.d
@@ -0,0 +1,45 @@
+#!/usr/sbin/dtrace -s
+#
+# Creates a report on each query executed at the individual statement
+# level, showing rows matched, updated, and total query time
+
+#pragma D option quiet
+
+dtrace:::BEGIN
+{
+ printf("%-60s %-8s %-8s %-8s\n", "Query", "RowsU", "RowsM", "Dur (ms)");
+}
+
+mysql*:::update-start, mysql*:::insert-start,
+mysql*:::delete-start, mysql*:::multi-delete-start,
+mysql*:::multi-delete-done, mysql*:::select-start,
+mysql*:::insert-select-start, mysql*:::multi-update-start
+{
+ self->query = copyinstr(arg0);
+ self->querystart = timestamp;
+}
+
+mysql*:::insert-done, mysql*:::select-done,
+mysql*:::delete-done, mysql*:::multi-delete-done, mysql*:::insert-select-done
+/ self->querystart /
+{
+ this->elapsed = ((timestamp - self->querystart)/1000000);
+ printf("%-60s %-8d %-8d %d\n",
+ self->query,
+ 0,
+ arg1,
+ this->elapsed);
+ self->querystart = 0;
+}
+
+mysql*:::update-done, mysql*:::multi-update-done
+/ self->querystart /
+{
+ this->elapsed = ((timestamp - self->querystart)/1000000);
+ printf("%-60s %-8d %-8d %d\n",
+ self->query,
+ arg1,
+ arg2,
+ this->elapsed);
+ self->querystart = 0;
+}
diff --git a/support-files/dtrace/statement-type-aggregate.d b/support-files/dtrace/statement-type-aggregate.d
new file mode 100644
index 00000000000..32d88cb5143
--- /dev/null
+++ b/support-files/dtrace/statement-type-aggregate.d
@@ -0,0 +1,46 @@
+#!/usr/sbin/dtrace -s
+#
+# Creates an aggregate report of the time spent perform queries of the four main
+# types (select, insert, update, delete)
+#
+# Report generated every 30s
+
+#pragma D option quiet
+
+dtrace:::BEGIN
+{
+ printf("Reporting...Control-C to stop\n");
+}
+
+mysql*:::update-start, mysql*:::insert-start,
+mysql*:::delete-start, mysql*:::multi-delete-start,
+mysql*:::multi-delete-done, mysql*:::select-start,
+mysql*:::insert-select-start, mysql*:::multi-update-start
+{
+ self->querystart = timestamp;
+}
+
+mysql*:::select-done
+{
+ @statements["select"] = sum(((timestamp - self->querystart)/1000000));
+}
+
+mysql*:::insert-done, mysql*:::insert-select-done
+{
+ @statements["insert"] = sum(((timestamp - self->querystart)/1000000));
+}
+
+mysql*:::update-done, mysql*:::multi-update-done
+{
+ @statements["update"] = sum(((timestamp - self->querystart)/1000000));
+}
+
+mysql*:::delete-done, mysql*:::multi-delete-done
+{
+ @statements["delete"] = sum(((timestamp - self->querystart)/1000000));
+}
+
+tick-30s
+{
+ printa(@statements);
+}