4

我正在尝试通过跟踪事件和4.4 内核（Ubuntu 16.04 LTS）来跟踪使用Lttng的 Linux 调度程序。有时我什至在线程关闭之前就收到了事件。我不明白这个唤醒的意义，因为线程已经在运行。以下是显示此行为的一段生成的 babeltrace 日志（tid = 2326，事件用箭头标记）：sched_wakeupsched_switchsched_wakeup

-->[15:22:39.515333895] (+0.000001956) usr-VirtualBox sched_switch: { cpu_id = 1 }, { vtid = 2342, procname = "test" }, { prev_comm = "test", prev_tid = 2342, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2326, next_prio = -11 }
   [15:22:39.515374982] (+0.000001397) usr-VirtualBox sched_switch: { cpu_id = 0 }, { vtid = 2323, procname = "test" }, { prev_comm = "test", prev_tid = 2323, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2328, next_prio = -11 }
   [15:22:39.515376100] (+0.000001118) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 1 }, { vtid = 2326, procname = "test" }, { rqtp = 140003026402816 }
   [15:22:39.515378336] (+0.000002236) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 0 }, { vtid = 2328, procname = "test" }, { ret = 0, rmtp = 140003009617392 }
-->[15:22:39.515413833] (+0.000003074) usr-VirtualBox sched_wakeup: { cpu_id = 1 }, { vtid = 2326, procname = "test" }, { comm = "test", tid = 2326, prio = -11, target_cpu = 1 }
   [15:22:39.515418026] (+0.000002516) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 0 }, { vtid = 2328, procname = "test" }, { rqtp = 140003009617408 }
   [15:22:39.515425293] (+0.000007267) usr-VirtualBox sched_switch: { cpu_id = 0 }, { vtid = 2328, procname = "test" }, { prev_comm = "test", prev_tid = 2328, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2334, next_prio = -11 }
   [15:22:39.515428088] (+0.000002795) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 0 }, { vtid = 2334, procname = "test" }, { ret = 0, rmtp = 140002959261168 }
   [15:22:39.515428647] (+0.000000559) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 1 }, { vtid = 2326, procname = "test" }, { ret = 0, rmtp = 140003026402800 }
   [15:22:39.515468616] (+0.000000838) usr-VirtualBox sched_wakeup: { cpu_id = 0 }, { vtid = 2334, procname = "test" }, { comm = "test", tid = 2336, prio = -11, target_cpu = 0 }
   [15:22:39.515475045] (+0.000002516) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 1 }, { vtid = 2326, procname = "test" }, { rqtp = 140003026402816 }
   [15:22:39.515482592] (+0.000007547) usr-VirtualBox syscall_entry_clock_gettime: { cpu_id = 0 }, { vtid = 2334, procname = "test" }, { which_clock = 1 }
-->[15:22:39.515483430] (+0.000000838) usr-VirtualBox sched_switch: { cpu_id = 1 }, { vtid = 2326, procname = "test" }, { prev_comm = "test", prev_tid = 2326, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2325, next_prio = -11 }

有谁知道这个唤醒是做什么的？我需要提供更多信息吗？

编辑：添加附加信息以及包含更多事件的新日志。

线程 2348 使用SCHED_RR优先级 10 进行调度。RR 的时间片是默认值（我认为是 100 毫秒）。该系统在设计时为了测试而严重超载，RT-scheduler总共运行了 53 个线程，全部调度使用SCHED_RR。

   [09:11:06.284125458] (+0.000001957) usr-VirtualBox sched_waking: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { comm = "test", tid = 2348, prio = -11, target_cpu = 0 }
   [09:11:06.284130489] (+0.000001957) usr-VirtualBox sched_wakeup: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { comm = "test", tid = 2348, prio = -11, target_cpu = 0 }
   [09:11:06.284133004] (+0.000002515) usr-VirtualBox timer_hrtimer_expire_exit: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88 }
   [09:11:06.284203160] (+0.000003354) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { rqtp = 140046423100928 }
   [09:11:06.284206234] (+0.000003074) usr-VirtualBox timer_hrtimer_init: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88, clockid = 1, mode = 1 }
   [09:11:06.284210707] (+0.000004473) usr-VirtualBox timer_hrtimer_start: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88, function = 0xFFFFFFFF810EED30, expires = 91708656312, softexpires = 91708656312 }
   [09:11:06.284225800] (+0.000011460) usr-VirtualBox sched_switch: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { prev_comm = "test", prev_tid = 2347, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2348, next_prio = -11 }
   [09:11:06.284270241] (+0.000002516) usr-VirtualBox timer_hrtimer_cancel: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88 }
   [09:11:06.284273036] (+0.000000279) usr-VirtualBox timer_hrtimer_expire_entry: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88, now = 91708703021, function = 0xFFFFFFFF810EED30 }
   [09:11:06.284276390] (+0.000000838) usr-VirtualBox sched_waking: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { comm = "test", tid = 2347, prio = -11, target_cpu = 0 }
   [09:11:06.284281421] (+0.000005031) usr-VirtualBox sched_wakeup: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { comm = "test", tid = 2347, prio = -11, target_cpu = 0 }
   [09:11:06.284285334] (+0.000003913) usr-VirtualBox timer_hrtimer_expire_exit: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88 }
   [09:11:06.284299310] (+0.000002796) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { ret = 0, rmtp = 140046414708208 }
   [09:11:06.284365832] (+0.000002516) usr-VirtualBox timer_hrtimer_cancel: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF88001969BE88 }
   [09:11:06.284369745] (+0.000003075) usr-VirtualBox timer_hrtimer_expire_entry: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF88001969BE88, now = 91708799171, function = 0xFFFFFFFF810EED30 }
   [09:11:06.284372260] (+0.000000559) usr-VirtualBox sched_waking: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { comm = "test", tid = 2319, prio = -11, target_cpu = 0 }
   [09:11:06.284375055] (+0.000000559) usr-VirtualBox sched_wakeup: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { comm = "test", tid = 2319, prio = -11, target_cpu = 0 }
   [09:11:06.284385956] (+0.000010901) usr-VirtualBox timer_hrtimer_expire_exit: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF88001969BE88 }
   [09:11:06.284406360] (+0.000001118) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { rqtp = 140046414708224 }
   [09:11:06.284408875] (+0.000000838) usr-VirtualBox timer_hrtimer_init: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, clockid = 1, mode = 1 }
   [09:11:06.284413627] (+0.000004752) usr-VirtualBox timer_hrtimer_start: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, function = 0xFFFFFFFF810EED30, expires = 91708869016, softexpires = 91708869016 }
   [09:11:06.284431795] (+0.000003634) usr-VirtualBox sched_switch: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { prev_comm = "test", prev_tid = 2348, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2347, next_prio = -11 }
   [09:11:06.284437105] (+0.000002795) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { ret = 0, rmtp = 140046423100912 }
   [09:11:06.284456950] (+0.000019845) usr-VirtualBox timer_hrtimer_cancel: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88 }
   [09:11:06.284459745] (+0.000001956) usr-VirtualBox timer_hrtimer_expire_entry: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, now = 91708890569, function = 0xFFFFFFFF810EED30 }
   [09:11:06.284462540] (+0.000001956) usr-VirtualBox sched_waking: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { comm = "test", tid = 2348, prio = -11, target_cpu = 0 }
   [09:11:06.284467292] (+0.000003913) usr-VirtualBox sched_wakeup: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { comm = "test", tid = 2348, prio = -11, target_cpu = 0 }
   [09:11:06.284470087] (+0.000001957) usr-VirtualBox timer_hrtimer_expire_exit: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88 }
   [09:11:06.284535212] (+0.000001118) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { rqtp = 140046423100928 }
   [09:11:06.284537727] (+0.000000838) usr-VirtualBox timer_hrtimer_init: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88, clockid = 1, mode = 1 }
   [09:11:06.284542479] (+0.000004752) usr-VirtualBox timer_hrtimer_start: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88, function = 0xFFFFFFFF810EED30, expires = 91708993675, softexpires = 91708993675 }
   [09:11:06.284559528] (+0.000002795) usr-VirtualBox sched_switch: { cpu_id = 0 }, { vtid = 2347, procname = "test" }, { prev_comm = "test", prev_tid = 2347, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2319, next_prio = -11 }
   [09:11:06.284579094] (+0.000002236) usr-VirtualBox timer_hrtimer_cancel: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88 }
   [09:11:06.284582727] (+0.000003354) usr-VirtualBox timer_hrtimer_expire_entry: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88, now = 91709012433, function = 0xFFFFFFFF810EED30 }
   [09:11:06.284585243] (+0.000000559) usr-VirtualBox sched_waking: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { comm = "test", tid = 2347, prio = -11, target_cpu = 0 }
   [09:11:06.284590833] (+0.000000559) usr-VirtualBox sched_wakeup: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { comm = "test", tid = 2347, prio = -11, target_cpu = 0 }
   [09:11:06.284593628] (+0.000002795) usr-VirtualBox timer_hrtimer_expire_exit: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { hrtimer = 0xFFFF8800256E7E88 }
   [09:11:06.284607324] (+0.000003075) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { ret = 0, rmtp = 140046658096624 }
   [09:11:06.284649529] (+0.000001956) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { rqtp = 140046658096640 }
   [09:11:06.284652045] (+0.000002516) usr-VirtualBox timer_hrtimer_init: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { hrtimer = 0xFFFF88001969BE88, clockid = 1, mode = 1 }
   [09:11:06.284656796] (+0.000001118) usr-VirtualBox timer_hrtimer_start: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { hrtimer = 0xFFFF88001969BE88, function = 0xFFFFFFFF810EED30, expires = 91709780826, softexpires = 91709780826 }
-->[09:11:06.284673007] (+0.000001118) usr-VirtualBox sched_switch: { cpu_id = 0 }, { vtid = 2319, procname = "test" }, { prev_comm = "test", prev_tid = 2319, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2348, next_prio = -11 }
   [09:11:06.284678318] (+0.000003634) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { ret = 0, rmtp = 140046414708208 }
   [09:11:06.284746238] (+0.000002516) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { rqtp = 140046414708224 }
   [09:11:06.284749033] (+0.000001398) usr-VirtualBox timer_hrtimer_init: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, clockid = 1, mode = 1 }
   [09:11:06.284753784] (+0.000001397) usr-VirtualBox timer_hrtimer_start: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, function = 0xFFFFFFFF810EED30, expires = 91709190725, softexpires = 91709190725 }
   [09:11:06.284800182] (+0.000036615) usr-VirtualBox timer_hrtimer_cancel: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88 }
   [09:11:06.284803257] (+0.000002795) usr-VirtualBox timer_hrtimer_expire_entry: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, now = 91709233521, function = 0xFFFFFFFF810EED30 }
   [09:11:06.284806331] (+0.000002236) usr-VirtualBox sched_waking: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { comm = "test", tid = 2348, prio = -11, target_cpu = 0 }
-->[09:11:06.284811921] (+0.000005031) usr-VirtualBox sched_wakeup: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { comm = "test", tid = 2348, prio = -11, target_cpu = 0 }
   [09:11:06.284814996] (+0.000002516) usr-VirtualBox timer_hrtimer_expire_exit: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88 }
   [09:11:06.284834282] (+0.000019007) usr-VirtualBox syscall_exit_nanosleep: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { ret = 0, rmtp = 140046414708208 }
   [09:11:06.284885990] (+0.000002515) usr-VirtualBox syscall_entry_nanosleep: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { rqtp = 140046414708224 }
   [09:11:06.284888506] (+0.000002236) usr-VirtualBox timer_hrtimer_init: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, clockid = 1, mode = 1 }
   [09:11:06.284893537] (+0.000004752) usr-VirtualBox timer_hrtimer_start: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { hrtimer = 0xFFFF8800256EFE88, function = 0xFFFFFFFF810EED30, expires = 91709347527, softexpires = 91709347527 }
-->[09:11:06.284915338] (+0.000021522) usr-VirtualBox sched_switch: { cpu_id = 0 }, { vtid = 2348, procname = "test" }, { prev_comm = "test", prev_tid = 2348, prev_prio = -11, prev_state = 1, next_comm = "test", next_tid = 2347, next_prio = -11 }
4

1 回答 1

0

不知道为什么 2326 线程在进入 nanosleep 后没有被调度出来（也许你有一些 RT 配置），但由于它正在休眠，所以可能会唤醒它。

您可以启用 sched_waking（确切知道什么是唤醒器）和 hrtimer 事件以获取更多信息。

于 2016-05-05T13:24:11.837 回答