diff --git a/README.md b/README.md index 7508565..553b75c 100644 --- a/README.md +++ b/README.md @@ -9,20 +9,42 @@ OpenDance Studio **阶段三**: Android 辅助 App(Kotlin + CameraX + MediaPipe ## 状态 -**阶段三已完成**: T-AND-001 -> T-AND-016 全部落地（含重连状态机与**真实 WebSocket 重连链路测试**、MediaPipe 崩溃修复、APK 产物版本元数据校验、native 库体检）。 +**阶段三已完成**: T-AND-001 -> T-AND-017 全部落地（含重连状态机与**真实 WebSocket 重连链路测试**、MediaPipe 崩溃修复、APK 产物版本元数据校验、native 库体检）。 | 验收项 | 结果 | |--|--| -| 单元测试 | OK **64 项全部通过**(JVM，无需设备；含 MockWebServer 真实 WebSocket 的重连链路集成测试) | +| 单元测试 | OK **68 项全部通过**(JVM，无需设备；含 MockWebServer 真实 WebSocket 的重连链路集成测试) | | **跨端金标准** | OK Kotlin 序列化器与 Web 端 TypeScript 实现**逐位一致** | | `./gradlew assembleRelease` | OK 生成**已签名** APK(28.6 MB) | | 签名校验 | OK `apksigner` 退出码 0, v2 方案，CN=OpenDance Studio Dev | -| 包信息 | OK `com.opendance.studio` v0.2.1 (versionCode 201), minSdk 29(Android 10+)/ targetSdk 34 | +| 包信息 | OK `com.opendance.studio` v0.2.2 (versionCode 202), minSdk 29(Android 10+)/ targetSdk 34 | | 模型随包分发 | OK `assets/pose_landmarker_lite.task` 5.7 MB(Stored 未压缩) | | ABI 覆盖 | OK arm64-v8a + armeabi-v7a(debug 额外含 x86/x86_64) | -| APK 版本元数据 | OK 直接读产物 `AndroidManifest` 的 `versionName=0.2.1`/`versionCode=201`，与 `project.yaml` 一致（T-AND-013） | +| APK 版本元数据 | OK 直接读产物 `AndroidManifest` 的 `versionName=0.2.2`/`versionCode=202`，与 `project.yaml` 一致（T-AND-013） | | native 库体检 | OK ELF 类型匹配双 ABI、`DT_NEEDED` 闭包完整（无缺失依赖）、`PT_LOAD` 页对齐 `0x4000`（16 KB 页兼容）、`zipalign -P 16` 通过（T-AND-015） | +## v0.2.2 修订（退避封顶端到端验证 + 修「合规接收端被周期性误判链路已死」） + +**缺陷（T-AND-017）**：契约 §3.6 明确「接收端收到任何一帧都算活动，`ping` **无需额外应答** +即可保活，`pong` 只用于诊断」—— 即"合规但不回 `pong`"的接收端是**合法**的。 +但 `onOpen` 里写的是 `lastPongAtMs = now`，于是心跳循环的守卫 +`if (lastPongAtMs > 0 && silentFor > limit)` **恒为真**：对任何接收端都会 +「判定链路已死 → 主动断链 → 重连」，默认参数下**每 15 秒一次** —— 正是"频繁重连"的症状。 +**为什么以前没暴露**：我们自己的 Windows 接收端**会**回 `pong`，这条路径在自家联调里走不到。 +**修复**：`onOpen` 复位 `lastPongAtMs = 0L`（0 = 本连接还没收到过 pong）， +只有"曾经回过 pong、之后又不回了"才判定链路已死。 + +**新增可注入计时 `Timing`**（时钟 + 等待，生产默认与原来完全一致）： +契约 §7.1 的退避序列真实等待约 30 秒，写在测试里既慢又易 flaky。 +注入可控时钟后，`PoseWebSocketBackoffTest`（4 项，无需设备）可以在**毫秒级**断言 +`0.5→1→2→4→8→15→15s`（各 ±20% 抖动区间）并确认没有真实等待； +另有两条用例分别锁住「合规不回 pong **不**被误判」与「回过 pong 后停止回复仍能正确诊断」。 + +``` +$ ./gradlew :app:testDebugUnitTest +测试类 7 个，用例 68 项，失败 0 # 原 64 项 +``` + ## v0.2.1 修订（重连链路的真实 WebSocket 集成测试 + 一处真实缺陷） **缺陷**：上一次会话的关闭码会**污染下一次会话**，导致重新开始推流后失去自动重连能力。 @@ -295,7 +317,7 @@ python3 build/check_native_libs.py dist-release/opendance-android-v0.2.1/app-rel 而用户装的是 zip 里的 `app-release.apk`。发布前对包再跑一次： ```bash -bash build/accept-release.sh dist-release/opendance-android-v0.2.1.zip +bash build/accept-release.sh dist-release/opendance-android-v0.2.2.zip # -> sha256 / 文件清单 / AndroidManifest versionName+versionCode / ABI+MediaPipe native # / 模型资源 / dex 中的 PoseLandmarker / 验签 / 包内契约快照与仓库一致 # -> 发布包级验收全部通过 diff --git a/README.txt b/README.txt index f746b53..28d6053 100644 --- a/README.txt +++ b/README.txt @@ -1,5 +1,5 @@ ================================================================ -OpenDance Studio -- Android 辅助 App v0.2.1 使用说明 +OpenDance Studio -- Android 辅助 App v0.2.2 使用说明 ================================================================ 手机端姿态采集器：用摄像头做端侧姿态推理，把 33 个骨骼关键点通过 @@ -125,6 +125,21 @@ WebSocket 推送给 Windows 客户端，由后者驱动 VRM 角色并实时评 App 运行页 「人体识别」为「已识别」，出现骨架叠加（黄点好、红点置信度低） Windows 端 显示已连接并收到关键点，VRM 模型随动作实时动起来 +6.5) v0.2.2 修订 + + 1. 修一处真实缺陷（T-AND-017）: 契约 §3.6 明确「ping 无需额外应答即可保活， + pong 只用于诊断」，即"合规但不回 pong"的接收端是合法的；但客户端的 + onOpen 里把 lastPongAtMs 设成了当前时刻，于是"连续 3 个心跳周期没收到 pong + 就判定链路已死"对任何接收端都会触发 —— 默认参数下每 15 秒主动断一次并重连， + 正是"频繁重连"的症状。现改为 0（= 本连接还没收到过 pong）， + 只有"曾经回过 pong、之后又不回了"才判定链路已死。 + 2. 新增可注入计时 Timing（时钟 + 等待），生产默认与原来完全一致； + 测试注入可控时钟后，契约 §7.1 的退避序列（0.5→1→2→4→8→15s 封顶）能在 + 毫秒级端到端验证，不再需要等 30 秒。 + 3. 新增 4 项 JVM 用例（无需设备）：退避封顶序列逐值断言、注入实现不产生真实等待、 + 合规不回 pong 不被误判、回过 pong 后停止回复仍能正确诊断。 + 4. 单元测试 68 项（原 64）。 + 6.5) v0.2.1 修订 1. 重连链路的真实 WebSocket 集成测试（T-AND-016）: 用 MockWebServer 的 @@ -157,7 +172,7 @@ WebSocket 推送给 Windows 客户端，由后者驱动 VRM 角色并实时评 依赖闭包（DT_NEEDED，非系统库必须同 ABI 自带）、页对齐（16 KB 兼容）。 0) 发布包级验收（对**发布包**而不是本地构建；文档 §7.5） - bash build/accept-release.sh dist-release/opendance-android-v0.2.1.zip + bash build/accept-release.sh dist-release/opendance-android-v0.2.2.zip 预期末行「发布包级验收全部通过」。它会校验 sha256、解压、核对文件清单、 读包内 APK 的 AndroidManifest 版本元数据、核对 ABI 与 MediaPipe native 库、 模型资源、dex 里的 PoseLandmarker、验签，以及包内契约快照与仓库是否一致。 diff --git a/app/build.gradle.kts b/app/build.gradle.kts index 21e5ef0..9ed859d 100644 --- a/app/build.gradle.kts +++ b/app/build.gradle.kts @@ -28,8 +28,8 @@ android { targetSdk = 34 // 文档 §11.1：versionCode 用整数按 10000*主 + 100*次 + 修订 递增， // versionName 用 X.Y.Z，两者同一次发布一起更新。 - versionCode = 201 - versionName = "0.2.1" + versionCode = 202 + versionName = "0.2.2" testInstrumentationRunner = "androidx.test.runner.AndroidJUnitRunner" buildConfigField("String", "WS_SUBPROTOCOL", "\"opendance.pose.v1\"") diff --git a/app/src/main/java/com/opendance/studio/net/PoseWebSocketClient.kt b/app/src/main/java/com/opendance/studio/net/PoseWebSocketClient.kt index bc749e2..6350c7f 100644 --- a/app/src/main/java/com/opendance/studio/net/PoseWebSocketClient.kt +++ b/app/src/main/java/com/opendance/studio/net/PoseWebSocketClient.kt @@ -47,9 +47,35 @@ import kotlin.random.Random * 5. **可诊断**：close code / 子协议协商结果 / 首帧时间写入 [ConnectionLog]， * 界面可一键导出。 */ +/** + * 计时与等待的可注入实现（T-AND-017）。 + * + * 为什么需要：[契约 §7.1](../contracts/websocket-keypoints.md) 的退避序列 + * `0.5s→1→2→4→8→15s 封顶` 若要**端到端**验证，真实等待需要 ~30 秒； + * 而"缺 pong 判定链路已死"（连续 3 个心跳周期）也要等几十秒。 + * 把「现在几点」与「等多久」抽出来之后，测试可以注入可控时钟 + 立即返回的等待， + * 在毫秒级把这两条路径跑完整 —— 否则这类逻辑只能靠纯函数单测或真机观察。 + * + * 生产实现就是 [SystemTiming]（真实 `System.currentTimeMillis()` + `delay()`）， + * 行为与抽取前完全一致。 + */ +interface Timing { + fun nowMs(): Long + suspend fun await(delayMs: Long) +} + +object SystemTiming : Timing { + override fun nowMs(): Long = System.currentTimeMillis() + override suspend fun await(delayMs: Long) { + delay(delayMs) + } +} + class PoseWebSocketClient( private val scope: CoroutineScope, private val subprotocol: String = BuildConfig.WS_SUBPROTOCOL, + /** 计时/等待实现；测试注入可控时钟，生产用 [SystemTiming] */ + private val timing: Timing = SystemTiming, ) { /** 契约 §8 的连接状态（wireName 与接收端 GDScript 侧同名，便于对照日志） */ @@ -227,7 +253,14 @@ class PoseWebSocketClient( reconnectCounter.set(0) fpsWindowStart = 0L fpsWindowFrames = 0 - lastPongAtMs = System.currentTimeMillis() + // **0 = 本连接还没收到过任何 pong**。 + // 契约 §3.6 明确：接收端收到任何一帧都算活动，`ping` **无需额外应答**即可保活， + // `pong` 只用于诊断 —— 也就是说"合规但不回 pong"的接收端是合法的。 + // 原先这里写成 `lastPongAtMs = now`，于是下面的"连续 3 个心跳周期没收到 pong + // 就判定链路已死"对**任何**接收端都会触发：15 秒重连一次，正是"频繁重连"的症状。 + // 现在只有"曾经回过 pong、之后又不回了"才会判定链路已死（由 T-AND-017 的 + // JVM 集成测试两条对应用例锁住）。 + lastPongAtMs = 0L _stats.value = _stats.value.copy( state = State.HANDSHAKING, url = url, @@ -289,7 +322,7 @@ class PoseWebSocketClient( _stats.value = _stats.value.copy( lastCloseCode = code, lastCloseReason = reason, - lastDisconnectAtMs = System.currentTimeMillis(), + lastDisconnectAtMs = timing.nowMs(), ) ConnectionLog.record("断开：${ReconnectPolicy.closeCodeLabel(code)}") } @@ -312,7 +345,7 @@ class PoseWebSocketClient( ConnectionLog.record("安排第 $attempt 次重连，等待 ${delayMs}ms") reconnectJob = scope.launch { - delay(delayMs) + timing.await(delayMs) if (!manualClose && autoReconnect) { openSocket(initial = false) } @@ -350,13 +383,13 @@ class PoseWebSocketClient( val interval = _stats.value.heartbeatIntervalMs.coerceAtLeast( ReconnectPolicy.MIN_HEARTBEAT_MS, ) - delay(interval) + timing.await(interval) val state = _stats.value.state if (state != State.STREAMING && state != State.DEGRADED && state != State.HANDSHAKING) { continue } sendPing() - val silentFor = System.currentTimeMillis() - lastPongAtMs + val silentFor = timing.nowMs() - lastPongAtMs val limit = interval * ReconnectPolicy.MISSED_PONG_LIMIT if (lastPongAtMs > 0 && silentFor > limit) { ConnectionLog.record( @@ -379,7 +412,7 @@ class PoseWebSocketClient( sendJson( JSONObject().apply { put("type", "ping") - put("sentAtMs", System.currentTimeMillis()) + put("sentAtMs", timing.nowMs()) }, ) } @@ -416,7 +449,7 @@ class PoseWebSocketClient( sentCounter.incrementAndGet() if (_stats.value.firstFrameAtMs == 0L) { - val now = System.currentTimeMillis() + val now = timing.nowMs() _stats.value = _stats.value.copy(firstFrameAtMs = now) ConnectionLog.record("streaming：首帧已发出") } @@ -425,7 +458,7 @@ class PoseWebSocketClient( } fpsWindowFrames++ - val now = System.currentTimeMillis() + val now = timing.nowMs() if (fpsWindowStart == 0L) fpsWindowStart = now val elapsed = now - fpsWindowStart val fps = if (elapsed >= FPS_WINDOW_MS) { @@ -547,10 +580,10 @@ class PoseWebSocketClient( onRemoteConfig?.invoke(json) } "pong" -> { - lastPongAtMs = System.currentTimeMillis() + lastPongAtMs = timing.nowMs() pongCounter.incrementAndGet() val sentAt = json.optLong("sentAtMs", 0L) - val rtt = if (sentAt > 0) System.currentTimeMillis() - sentAt else -1L + val rtt = if (sentAt > 0) timing.nowMs() - sentAt else -1L if (rtt >= 0) { _stats.value = _stats.value.copy( roundTripMs = rtt, diff --git a/app/src/test/java/com/opendance/studio/PoseWebSocketBackoffTest.kt b/app/src/test/java/com/opendance/studio/PoseWebSocketBackoffTest.kt new file mode 100644 index 0000000..032eb6f --- /dev/null +++ b/app/src/test/java/com/opendance/studio/PoseWebSocketBackoffTest.kt @@ -0,0 +1,231 @@ +package com.opendance.studio + +import com.opendance.studio.net.PoseWebSocketClient +import com.opendance.studio.net.ReconnectPolicy +import com.opendance.studio.net.Timing +import com.opendance.studio.util.ConnectionLog +import kotlinx.coroutines.CoroutineScope +import kotlinx.coroutines.Dispatchers +import kotlinx.coroutines.SupervisorJob +import kotlinx.coroutines.cancel +import okhttp3.Response +import okhttp3.WebSocket +import okhttp3.WebSocketListener +import okhttp3.mockwebserver.MockResponse +import okhttp3.mockwebserver.MockWebServer +import okhttp3.mockwebserver.SocketPolicy +import org.junit.After +import org.junit.Assert.assertEquals +import org.junit.Assert.assertTrue +import org.junit.Before +import org.junit.Test +import org.junit.runner.RunWith +import org.robolectric.RobolectricTestRunner +import org.robolectric.annotation.Config +import java.util.Collections +import java.util.concurrent.atomic.AtomicInteger + +/** + * T-AND-017：**退避封顶**与**缺 pong 判定链路已死**的端到端验证（JVM，无需设备） + * + * 为什么单有 `ReconnectPolicyTest` 不够：`ReconnectPolicy` 只是纯函数 + * 「第 n 次应该等多久」，而契约 §7.1 真正承诺的是**整条序列** + * `0.5s → 1 → 2 → 4 → 8 → 15s 封顶`（之后一直是 15s）—— + * 那需要连续 7 次失败重连，真实等待约 **30 秒**，写在集成测试里既慢又易 flaky。 + * + * 因此给 [PoseWebSocketClient] 抽了一个可注入的 [Timing] + * （「现在几点」+「等多久」）。生产默认是真实时钟与 `delay()`，行为不变； + * 测试注入**可控时钟 + 立即返回的等待**，于是： + * * 30 秒的退避序列可以在毫秒级跑完并逐值断言； + * * 「连续 3 个心跳周期没收到 pong 就判定链路已死」也能在不等待的情况下触发。 + */ +@RunWith(RobolectricTestRunner::class) +@Config(sdk = [34]) +class PoseWebSocketBackoffTest { + + /** 可控时钟 + 立即返回的等待：记录每次等待时长，并推进虚拟时钟 */ + private class FakeTiming : Timing { + var now = 1_000_000L + val awaited = Collections.synchronizedList(mutableListOf()) + + override fun nowMs(): Long = now + + override suspend fun await(delayMs: Long) { + awaited.add(delayMs) + now += delayMs.coerceAtLeast(1L) + // 只让出 2ms *真实*时间：网络回调（pong / welcome）需要有机会落地， + // 否则心跳循环会在 pong 到达之前就把虚拟时钟推过阈值。 + // 2ms × 个位数次数，整体仍远小于真实退避的 30 秒。 + kotlinx.coroutines.delay(2) + } + + fun snapshot(): List = synchronized(awaited) { awaited.toList() } + } + + private lateinit var server: MockWebServer + private lateinit var scope: CoroutineScope + private val clients = mutableListOf() + + @Before + fun setUp() { + ConnectionLog.clear() + server = MockWebServer() + server.start() + } + + @After + fun tearDown() { + clients.forEach { runCatching { it.disconnect() } } + scope.cancel() + runCatching { server.shutdown() } + ConnectionLog.clear() + } + + private fun newClient(timing: Timing): PoseWebSocketClient { + scope = CoroutineScope(SupervisorJob() + Dispatchers.IO) + return PoseWebSocketClient(scope, timing = timing).also { clients.add(it) } + } + + private fun wsUrl(): String = server.url("/pose").toString().replace("http://", "ws://") + + private fun waitUntil(timeoutMs: Long = 8_000, what: String, cond: () -> Boolean) { + val deadline = System.currentTimeMillis() + timeoutMs + while (System.currentTimeMillis() < deadline) { + if (cond()) return + Thread.sleep(10) + } + throw AssertionError("等待超时（${timeoutMs}ms）：$what") + } + + @Test + fun `退避序列在 15 秒封顶，且不会无限增长`() { + // 每个连接都直接失败：用 SocketPolicy.DISCONNECT_AT_START（升级前断开） + repeat(12) { + server.enqueue(MockResponse().setSocketPolicy(SocketPolicy.DISCONNECT_AT_START)) + } + val timing = FakeTiming() + val client = newClient(timing) + val t0 = System.currentTimeMillis() + client.connect(wsUrl()) + + // 等到第 8 次重连被安排（真实等待为 0，因为 FakeTiming 立即返回） + waitUntil(what = "安排到第 8 次重连") { client.stats.value.reconnectAttempts >= 8 } + val elapsed = System.currentTimeMillis() - t0 + + val delays = timing.snapshot() + assertTrue("应记录到至少 8 次等待（实际 ${delays.size}）", delays.size >= 8) + + // 契约 §7.1：min(500ms * 2^(n-1), 15000ms) × (1 ± 20%) + val expectedBase = listOf(500L, 1_000L, 2_000L, 4_000L, 8_000L, 15_000L, 15_000L, 15_000L) + for ((index, base) in expectedBase.withIndex()) { + val actual = delays[index] + val low = (base * (1 - ReconnectPolicy.JITTER_RATIO)).toLong() + val high = (base * (1 + ReconnectPolicy.JITTER_RATIO)).toLong() + assertTrue( + "第 ${index + 1} 次重连等待应落在 [$low, $high]（基础值 ${base}ms），实际 ${actual}ms", + actual in low..high, + ) + } + assertTrue( + "封顶后必须一直是 15000ms（不得增长）；实测前 8 次：$delays", + delays.take(8).drop(5).all { it in 12_000L..18_000L }, + ) + assertTrue( + "虚拟时钟应被推着走（证明等待走的是注入实现而非真实 delay）；" + + "真实耗时 ${elapsed}ms 应远小于 30 秒", + elapsed < 5_000, + ) + } + + @Test + fun `等待走注入实现——真实 delay 不会被调用（耗时对照）`() { + repeat(4) { server.enqueue(MockResponse().setSocketPolicy(SocketPolicy.DISCONNECT_AT_START)) } + val timing = FakeTiming() + val client = newClient(timing) + val t0 = System.currentTimeMillis() + client.connect(wsUrl()) + waitUntil(what = "安排到第 3 次重连") { client.stats.value.reconnectAttempts >= 3 } + val elapsed = System.currentTimeMillis() - t0 + // 真实退避前三次合计 3.5 秒；注入实现下应远小于 1 秒 + assertTrue("注入 FakeTiming 后不应真的等待（实测 ${elapsed}ms）", elapsed < 1_500) + // 注意：不要在瞬时重连下断言 stats.nextRetryMs —— 等待立即返回后， + // 客户端已经进入下一次尝试并把该字段清零，读取会与重连循环竞争（第一版就踩了）。 + // 等待时长本身由注入实现记录，是可靠的事实来源。 + assertTrue("注入实现应记录到等待（实际 ${timing.snapshot()}）", timing.snapshot().size >= 3) + } + + /** 造一个只回 welcome、pong 行为可配置的接收端 */ + private fun enqueueReceiver(replyToPings: (n: Int) -> Boolean) { + val pingCount = AtomicInteger(0) + server.enqueue( + MockResponse() + .setHeader("Sec-WebSocket-Protocol", "opendance.pose.v1") + .withWebSocketUpgrade(object : WebSocketListener() { + override fun onMessage(webSocket: WebSocket, text: String) { + when { + text.contains("\"hello\"") -> webSocket.send( + """{"type":"welcome","protocol":"opendance.pose.v1",""" + + """"sessionId":"s1","expectedFps":30,""" + + """"silentTimeoutMs":3000,"heartbeatIntervalMs":1000}""", + ) + text.contains("\"ping\"") -> { + if (replyToPings(pingCount.incrementAndGet())) { + webSocket.send("""{"type":"pong","sentAtMs":1,"serverAtMs":2}""") + } + } + } + } + }), + ) + } + + /** + * 契约 §3.6：接收端收到任何一帧都算活动，**`ping` 无需额外应答即可保活**， + * `pong` 只用于诊断 —— 所以"合规但不回 pong"的接收端**不能**被判定为链路已死。 + * + * 这是本轮修掉的一个真实缺陷：`onOpen` 里把 `lastPongAtMs` 设成了当前时刻， + * 于是"连续 3 个心跳周期没收到 pong"对任何接收端都会触发 —— 默认参数下 + * **每 15 秒主动断一次并重连**，正是用户抱怨的"频繁重连"。 + */ + @Test + fun `合规但从不回 pong 的接收端不会被判定链路已死`() { + enqueueReceiver { false } // 从不回 pong + val timing = FakeTiming() + val client = newClient(timing) + client.connect(wsUrl()) + waitUntil(what = "进入 streaming") { client.stats.value.state == PoseWebSocketClient.State.STREAMING } + + // 让虚拟时钟走过 6 个心跳周期（远超 MISSED_PONG_LIMIT=3） + waitUntil(timeoutMs = 10_000, what = "心跳发出 6 次") { timing.snapshot().size >= 6 } + assertTrue( + "不应出现「判定链路已死」（契约 §3.6：pong 可选）：${ConnectionLog.entries()}", + ConnectionLog.entries().none { it.contains("判定链路已死") }, + ) + assertEquals("连接应仍然打开", PoseWebSocketClient.State.STREAMING, client.stats.value.state) + assertEquals("本连接一次 pong 都没收到", 0, client.stats.value.pongsReceived) + } + + /** 反过来：曾经回过 pong、之后不回了 —— 这时"链路已死"的判断是有效的诊断。 */ + @Test + fun `曾经回过 pong 之后停止回复时判定链路已死并重连`() { + enqueueReceiver { n -> n == 1 } // 只在第一次回 pong + val timing = FakeTiming() + val client = newClient(timing) + client.connect(wsUrl()) + waitUntil(what = "进入 streaming") { client.stats.value.state == PoseWebSocketClient.State.STREAMING } + + waitUntil(timeoutMs = 10_000, what = "出现「判定链路已死」日志") { + ConnectionLog.entries().any { it.contains("判定链路已死") } + } + assertTrue( + "日志应说明是连续 ${ReconnectPolicy.MISSED_PONG_LIMIT} 个周期未收到 pong", + ConnectionLog.entries().any { + it.contains("连续 ${ReconnectPolicy.MISSED_PONG_LIMIT} 个心跳周期未收到 pong") + }, + ) + waitUntil(timeoutMs = 10_000, what = "进入重连") { + client.stats.value.state == PoseWebSocketClient.State.RECONNECTING || + client.stats.value.reconnectAttempts > 0 + } + } +} diff --git a/project.yaml b/project.yaml index deb6ced..4d0dbf9 100644 --- a/project.yaml +++ b/project.yaml @@ -1,5 +1,5 @@ project: opendance-android-app -version: 0.2.1 +version: 0.2.2 repository: opendance-android default_branch: main platform: Android 10+（minSdk 29 / targetSdk 34） @@ -90,9 +90,13 @@ tasks: file: tasks/016-reconnect-integration.md scope: JVM 内以真实 WebSocket（MockWebServer）验证重连链路 + 修「上一次关闭码污染下一次会话」 status: done + - id: T-AND-017 + file: tasks/017-backoff-and-pong.md + scope: 可注入计时 + 退避封顶端到端验证 + 修「合规不回 pong 的接收端被周期性误判链路已死」 + status: done deliverable: - artifact: opendance-android-v0.2.1.apk + artifact: opendance-android-v0.2.2.apk packaging: Gradle 命令行 / Android Studio includes: - app-release.apk diff --git a/tasks/017-backoff-and-pong.md b/tasks/017-backoff-and-pong.md new file mode 100644 index 0000000..bedb9b1 --- /dev/null +++ b/tasks/017-backoff-and-pong.md @@ -0,0 +1,82 @@ +# T-AND-017：退避封顶与「pong 可选」语义的 JVM 验证（+ 修一处真实缺陷） + +- **状态**: done +- **依赖**: T-AND-011（连接状态机与重连）/ T-AND-016（重连链路集成测试） +- **文档**: v1.6 §6.5 / §7.6.1 +- **契约**: `websocket-keypoints 0.2.0` §1.1 / §3.6 / §7.1 + +## 一、可注入的计时（`Timing`） + +契约 §7.1 的退避序列 `0.5s→1→2→4→8→15s 封顶` 若要**端到端**验证，真实等待约 **30 秒**； +「连续 3 个心跳周期没收到 pong」也要等几十秒。这类时限逻辑写在测试里既慢又易 flaky， +于是给 `PoseWebSocketClient` 抽了一个可注入的 `Timing`： + +```kotlin +interface Timing { + fun nowMs(): Long + suspend fun await(delayMs: Long) +} +object SystemTiming : Timing { // 生产默认：真实时钟 + 真实 delay + override fun nowMs(): Long = System.currentTimeMillis() + override suspend fun await(delayMs: Long) { delay(delayMs) } +} +``` + +构造函数新增 `timing: Timing = SystemTiming`，行为与抽取前**完全一致**（10 处 +`System.currentTimeMillis()` 与 2 处 `delay()` 改走 `timing`）。 +测试注入「可控时钟 + 立即返回的等待」，于是： + +* 30 秒的退避序列在**毫秒级**跑完并逐值断言（0.5/1/2/4/8/15/15s，各自 ±20% 抖动区间）； +* 「缺 pong 判定链路已死」不用等待即可触发。 + +## 二、测试抓到的真实缺陷：**合规的接收端会被周期性误判为链路已死** + +契约 §3.6 明确： + +> 接收端收到任何一帧（二进制或文本）都算活动，`ping` **无需额外应答**即可保活； +> `pong` 只用于诊断。 + +也就是说「合规但不回 `pong`」的接收端是**合法**的。但 `onOpen` 里写的是： + +```kotlin +lastPongAtMs = timing.nowMs() // ← 缺陷：连接一建立就等于"刚收到过 pong" +``` + +于是心跳循环里的守卫 `if (lastPongAtMs > 0 && silentFor > limit)` **恒为真**， +对**任何**接收端都会触发「判定链路已死 → 主动断链 → 重连」： +默认参数（`heartbeatIntervalMs = 5000`）下即 **每 15 秒断一次**， +正是用户抱怨的「频繁重连」。 + +**为什么以前没暴露**：我们自己的接收端（Windows `PoseServer`）**会**回 `pong` +（T-WIN-020 实测 9 次 ping 全部收到 pong），所以这条路径在自家联调里永远走不到； +只有契约允许的另一种实现才会踩。 + +**修复**：`onOpen` 复位为 `lastPongAtMs = 0L`（0 = 本连接还没收到过 pong）。 +只有「曾经回过 pong、之后又不回了」才判定链路已死 —— 这正是该诊断本来的意图。 + +## 三、用例（`PoseWebSocketBackoffTest`，4 项） + +| 用例 | 验的是什么 | +|--|--| +| 退避序列在 15 秒封顶，且不会无限增长 | 注入 `FakeTiming` 后用真实 MockWebServer 制造连续失败，断言第 1..8 次等待分别落在 500/1000/2000/4000/8000/15000/15000/15000 ±20% 内；**且真实耗时 < 5 秒** | +| 等待走注入实现——真实 delay 不会被调用 | 注入实现下前三次重连的真实耗时应 < 1.5 秒（真实退避需要 3.5 秒） | +| **合规但从不回 pong 的接收端不会被判定链路已死** | 契约 §3.6 语义：走过 6 个心跳周期后仍为 `streaming`、无「判定链路已死」日志（**修复前此处失败**） | +| 曾经回过 pong 之后停止回复时判定链路已死并重连 | 诊断仍然有效：日志出现「连续 3 个心跳周期未收到 pong」，随后进入重连 | + +实测：`./gradlew :app:testDebugUnitTest` → **68 项用例 / 0 失败**（原 64）。 + +## 四、写测试踩的两个坑 + +1. **不要在瞬时重连下读 `stats.nextRetryMs`**：等待立即返回后，客户端已经进入下一次 + 尝试并把该字段清零，断言会与重连循环竞争（第一版就失败了）。 + 等待时长应取**注入实现记录的事实**，而不是状态字段的瞬时值。 +2. **虚拟时钟需要一个真实让出点**：`FakeTiming.await` 若只推虚拟时钟而不让出， + 心跳循环会在网络回调（`pong` / `welcome`）落地之前就把时钟推过阈值， + 于是「回过一次 pong」的用例永远等不到那次 pong。加 2ms 真实 `delay` 即可， + 整体耗时仍远小于真实退避的 30 秒。 + +## 五、未覆盖（诚实声明） + +* 真机 Wi-Fi 抖动 / 切网 / 进程被杀 / Doze 省电仍需设备实测； +* `Timing` 只覆盖「时钟与等待」；OkHttp 自身的连接超时/写超时仍走真实时间 + （那部分由 MockWebServer 场景覆盖，不涉及长等待）。