Systemtap Example : OUTPUT hist_linear for processes io size and io time use @entry

9 minute read

背景

systemtap的.return探针有一个特殊的操作符@entry(), 用于存储该探针的入口处的表达式的值.   
例如获取vfs.read.return探针入口处的时间@entry(gettimeofday_ns()), 使用gettimeofday_ns()减去@entry(gettimeofday_ns())就可以得到本次vfs.read消耗的时间, 非常实用.  
@entry中可以输入探针所在函数的本地变量$$local中的变量. 或者tapset中的时间函数等.  
不可以使用alias中的变量, 例如 :   
以下例子中size是一个alias变量, 使用@entry(size)将报错, 提示请使用local变量.  
[root@db-172-16-3-150 tapset]# /opt/systemtap/bin/stap -e 'probe tcp.recvmsg.return {printdln("---", @entry($size), $size)}'  
semantic error: unable to find local 'size', [man error::dwarf] dieoffset 0x3cbb0fd in kernel, near pc 0xffffffff8148e640 in tcp_recvmsg net/ipv4/tcp.c (alternatives: $iocb $sk $msg $len $nonblock $flags $addr_len $tp $copied $peek_seq $seq $used $err $target $timeo $user_recv $copied_early $skb $urg_hole): identifier '$size' at <input>:1:50  
        source: probe tcp.recvmsg.return {printdln("---", @entry($size), $size)}  
                                                                 ^  
  
semantic error: unable to find local 'size', [man error::dwarf] dieoffset 0x3cbb0fd in kernel, near pc 0xffffffff8148e640 in tcp_recvmsg net/ipv4/tcp.c (alternatives: $iocb $sk $msg $len $nonblock $flags $addr_len $tp $copied $peek_seq $seq $used $err $target $timeo $user_recv $copied_early $skb $urg_hole): identifier '$size' at :1:58  
        source: probe tcp.recvmsg.return {printdln("---", @entry($size), $size)}  
                                                                         ^  
  
semantic error: unresolved type : identifier '$size' at :1:50  
        source: probe tcp.recvmsg.return {printdln("---", @entry($size), $size)}  
                                                                 ^  
  
Pass 2: analysis failed.  [man error::pass2]  
size变量在tapset alias中的定义.  
/**  
 * probe tcp.recvmsg - Receiving TCP message  
 * @name: Name of this probe  
 * @sock: Network socket  
 * @size: Number of bytes to be received    
 * @family: IP address family  
 * @saddr: A string representing the source IP address  
 * @daddr: A string representing the destination IP address  
 * @sport: TCP source port   
 * @dport: TCP destination port  
 * Context:  
 *  The process which receives a tcp message  
 */  
probe tcp.recvmsg = kernel.function("tcp_recvmsg") {  
        name = "tcp.recvmsg"  
        sock    = $sk  
        size    = $len  
        family  = __ip_sock_family($sk)  
        saddr   = format_ipaddr(__ip_sock_saddr($sk), __ip_sock_family($sk))  
        daddr   = format_ipaddr(__ip_sock_daddr($sk), __ip_sock_family($sk))  
        sport   = __tcp_sock_sport($sk)  
        dport   = __tcp_sock_dport($sk)  
}  
  
/**  
 * probe tcp.recvmsg.return - Receiving TCP message complete  
 * @name: Name of this probe  
 * @size: Number of bytes received or error code if an error occurred.  
 * @family: IP address family  
 * @saddr: A string representing the source IP address  
 * @daddr: A string representing the destination IP address  
 * @sport: TCP source port   
 * @dport: TCP destination port  
 *  
 * Context:  
 *  The process which receives a tcp message  
 */  
probe tcp.recvmsg.return = kernel.function("tcp_recvmsg").return {  
        name = "tcp.recvmsg"  
        size = $return  
        family  = __ip_sock_family($sk)  
        saddr   = format_ipaddr(__ip_sock_saddr($sk), __ip_sock_family($sk))  
        daddr   = format_ipaddr(__ip_sock_daddr($sk), __ip_sock_family($sk))  
        sport = __tcp_sock_sport($sk)  
        dport = __tcp_sock_dport($sk)  
}  
  
使用时间函数的例子, var1存储syscall.read触发时的时间. var2存储syscall.read.return的@entry存储的时间, 按照@entry的定义var2和var1应该是相差不大的, var3则存储syscall.read.return的触发时间. var3-var2应该就是本次syscall.read的消耗时间.  
[root@db-172-16-3-150 tapset]# /opt/systemtap/bin/stap -e '  
global var1%[60000], var2%[60000], var3%[60000];   
probe syscall.read {  
if (execname()=="postgres")   
  var1[pid(),execname()] = gettimeofday_ns()  
}   
probe syscall.read.return {  
if (execname()=="postgres")   
  { var2[pid(),execname()] = @entry(gettimeofday_ns());   
    var3[pid(),execname()] = gettimeofday_ns();   
    printf("%d, %s, var1:%d, var2:%d, var3:%d, var2-var1:%d, var3-var2:%d\n",   
      pid(),   
      execname(),   
      var1[pid(),execname()],   
      var2[pid(),execname()],   
      var3[pid(),execname()],   
      (var2[pid(),execname()]-var1[pid(),execname()]),   
      (var3[pid(),execname()]-var2[pid(),execname()])  
    )   
  }   
}'  
输出 :   
22116, postgres, var1:1381714826271039155, var2:1381714826271037869, var3:1381714826271045724, var2-var1:-1286, var3-var2:7855  
22116, postgres, var1:1381714826521400878, var2:1381714826521399206, var3:1381714826521404868, var2-var1:-1672, var3-var2:5662  
22116, postgres, var1:1381714826771795631, var2:1381714826771794217, var3:1381714826771799345, var2-var1:-1414, var3-var2:5128  
22116, postgres, var1:1381714827022159648, var2:1381714827022158097, var3:1381714827022163653, var2-var1:-1551, var3-var2:5556  
22116, postgres, var1:1381714827272758697, var2:1381714827272757216, var3:1381714827272762394, var2-var1:-1481, var3-var2:5178  
22116, postgres, var1:1381714827523124216, var2:1381714827523122758, var3:1381714827523128234, var2-var1:-1458, var3-var2:5476  
22116, postgres, var1:1381714827773750205, var2:1381714827773748784, var3:1381714827773753907, var2-var1:-1421, var3-var2:5123  
22116, postgres, var1:1381714828024104164, var2:1381714828024102695, var3:1381714828024108166, var2-var1:-1469, var3-var2:5471  
22116, postgres, var1:1381714828274473444, var2:1381714828274471917, var3:1381714828274477424, var2-var1:-1527, var3-var2:5507  
22116, postgres, var1:1381714828524819140, var2:1381714828524817721, var3:1381714828524822867, var2-var1:-1419, var3-var2:5146  
22116, postgres, var1:1381714828775193449, var2:1381714828775191981, var3:1381714828775197404, var2-var1:-1468, var3-var2:5423  
22116, postgres, var1:1381714829025818691, var2:1381714829025817277, var3:1381714829025822387, var2-var1:-1414, var3-var2:5110  
22116, postgres, var1:1381714829276193159, var2:1381714829276191620, var3:1381714829276197164, var2-var1:-1539, var3-var2:5544  
22116, postgres, var1:1381714829526833678, var2:1381714829526832262, var3:1381714829526837378, var2-var1:-1416, var3-var2:5116  
22116, postgres, var1:1381714829777204863, var2:1381714829777203395, var3:1381714829777208836, var2-var1:-1468, var3-var2:5441  
22116, postgres, var1:1381714830027777463, var2:1381714830027776005, var3:1381714830027781167, var2-var1:-1458, var3-var2:5162  
22116, postgres, var1:1381714830278140039, var2:1381714830278138500, var3:1381714830278144004, var2-var1:-1539, var3-var2:5504  
22116, postgres, var1:1381714830528556661, var2:1381714830528555265, var3:1381714830528560388, var2-var1:-1396, var3-var2:5123  
22116, postgres, var1:1381714830778821725, var2:1381714830778820261, var3:1381714830778825447, var2-var1:-1464, var3-var2:5186  
22116, postgres, var1:1381714831029189095, var2:1381714831029187985, var3:1381714831029193065, var2-var1:-1110, var3-var2:5080  
22116, postgres, var1:1381714831279775453, var2:1381714831279773954, var3:1381714831279779199, var2-var1:-1499, var3-var2:5245  
22116, postgres, var1:1381714831530149276, var2:1381714831530147817, var3:1381714831530153279, var2-var1:-1459, var3-var2:5462  
22115, postgres, var1:1381714831692810418, var2:1381714831692808876, var3:1381714831692814924, var2-var1:-1542, var3-var2:6048  
22116, postgres, var1:1381714831780769441, var2:1381714831780768343, var3:1381714831780773188, var2-var1:-1098, var3-var2:4845  
22115, postgres, var1:1381714831893109823, var2:1381714831893108771, var3:1381714831893112924, var2-var1:-1052, var3-var2:4153  
22116, postgres, var1:1381714832031128988, var2:1381714832031127902, var3:1381714832031132975, var2-var1:-1086, var3-var2:5073  
22116, postgres, var1:1381714832281728962, var2:1381714832281727458, var3:1381714832281732664, var2-var1:-1504, var3-var2:5206  
22116, postgres, var1:1381714832532094334, var2:1381714832532092865, var3:1381714832532098319, var2-var1:-1469, var3-var2:5454  
22116, postgres, var1:1381714832782456077, var2:1381714832782454614, var3:1381714832782460050, var2-var1:-1463, var3-var2:5436  
22116, postgres, var1:1381714833032789667, var2:1381714833032788256, var3:1381714833032793372, var2-var1:-1411, var3-var2:5116  
22116, postgres, var1:1381714833283152804, var2:1381714833283151268, var3:1381714833283156769, var2-var1:-1536, var3-var2:5501  
22116, postgres, var1:1381714833533733086, var2:1381714833533731668, var3:1381714833533736800, var2-var1:-1418, var3-var2:5132  
22116, postgres, var1:1381714833784092135, var2:1381714833784090671, var3:1381714833784096095, var2-var1:-1464, var3-var2:5424  
22116, postgres, var1:1381714834034445660, var2:1381714834034444152, var3:1381714834034449618, var2-var1:-1508, var3-var2:5466  
22116, postgres, var1:1381714834284818865, var2:1381714834284817373, var3:1381714834284822614, var2-var1:-1492, var3-var2:5241  
22116, postgres, var1:1381714834535190099, var2:1381714834535188628, var3:1381714834535194034, var2-var1:-1471, var3-var2:5406  
22116, postgres, var1:1381714834785777628, var2:1381714834785776222, var3:1381714834785781327, var2-var1:-1406, var3-var2:5105  
22116, postgres, var1:1381714835036158608, var2:1381714835036155986, var3:1381714835036168009, var2-var1:-2622, var3-var2:12023  
22116, postgres, var1:1381714835286815407, var2:1381714835286813983, var3:1381714835286819171, var2-var1:-1424, var3-var2:5188  
22116, postgres, var1:1381714835537182649, var2:1381714835537181175, var3:1381714835537186606, var2-var1:-1474, var3-var2:5431  
22116, postgres, var1:1381714835787783520, var2:1381714835787782101, var3:1381714835787787216, var2-var1:-1419, var3-var2:5115  
22116, postgres, var1:1381714836038149554, var2:1381714836038148088, var3:1381714836038153536, var2-var1:-1466, var3-var2:5448  
22116, postgres, var1:1381714836288771270, var2:1381714836288769671, var3:1381714836288775042, var2-var1:-1599, var3-var2:5371  
22116, postgres, var1:1381714836539125714, var2:1381714836539124255, var3:1381714836539129684, var2-var1:-1459, var3-var2:5429  
22116, postgres, var1:1381714836789477555, var2:1381714836789476082, var3:1381714836789481513, var2-var1:-1473, var3-var2:5431  
22116, postgres, var1:1381714837039805361, var2:1381714837039803815, var3:1381714837039809058, var2-var1:-1546, var3-var2:5243  
22116, postgres, var1:1381714837290170964, var2:1381714837290169425, var3:1381714837290174944, var2-var1:-1539, var3-var2:5519  
22116, postgres, var1:1381714837540785090, var2:1381714837540783689, var3:1381714837540788785, var2-var1:-1401, var3-var2:5096  
22116, postgres, var1:1381714837791150704, var2:1381714837791149220, var3:1381714837791154669, var2-var1:-1484, var3-var2:5449  
22116, postgres, var1:1381714838041768940, var2:1381714838041767451, var3:1381714838041772667, var2-var1:-1489, var3-var2:5216  
22116, postgres, var1:1381714838292128353, var2:1381714838292126816, var3:1381714838292132318, var2-var1:-1537, var3-var2:5502  
22116, postgres, var1:1381714838542733447, var2:1381714838542731895, var3:1381714838542737149, var2-var1:-1552, var3-var2:5254  
22116, postgres, var1:1381714838793107875, var2:1381714838793106411, var3:1381714838793111822, var2-var1:-1464, var3-var2:5411  
22116, postgres, var1:1381714839043479119, var2:1381714839043477652, var3:1381714839043483079, var2-var1:-1467, var3-var2:5427  
22116, postgres, var1:1381714839293788101, var2:1381714839293786412, var3:1381714839293791978, var2-var1:-1689, var3-var2:5566  
22116, postgres, var1:1381714839544153472, var2:1381714839544152014, var3:1381714839544157490, var2-var1:-1458, var3-var2:5476  
22116, postgres, var1:1381714839794554150, var2:1381714839794552732, var3:1381714839794557852, var2-var1:-1418, var3-var2:5120  
22116, postgres, var1:1381714840044788826, var2:1381714840044787410, var3:1381714840044792532, var2-var1:-1416, var3-var2:5122  
22116, postgres, var1:1381714840295160569, var2:1381714840295159033, var3:1381714840295164599, var2-var1:-1536, var3-var2:5566  
22116, postgres, var1:1381714840545749277, var2:1381714840545747833, var3:1381714840545752999, var2-var1:-1444, var3-var2:5166  
22116, postgres, var1:1381714840796097447, var2:1381714840796095958, var3:1381714840796101342, var2-var1:-1489, var3-var2:5384  
22116, postgres, var1:1381714841046472576, var2:1381714841046471548, var3:1381714841046476546, var2-var1:-1028, var3-var2:4998  
22116, postgres, var1:1381714841296782968, var2:1381714841296781316, var3:1381714841296786687, var2-var1:-1652, var3-var2:5371  
22116, postgres, var1:1381714841547142380, var2:1381714841547140911, var3:1381714841547146383, var2-var1:-1469, var3-var2:5472  
22116, postgres, var1:1381714841797773244, var2:1381714841797771826, var3:1381714841797777001, var2-var1:-1418, var3-var2:5175  
22115, postgres, var1:1381714841902801405, var2:1381714841902799883, var3:1381714841902805753, var2-var1:-1522, var3-var2:5870  
22116, postgres, var1:1381714842048120871, var2:1381714842048119846, var3:1381714842048124831, var2-var1:-1025, var3-var2:4985  
22115, postgres, var1:1381714842103106941, var2:1381714842103105528, var3:1381714842103110854, var2-var1:-1413, var3-var2:5326  
22116, postgres, var1:1381714842298476703, var2:1381714842298475166, var3:1381714842298480683, var2-var1:-1537, var3-var2:5517  
22116, postgres, var1:1381714842548804292, var2:1381714842548802876, var3:1381714842548808009, var2-var1:-1416, var3-var2:5133  
22116, postgres, var1:1381714842799178954, var2:1381714842799177495, var3:1381714842799182911, var2-var1:-1459, var3-var2:5416  
22116, postgres, var1:1381714843049804167, var2:1381714843049802751, var3:1381714843049807869, var2-var1:-1416, var3-var2:5118  
22116, postgres, var1:1381714843300150256, var2:1381714843300148720, var3:1381714843300154284, var2-var1:-1536, var3-var2:5564  
22116, postgres, var1:1381714843550770421, var2:1381714843550769008, var3:1381714843550774130, var2-var1:-1413, var3-var2:5122  
22116, postgres, var1:1381714843801137544, var2:1381714843801136080, var3:1381714843801141503, var2-var1:-1464, var3-var2:5423  
22116, postgres, var1:1381714844051764015, var2:1381714844051762627, var3:1381714844051767737, var2-var1:-1388, var3-var2:5110  
22116, postgres, var1:1381714844302131981, var2:1381714844302130442, var3:1381714844302135946, var2-var1:-1539, var3-var2:5504  
22116, postgres, var1:1381714844552738244, var2:1381714844552736828, var3:1381714844552741945, var2-var1:-1416, var3-var2:5117  
22116, postgres, var1:1381714844803112341, var2:1381714844803110882, var3:1381714844803116311, var2-var1:-1459, var3-var2:5429  
22116, postgres, var1:1381714845053481725, var2:1381714845053478988, var3:1381714845053491289, var2-var1:-2737, var3-var2:12301  
22116, postgres, var1:1381714845303805410, var2:1381714845303803934, var3:1381714845303809147, var2-var1:-1476, var3-var2:5213  
22116, postgres, var1:1381714845554179961, var2:1381714845554178497, var3:1381714845554183931, var2-var1:-1464, var3-var2:5434  
22116, postgres, var1:1381714845804780501, var2:1381714845804779093, var3:1381714845804784215, var2-var1:-1408, var3-var2:5122  
从结果来看不管var3-var2多大, var2-var1基本维持在一个比较稳定的范围内. 说明前面对@entry的定义理解应该没有问题.  
例如这些, var3-var2较大  
22116, postgres, var1:1381714835036158608, var2:1381714835036155986, var3:1381714835036168009, var2-var1:-2622, var3-var2:12023  
22116, postgres, var1:1381714845053481725, var2:1381714845053478988, var3:1381714845053491289, var2-var1:-2737, var3-var2:12301  
但是 var2-var1的差别和其他的var2-var1的差别并不大.  
  
接下来的例子使用@entry, 来输出每次io请求的大小的柱状分布, 以及每次io请求消耗时间的柱状分布.  
(仅输出io请求量排前3的进程的io柱状图, 以及总的io请求柱状图)  
[root@db-172-16-3-150 tapset]# /opt/systemtap/bin/stap -e '  
global var1%[60000], var2%[60000], var3%[60000], var4%[60000];  
  
probe syscall.read.return {  
  cnt = $count  
  ns = gettimeofday_ns() - @entry(gettimeofday_ns())  
  var1[pid(),execname()] <<< cnt  
  var2[pid(),execname()] <<< ns  
  var3[pid(),execname()] <<< cnt  
  var4[pid(),execname()] <<< ns  
}  
  
probe timer.s($1) {  
  printf("\npid, execname, hist_log\n----------\n")  
  foreach ([x,y] in var1 @count - limit 3) {  
    printf("size_hist_log: %d, %s\n", x, y)  
    print(@hist_log(var1[x,y]))  
    printf("time_hist_log: %d, %s\n", x, y)  
    print(@hist_log(var2[x,y]))  
  }  
  delete var1  
  delete var2  
}  
  
probe end {  
  printf("\nEND: pid, execname, hist_log\n----------\n")  
  foreach ([x,y] in var3 @count - limit 3) {  
    printf("size_hist_log: %d, %s\n", x, y)  
    print(@hist_log(var3[x,y]))  
    printf("time_hist_log: %d, %s\n", x, y)  
    print(@hist_log(var4[x,y]))  
  }  
  delete var1  
  delete var2  
  delete var3  
  delete var4  
  exit();  
}  
' 5  
  
输出 :   
pid, execname, hist_log  
----------  
size_hist_log: 22116, postgres  
value |-------------------------------------------------- count  
    4 |                                                      0  
    8 |                                                      0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   1951  
   32 |                                                      0  
   64 |                                                      0  
  
time_hist_log: 22116, postgres  
value |-------------------------------------------------- count  
  256 |                                                      0  
  512 |                                                      0  
 1024 |@@@@@@@@@@@@@@@@                                    465  
 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   1365  
 4096 |@@@@                                                115  
 8192 |                                                      6  
16384 |                                                      0  
32768 |                                                      0  
  
size_hist_log: 7096, postgres  
value |-------------------------------------------------- count  
 2048 |                                                    0  
 4096 |                                                    0  
 8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                    63  
16384 |                                                    0  
32768 |                                                    0  
  
time_hist_log: 7096, postgres  
value |-------------------------------------------------- count  
  512 |                                                    0  
 1024 |                                                    0  
 2048 |                                                    1  
 4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@                       56  
 8192 |@@@                                                 6  
16384 |                                                    0  
32768 |                                                    0  
  
size_hist_log: 22118, postgres  
value |-------------------------------------------------- count  
    4 |                                                    0  
    8 |                                                    0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@    47  
   32 |                                                    0  
   64 |                                                    0  
  
time_hist_log: 22118, postgres  
value |-------------------------------------------------- count  
  256 |                                                    0  
  512 |                                                    0  
 1024 |@@@@@                                               5  
 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@          41  
 4096 |@                                                   1  
 8192 |                                                    0  
16384 |                                                    0  
  
  
pid, execname, hist_log  
----------  
size_hist_log: 22116, postgres  
value |-------------------------------------------------- count  
    4 |                                                      0  
    8 |                                                      0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   1855  
   32 |                                                      0  
   64 |                                                      0  
  
time_hist_log: 22116, postgres  
value |-------------------------------------------------- count  
  256 |                                                      0  
  512 |                                                      0  
 1024 |@@@@@@@@@@@@                                        361  
 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   1457  
 4096 |@                                                    34  
 8192 |                                                      3  
16384 |                                                      0  
32768 |                                                      0  
  
size_hist_log: 1523, irqbalance  
value |-------------------------------------------------- count  
  256 |                                                    0  
  512 |                                                    0  
 1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                    62  
 2048 |                                                    0  
 4096 |                                                    0  
  
time_hist_log: 1523, irqbalance  
  value |-------------------------------------------------- count  
    256 |                                                    0  
    512 |                                                    0  
   1024 |@@@                                                 3  
   2048 |                                                    0  
   4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  49  
   8192 |@@                                                  2  
  16384 |@@@@@                                               5  
  32768 |@                                                   1  
  65536 |                                                    0  
 131072 |@                                                   1  
 262144 |@                                                   1  
 524288 |                                                    0  
1048576 |                                                    0  
  
size_hist_log: 22118, postgres  
value |-------------------------------------------------- count  
    4 |                                                    0  
    8 |                                                    0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@      45  
   32 |                                                    0  
   64 |                                                    0  
  
time_hist_log: 22118, postgres  
value |-------------------------------------------------- count  
  256 |                                                    0  
  512 |                                                    0  
 1024 |@@                                                  2  
 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@          41  
 4096 |@@                                                  2  
 8192 |                                                    0  
16384 |                                                    0  
  
  
pid, execname, hist_log  
----------  
size_hist_log: 22116, postgres  
value |-------------------------------------------------- count  
    4 |                                                      0  
    8 |                                                      0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  1789  
   32 |                                                      0  
   64 |                                                      0  
  
time_hist_log: 22116, postgres  
 value |-------------------------------------------------- count  
   256 |                                                      0  
   512 |                                                      0  
  1024 |@@@@@@@@@@@@@@@                                     407  
  2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  1345  
  4096 |@                                                    36  
  8192 |                                                      0  
 16384 |                                                      0  
 32768 |                                                      1  
 65536 |                                                      0  
131072 |                                                      0  
  
size_hist_log: 22118, postgres  
value |-------------------------------------------------- count  
    4 |                                                    0  
    8 |                                                    0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@      45  
   32 |                                                    0  
   64 |                                                    0  
  
time_hist_log: 22118, postgres  
 value |-------------------------------------------------- count  
   256 |                                                    0  
   512 |                                                    0  
  1024 |@@@                                                 3  
  2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                35  
  4096 |@@@@                                                4  
  8192 |@@                                                  2  
 16384 |                                                    0  
 32768 |                                                    0  
 65536 |                                                    0  
131072 |@                                                   1  
262144 |                                                    0  
524288 |                                                    0  
  
size_hist_log: 7093, stapio  
 value |-------------------------------------------------- count  
 32768 |                                                    0  
 65536 |                                                    0  
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@                         26  
262144 |                                                    0  
524288 |                                                    0  
  
time_hist_log: 7093, stapio  
value |-------------------------------------------------- count  
  256 |                                                    0  
  512 |                                                    0  
 1024 |@                                                   1  
 2048 |@@@@@@@@@@@@@@                                     14  
 4096 |@@@@@@@@@@@                                        11  
 8192 |                                                    0  
16384 |                                                    0  
  
^C  
END: pid, execname, hist_log  
----------  
size_hist_log: 22116, postgres  
value |-------------------------------------------------- count  
    4 |                                                      0  
    8 |                                                      0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  5781  
   32 |                                                      0  
   64 |                                                      0  
  
time_hist_log: 22116, postgres  
 value |-------------------------------------------------- count  
   256 |                                                      0  
   512 |                                                      0  
  1024 |@@@@@@@@@@@@@@@                                    1308  
  2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  4273  
  4096 |@@                                                  190  
  8192 |                                                      9  
 16384 |                                                      0  
 32768 |                                                      1  
 65536 |                                                      0  
131072 |                                                      0  
  
size_hist_log: 22118, postgres  
value |-------------------------------------------------- count  
    4 |                                                     0  
    8 |                                                     0  
   16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@    142  
   32 |                                                     0  
   64 |                                                     0  
  
time_hist_log: 22118, postgres  
 value |-------------------------------------------------- count  
   256 |                                                     0  
   512 |                                                     0  
  1024 |@@@                                                 10  
  2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@           122  
  4096 |@@                                                   7  
  8192 |                                                     2  
 16384 |                                                     0  
 32768 |                                                     0  
 65536 |                                                     0  
131072 |                                                     1  
262144 |                                                     0  
524288 |                                                     0  
  
size_hist_log: 7093, stapio  
 value |-------------------------------------------------- count  
  2048 |                                                    0  
  4096 |                                                    0  
  8192 |@                                                   2  
 16384 |                                                    0  
 32768 |                                                    0  
 65536 |                                                    0  
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@           80  
262144 |                                                    0  
524288 |                                                    0  
  
time_hist_log: 7093, stapio  
value |-------------------------------------------------- count  
  256 |                                                    0  
  512 |                                                    0  
 1024 |@@@@                                                4  
 2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                 34  
 4096 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@        43  
 8192 |@                                                   1  
16384 |                                                    0  
32768 |                                                    0  

参考

1. https://access.redhat.com/site/documentation/en-US/Red_Hat_Enterprise_Linux/5/html/5.6_Technical_Notes/systemtap.html

A new operator, @entry, is available for automatically saving an expression at entry time for use in a .return probe.

Flag Counter

digoal’s 大量PostgreSQL文章入口