Re: tracing/kprobes: [Bug] Identical timestamps on two kprobes that are few instructions apart

[Arun Kalyanasundaram]

Hi Masama,

Thank you for looking into this.
You are right, I don't see the issue when my trace_clock = x86-tsc.

I tried with other clocks and apparently, I only see this when my
clock is either perf or global.
You mentioned this happens when "it adjusts timestamp", so does that
mean this is an expected behavior in this case?

I am running this on a haswell x86 architecture with 72 cores.

Thank you,
- Arun




On Sun, Jul 9, 2017 at 5:18 PM, Masami Hiramatsu <mhiramat@xxxxxxxxxx> wrote:
> Hello Arun,
>
> On Fri, 7 Jul 2017 16:06:40 -0700
> Arun Kalyanasundaram <arunkaly@xxxxxxxxxx> wrote:
>
>> Hi Steven,
>>
>> Thank you very much for your reply. I am using kernel - v4.12-rc3.
>>
>> I did something like this and see the issue:
>> # trace-cmd record -e kprobes:s1 -e kprobes:s2 -- taskset -c 0 my_program
>> # ./trace-cmd report -t --cpu 0
>>
>> The issue is pretty intermittent and only happens when there are a lot
>> of samples, and so "my_program" generates a few hundred threads. Any
>> pointers on debugging this would be very helpful, or please let me
>> know if you want me to collect any log messages.
>
> Ok, so this happens with ftrace+trace-cmd too.
> If you run it on x86-64, could you add "-C x86-tsc" and check still
> it happens? If not, I guess it happens when it adjusts timestamp.
>
> Thank you,
>
> --
> Masami Hiramatsu <mhiramat@xxxxxxxxxx>