simple postgres io statistics

pg-fsync.stp

#!/usr/bin/env stap

#
# logs sync events triggered from postgres
#
#
# example output:
#
#  = table insert =
#
#      kernel.function("SyS_fdatasync@/build/linux-GSgHvp/linux-3.16.39/fs/sync.c:217")
#        invoked by process: 'postgres', pid: '3346', cmd: 'postgres: j j [local] INSERT'
#        on file: '000000010000000000000012'
#
#
#  = checkpoint =
#
#      kernel.function("SyS_fsync@/build/linux-GSgHvp/linux-3.16.39/fs/sync.c:212")
#        invoked by process: 'postgres', pid: '8307', cmd: 'postgres: checkpointer process   '
#        on file: '0000'
#      kernel.function("SyS_fsync@/build/linux-GSgHvp/linux-3.16.39/fs/sync.c:212")
#        invoked by process: 'postgres', pid: '8307', cmd: 'postgres: checkpointer process   '
#        on file: '16681'
#      kernel.function("SyS_fdatasync@/build/linux-GSgHvp/linux-3.16.39/fs/sync.c:217")
#        invoked by process: 'postgres', pid: '8307', cmd: 'postgres: checkpointer process   '
#        on file: '000000010000000000000012'
#      kernel.function("SyS_fsync@/build/linux-GSgHvp/linux-3.16.39/fs/sync.c:212")
#        invoked by process: 'postgres', pid: '8307', cmd: 'postgres: checkpointer process   '
#        on file: 'pg_control'
#



# sync a file 
probe kernel.function("sys_fsync"), kernel.function("sys_fdatasync") {
  if(execname() == "postgres") {
    println(pp())
    file = @cast(task_current(), "task_struct")->files->fdt->fd[$fd];
    printf("  invoked by process: '%s', pid: '%d', cmd: '%s'\n", execname(), pid(), cmdline_arg(0))
    printf("  on file: '%s'\n", __file_filename(file))
  }
}



# sync event - sync's ALL files
probe kernel.function("sys_sync"){
  if(execname() == "postgres") {
    println(pp())
    printf("  invoked by process: '%s', pid: '%d', cmd: '%s'\n", execname(), pid(), cmdline_arg(0))
  }
}

probe begin{
  println("ready...")
}

pg-iostat.stp

#! /usr/bin/env stap
#
# simple io stats over postgres processes and files
#
#
#   * displays every second the read / write amount from the top N postgres processes / files
#
#   * you can give the parameter 'N' as an additional argument at the command line: `./pg-iostat.stp 15`
#
#   * to get the relation name from a filename use:
#
#       SELECT relname FROM pg_class WHERE relfilenode = 21053;
#
#
# example output:
#
#
# =============================================================   Wed May  3 20:25:04 2017
# processes (top 10)
# 
#      pid                  read                 write process
#    12542         81920 (  80K)     788652032 ( 752M) postgres: j j [local] INSERT
#     8307             3 (   3B)     355020923 ( 338M) postgres: checkpointer process   
#    16292     189710336 ( 180M)     119177216 ( 113M) postgres: autovacuum worker process   j
#     8309             0 (   0B)     122068992 ( 116M) postgres: wal writer process   
#     8308            11 (  11B)        475147 ( 464K) postgres: writer process   
#    16592        287536 ( 280K)             0 (   0B) postgres: autovacuum worker process   
#    16589        131888 ( 128K)             0 (   0B) postgres: autovacuum worker process   
#    16590        131888 ( 128K)             0 (   0B) postgres: autovacuum worker process   
#    16591        131888 ( 128K)             0 (   0B) postgres: autovacuum worker process   
#     8311             0 (   0B)         80715 (  78K) postgres: stats collector process   
#    16591         29643 (  28K)             0 (   0B) postgres: autovacuum worker process   j
#          -------------------------------------------
#              190557033 ( 181M)    1385475041 (   1G) sum over ALL processes
# 
# 
# files (top 10)
# 
#                           read                 write filename
#               37052416 (  35M)     684867584 ( 653M) 21393.2
#               95780864 (  91M)      84787200 (  80M) 21393.1
#               56877056 (  54M)             0 (   0B) 21393
#                      0 (   0B)      16785408 (  16M) 000000010000000F000000CA
#                      0 (   0B)      16785408 (  16M) 000000010000000F000000CB
#                      0 (   0B)      16785408 (  16M) 000000010000000F000000CF
#                      0 (   0B)      16785408 (  16M) 000000010000000F000000D2
#                      0 (   0B)      16785408 (  16M) 000000010000000F000000D8
#                      0 (   0B)      16785408 (  16M) 000000010000000F000000DB
#                      0 (   0B)      16785408 (  16M) 000000010000000F000000DE
#          -------------------------------------------
#              190557033 ( 181M)    1385475041 (   1G) sum over ALL files
#


global ptotal, preads, pwrites
global ftotal, freads, fwrites

global N = %($# > 0 %? $1 %: 10%)




probe vfs.read.return {
  if ($return > 0 && execname() == "postgres") {
    preads[pid(), execname(), cmdline_arg(0)] += $return
    ptotal[pid(), execname(), cmdline_arg(0)] += $return

    freads[__file_filename($file)] += $return
    ftotal[__file_filename($file)] += $return
  }
}
    

probe vfs.write.return {
  if ($return > 0 && execname() == "postgres") {
    pwrites[pid(), execname(), cmdline_arg(0)] += $return
    ptotal[pid(), execname(), cmdline_arg(0)] += $return

    fwrites[__file_filename($file)] += $return
    ftotal[__file_filename($file)] += $return
  }
}



probe timer.s(1) {


  #
  # reads / writes per process
  #
  println("\n\n=============================================================   ", ctime(gettimeofday_s()))
  printf("processes (top %d)\n\n", N)
  printf("     pid %21s %21s process\n", "read", "write")
  foreach([pid, exec, cmd] in ptotal- limit N) {
    name = cmd
    if(name == "") name = exec
    printf("%8d %13d (%5s) %13d (%5s) %-s\n", pid, 
           preads[pid, exec, cmd], pretty(preads[pid, exec, cmd]),
           pwrites[pid, exec, cmd], pretty(pwrites[pid, exec, cmd]), name)
  }
  
  foreach([pid, exec, cmd] in ptotal) {
    rsum += preads[pid, exec, cmd]
    wsum += pwrites[pid, exec, cmd]
  }
  printf("         -------------------------------------------\n")
  printf("         %13d (%5s) %13d (%5s) sum over ALL processes\n", rsum, pretty(rsum), wsum, pretty(wsum))


  #
  # reads / writes per file
  #
  printf("\n\nfiles (top %d)\n\n", N)
  printf("         %21s %21s filename\n", "read", "write")
  foreach(f in ftotal- limit N) {
    printf("         %13d (%5s) %13d (%5s) %s\n", freads[f], pretty(freads[f]), fwrites[f], pretty(fwrites[f]), f)
  }
  foreach([f] in ftotal) {
    rfsum += freads[f]
    wfsum += fwrites[f]
  }
  printf("         -------------------------------------------\n")
  printf("         %13d (%5s) %13d (%5s) sum over ALL files\n", rfsum, pretty(rfsum), wfsum, pretty(wfsum))

  printf("\n")
}



function pretty(bytes) {
  if (bytes > 1024*1024*1024) {
    return sprintf("%dG", bytes/1024/1024/1024)
  } else if (bytes > 1024*1024) {
    return sprintf("%dM", bytes/1024/1024)
  } else if (bytes > 1024) {
    return sprintf("%dK", bytes/1024)
  } else {
    return sprintf("%dB", bytes)
  }
}