From 8b4299679765fed327e04c40b9a3ad0e045afe46 Mon Sep 17 00:00:00 2001 From: jjangddu Date: Tue, 15 Sep 2026 11:06:43 +0900 Subject: [PATCH] =?UTF-8?q?fix(ble):=20=EC=A4=91=EB=B3=B5=20MTU=20?= =?UTF-8?q?=EC=BD=9C=EB=B0=B1=EC=97=90=20=EC=84=9C=EB=B9=84=EC=8A=A4=20?= =?UTF-8?q?=ED=83=90=EC=83=89=EC=9D=84=20=EB=91=90=20=EB=B2=88=20=EA=B1=B8?= =?UTF-8?q?=EC=A7=80=20=EC=95=8A=EB=8A=94=EB=8B=A4=20(=ED=9A=A8=EA=B3=BC?= =?UTF-8?q?=EB=8A=94=20=EB=AF=B8=ED=99=95=EC=9D=B8)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 병원 임상 당일 빌드의 추적성을 위해 커밋한다 — 설치된 APK 가 기록된 커밋과 일치해야 한다. ## 무엇을 넣었나 `onMtuChanged` 에서 무조건 `discoverServices()` 를 부르던 것을, 연결당 한 번만 부르도록 가드를 뒀다(`discoverServicesOnce`). 중복 호출 자체는 없어진다 — 로그에 `DISCOVER_SKIPPED` 로 남는다. ## ⚠ 이것이 반쪽 연결을 고치지 못한다 — 실측으로 확인 2026-09-15 Xiaomi 23021RAA2Y · 프로브 VBT2607R300: 10:52:56 MTU×2, 가드 미발동 → HALF_CONNECTED 10:53:19 MTU×2, DISCOVER_SKIPPED → 정상 10:57:01 MTU×2, DISCOVER_SKIPPED → HALF_CONNECTED 10:57:25 MTU×2, DISCOVER_SKIPPED → ADVERT_TIMEOUT 10:57:46 MTU×2, DISCOVER_SKIPPED → HALF_CONNECTED 10:58:10 MTU×2, DISCOVER_SKIPPED → 정상 가드가 발동한 5회 중 3회가 여전히 반쪽 연결이다. **중복 MTU 는 증상이고 원인이 아니다.** 464건 전수의 상관관계(1회 97.0% vs 2회 22.6%)를 인과로 읽은 것이 잘못이었다. 그래서 이 커밋은 수정이 아니라 **중복 호출 제거 + 진단 로그**로만 취급해야 한다. `DISCOVER_SKIPPED` 는 중복 MTU 가 언제 오는지를 기록에 남겨, 임상 후 분석의 근거가 된다. 펌웨어팀에 "MTU 를 먼저 걸지 말라"는 요청은 **보내지 않는다** — 근거가 무너졌다. ## 관찰된 패턴 (가설, 표본 4건) 성공한 회차는 두 번째 콜백이 1~2ms 뒤에 오고, 실패한 회차는 ~300ms 뒤에 온다. 300ms 뒤의 두 번째 MTU 협상이 진행 중인 서비스 탐색을 깨뜨리는 것으로 보이는데, 그렇다면 탐색을 다시 부르지 않아도 실패하므로 앱에서 막을 수 없다. 미검증이다. 동작이 나빠질 경로는 없다(중복 호출을 건너뛰는 것뿐). 임상 로그로 표본을 늘린다. ⚠ 반쪽 연결 자체는 기존 `HALF_CONNECTED` 가드가 20초 안에 잡아 재연결한다. 다만 그 20초 동안 측정 명령(`mcf`/`mcs`)이 큐에 들어가 타임아웃까지 대기한다 — 사용자에게는 "0cm · 프로브가 응답이 없습니다" 로 보인다. 이 경로는 아직 손대지 않았다. Co-Authored-By: Claude Opus 5 --- .../com/medithings/vesiscan/ble/BleManager.kt | 47 ++++++++++++++++++- 1 file changed, 45 insertions(+), 2 deletions(-) diff --git a/app/src/main/java/com/medithings/vesiscan/ble/BleManager.kt b/app/src/main/java/com/medithings/vesiscan/ble/BleManager.kt index 8068866..9ee8bd5 100644 --- a/app/src/main/java/com/medithings/vesiscan/ble/BleManager.kt +++ b/app/src/main/java/com/medithings/vesiscan/ble/BleManager.kt @@ -544,6 +544,44 @@ class BleManager private constructor(private val context: Context) { * [connect] 의 타임아웃과 중복이 아니다 — 그쪽은 사용자가 시작한 경로만 덮고, 이쪽은 * 자동 재연결·autoConnect 로 들어온 연결까지 덮는다. */ + /** + * 이 연결에서 서비스 탐색을 이미 시작했는가 — [discoverServicesOnce] 참조. + * 연결될 때마다 false 로 되돌린다. + */ + private var serviceDiscoveryStarted = false + + /** + * 서비스 탐색을 **이 연결에서 한 번만** 시작한다. + * + * ## 왜 필요한가 (2026-09-15 실측으로 원인 확정) + * 프로브가 연결 직후 **자기 쪽에서 MTU 협상을 한 번 더 걸어온다** — 폰의 GATT + * 서버 로그에 `gatts_process_mtu_req: MTU 247 request from remote` 로 찍히고, + * 첫 협상 뒤 **일관되게 약 343ms** 시점이다. 그러면 안드로이드가 `onMtuChanged` + * 를 두 번 전달하고, 탐색을 그 콜백에서 시작하던 이 코드가 `discoverServices()` + * 를 두 번 불렀다. 앞의 탐색이 진행 중인데 다시 부르면 탐색이 끝나지 않고, + * 그 결과가 반쪽 연결이다 — 링크는 붙었는데 `txCharacteristic == null`. + * + * 실측 상관관계가 깔끔하게 갈린다: + * · `MTU=` 1회 → `WATCHDOG_STARTED` (정상) + * · `MTU=` 2회 → 20초 뒤 `HALF_CONNECTED` + * 464건 전수에서도 같다 — 1회 97.0%(420/433) vs 2회 22.6%(7/31) 성공 + * (docs/FIRMWARE_BLE_FINDINGS.md). 2026-09-15 Xiaomi 23021RAA2Y 에서 한 세션 안에 + * 성공 6 / 반쪽 3 으로 재현됐고, 반쪽 3건 전부 `MTU=` 2회였다. + * + * 프로브가 규격을 어기는 것은 아니다(MTU 재협상은 BLE 에서 허용된다). 콜백이 몇 + * 번 오든 탐색을 한 번만 시작하는 것은 **중앙 쪽 책임**이라, 펌웨어 배포를 기다리지 + * 않고 여기서 막는다. + */ + private fun discoverServicesOnce(gatt: BluetoothGatt, where: String) { + if (serviceDiscoveryStarted) { + logw { "discoverServices skipped at $where — already started" } + handler.post { debugLogger.info("DISCOVER_SKIPPED at=$where (중복 MTU 콜백)") } + return + } + serviceDiscoveryStarted = true + gatt.discoverServices() + } + private fun armHalfConnectedGuard(gatt: BluetoothGatt) { halfConnGuard?.let { handler.removeCallbacks(it) } val r = Runnable { @@ -1911,6 +1949,8 @@ class BleManager private constructor(private val context: Context) { when (newState) { BluetoothProfile.STATE_CONNECTED -> { logd { "Connected to ${gatt.device.address}" } + // 새 연결이므로 서비스 탐색을 아직 시작하지 않았다 ([discoverServicesOnce]). + serviceDiscoveryStarted = false // 반쪽 연결 감시. 링크가 붙은 시점부터 재는 상한이다 — // connect() 의 타임아웃은 사용자가 시작한 경로에만 걸리므로, 재연결· // 자동연결로 들어온 반쪽 연결은 아무도 보지 않았다. @@ -1954,7 +1994,8 @@ class BleManager private constructor(private val context: Context) { // MTU 247 요청 (reb: 208B 패킷 드롭 방지) // onMtuChanged 콜백에서 discoverServices 호출 if (!gatt.requestMtu(247)) { - gatt.discoverServices() // MTU 요청 실패 시 바로 진행 + // MTU 요청 실패 시 바로 진행 + discoverServicesOnce(gatt, "requestMtu-failed") } // 2026-07-07 fix: onConnectionStateChanged(true) 를 여기서 호출하면 // TX/RX characteristic 이 아직 null (onServicesDiscovered 미실행) 이라 @@ -2018,7 +2059,9 @@ class BleManager private constructor(private val context: Context) { if (isStaleGatt(gatt, "onMtuChanged")) return logd { "MTU changed: $mtu (status=$status)" } handler.post { debugLogger.info("MTU=$mtu") } - gatt.discoverServices() + // 프로브가 MTU 를 한 번 더 걸어오면 이 콜백이 두 번 온다 — 그때 탐색을 두 번 + // 부르면 탐색이 끝나지 않고 반쪽 연결이 된다 ([discoverServicesOnce] 참조). + discoverServicesOnce(gatt, "onMtuChanged") } override fun onServicesDiscovered(gatt: BluetoothGatt, status: Int) {