/
trace_oracle_iocalls_12102.stp
executable file
·147 lines (130 loc) · 6.38 KB
/
trace_oracle_iocalls_12102.stp
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
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
#!/usr/local/bin/stap
#
# trace_oracle_iocalls_12102.stp
#
# This is a SystemTap probe to trace physical I/O to block devices and Oracle wait events
# the script works by hooking into the OS syscalls and to Oracle kernel function kskthewt
# for Oracle 12.1.0.2
# For more info on how this works, see also trace_oracle_events_12102.stp
#
# Dependencies (for Oracle userspace tracing):
# Use systemtap 2.5 or higher
# Kernel must have support for uprobes or utrace (for example RHEL/OL 7.x and 6.x)
# The oracle executable should be in the path: add $ORACLE_HOME/bin in $PATH
# Needs kernel debug info
# This is for oracle 12.1.0.2 (edit the probe on function("kskthewt") to port for a different version)
#
# Notable exception and issue with Oracle 12.1.0.2:
# this script will throw "inode-offset registration error" when run against 12.1.0.2 on
# RHEL/OL7.1 (i.e. kernel 3.10.0-229.x). The workaround is to use an older kernel
# such as RHEL/OL7.0 (kernel 3.10.0-123.x). It seems to work fine on RHEL/OL 7.1 and 11g.
#
# Version 1.0, Aug 2014 by Luca.Canali@cern.ch
# Additional credits for original contributions: @FritsHoogland
#
# Note: this is experimental code, use at your own risk
##############################
# Trace wait events 12.1.0.2 #
##############################
probe process("oracle").function("kskthbwt") {
xksuse = register("r13")-3928
ksusenum = user_uint16(xksuse + 1704)
printf("==========\nDB WAIT EVENT BEGIN: timestamp_ora=%ld, pid=%d, sid=%d, event#=%u\n",
register("rsi"), pid(), ksusenum, register("rdx"))
}
probe process("oracle").function("kskthewt") {
xksuse = register("r13") - 3928
ksuudnam = user_string(xksuse + 140)
ksusenum = user_uint16(xksuse + 1704)
ksuseopc = user_uint16(xksuse + 1602)
ksusep1 = user_uint64(xksuse + 1608)
ksusep2 = user_uint64(xksuse + 1616)
ksusep3 = user_uint64(xksuse + 1624)
ksusetim = user_uint32(xksuse + 1632)
ksusesqh = user_uint32(xksuse + 1868)
ksuseobj = user_uint32(xksuse + 2312)
printf("DB WAIT EVENT END: timestamp_ora=%ld, pid=%d, sid=%d, name=%s, event#=%u, p1=%lu, p2=%lu, p3=%lu, wait_time=%u, obj=%d, sql_hash=%u\n==========\n",
register("rdi"), pid(), ksusenum, ksuudnam, ksuseopc, ksusep1, ksusep2, ksusep3, ksusetim, ksuseobj, ksusesqh)
}
###########################
# Trace Physical IO - ASM #
###########################
probe syscall.pread, syscall.pwrite {
if (pid() == target()) {
printf ("OS: ->%s: timestamp=%d, program=%s, pid=%d, fd=%d, offset=%d, count(bytes)=%d\n", name, local_clock_us(), execname(), pid(), fd, offset, count)
}
}
probe syscall.pread.return, syscall.pwrite.return {
if (pid() == target()) {
printf ("OS: <-%s: timestamp=%d, program=%s, pid=%d, return(bytes)=%d\n", name, local_clock_us(), execname(), pid(), $return)
}
}
# some ugly tricks added here for compatibility, in particular there seem to be problems in RHEL/EL 7.x debuginfo related to
# $iocbpp which is incorrectly reported as long int in those system instead of struct iocb**, also we use a trick to resolve the array
# the use of a probe on kernel.function instead of syscall.io_submit also needed for some platforms (RHEL 6.7)
# See below for a more basic probe that works on RHEL and RHEL6.6
probe kernel.function("sys_io_submit") {
if (pid() == target()) {
printf ("OS: ->%s: timestamp=%d, program=%s, pid=%d, nr(num I/O)=%d\n", "io_submit", local_clock_us(), execname(), pid(), $nr)
for (i=0; i<$nr; i++) {
printf(" %d: file descriptor=%d, offset=%d, bytes=%d, opcode=%d\n", i+1, @cast(user_int64($iocbpp+8*i), "struct iocb")->aio_fildes,
@cast(user_int64($iocbpp+8*i), "struct iocb")->aio_offset, @cast(user_int64($iocbpp+8*i), "struct iocb")->aio_nbytes,
@cast(user_int64($iocbpp+8*i), "struct iocb")->aio_lio_opcode)
}
}
}
# For reference this is the original probe on io_submit without the compatibility tricks used above
# probe syscall.io_submit {
# if (pid() == target()) {
# printf ("OS: ->%s: timestamp=%d, program=%s, pid=%d, nr(num I/O)=%d\n", name, local_clock_us(), execname(), pid(), nr)
# for (i=0; i<$nr; i++) {
# printf(" %d: file descriptor=%d, offset=%d, bytes=%d, opcode=%d\n", i+1, $iocbpp[i]->aio_fildes,
# $iocbpp[i]->aio_offset, $iocbpp[i]->aio_nbytes, $iocbpp[i]->aio_lio_opcode)
# }
# }
# }
probe syscall.io_submit.return {
if (pid() == target()) {
printf ("OS: <-%s: timestamp=%d, program=%s, pid=%d, return(num I/O)=%ld\n", name, local_clock_us(), execname(), pid(), $return)
}
}
probe syscall.io_getevents {
if (pid() == target()) {
printf ("OS: ->%s: timestamp=%d, program=%s, pid=%d, min_nr=%d, timeout=%s\n", name, local_clock_us(), execname(), pid(), min_nr, $timeout$)
}
}
# need to explicitly cast $events for RHEL/EL 7.x kernels, where debuginfo issues report $events as long int instead of struct io_event*
probe syscall.io_getevents.return {
if (pid() == target()) {
printf ("OS: <-%s: timestamp=%d, program=%s, pid=%d, return(num I/O)=%ld\n", name, local_clock_us(), execname(), pid(), $return)
for (i=0; i<$return; i++) { # cycle over the reaped I/Os
obj_addr = @cast($events, "struct io_event")[i]->obj # details of struct iocb in /usr/include/libaio.h
fildes = user_uint32(obj_addr +20)
bytes = user_uint64(obj_addr +32)
offset = user_uint64(obj_addr +40)
printf(" %d:, fildes=%d, offset=%lu, bytes=%lu\n", i+1, fildes, offset, bytes)
}
}
}
global active_bio[10000]
probe ioblock.request {
if (pid() == target()) {
printf("OS: ->%s, timestamp=%d, pid=%d, devname=%s, sector=%d, size=%d, rw=%d, address_bio=%lu\n",
name, local_clock_us(), pid(), devname, sector, size, rw, $bio )
active_bio[$bio] += 1
}
}
probe ioblock_trace.request {
if (pid() == target()) {
printf("OS: ->%s, timestamp=%d, pid=%d, devname=%s, sector=%d, size=%d, rw=%d, address_bio=%lu\n",
name, local_clock_us(), pid(), devname, sector, size, rw, $bio )
}
}
# the use of active_bio[] is a workaround as pid is not populated in ioblock.end and therefore cannot be used for filtering
probe ioblock.end {
if (active_bio[$bio] >= 1) {
printf("OS: <-%s, timestamp=%d, pid=%d, devname=%s, sector=%d, rw=%d, address_bio=%lu\n",
name, local_clock_us(), pid(), devname, sector, rw, $bio)
active_bio[$bio] -= 1
}
}