BiteTheDDDDt opened a new pull request, #62258:
URL: https://github.com/apache/doris/pull/62258
ScannerCpuTime 142小时 Bug 来龙去脉
一、Bug 现象
Profile 中 ScannerCpuTime 报出 142 小时 55 分钟，远超正常值。
二、根本原因
ScannerScheduler::submit() 在调度线程上调用 scanner->pause()，而 pause() 内部的
_update_scan_cpu_timer() 会读取 ThreadCpuStopWatch（基于
CLOCK_THREAD_CPUTIME_ID）。该时钟是线程私有的——每个线程有自己独立的 CPU 时间计数器。但
_cpu_watch 是在线程池工作线程上通过 resume() 启动的，因此 submit() 中跨线程对比两个不同线程的 CPU
时钟，产生了毫无意义的巨大数值并累加进 _scan_cpu_timer。
三、演化历史（共 4 个阶段）
阶段 1：原始代码（2026年2月前）✅ 正确
submit(): scanner->start_wait_worker_timer() // 只启动等待计时器
_scanner_scan(): Defer { update_scan_cpu_timer();
update_realtime_counters(); start_wait_worker_timer(); }
- submit() 只碰等待计时器，不碰 CPU 计时器
- Defer 保证每轮（无论 eos 还是 non-eos）都在同一线程更新 CPU 计时器
阶段 2：b01fef51ed3 (#60615) — 2026.02.11 ✅ 仍然正确
"extract scanner profile update logic and update on eos"
- 将 Defer 中的逻辑提取成 update_scanner_profile lambda
- Defer 仍然无条件调用 update_scanner_profile()
- 只是重构，行为不变
阶段 3：d070e9ef6ca (#61064) — 2026.03.13 ⚠️ 埋下隐患
"fix wrong count of scan wait worker timer"
- 从 Defer 中移除了 update_scanner_profile()
- Defer 改为仅在 status.ok() && !eos 时调用 start_wait_worker_timer()
- update_scanner_profile() 仅在 eos 路径中显式调用
- 后果：非 eos 轮次的 CPU 时间不再被记录（under-counting），但因为 submit() 仍只调用
start_wait_worker_timer()，没有跨线程问题
阶段 4：92f75f3d356 (#61271) — 2026.04.01 ❌ Bug 引入
"Global mem control on scan nodes"
关键改动：
1. 将 start_wait_worker_timer() / update_scan_cpu_timer() 等 public 方法打包为
pause() 和 resume()，并改为 private
2. submit() 中将 start_wait_worker_timer() 替换为 scanner->pause() —
这导致在调度线程上调用了 _update_scan_cpu_timer()（跨线程读 CLOCK_THREAD_CPUTIME_ID）
3. 完全删除了 Defer
4. update_scanner_profile() 仅在 eos 路径调用
- scanner_delegate->_scanner->start_wait_worker_timer(); // 只碰等待计时器
+ scanner_delegate->_scanner->pause(); // 同时碰了 CPU 计时器！跨线程！
四、Bug 触发机制
Thread Pool (线程A) Scheduler (线程B)
───────────────── ──────────────────
resume() →
_start = 线程A的CPU时钟
做扫描工作...
[non-eos, 不调 pause()]
submit() → pause() →
_cpu_watch.elapsed_time():
end = 线程B的CPU时钟
_start = 线程A的CPU时钟
差值 = 垃圾值（可能数小时）
_scan_cpu_timer += 垃圾值 💥
每次非 eos 轮次的 re-submit 都会累加一个垃圾值。Scanner 被调度次数越多，累加的垃圾值越大。
五、修复方案
1. 新增 Scanner::start_queue_wait() — 仅启动等待计时器，不碰 CPU 计时器
2. submit() 改用 start_queue_wait() 替换 pause()
3. _scanner_scan() 末尾无条件调用 update_scanner_profile()（eos 和 non-eos 都调），确保
CPU 计时器始终在同一线程上 start/stop
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
