^^&&^^

Edit File: iotime.stp

#!/usr/bin/stap

/*
 * Copyright (C) 2006-2018 Red Hat Inc.
 * 
 * This copyrighted material is made available to anyone wishing to use,
 * modify, copy, or redistribute it subject to the terms and conditions
 * of the GNU General Public License v.2.
 *
 * You should have received a copy of the GNU General Public License
 * along with this program.  If not, see <http://www.gnu.org/licenses/>.
 *
 * Print out the amount of time spent in the read and write systemcall
 * when each file opened by the process is closed. Note that the systemtap 
 * script needs to be running before the open operations occur for
 * the script to record data.
 *
 * This script could be used to to find out which files are slow to load
 * on a machine. e.g.
 *
 * stap iotime.stp -c 'firefox'
 *
 * Output format is:
 * timestamp pid (executabable) info_type path ...
 *
 * 200283135 2573 (cupsd) access /etc/printcap read: 0 write: 7063
 * 200283143 2573 (cupsd) iotime /etc/printcap time: 69
 *
 */

global start
global time_io

function timestamp:long() { return gettimeofday_us() - start }

function proc:string() { return sprintf("%d (%s)", pid(), execname()) }

probe begin { start = gettimeofday_us() }

global possible_filename, filehandles, fileread, filewrite

probe syscall.open, syscall.openat {
  possible_filename[tid()] = filename
}

probe syscall.open.return, syscall.openat.return {
  // Get filename even if non-dwarf syscall return probe are used.
  filename = possible_filename[tid()]
  delete  possible_filename[tid()]
  if (retval != -1) {
    filehandles[pid(), retval] = filename
  } else {
    printf("%d %s access %s fail\n", timestamp(), proc(), filename)
  }
}

global read_fds, write_fds

probe syscall.read { read_fds[tid()] = fd }

probe syscall.read.return {
  p = pid()
  // Get fd even if non-dwarf syscall return probe.
  fd = read_fds[tid()]
  delete read_fds[tid()]
  bytes = retval
  time = gettimeofday_us() - @entry(gettimeofday_us())
  if (bytes > 0)
    fileread[p, fd] <<< bytes
  time_io[p, fd] <<< time
}

probe syscall.write { write_fds[tid()] = fd }

probe syscall.write.return {
  p = pid()
  // Get fd even if non-dwarf syscall return probe.
  fd = write_fds[tid()]
  delete write_fds[tid()]
  bytes = retval
  time = gettimeofday_us() - @entry(gettimeofday_us())
  if (bytes > 0)
    filewrite[p, fd] <<< bytes
  time_io[p, fd] <<< time
}

probe syscall.close {
  if ([pid(), fd] in filehandles) {
    printf("%d %s access %s read: %d write: %d\n",
           timestamp(), proc(), filehandles[pid(), fd],
           @sum(fileread[pid(), fd]), @sum(filewrite[pid(), fd]))
    if (@count(time_io[pid(), fd]))
      printf("%d %s iotime %s time: %d\n",  timestamp(), proc(),
             filehandles[pid(), fd], @sum(time_io[pid(), fd]))
   }
  delete fileread[pid(), fd]
  delete filewrite[pid(), fd]
  delete filehandles[pid(), fd]
  delete time_io[pid(),fd]
}