Re: newbie question: tracing userspace call/return sequences

["Naveen N. Rao" <naveen.n.rao@linux.vnet.ibm.com>]

On 2017/01/09 10:19AM, Christian Convey wrote:
> Hi Masami,
> 
> On Sat, Jan 7, 2017 at 6:44 PM, Masami Hiramatsu <mhiramat@kernel.org> wrote:
> >
> > No, you can use $params for tracing all function parameters :)
> > So, please try "* $params" instead of "*".
> 
> Thanks for the tip!  I tried it out, and got some strange results: The
> correct set of function parameter names is present in
> "trace_unhandled" 's "event_fields_dict" dictionary.  However, the
> actual runtime values of those parameters is sometimes inaccurate.
> 
> I'm using a simple Fibonacci program with just two functions: "main"
> and "fibfunc".
> 
> Here are my steps:
> 
> gcc -g -fno-omit-frame-pointer -O0 fib.c -o fib
> 
> export PERF_EXEC_PATH=/home/cconvey/src/linux-4.8.0/tools/perf
> 
> sudo -E ${PERF_EXEC_PATH}/perf probe --exec=./fib --del='*'
> 
> sudo -E ${PERF_EXEC_PATH}/perf probe --exec=./fib --add='* $params'
> 
> sudo -E ${PERF_EXEC_PATH}/perf record -e 'probe_fib:*' -aR ./fib 3
> 
> # My script which currently just prints the parameters passed to
> 'trace_unhandled'.
> sudo -E ${PERF_EXEC_PATH}/perf script -s ./perf-script-2.py
> 
> 
> Here's an example of the output from my script:
> 
> > in trace_begin
> > event_name = "probe_fib__main"
> > event_fields_dict: {'common_callchain': [], 'common_pid': 18631, 'common_s': 98414, 'common_comm': 'fib', 'common_ns': 209748661, 'argv': 94718640125824, 'common_cpu': 6, 'argc': 22053, '__probe_ip': 94718640125737}
> >
> > event_name = "probe_fib__fibfunc"
> > event_fields_dict: {'common_callchain': [], 'common_pid': 18631, 'common_s': 98414, 'common_comm': 'fib', 'common_ns': 209756797, 'n': 0, 'common_cpu': 6, '__probe_ip': 94718640125664}
> >
> > event_name = "probe_fib__fibfunc"
> > event_fields_dict: {'common_callchain': [], 'common_pid': 18631, 'common_s': 98414, 'common_comm': 'fib', 'common_ns': 209757849, 'n': 32764, 'common_cpu': 6, '__probe_ip': 94718640125664}
> >
> > event_name = "probe_fib__fibfunc"
> > event_fields_dict: {'common_callchain': [], 'common_pid': 18631, 'common_s': 98414, 'common_comm': 'fib', 'common_ns': 209758915, 'n': 2, 'common_cpu': 6, '__probe_ip': 94718640125664}
> >
> > in trace_end
> 
> Notice, for example, that the reported value for "argc" is 22053, rather than 2.
> 
> Any idea why that might be happening?

Try compiling your program with -O2, or use a newer perf:
https://git.kernel.org/cgit/linux/kernel/git/powerpc/linux.git/commit/?id=e47392bf9c0613a058cd20ee89d8ce9d957d4b24

- Naveen