4
lttngを使用してリモートシステムのスケジューリングを分析しようとしています。 しかし、babeltraceを使用してトレースをテキスト形式で表示すると、記録されたすべてのイベントのタイムスタンプは同じになります。その結果、TraceCompassの視覚化は失敗します。lttngのタイムスタンプが間違っています
[email protected]: babeltrace ~/temp/lttng/my-trace/MySystem/my-session-20170608-133943/ | head
[13:41:59.444999936] (+?.?????????) MySystem sched_stat_runtime: { cpu_id = 0 }, { comm = "lttng-sessiond", tid = 1533, runtime = 5016120, vruntime = 451268995605 }
[13:41:59.444999936] (+0.000000000) MySystem sched_waking: { cpu_id = 0 }, { comm = "lttng-consumerd", tid = 1547, prio = 20, target_cpu = 0 }
[13:41:59.444999936] (+0.000000000) MySystem sched_stat_runtime: { cpu_id = 0 }, { comm = "lttng-sessiond", tid = 1533, runtime = 276632, vruntime = 451269272237 }
[13:41:59.444999936] (+0.000000000) MySystem sched_wakeup: { cpu_id = 0 }, { comm = "lttng-consumerd", tid = 1547, prio = 20, target_cpu = 0 }
[13:41:59.444999936] (+0.000000000) MySystem sched_switch: { cpu_id = 0 }, { prev_comm = "lttng-sessiond", prev_tid = 1533, prev_prio = 20, prev_state = 4096, next_comm = "lttng-consumerd", next_tid = 1547, next_prio = 20 }
[13:41:59.444999936] (+0.000000000) MySystem syscall_exit_epoll_wait: { cpu_id = 0 }, { ret = 1, fds_length = 1, overflow = 0, fds = [ [0] = { data_union = { u64 = 0x1C, fd = 28 }, raw_events = 0x1, events = { EPOLLIN = 1, EPOLLPRI = 0, EPOLLOUT = 0, EPOLLERR = 0, padding = 0 } } ] }
[13:41:59.444999936] (+0.000000000) MySystem syscall_entry_ioctl: { cpu_id = 0 }, { fd = 28, cmd = 62981, arg = 1547 }
[13:41:59.444999936] (+0.000000000) MySystem syscall_exit_ioctl: { cpu_id = 0 }, { ret = 0, arg = 1547 }
[13:41:59.444999936] (+0.000000000) MySystem syscall_entry_ioctl: { cpu_id = 0 }, { fd = 28, cmd = 2147808776, arg = 3047156396 }
[13:41:59.444999936] (+0.000000000) MySystem syscall_exit_ioctl: { cpu_id = 0 }, { ret = 0, arg = 3047156396 }
[email protected]: babeltrace ~/temp/lttng/my-trace/MySystem/my-session-20170608-133943/ | tail
[13:41:59.444999936] (+0.000000000) MySystem sched_wakeup: { cpu_id = 0 }, { comm = "rcu_preempt", tid = 7, prio = 20, target_cpu = 0 }
[13:41:59.444999936] (+0.000000000) MySystem sched_switch: { cpu_id = 0 }, { prev_comm = "lttng", prev_tid = 1698, prev_prio = 20, prev_state = 4096, next_comm = "rcu_preempt", next_tid = 7, next_prio = 20 }
[13:41:59.444999936] (+0.000000000) MySystem sched_stat_runtime: { cpu_id = 0 }, { comm = "rcu_preempt", tid = 7, runtime = 128301, vruntime = 456917982563 }
[13:41:59.444999936] (+0.000000000) MySystem sched_switch: { cpu_id = 0 }, { prev_comm = "rcu_preempt", prev_tid = 7, prev_prio = 20, prev_state = 1, next_comm = "lttng", next_tid = 1698, next_prio = 20 }
[13:41:59.444999936] (+0.000000000) MySystem sched_waking: { cpu_id = 0 }, { comm = "lttng-sessiond", tid = 1533, prio = 20, target_cpu = 0 }
[13:41:59.444999936] (+0.000000000) MySystem sched_stat_runtime: { cpu_id = 0 }, { comm = "lttng", tid = 1698, runtime = 209068, vruntime = 456921063330 }
[13:41:59.444999936] (+0.000000000) MySystem sched_wakeup: { cpu_id = 0 }, { comm = "lttng-sessiond", tid = 1533, prio = 20, target_cpu = 0 }
[13:41:59.444999936] (+0.000000000) MySystem sched_switch: { cpu_id = 0 }, { prev_comm = "lttng", prev_tid = 1698, prev_prio = 20, prev_state = 4096, next_comm = "lttng-sessiond", next_tid = 1533, next_prio = 20 }
[13:41:59.444999936] (+0.000000000) MySystem syscall_exit_recvmsg: { cpu_id = 0 }, { ret = 13156, msg = 3046107868 }
[13:41:59.444999936] (+0.000000000) MySystem syscall_entry_ioctl: { cpu_id = 0 }, { fd = 31, cmd = 63063, arg = 17 }
トレースは数秒間実行され、912Kです。 私は、分析のための私のホストシステムにデータを転送するlttng-relaydを使用して、組み込みLinuxデバイス上のトレースを開始するには、次のコマンドを使用：
lttng create my-session --set-url=net://10.0.28.1
lttng enable-channel --kernel --subbuf-size=2621440 channel0
lttng enable-event --kernel --syscall --all --channel channel0
lttng enable-event --kernel --channel channel0 sched*
lttng start
# Wait a bit
lttng stop
がどのようにタイムスタンプを修正できますか？