The *row-{start,done}
probes are triggered
each time a row operation is pushed down to a storage engine.
For example, if you execute an
INSERT
statement with 100 rows of
data, then the insert-row-start
and
insert-row-done
probes will be triggered 100
times each, for each row insert.
insert-row-start(database, table) insert-row-done(status) update-row-start(database, table) update-row-done(status) delete-row-start(database, table) delete-row-done(status)
insert-row-start
— is triggered
before a row is inserted into a table.
insert-row-done
— is triggered
after a row is inserted into a table.
update-row-start
— is triggered
before a row is updated in a table.
update-row-done
— is triggered
before a row is updated in a table.
delete-row-start
— is triggered
before a row is deleted from a table.
delete-row-done
— is triggered
before a row is deleted from a table.
The arguments supported by the probes are consistent for the
corresponding start
and
done
probes in each case:
database
— the database name.
table
— the table name.
status
— the status; 0 for success
or 1 for failure.
Because the row-level probes are triggered for each individual
row access, these probes can be triggered many thousands of
times each second, which may have a detrimental effect on both
the monitoring script and MySQL. The DTrace environment should
limit the triggering on these probes to prevent the performance
being adversely affected. Either use the probes sparingly, or
use counter or aggregation functions to report on these probes
and then provide a summary when the script terminates or as part
of a query-done
or
query-exec-done
probes.
The following example script summarizes the duration of each row operation within a larger query:
#!/usr/sbin/dtrace -s #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); }
Running the above script with a query that inserts data into a table, you can monitor the exact time spent performing the raw row insertion:
St Who DB ConnID Dur ms Query 0 @localhost test 13 20767 insert into t1(select * from t2) 4827 -> Row ops
User Comments
Add your own comment.