5.7.1.12. Statement Probes

The individual statement probes are provided to give specific information about different statement types. For the start probes the string of the query is provided as a the only argument. Depending on the statement type, the information provided by the corresponding done probe will differ. For all done probes the status of the operation (0 for success, >0 for failure) is provided. For SELECT, INSERT, INSERT ... (SELECT FROM ...), DELETE, and DELETE FROM t1,t2 operations the number of rows affected is returned.

For UPDATE and UPDATE t1,t2 ... statements the number of rows matched and the number of rows actually changed is provided. This is because the number of rows actually matched by the corresponding WHERE clause, and the number of rows changed can differ. MySQL does not update the value of a row if the value already matches the new setting.

select-start(query)select-done(status,rows)insert-start(query)insert-done(status,rows)insert-select-start(query)insert-select-done(status,rows)update-start(query)update-done(status,rowsmatched,rowschanged)multi-update-start(query)multi-update-done(status,rowsmatched,rowschanged)delete-start(query)delete-done(status,rows)multi-delete-start(query)multi-delete-done(status,rows)

select-start: Triggered before a SELECT statement.
select-done: Triggered at the end of a SELECT statement.
insert-start: Triggered before a INSERT statement.
insert-done: Triggered at the end of an INSERT statement.
insert-select-start: Triggered before an INSERT ... SELECT statement.
insert-select-done: Triggered at the end of an INSERT ... SELECT statement.
update-start: Triggered before an UPDATE statement.
update-done: Triggered at the end of an UPDATE statement.
multi-update-start: Triggered before an UPDATE statement involving multiple tables.
multi-update-done: Triggered at the end of an UPDATE statement involving multiple tables.
delete-start: Triggered before a DELETE statement.
delete-done: Triggered at the end of a DELETE statement.
multi-delete-start: Triggered before a DELETE statement involving multiple tables.
multi-delete-done: Triggered at the end of a DELETE statement involving multiple tables.

The arguments for the statement probes are:

query: The query string.
status: The status of the query. 0 for success, and >0 for failure.
rows: The number of rows affected by the statement. This returns the number rows found for SELECT, the number of rows deleted for DELETE, and the number of rows successfully inserted for INSERT.
rowsmatched: The number of rows matched by the WHERE clause of an UPDATE operation.
rowschanged: The number of rows actually changed during an UPDATE operation.

You use these probes to monitor the execution of these statement types without having to monitor the user or client executing the statements. A simple example of this is to track the execution times:

#!/usr/sbin/dtrace -s#pragma D option quietdtrace:::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;}

When executed you can see the basic execution times and rows matches:

Query                                                        RowsU    RowsM    Dur (ms)select * from t2                                             0        275      0insert into t2 (select * from t2)                            0        275      9update t2 set i=5 where i > 75                               110      110      8update t2 set i=5 where i < 25                               254      134      12delete from t2 where i < 5                                   0        0        0

Another alternative is to use the aggregation functions in DTrace to aggregate the execution time of individual statements together:

#!/usr/sbin/dtrace -s#pragma D option quietmysql*:::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);}

The script just shown aggregates the times spent doing each operation, which could be used to help benchmark a standard suite of tests.

 delete                                                            0  update                                                            0  insert                                                           23  select                                                         2484  delete                                                            0  update                                                            0  insert                                                           39  select                                                        10744  delete                                                            0  update                                                           26  insert                                                           56  select                                                        10944  delete                                                            0  update                                                           26  insert                                                         2287select                                                        15985