The network probes monitor the transfer of information from the MySQL server and clients of all types over the network. The probes are defined as follows:
net-read-start() net-read-done(status, bytes) net-write-start(bytes) net-write-done(status)
net-read-start
: Triggered when a network read operation is started.net-read-done
: Triggered when the network read operation completes. Thestatus
is aninteger
representing the return status for the operation,0
for success and1
for failure. Thebytes
argument is an integer specifying the number of bytes read during the process.net-start-bytes
: Triggered when data is written to a network socket. The single argument,bytes
, specifies the number of bytes written to the network socket.net-write-done
: Triggered when the network write operation has completed. The single argument,status
, is an integer representing the return status for the operation,0
for success and1
for failure.
You can use the network probes to monitor the time spent reading
from and writing to network clients during execution. The
following D script provides an example of this. Both the
cumlative time for the read or write is calculated, and the
number of bytes. Note that the dynamic variable size has been
increased (using the dynvarsize
option) to
cope with the rapid firing of the individual probes for the
network reads/writes.
#!/usr/sbin/dtrace -s #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)); }
When executing the above script on a machine with a remote client, you can see that approximately a third of the time spent executing the query is related to writing the query results back to the client.
St Who DB ConnID Dur microsec Query 0 root@::ffff:192.168.0.108 test 31 3495 select * from t1 limit 1000000 Net read: 0 bytes (0 ms) write: 10000075 bytes (1220 ms)