<div dir="ltr">Hi lttng-people!<div><br></div><div>I have been using lttng to make a combined kernel and userspace trace and I can't make sense of a simple sequence of events. I am using a two core cpu, a custom distro (by yocto), linux kernel version is 3.12.15 with the PREEMPT RT patches, the lttng probe module lttng-probe-sched loaded.</div><div>This is my strange sequence:</div><div><div><br></div><div>[13:26:17.542825060] (+0.000003659) unit1 sched_switch: { cpu_id = 1 }, { pid = 2390 }, { prev_comm = "ThreadA", prev_tid = 2547, prev_prio = -19, prev_state = 1024, next_comm = "KernelThreadB", next_tid = 2410, next_prio = -51 }</div><div>[13:26:17.542831008] (+0.000005948) unit1 sched_migrate_task: { cpu_id = 0 }, { pid = 2408 }, { comm = "ThreadA", tid = 2547, prio = -19, orig_cpu = 1, dest_cpu = 0 }</div><div>[13:26:17.542837060] (+0.000003256) unit1 ust_event:my_ust_event: { cpu_id = 1 }, { vtid = 2547 }, { }</div></div><div><br></div><div>ThreadA makes the userspace trace event 'my_ust_event'.</div><div><br></div><div>What is strange to me is either the timestamp of 'my_ust_event' is "wrong" (it should have been a time before the sched_switch), or the cpu_id of the ust_event is "wrong" (it should be 0 since ThreadA has been migrated to cpu_id 0 at 13:26:17.542831008).</div><div><br></div><div>Or am I interpreting the sequence wrong?</div><div><br></div><div>Or could it be that the my_ust_event itself got interrupted and had already sampled the cpu_id, and after the migration completed the event, thus the trace is "correct"?</div><div><br></div><div>Thanks!</div><div>/Mattias</div><div><br></div></div>