2017-06-08 187 views
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大。 我用下面的命令来启动嵌入式Linux设备上的追踪,使用lttng-relayd将数据传输到我的主机系统进行分析:

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 

如何解决的时间戳?

回答

0

The folks at the lttng-dev mailing list solved the problem for me:我不小心加载了内核模块的假测试时钟,而不是真正的时钟内核模块。

我的错误是我跑insmod所有.ko由lttng手动提供的文件。但是,正确的方法是让lttng-sessiond自动加载模块,这将忽略假测试时钟模块。自动模块加载失败,因为我在安装内核模块后没有运行depmod -a

depmod -a之后,一切工作正常,时间戳是正确的。