[shutdown] Total frames 日志在退出时打印两次 #22

Closed
opened 2026-06-13 23:05:44 +08:00 by dailz · 1 comment
Owner

现象

会话末尾:

14:49:54.527990  INFO  Total: 5429 frames in 119.4s, avg 45.5fps
14:49:54.527990  INFO  StatePortal shutdown complete
14:49:54.528013  INFO  Total: 5429 frames in 119.4s, avg 45.5fps   ← 重复
14:49:54.528017  INFO  StatePortal shutdown complete                ← 也重复

两次打印间隔 23 µs。

根因(怀疑)

StatePortal 同时:

  1. 在显式 shutdown 路径调用了打印(StatePortal shutdown complete 上方)
  2. Drop trait 实现里又调用了一遍

两路径未做幂等保护。

影响

  • 日志噪音,无功能影响
  • 若有人写脚本解析 Total: N frames 行会双计

修复方向

  • AtomicBoolOnceCell 标记 shutdown 已打印
  • 或删除显式调用,只走 Drop
  • 或删除 Drop 内打印,只保留显式

复现

wl-webrtc --port 56666 -v &
sleep 5
kill -INT %1
# 看末尾日志
## 现象 会话末尾: ``` 14:49:54.527990 INFO Total: 5429 frames in 119.4s, avg 45.5fps 14:49:54.527990 INFO StatePortal shutdown complete 14:49:54.528013 INFO Total: 5429 frames in 119.4s, avg 45.5fps ← 重复 14:49:54.528017 INFO StatePortal shutdown complete ← 也重复 ``` 两次打印间隔 23 µs。 ## 根因(怀疑) `StatePortal` 同时: 1. 在显式 shutdown 路径调用了打印(`StatePortal shutdown complete` 上方) 2. 在 `Drop` trait 实现里又调用了一遍 两路径未做幂等保护。 ## 影响 - 日志噪音,无功能影响 - 若有人写脚本解析 `Total: N frames` 行会双计 ## 修复方向 - 用 `AtomicBool` 或 `OnceCell` 标记 shutdown 已打印 - 或删除显式调用,只走 Drop - 或删除 Drop 内打印,只保留显式 ## 复现 ```bash wl-webrtc --port 56666 -v & sleep 5 kill -INT %1 # 看末尾日志 ```
dailz added the priority/lowarea/observabilitytype/bug labels 2026-06-13 23:05:44 +08:00
Author
Owner

修复已合并

Commit: 92760dd fix(state_portal): make shutdown() idempotent to prevent duplicate log lines (#22)

根因(代码审计 + Oracle 二次审核确认)

main.rs:370 显式调用 state.shutdown()state 出函数作用域 → Drop::drop() 再次调用 self.shutdown()。两条路径都进入 shutdown() 末尾的日志输出,但内部 .take() 已经把 enc_thread/webrtc_thread/enc 清空,所以重复的只是两条 INFO 日志,没有重复的资源清理或线程 join。

修复

src/state_portal.rsshutdown_started: bool 守卫,函数入口短路:

pub fn shutdown(&mut self) {
    if self.shutdown_started {
        return;
    }
    self.shutdown_started = true;
    // ... 原清理逻辑
}

关键设计决策(Oracle review 修正):

  • bool 而非 AtomicBool——shutdown(&mut self)&mut self 已提供独占访问
  • 守卫在清理之前置位——防止清理 panic 时 Drop 重入造成双重 unwinding
  • 保留 main.rs 显式调用(保证 "Done" 日志在清理之后)+ 保留 Drop 作为安全网

验证

scripts/test_shutdown_idempotency.sh 在 KWin Wayland 会话实测 PASS:

"Total: N frames in ...":        1 occurrence(s) (expected 1)
"StatePortal shutdown complete": 1 occurrence(s) (expected 1)
PASS: shutdown is idempotent (issue #22 fixed)

完整关闭序列(无重复):

INFO Shutting down...
INFO Encode thread input closed, flushing encoder
INFO Encode thread exiting
[libx264] final ratefactor: 28.26
INFO WebRTC channel disconnected, exiting thread
INFO Total: 104 frames in 2.9s, avg 36.2fps
INFO StatePortal shutdown complete
INFO Done

关闭本 issue。

## 修复已合并 **Commit**: `92760dd` fix(state_portal): make shutdown() idempotent to prevent duplicate log lines (#22) ### 根因(代码审计 + Oracle 二次审核确认) `main.rs:370` 显式调用 `state.shutdown()` → `state` 出函数作用域 → `Drop::drop()` 再次调用 `self.shutdown()`。两条路径都进入 `shutdown()` 末尾的日志输出,但内部 `.take()` 已经把 `enc_thread`/`webrtc_thread`/`enc` 清空,所以**重复的只是两条 INFO 日志**,没有重复的资源清理或线程 join。 ### 修复 `src/state_portal.rs` 加 `shutdown_started: bool` 守卫,函数入口短路: ```rust pub fn shutdown(&mut self) { if self.shutdown_started { return; } self.shutdown_started = true; // ... 原清理逻辑 } ``` **关键设计决策**(Oracle review 修正): - 用 `bool` 而非 `AtomicBool`——`shutdown(&mut self)` 的 `&mut self` 已提供独占访问 - 守卫在清理**之前**置位——防止清理 panic 时 `Drop` 重入造成双重 unwinding - 保留 main.rs 显式调用(保证 `"Done"` 日志在清理之后)+ 保留 Drop 作为安全网 ### 验证 `scripts/test_shutdown_idempotency.sh` 在 KWin Wayland 会话实测 PASS: ``` "Total: N frames in ...": 1 occurrence(s) (expected 1) "StatePortal shutdown complete": 1 occurrence(s) (expected 1) PASS: shutdown is idempotent (issue #22 fixed) ``` 完整关闭序列(无重复): ``` INFO Shutting down... INFO Encode thread input closed, flushing encoder INFO Encode thread exiting [libx264] final ratefactor: 28.26 INFO WebRTC channel disconnected, exiting thread INFO Total: 104 frames in 2.9s, avg 36.2fps INFO StatePortal shutdown complete INFO Done ``` 关闭本 issue。
dailz closed this issue 2026-06-20 18:48:12 +08:00
Sign in to join this conversation.