#! /usr/bin/env 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 . * * 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] }