1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
|
#! /usr/bin/env stap
/*
* Copyright (C) 2006-2007 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, write to the Free Software Foundation,
* Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
*
* 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 entry_io
global fd_io
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 filenames
global filehandles
global fileread
global filewrite
probe syscall.open {
filenames[pid()] = user_string($filename)
}
probe syscall.open.return {
if ($return != -1) {
filehandles[pid(), $return] = filenames[pid()]
fileread[pid(), $return] = 0
filewrite[pid(), $return] = 0
} else {
printf("%d %s access %s fail\n", timestamp(), proc(), filenames[pid()])
}
delete filenames[pid()]
}
probe syscall.read {
if ($count > 0) {
fileread[pid(), $fd] += $count
}
t = gettimeofday_us(); p = pid()
entry_io[p] = t
fd_io[p] = $fd
}
probe syscall.read.return {
t = gettimeofday_us(); p = pid()
fd = fd_io[p]
time_io[p,fd] <<< t - entry_io[p]
}
probe syscall.write {
if ($count > 0) {
filewrite[pid(), $fd] += $count
}
t = gettimeofday_us(); p = pid()
entry_io[p] = t
fd_io[p] = $fd
}
probe syscall.write.return {
t = gettimeofday_us(); p = pid()
fd = fd_io[p]
time_io[p,fd] <<< t - entry_io[p]
}
probe syscall.close {
if (filehandles[pid(), $fd] != "") {
printf("%d %s access %s read: %d write: %d\n",
timestamp(), proc(), filehandles[pid(), $fd],
fileread[pid(), $fd], 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 fd_io[pid()]
delete entry_io[pid()]
delete time_io[pid(),$fd]
}
|