Skip to content

Commit 3cc4c0a

Browse files
4ast4ast
authored
Merge pull request iovisor#911 from goldshtn/trace-params-signature
trace: Allow function signatures in uprobes and kprobes
2 parents e30eaec + 23e72b8 commit 3cc4c0a

3 files changed

Lines changed: 54 additions & 10 deletions

File tree

‎man/man8/trace.8‎

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -62,7 +62,7 @@ information. See PROBE SYNTAX below.
6262
.SH PROBE SYNTAX
6363
The general probe syntax is as follows:
6464

65-
.B [{p,r}]:[library]:function [(predicate)] ["format string"[, arguments]]
65+
.B [{p,r}]:[library]:function[(signature)] [(predicate)] ["format string"[, arguments]]
6666

6767
.B {t:category:event,u:library:probe} [(predicate)] ["format string"[, arguments]]
6868
.TP
@@ -84,6 +84,12 @@ The tracepoint category. For example, "sched" or "irq".
8484
.B function
8585
The function to probe.
8686
.TP
87+
.B signature
88+
The optional signature of the function to probe. This can make it easier to
89+
access the function's arguments, instead of using the "arg1", "arg2" etc.
90+
argument specifiers. For example, "(struct timespec *ts)" in the signature
91+
position lets you use "ts" in the filter or print expressions.
92+
.TP
8793
.B event
8894
The tracepoint event. For example, "block_rq_complete".
8995
.TP
@@ -159,6 +165,10 @@ Trace the block:block_rq_complete tracepoint and print the number of sectors com
159165
Trace the pthread_create USDT probe from the pthread library and print the address of the thread's start function:
160166
#
161167
.B trace 'u:pthread:pthread_create """start addr = %llx"", arg3'
168+
.TP
169+
Trace the nanosleep system call and print the sleep duration in nanoseconds:
170+
#
171+
.B trace 'p::SyS_nanosleep(struct timespec *ts) "sleep for %lld ns", ts->tv_nsec'
162172
.SH SOURCE
163173
This is from bcc.
164174
.IP

‎tools/trace.py‎

Lines changed: 21 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -93,15 +93,24 @@ def _bail(self, error):
9393
def _parse_probe(self):
9494
text = self.raw_probe
9595

96-
# Everything until the first space is the probe specifier
97-
first_space = text.find(' ')
98-
spec = text[:first_space] if first_space >= 0 else text
96+
# There might be a function signature preceding the actual
97+
# filter/print part, or not. Find the probe specifier first --
98+
# it ends with either a space or an open paren ( for the
99+
# function signature part.
100+
# opt. signature
101+
# probespec | rest
102+
# --------- ---------- --
103+
(spec, sig, rest) = re.match(r'([^ \t\(]+)(\([^\(]*\))?(.*)',
104+
text).groups()
105+
99106
self._parse_spec(spec)
100-
if first_space >= 0:
101-
text = text[first_space:].lstrip()
102-
else:
103-
text = ""
107+
self.signature = sig[1:-1] if sig else None # remove the parens
108+
if self.signature and self.probe_type in ['u', 't']:
109+
self._bail("USDT and tracepoint probes can't have " +
110+
"a function signature; use arg1, arg2, " +
111+
"... instead")
104112

113+
text = rest.lstrip()
105114
# If we now have a (, wait for the balanced closing ) and that
106115
# will be the predicate
107116
self.filter = None
@@ -396,6 +405,8 @@ def generate_program(self, include_self):
396405

397406
prefix = ""
398407
signature = "struct pt_regs *ctx"
408+
if self.signature:
409+
signature += ", " + self.signature
399410

400411
data_fields = ""
401412
for i, expr in enumerate(self.values):
@@ -561,7 +572,7 @@ class Tool(object):
561572
Trace the open syscall and print the filename being opened
562573
trace 'sys_read (arg3 > 20000) "read %d bytes", arg3'
563574
Trace the read syscall and print a message for reads >20000 bytes
564-
trace 'r::do_sys_return "%llx", retval'
575+
trace 'r::do_sys_open "%llx", retval'
565576
Trace the return from the open syscall and print the return value
566577
trace 'c:open (arg2 == 42) "%s %d", arg1, arg2'
567578
Trace the open() call from libc only if the flags (arg2) argument is 42
@@ -577,6 +588,8 @@ class Tool(object):
577588
Trace the block_rq_complete kernel tracepoint and print # of tx sectors
578589
trace 'u:pthread:pthread_create (arg4 != 0)'
579590
Trace the USDT probe pthread_create when its 4th argument is non-zero
591+
trace 'p::SyS_nanosleep(struct timespec *ts) "sleep for %lld ns", ts->tv_nsec'
592+
Trace the nanosleep syscall and print the sleep duration in ns
580593
"""
581594

582595
def __init__(self):

‎tools/trace_example.txt‎

Lines changed: 22 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -146,6 +146,25 @@ TIME PID COMM FUNC -
146146
^C
147147

148148

149+
In the preceding example, as well as in many others, readability may be
150+
improved by providing the function's signature, which names the arguments and
151+
lets you access structure sub-fields, which is hard with the "arg1", "arg2"
152+
convention. For example:
153+
154+
# trace 'p:c:open(char *filename) "opening %s", filename'
155+
PID TID COMM FUNC -
156+
17507 17507 cat open opening FAQ.txt
157+
^C
158+
159+
# trace 'p::SyS_nanosleep(struct timespec *ts) "sleep for %lld ns", ts->tv_nsec'
160+
PID TID COMM FUNC -
161+
777 785 automount SyS_nanosleep sleep for 500000000 ns
162+
777 785 automount SyS_nanosleep sleep for 500000000 ns
163+
777 785 automount SyS_nanosleep sleep for 500000000 ns
164+
777 785 automount SyS_nanosleep sleep for 500000000 ns
165+
^C
166+
167+
149168
As a final example, let's trace open syscalls for a specific process. By
150169
default, tracing is system-wide, but the -p switch overrides this:
151170

@@ -205,7 +224,7 @@ trace 'do_sys_open "%s", arg2'
205224
Trace the open syscall and print the filename being opened
206225
trace 'sys_read (arg3 > 20000) "read %d bytes", arg3'
207226
Trace the read syscall and print a message for reads >20000 bytes
208-
trace 'r::do_sys_return "%llx", retval'
227+
trace 'r::do_sys_open "%llx", retval'
209228
Trace the return from the open syscall and print the return value
210229
trace 'c:open (arg2 == 42) "%s %d", arg1, arg2'
211230
Trace the open() call from libc only if the flags (arg2) argument is 42
@@ -221,3 +240,5 @@ trace 't:block:block_rq_complete "sectors=%d", args->nr_sector'
221240
Trace the block_rq_complete kernel tracepoint and print # of tx sectors
222241
trace 'u:pthread:pthread_create (arg4 != 0)'
223242
Trace the USDT probe pthread_create when its 4th argument is non-zero
243+
trace 'p::SyS_nanosleep(struct timespec *ts) "sleep for %lld ns", ts->tv_nsec'
244+
Trace the nanosleep syscall and print the sleep duration in ns

0 commit comments

Comments
 (0)