编译

编译PG时需要加入 –enable-dtrace 参数，即：

snippet.bash
[yz@bogon postgres_src]$ ./configure --enable-dtrace 其它参数……

stap测试脚本

mark可以在src/backend/utils/probes.d文件查询。

snippet.bash
[yz@bogon test]$ vim postgresql-query.stp
global query_time, query_summary
 
probe process("/home/yz/postgresql/pg_bin/bin/postgres").mark("query__start")
{
  query_time[tid(), $arg1] = gettimeofday_us();
}
 
probe process("/home/yz/postgresql/pg_bin/bin/postgres").mark("query__done")
{
  p = tid()
  t = query_time[p, $arg1]; delete query_time[p, $arg1]
  if (t)
  {
    query_summary[p] <<< (gettimeofday_us() - t);
  }
}
 
probe end
{
  printf("\ntid count min(us) avg(us) max(us)\n");
  foreach (p in query_summary)
  {
    printf("%d %d %d %d %d\n", p, @count(query_summary[p]),
     @min(query_summary[p]), @avg(query_summary[p]), @max(query_summary[p]));
  }
}

执行脚本：

snippet.bash
[yz@bogon test]$ stap postgresql-query.stp

如果是非root用户，会报错： 

You are trying to run systemtap as a normal user.
You should either be root, or be part of the group "stapusr" and possibly one of the groups "stapsys" or "stapdev".  [man stap]
Try '--help' for more information.

提升权限

将当前普通用户加入 stapdev,stapusr 组：

snippet.bash
[yz@bogon test]$ sudo usermod -G stapdev,stapusr yz

注：需要退出当前用户，重新登录才生效。

重新执行 stap postgresql-query.stp。

执行SQL

在另一个终端执行SQL： 

[yz@bogon postgres_src]$ psql -p 7404 test
psql (14.0)
Type "help" for help.

test=# select count(1) from t;
 count
-------
   110
(1 row)

test=# begin;
BEGIN
test=*# select * from t for update;
  a
-----
   1
test=*# end;
COMMIT
test=# select txid_current();
 txid_current
--------------
         1111
(1 row)

查看跟踪结果

使用 Ctrl + C 中止stap命令：

snippet.bash
[yz@bogon test]$ stap postgresql-query.stp
Missing separate debuginfos, use: debuginfo-install kernel-3.10.0-957.el7.x86_64
^C
tid count min(us) avg(us) max(us)
31590 5 158 742 1282

跟踪函数

对PG函数的跟踪： 

global var1
global var2
probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("ExecInsert").call {   
  var1[pid(),0] = gettimeofday_us()
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("ExecInsert").return {   
  var1[pid(),1] = gettimeofday_us()
  var2[1] <<< var1[pid(),1] - var1[pid(),0]
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("heap_insert").call {   
  var1[pid(),2] = gettimeofday_us()
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("heap_insert").return {   
  var1[pid(),3] = gettimeofday_us()
  var2[2] <<< var1[pid(),3] - var1[pid(),2] 
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("ExecInsertIndexTuples").call {   
  var1[pid(),4] = gettimeofday_us()
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("ExecInsertIndexTuples").return {   
  var1[pid(),5] = gettimeofday_us()
  var2[3] <<< var1[pid(),5] - var1[pid(),4]
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("setLastTid").call {   
  var1[pid(),6] = gettimeofday_us()
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("setLastTid").return {   
  var1[pid(),7] = gettimeofday_us()
  var2[4] <<< var1[pid(),7] - var1[pid(),6]
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("list_free").call {   
  var1[pid(),8] = gettimeofday_us()
}

probe process("/home/yz/postgresql/pg_bin/bin/postgres").function("list_free").return {   
  var1[pid(),9] = gettimeofday_us()
  var2[5] <<< var1[pid(),9] - var1[pid(),8]
}

probe timer.s(5) {
	if ( @count(var2[1]) > 0 ) {
		printf("time : %d \n",gettimeofday_s())
		printf("ExecInsert            us min: %d, max: %d, avg: %d, sum: %d, count: %d\n", @min(var2[1]), @max(var2[1]), @avg(var2[1]), @sum(var2[1]), @count(var2[1]) )  
		printf("heap_insert           us min: %d, max: %d, avg: %d, sum: %d, count: %d\n", @min(var2[2]), @max(var2[2]), @avg(var2[2]), @sum(var2[2]), @count(var2[2]) )
		printf("setLastTid           us min: %d, max: %d, avg: %d, sum: %d, count: %d\n", @min(var2[4]), @max(var2[4]), @avg(var2[4]), @sum(var2[4]), @count(var2[4]) )
		printf("list_free           us min: %d, max: %d, avg: %d, sum: %d, count: %d\n", @min(var2[5]), @max(var2[5]), @avg(var2[5]), @sum(var2[5]), @count(var2[5]) )
			if ( @count(var2[3]) > 0 ){
	    printf("ExecInsertIndexTuples us min: %d, max: %d, avg: %d, sum: %d, count: %d\n", @min(var2[3]), @max(var2[3]), @avg(var2[3]), @sum(var2[3]), @count(var2[3]) )
		}
		printf(" \n")
	}
}

参考