Messages in this thread | | | From | Arun Kalyanasundaram <> | Date | Fri, 7 Jul 2017 11:00:56 -0700 | Subject | [Resend: Adding linux-kernel] tracing/kprobes: [Bug] Identical timestamps on two kprobes that are few instructions apart |
| |
Hi,
I am trying to use kprobes to time a few kernel functions. However, when I add two kprobes on a function that are a few instructions apart, I sometimes get the same timestamp (measured in nano seconds) on the two probes.
For example, if I add the two probes as follows, 1) perf probe -a "kprobe1=__schedule" 2) perf probe -a "kprobe2=__schedule+12"
I then use "perf record" on a multi-threaded benchmark (e.g. www.cs.virginia.edu/stream/) to collect samples. I then see the same timestamp on kprobe1 and kprobe2 for the same thread running on the same CPU. Following is an example of the output showing the same timestamp on the two probes.
comm,tid,cpu,time,event,ip,sym stream,62182,[064],3020935.384132080,probe:kprobe1,ffffffffb36399f1,__schedule stream,62182,[064],3020935.384132080,probe:kprobe2,ffffffffb36399fd,__schedule
Since it happens intermittently, I am wondering if there is some sort of race condition here. Please let me know if this is an expected behavior or is there something wrong in the way I use kprobes.
Thank you, - Arun
| |