[lttng-dev] trace time out of order

[zhenyu.ren]

Hi,lttng-dev

   I traced my rpc application. On the server side ,a thread reads a request from the socket and push the workitem to a queue(pushWorkItem tracepoint after queuing),another thread will get the workitem from queue and process it(ProcessWorkItem tracepoint here). However, in the trace log,I saw the ProcessWorkItem before pushWorkItem.Is this a clock issue?

[14:38:07.619841156] (+0.000000693)  arpc_server:ProcessWorkItem: { cpu_id = 0 }, { vtid = 28581 }, { Item = 112046400 }                 A
[14:38:07.619841558] (+0.000000402)  arpc_server:ProcessWorkItem: { cpu_id = 12 }, { vtid = 28583 }, { Item = 112049088 }                B
[14:38:07.619844551] (+0.000002993)  arpc_server:ProcessWorkItem: { cpu_id = 9 }, { vtid = 28582 }, { Item = 72969600 }                   C
[14:38:07.619845090] (+0.000000539)  arpc_server:pushWorkItem: { cpu_id = 3 }, { vtid = 28569 }, { Item = 112046400 }                      A
[14:38:07.619846525] (+0.000001435)  sched_wakeup: { cpu_id = 12 }, { vtid = 28583 }, { comm = "", tid = 28581, prio = 120, success = 0, target_cpu = 0 }
[14:38:07.619846872] (+0.000000347)  arpc_server:pushWorkItem: { cpu_id = 7 }, { vtid = 28563 }, { Item = 72968352 }
[14:38:07.619849172] (+0.000002300)  arpc_server:ProcessWorkItem: { cpu_id = 19 }, { vtid = 28587 }, { Item = 72968352 }
[14:38:07.619850525] (+0.000001353)  arpc_server:pushWorkItem: { cpu_id = 6 }, { vtid = 28564 }, { Item = 112049088 }                      B
[14:38:07.619862696] (+0.000012171)  sched_switch: { cpu_id = 3 }, { vtid = 28569 }, { prev_comm = "pangu_chunkserv", prev_tid = 28569, prev_prio = 20, prev_state = 1, next_comm = "swapper", next_tid = 0, next_prio = 20 }
[14:38:07.619864494] (+0.000001798)  sched_switch: { cpu_id = 6 }, { vtid = 28564 }, { prev_comm = "pangu_chunkserv", prev_tid = 28564, prev_prio = 20, prev_state = 1, next_comm = "pangu_chunkserv", next_tid = 28568, next_prio = 20 }
[14:38:07.619867101] (+0.000002607)  arpc_server:pushWorkItem: { cpu_id = 6 }, { vtid = 28568 }, { Item = 72969600 }                       C



ps: Hardware: 2 x Xeon E5-2430 0 2.20GHz(24HT) ， 96G mem 
      urcu 0.8 lttng 2.3

Thanks
zhenyu.ren