With Oracle we can enable session level trace and it makes sense that we can do the same thing with PostgreSQL Using DTrace we can attache ourselves to a session as so:
Check the session
Check Session
jianhuiz=# select * from pg_stat_activity where usename=’jianhuiz’; datid | datname | pid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | query_start | state_change | waiting | state | backend_xid | backend_xmin | query ——-+———-+——+———-+———-+——————+————-+—————–+————-+——————————-+——————————-+——————————-+——————————-+———+——–+————-+————–+———————————————————- 16384 | jianhuiz | 4139 | 16385 | jianhuiz | psql | | | -1 | 2015-04-15 17:06:43.916526-07 | 2015-04-15 17:11:53.436622-07 | 2015-04-15 17:11:53.436622-07 | 2015-04-15 17:11:53.436626-07 | f | active | | 1013 | select * from pg_stat_activity where usename=’jianhuiz’; (1 row)
Then we can attache to:
Attach to the session
root# ./query.d 4139 —– Ctrl_C to stop —— select count(1) from foo; ends at 1429143285567982000 select count(1) from foo; starts at 1429143285556178000 select count(1) from foo; ends at 1429143293632244000 select count(1) from foo; starts at 1429143293631820000 select count(1) from foo; ends at 1429143296421384000 select count(1) from foo; starts at 1429143296420958000 select * from foo where i=10; ends at 1429143315062385000 select * from foo where i=10; starts at 1429143315059582000 select * from foo where i=20; ends at 1429143322032015000 select * from foo where i=20; starts at 1429143322031590000
The script you can see below:
DTrace script
#!/usr/sbin/dtrace -qs dtrace:::BEGIN { printf(” —– Ctrl_C to stop —— \n”); } postgresql$1:::query-start { @query_count[copyinstr(arg0)] = count(); self->ts = walltimestamp; printf(” %60s starts at %30d \n”, copyinstr(arg0), self->ts); } postgresql$1:::query-done /self->ts/ { self->te = walltimestamp; @query_time[copyinstr(arg0)] = sum(self->te – self->ts); printf(” %60s ends at %30d \n”, copyinstr(arg0), self->te); } dtrace:::END { printf(” —– Query Execution Count Summary —— \n”); printa(@query_count); printf(” —– Query Elapsed Time(ns) Summary —— \n”); printa(@query_time); }