On Wed, Apr 16, 2014 at 07:44:44PM -0400, Steven Rostedt wrote:
> On Thu, 17 Apr 2014 08:08:08 +1000
> Dave Chinner <david@xxxxxxxxxxxxx> wrote:
>
>
> > > Here's the "best" I've come up with so far...
> > >
> > > # for FUNCTION in `grep "t xfs_" /proc/kallsyms | awk '{print $3}'`; do echo "r:ret_$FUNCTION $FUNCTION \$retval" >> /sys/kernel/debug/tracing/kprobe_events; done
>
> BTW, it's usually better to do:
>
> grep 't xfs_' /proc/kallsyms | awk '{print $3}' ; while read FUNCTION; do ....
grep -i 't xfs' .....
> > > # for ENABLE in /sys/kernel/debug/tracing/events/kprobes/ret_xfs_*/enable; do echo 1 > $ENABLE; done
> > >
> > > run a test that fails:
> > >
> > > # dd if=/dev/zero of=newfile bs=513 oflag=direct
> > > dd: writing `newfile': Invalid argument
> > >
> > > # for ENABLE in /sys/kernel/debug/tracing/events/kprobes/ret_xfs_*/enable; do echo 0 > $ENABLE; done
> > >
> > > # cat /sys/kernel/debug/tracing/trace
> > > <snip>
> > > <...>-63791 [000] d... 705435.568913: ret_xfs_vn_mknod: (xfs_vn_create+0x13/0x20 [xfs] <- xfs_vn_mknod) arg1=0
> > > <...>-63791 [000] d... 705435.568913: ret_xfs_vn_create: (vfs_create+0xdb/0x100 <- xfs_vn_create) arg1=0
> > > <...>-63791 [000] d... 705435.568918: ret_xfs_file_open: (do_dentry_open+0x24e/0x2e0 <- xfs_file_open) arg1=0
> > > <...>-63791 [000] d... 705435.568934: ret_xfs_file_dio_aio_write: (xfs_file_aio_write+0x147/0x150 [xfs] <- xfs_file_dio_aio_write) arg1=ffffffffffffffea
> > >
> > > Hey look, it's "-22" in hex! ;)
> > >
> > > so it's possible, but bleah.
> >
> > Steve, we want to be able to trap specific return codes from
> > functions. Say, for example, the first function that returns
> > EINVAL/-EINVAL in XFS under a given workload.
> >
> > What's the most efficient way to do that with ftrace?
> >
> > And can that be set up as a trigger so we can use it to dump a
> > snapshot of the last N events into the trace buffer or do other
> > interesting things with that event?
>
> Well, after you do the above, you could also do a while loop to all
> those events and update the filter:
>
> echo 'arg1 > 0xffffffffffffff00' > /debug/tracing/events/kprobes/filter
>
> Which would trace only those functions that had an error code (assuming
> the error code is less than 256). You could also use the trigger files:
>
> echo 'traceoff if arg1 > 0xffffffffffffff00' > /debug/tracing/events/kprobes/*/trigger
>
> The above wont actually work as is, you would need to do another while
> loop of trigger files and set them each individually.
so, basically a script that does:
#!/bin/bash
TRACEDIR=/sys/kernel/debug/tracing
grep -i 't xfs_' /proc/kallsyms | awk '{print $3}' ; while read F; do
echo "r:ret_$F $F \$retval" >> $TRACEDIR/kprobe_events
done
for E in $TRACEDIR/events/kprobes/ret_xfs_*/enable; do
echo 1 > $E
done;
echo 'arg1 > 0xffffffffffffff00' > $TRACEDIR/events/kprobes/filter
for T in $TRACEDIR/events/kprobes/ret_xfs_*/trigger; do
echo 'traceoff if arg1 > 0xffffffffffffff00' > $T
done
And that gives:
# dd if=/dev/zero of=/mnt/scratch/newfile bs=513 oflag=direct
dd: error writing ¿/mnt/scratch/newfile¿: Invalid argument
1+0 records in
0+0 records out
0 bytes (0 B) copied, 0.000259882 s, 0.0 kB/s
root@test4:~# cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 1/1 #P:16
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
<...>-8073 [006] d... 145740.460546: ret_xfs_file_dio_aio_write: (xfs_file_aio_write+0x170/0x180 <- xfs_file_dio_aio_write) arg1=0xffffffffffffffea
Which is precisely the detection that XFS_ERROR would have given us.
Ok, so I guess we can now add whatever need need to that trigger...
Basically, pass in teh XFs function names you want to trace, the
sets up teh events, whatever trigger beahviour you want, and
we're off to the races...
Cheers,
Dave.
--
Dave Chinner
david@xxxxxxxxxxxxx
_______________________________________________
xfs mailing list
xfs@xxxxxxxxxxx
http://oss.sgi.com/mailman/listinfo/xfs
