diff --git a/docs/FIRMWARE_BLE_FINDINGS.md b/docs/FIRMWARE_BLE_FINDINGS.md new file mode 100644 index 0000000..4c91293 --- /dev/null +++ b/docs/FIRMWARE_BLE_FINDINGS.md @@ -0,0 +1,521 @@ +# 프로브 BLE 동작 이상 — 실측 근거와 앱 측 대응 + +> 수신: 펌웨어팀 · 작성: 앱팀 · 2026-09-11 +> +> 이 문서의 모든 수치는 **실기기 로그 실측**입니다. 관측과 추정을 구분해 적었고, 추정에는 +> `(추정)` 을 붙였습니다. 통계는 폰 1대(`d69abfbb`)에 남은 2026-09-02 ~ 09-11 로그의 +> **연결 에피소드 464건 전수**를 집계한 것입니다. 원본 로그와 재현 절차는 +> [8장](#8-원본-로그와-재현-절차)에 있습니다. + +--- + +## 1. 핵심 결론 한 장 + +**연결을 끊고 곧바로 다시 연결하면, 링크는 붙지만 GATT 서비스 탐색에 응답하지 않습니다.** + +그 순간의 서명은 **`MTU` 협상 응답이 두 번 오는 것**입니다. 전수 집계 결과: + +| 구분 | 연결 수 | 사용 가능 상태 도달 | 성공률 | +|---|---|---|---| +| `MTU` 응답 **1회** (정상) | 433 | 420 | **97.0%** | +| `MTU` 응답 **2회** | 31 | 7 | **22.6%** | + +**이중 `MTU` 가 보이면 그 연결은 77% 실패합니다.** 그리고 이중 `MTU` 발생률은 **직전 해제로 +부터 얼마나 빨리 재연결했는지**에 따라 달라집니다: + +| 해제 → 재연결 간격 | 연결 수 | 이중 `MTU` 발생률 | 성공률 | +|---|---|---|---| +| **2초 미만** | 5 | **60.0%** | **0.0%** ← 5건 전부 실패 | +| 2~5초 | 36 | 13.9% | 91.7% | +| 5~15초 | 30 | 23.3% | 73.3% | +| 15~60초 | 22 | 13.6% | 86.4% | +| 60초 이상 | 74 | 5.4% | **95.9%** | + +> `<2초` 구간은 **n=5 로 표본이 작습니다.** 다만 5건 전부 실패했고 간격이 늘수록 단조적으로 +> 좋아지므로 **방향성은 분명합니다.** 펌웨어 쪽에서 의도적으로 반복 시험하면 재현율을 +> 확정할 수 있을 것으로 봅니다. + +그리고 **실패는 "느린 것"이 아니라 "영원히 안 오는 것"입니다.** 정상 연결이 사용 가능해지는 +데 걸리는 시간은: + +``` +중앙값 0.836초 최대 2.624초 (n=420) +``` + +**정상은 3초 안에 끝납니다.** 그런데 실패한 연결은 20~25초를 기다려도 오지 않았습니다. +중간이 없습니다 — **타이밍 문제가 아니라 상태 문제로 보입니다.** + +### 요청 + +1. **해제 후 GATT 서버가 다시 요청을 받을 수 있게 되기까지 설계상 몇 초가 필요합니까?** + 그 값을 알려 주시면 앱이 정확히 그만큼 기다립니다. +2. **`MTU` 응답이 두 번 나가는 조건이 무엇입니까?** 앱은 연결당 `requestMtu` 를 한 번만 + 호출합니다. +3. 해제 시 GATT 서버를 재초기화하는 절차가 있습니까? 끝나기 전에 새 연결이 들어오면 + 어떻게 처리됩니까? + +나머지 질문은 [7장](#7-펌웨어팀에-드리는-질문)에 정리했습니다. + +--- + +## 2. 용어 — BLE 연결은 네 단계입니다 + +이 문서를 읽는 데 필요한 전제입니다. + +``` +① 링크 수립 central ──연결 요청──► peripheral → STATE_CONNECTED +② MTU 협상 central ──requestMtu──► → onMtuChanged +③ 서비스 탐색 central ──discoverServices──► → onServicesDiscovered +④ 알림 구독 central ──CCCD write──► → 이제 사용 가능 +``` + +**①②는 되고 ③이 안 돌아오는 상태를 이 문서에서 "반쪽 연결"이라 부릅니다.** 앱은 "연결됨" +인데 characteristic 핸들이 없어 **명령을 한 바이트도 보낼 수 없습니다.** + +로그에서 구별하는 방법: + +| 줄 | 뜻 | +|---|---| +| `CONN CONNECTED` | ① 링크 수립. **아직 사용 가능하지 않습니다** | +| `MTU=247` | ② 완료 → 앱이 `discoverServices()` 호출 | +| `CONN_PRIORITY HIGH` | ③④ 완료 후 | +| **`WATCHDOG_STARTED`** | **사용 준비 완료.** 이 줄이 없으면 반쪽 연결 | + +```bash +# 반쪽 연결 빠른 확인 — CONNECTED 뒤에 WATCHDOG_STARTED 가 따라오는지 본다 +grep -E "CONNECTED|WATCHDOG_STARTED|MTU=" VesiScan_BLE_*.log +``` + +--- + +## 3. 증상 A — 서비스 탐색 무응답 (`VBTFW0203`) + +### 3.1 실측 1 — 2026-09-11 10:50~10:51 + +기기 `VBT2607R300` (`E7:17:AF:06:6A:FB`) · 펌웨어 `VBTFW0203` +폰 Xiaomi 23021RAA2Y (Android 13) · 로그 `VesiScan_BLE_2026-09-11_105013.log` + +#### 정상 연결 — 비교 기준 + +``` +10:50:20.751 CONN CONNECTED VBT2607R300 (E7:17:AF:06:6A:FB) +10:50:20.762 INFO MTU=247 ← 한 번 +10:50:21.655 INFO CONN_PRIORITY HIGH requested (ok=true) +10:50:21.667 INFO WATCHDOG_STARTED timeout=25000ms ← 0.92초만에 사용 가능 +10:50:23.178 CONN DISCONNECTED reason=user gatt_status=0 session=2s tx=0 rx=0 err=0 + └ 사용자가 [연결 해제] 를 누름 +``` + +#### 이상 1회차 — 해제 후 1.40초 뒤 재연결 + +``` +10:50:24.574 CONN CONNECTED VBT2607R300 (E7:17:AF:06:6A:FB) +10:50:24.585 INFO MTU=247 +10:50:24.874 INFO MTU=247 ← 두 번 (289ms 간격) + ······ 20초 동안 아무 줄도 없음 ······ +10:50:44.571 ERROR HALF_CONNECTED 링크는 붙었는데 서비스가 준비되지 않았습니다 (20000ms) — 끊습니다 +10:50:44.579 CONN RECONNECTING attempt=1/-1 delay=3000ms +10:50:47.583 INFO RECONNECT_SCAN #1 scanning for VBT2607R300 +10:50:48.582 INFO RECONNECT_FOUND VBT2607R300 (E7:17:AF:06:6A:FB) RSSI=-49 +``` + +`CONN_PRIORITY`·`WATCHDOG_STARTED` 가 **없습니다** — `onServicesDiscovered` 콜백이 오지 +않았습니다. 앱이 20초 상한에서 끊고 재연결을 걸었습니다. RSSI `-49 dBm` — 전파는 충분합니다. + +#### 이상 2회차 — 같은 증상 반복 + +``` +10:50:48.649 CONN CONNECTED VBT2607R300 (E7:17:AF:06:6A:FB) +10:50:48.654 INFO MTU=247 +10:50:48.947 INFO MTU=247 ← 또 두 번 (293ms) +10:51:01.533 INFO ADVERT_WAIT VBT2607R300 — 광고 확인 후 연결 (최대 6000ms) +10:51:07.555 WARN ADVERT_TIMEOUT VBT2607R300 — 광고가 없습니다 ← 증상 B 동시 발생 +10:51:08.638 ERROR HALF_CONNECTED ... (20000ms) — 끊습니다 +10:51:08.651 CONN RECONNECTING attempt=1/-1 delay=3000ms +10:51:11.654 INFO RECONNECT_SCAN #1 scanning for VBT2607R300 +10:51:11.777 INFO RECONNECT_FOUND VBT2607R300 (E7:17:AF:06:6A:FB) RSSI=-48 +``` + +이 구간에서 사용자가 수동으로 다시 눌렀는데, 그때는 **광고도 잡히지 않았습니다** +(10:51:01~07, 6초간 0건 — [4장](#4-증상-b--광고-재개-지연-vbtfw0205)). + +#### 최종 정상화 + +``` +10:51:11.903 CONN CONNECTED VBT2607R300 (E7:17:AF:06:6A:FB) +10:51:11.907 INFO MTU=247 ← 한 번 +10:51:12.259 INFO CONN_PRIORITY HIGH requested (ok=true) +10:51:12.263 INFO WATCHDOG_STARTED timeout=25000ms ← 0.36초만에 사용 가능 +10:51:14.291 TX msn battery query [7B] +10:51:14.343 RX rsn battery=3943mV (62%) [8B] +10:51:14.345 TX mid device info query [7B] +10:51:14.373 RX rid device_info=VB0HW0000 VBT2607R300 VBTFW0203 [42B] +``` + +#### 타임라인 + +| 시각 | 사건 | 해제로부터 | `MTU` | +|---|---|---|---| +| `10:50:23.178` | 사용자 [연결 해제] | 0s | — | +| `10:50:24.574` | 재연결 → **무응답** | +1.4s | **2회** | +| `10:50:44.571` | 앱이 끊음 (20초 상한) | +21.4s | | +| `10:50:48.649` | 재연결 → **또 무응답** | +25.5s | **2회** | +| `10:51:08.638` | 앱이 끊음 | +45.5s | | +| `10:51:11.903` | 재연결 → **성공** | **+48.7s** | 1회 | + +### 3.2 실측 2 — 2026-09-10 13:39 (가드 도입 전, 같은 서명) + +로그 `VesiScan_BLE_2026-09-10_131515.log` · 같은 기기 · 같은 펌웨어 + +``` +13:39:50.053 CONN DISCONNECTED reason=user gatt_status=0 session=21s tx=3 rx=3 err=0 +13:39:55.270 CONN CONNECTED VBT2607R300 (E7:17:AF:06:6A:FB) ← 해제 후 5.2초 +13:39:55.277 INFO MTU=247 +13:39:55.558 INFO MTU=247 ← 두 번 (281ms) + ······ 25초 침묵 ······ +13:40:20.774 ERROR GATT_ERROR status=8 newState=0 wasConnected=true +13:40:20.786 CONN DISCONNECTED reason=gatt_error gatt_status=8 session=25s tx=0 rx=0 err=1 +13:40:20.787 CONN RECONNECTING attempt=1/-1 delay=3000ms +``` + +**날짜가 다르고 앱 버전이 다른데 서명이 같습니다** — 해제 직후 재연결 → 이중 `MTU` → +장시간 침묵 → `tx=0 rx=0`. 한 바이트도 주고받지 못한 세션입니다. + +당시에는 아직 앱의 20초 가드가 없어서 **OS 의 link supervision timeout (`status=8`)이 먼저 +끊었습니다.** 같은 증상의 다른 표현입니다. 이 점이 중요합니다: + +> **종전에 `status=8`(연결 끊김)으로 보고된 건 중 일부는 실제로는 서비스 탐색 무응답입니다.** +> `tx=0 rx=0` 인지 보면 구별됩니다. + +### 3.3 이중 `MTU` 전수 집계 + +| 이중 `MTU` 두 응답 사이 간격 | n=31 | +|---|---| +| 최소 | 10 ms | +| 중앙값 | **281 ms** | +| 최대 | 2,186 ms | + +31건이 **로그 파일 19개에 걸쳐 분산**돼 있습니다 — 특정 날짜의 일회성 현상이 아닙니다. + +``` +09-02 1건 09-08 1건 09-10 19건 ← 해제/연결 반복 시험을 집중한 날 +09-03 1건 09-09 3건 09-11 2건 +09-07 4건 +``` + +09-10 에 몰린 이유는 그날 **해제/연결 반복 시험을 집중적으로 했기 때문**입니다. 1장의 +간격별 발생률과 일치합니다. + +> **(추정)** 앱은 `onMtuChanged` 안에서 `discoverServices()` 를 호출하므로, `MTU` 콜백이 두 번 +> 오면 `discoverServices()` 도 두 번 호출됩니다. 이것이 원인인지 결과인지는 **판단하지 +> 않았습니다.** 다만 앱 코드에서 `requestMtu` 는 연결당 한 번만 부르므로 **중복 요청은 앱 +> 쪽이 아닙니다.** peripheral 이 응답을 두 번 보냈거나, 한 번의 요청에 두 개의 이벤트가 +> 생기는 상황으로 보입니다. + +--- + +## 4. 증상 B — 광고 재개 지연 (`VBTFW0205`) + +### 4.1 실측 — 2026-09-11 09:10~09:11 + +기기 `VBT26080001` (`C8:AF:D2:11:95:AA`) · 펌웨어 `VBTFW0205` +폰 FYD IM-H091 (Android 15) · 로그 `VesiScan_BLE_2026-09-11_090142.log` + +연결/해제를 빠르게 **7회** 반복한 시험입니다. + +| # | 해제 | 연결 누름 | 간격 | 광고 확인 | 결과 | +|---|---|---|---|---|---| +| 1 | `09:10:57.411` | `09:10:59.503` | 2.09s | 즉시 (최근 5초 내 목격) | 성공 | +| 2 | `09:11:01.946` | `09:11:03.095` | 1.15s | 즉시 | 성공 | +| 3 | `09:11:05.303` | `09:11:06.114` | 0.81s | **0.26초 대기** | 성공 | +| 4 | `09:11:08.471` | `09:11:09.833` | 1.36s | 즉시 | 성공 | +| 5 | `09:11:11.980` | `09:11:12.863` | 0.88s | **6초 초과 → 실패** | 거부 | +| 6 | — | `09:11:20.985` | — | **6초 초과 → 실패** | 거부 | +| 7 | — | `09:11:28.879` | — | **0.09초** | 성공 | + +``` +09:11:11.980 CONN DISCONNECTED reason=user gatt_status=0 session=2s tx=0 rx=0 err=0 +09:11:12.863 INFO ADVERT_WAIT VBT26080001 (C8:AF:D2:11:95:AA) — 광고 확인 후 연결 (최대 6000ms) +09:11:18.867 WARN ADVERT_TIMEOUT VBT26080001 (C8:AF:D2:11:95:AA) — 광고가 없습니다 +09:11:20.985 INFO ADVERT_WAIT VBT26080001 (C8:AF:D2:11:95:AA) — 광고 확인 후 연결 (최대 6000ms) +09:11:26.988 WARN ADVERT_TIMEOUT VBT26080001 (C8:AF:D2:11:95:AA) — 광고가 없습니다 +09:11:28.879 INFO ADVERT_WAIT VBT26080001 (C8:AF:D2:11:95:AA) — 광고 확인 후 연결 (최대 6000ms) +09:11:28.967 INFO ADVERT_FOUND VBT26080001 rssi=-59 — 연결 +09:11:29.282 CONN CONNECTED VBT26080001 (C8:AF:D2:11:95:AA) +``` + +**09:11:12 부터 09:11:28.9 까지 약 16초간 광고 패킷이 하나도 잡히지 않았습니다.** + +이것이 스캔 쪽 문제가 아닌 근거: + +- 주소 필터(`ScanFilter.setDeviceAddress`) + `SCAN_MODE_LOW_LATENCY` 로 스캔했습니다 +- RSSI 가 직전 `-56`, 직후 `-59` — **거리·전파 환경 변화가 아닙니다** +- 광고가 재개된 뒤에는 **0.09초**에 잡혔습니다 — 스캔 경로는 정상입니다 +- 같은 시험의 1~4회차는 1초 내에 재개됐습니다 — **반복한 뒤에 나타납니다** + +### 4.2 이 증상이 만들던 2차 피해 (조치 전) + +광고하지 않는 기기에 `connectGatt` 를 걸면 **링크 수립이 성립하지 않고 콜백도 오지 +않습니다.** 조치 전 앱은 이 상태를 감지하지 못해, 다음 연쇄로 이어졌습니다: + +``` +광고 전에 연결 시도 → 콜백 없음 → 화면 무한 대기 + → 화면은 "연결됨" (링크 플래그만 true) + → 모든 명령 실패 (배터리·IMU·측정 전무) + → 사용자가 [페어링 삭제] 를 누름 + → msr? 가 기기에 나가지 못했는데 폰 본드만 삭제됨 + → 본드 비대칭: 기기는 LTK 를 계속 들고 있음 + → 다음 연결에서 "PIN 또는 passkey 가 올바르지 않습니다" + → 앱으로 복구 불가 → 기기 버튼 15초 길게 눌러 초기화 +``` + +**이 연쇄는 2026-09-10 현장에서 실제로 발생해 기기를 물리적으로 초기화했습니다.** +앱 측은 모두 조치했습니다([6장](#6-앱-측-대응--지금-어떻게-동작하나)). + +--- + +## 5. 증상 C — GATT 오류 분포 + +폰 `d69abfbb` 에 남은 **전체 로그**의 GATT 오류입니다. + +| status | 의미 | 건수 | +|---|---|---| +| **5** | `GATT_INSUFFICIENT_AUTHENTICATION` — 본드 충돌 | **29** | +| **62** (`0x3E`) | `GATT_CONN_FAIL_ESTABLISH` — 링크 수립 실패 | **23** | +| **8** | `GATT_CONN_TIMEOUT` — link supervision timeout | **15** | +| **22** | `GATT_CONN_TERMINATE_LOCAL_HOST` | **7** | +| **19** | `GATT_CONN_TERMINATE_PEER_USER` — peripheral 이 명시적 종료 | **1** | + +해제 사유 분포: `user/0` 54 · `gatt_error/5` 22 · `gatt_error/8` 15 · `unexpected/0` 12 · +`gatt_error/22` 2 · `gatt_error/19` 1. + +### 5.1 `status=8` — 세션 길이가 제각각입니다 + +``` +11:10:59.485 ERROR GATT_ERROR status=8 newState=0 wasConnected=true +11:10:59.495 CONN DISCONNECTED reason=gatt_error gatt_status=8 session=434s tx=383 rx=2578 err=1 +``` +434초(7분) 정상 통신 후 갑자기 끊김. + +``` +11:11:29.974 ERROR GATT_ERROR status=8 newState=0 wasConnected=true +11:11:29.983 CONN DISCONNECTED reason=gatt_error gatt_status=8 session=23s tx=4 rx=2 err=1 +``` +23초 후 끊김. 직전 RSSI `-62 dBm` — 신호는 충분합니다. + +**주의**: `status=8` 중 `tx=0 rx=0` 으로 끝난 건은 통신 중 끊긴 것이 아니라 증상 A(서비스 +탐색 무응답)입니다([3.2장](#32-실측-2--2026-09-10-1339-가드-도입-전-같은-서명)). +**두 부류를 나눠 봐야 합니다.** + +### 5.2 `status=5` — 본드 allowlist + +``` +09:39:08.702 ERROR GATT_ERROR status=5 newState=0 wasConnected=false +09:39:08.795 WARN BOND_CONFLICT addr=C8:AF:D2:11:95:AA — FW allowlist rejected (status 5) +``` + +펌웨어 allowlist 정책상 **다른 central 과 이미 본드된 기기**에 붙으려 하면 인증을 거부하는 +것으로 이해하고 있습니다. 앱은 이 경우 "다른 폰에서 페어링을 해제하세요"로 안내합니다. +**이 동작이 의도된 것인지 확인 부탁드립니다.** + +--- + +## 6. 앱 측 대응 — 지금 어떻게 동작하나 + +펌웨어 동작을 **숨기지 않고 기록하면서** 사용자 피해만 막는 것이 목표입니다. 로그는 그대로 +남으므로, 조치 후에도 증상은 계속 관측 가능합니다 — 3.1장이 조치 후에 잡힌 기록입니다. + +``` +① 예방 연결 전에 광고를 확인한다 → 증상 B +② 복구 서비스가 준비 안 되면 끊고 다시 붙는다 → 증상 A +③ 표시 "연결됨" 을 isServiceReady 기준으로 말한다 +④ 방어 명령을 보낼 수 없으면 본드를 지우지 않는다 +``` + +### 6.1 ① 광고 확인 후 연결 + +| 상황 | 동작 | 로그 | +|---|---|---| +| 최근 **5초** 내 광고를 봤음 | **대기 없이** 연결 | (없음) | +| 못 봤음 | 주소 필터로 **최대 6초** 대기 | `ADVERT_WAIT` → `ADVERT_FOUND` | +| 6초 내 광고 없음 | **연결을 시도하지 않음** | `ADVERT_TIMEOUT` | + +기기 목록 화면은 상시 스캔하므로 **정상 사용에서 추가 지연은 0초**입니다(4.1장 시험 중 +3회가 이 경로). + +### 6.2 ② 반쪽 연결 가드 + +링크 수립(`STATE_CONNECTED`)부터 **20초** 안에 `isServiceReady` 에 도달하지 못하면 끊고 +재연결합니다. + +``` +10:50:44.571 ERROR HALF_CONNECTED 링크는 붙었는데 서비스가 준비되지 않았습니다 (20000ms) — 끊습니다 +10:50:44.579 CONN RECONNECTING attempt=1/-1 delay=3000ms +``` + +**20초라는 값의 근거와 한계:** + +- 정상 준비 시간은 **중앙 0.836초 · 최대 2.624초**(n=420)입니다. 20초는 최악값의 7.6배로 + **정상 연결을 잘못 끊을 위험은 사실상 없습니다.** +- 그러나 **증상 A 의 실제 회복까지 약 48초**가 걸리므로 20초 가드로는 첫 재시도에서도 + 못 붙습니다 — 3.1장에서 2회 반복 후 3번째에 성공했습니다. +- **펌웨어 쪽 정상 회복 시간을 알려 주시면 그 값에 맞추겠습니다.** 지금은 근거 없이 + 정한 값이라, 너무 짧으면 헛재시도를 하고 너무 길면 사용자가 오래 기다립니다. + +### 6.3 ③ "연결됨" 의 기준 + +``` +종전: isConnected (링크 플래그) → 반쪽 연결에서도 "연결됨" 이라 표시 +현재: isServiceReady (사용 가능) → 반쪽 연결은 "연결 안 됨" 으로 표시 +``` + +### 6.4 ④ 본드 비대칭 차단 + +`msr?`(본드 삭제 + 재부팅)을 **실제로 보낼 수 있을 때만** 폰 쪽 본드를 지웁니다. 보낼 수 +없으면 아무것도 지우지 않고 기기 초기화를 안내합니다. + +``` +UNBOND_REFUSED canSend=false serviceReady=false tx=false gatt=true — + msr? 를 보낼 수 없어 폰 본드도 지우지 않습니다(비대칭 방지) +``` + +**한쪽만 지운 상태는 앱으로 복구가 불가능**하고, 양쪽 다 남은 상태는 그냥 다시 연결하면 +됩니다. 후자를 택합니다. + +### 6.5 그 외 + +| 조치 | 내용 | +|---|---| +| 재연결 쿨다운 | `close()` 직후 같은 기기로 여는 것을 **600ms** 지연 | +| 옛 콜백 차단 | 이전 연결의 GATT 콜백이 새 연결 상태를 덮지 않게 (콜백 7개 전부) | +| 연결 타임아웃 | `isServiceReady` 기준 **20초** (종전은 `isConnected` 기준 10초) | +| 배터리 폴링 | 측정 중(직전 TX 5초 내)에는 `msn?` 을 보내지 않음 — 스트림 끼어들기 방지 | + +> **쿨다운 600ms 는 증상 A 에 대해 부족합니다.** 1장의 통계대로 `<2초` 재연결은 5건 전부 +> 실패했습니다. 펌웨어가 필요한 시간을 알려 주시면 이 값을 올리겠습니다 — 지금은 사용자 +> 대기 시간을 늘리는 게 맞는지 판단할 근거가 없어 600ms 로 두고 있습니다. + +--- + +## 7. 펌웨어팀에 드리는 질문 + +### 증상 A — 서비스 탐색 무응답 (우선순위 최상) + +1. **연결 해제 후 GATT 서버가 다시 요청을 받을 수 있게 되기까지 설계상 몇 초가 필요합니까?** + → 앱의 쿨다운(현재 600ms)과 가드(현재 20초)를 그 값에 맞추겠습니다. +2. **`MTU` 협상 응답이 두 번 나가는 조건이 무엇입니까?** 실패 연결의 77%에서 관측되고, + 앱은 연결당 `requestMtu` 를 한 번만 호출합니다. +3. 해제 시 GATT 서버/스택을 재초기화하는 절차가 있습니까? 그 절차가 끝나기 전에 새 연결 + 요청이 들어오면 어떻게 처리됩니까? +4. 무응답 상태에서 `discoverServices()` 를 다시 호출하면 회복됩니까? (앱이 재연결 대신 + 재탐색으로 복구할 수 있다면 사용자 대기가 크게 줄어듭니다.) + +### 증상 B — 광고 재개 지연 + +5. **연결 해제 후 광고를 재개하기까지 설계상 몇 초가 걸립니까?** 실측 최대 16초였습니다. +6. 빠른 연결/해제 반복이 광고 재개를 지연시키는 **누적 효과**가 있습니까? 7회 반복 후 + 발생했고, 그 전 4회는 1초 내 재개됐습니다. + +### 증상 C — `status=8` + +7. link supervision timeout 으로 끊기는 조건을 알 수 있습니까? 세션 23초~434초로 일정하지 + 않고, RSSI 는 `-62 dBm` 이상으로 충분했습니다. +8. 펌웨어가 기대하는 connection interval / slave latency / supervision timeout 값은? + 앱은 `CONNECTION_PRIORITY_HIGH` 를 요청하고 `ok=true` 를 받습니다. + +### 증상 D — `status=5` 본드 allowlist + +9. **다른 central 과 본드된 상태에서 새 central 의 인증을 거부하는 동작이 의도된 + 것입니까?** 의도라면 앱 안내 문구를 그에 맞추고, 아니라면 원인을 확인하고 싶습니다. + +### 공통 + +10. 위 증상에 대해 **펌웨어 측 로그나 디버그 출력**을 받을 수 있습니까? 앱은 central + 관점만 보이므로, peripheral 쪽에서 그 순간 무엇을 하고 있었는지 알면 원인 특정이 + 훨씬 빠릅니다. 특히 **이중 `MTU` 가 나가는 순간의 펌웨어 상태**를 알고 싶습니다. + +--- + +## 8. 원본 로그와 재현 절차 + +### 8.1 파일 위치 + +폰 내부 저장소 `Download/VesiScan_BLE_<날짜>_<시각>.log` — 앱 실행마다 한 파일. + +```bash +adb pull /sdcard/Download/VesiScan_BLE_2026-09-11_105013.log # 증상 A · VBTFW0203 +adb pull /sdcard/Download/VesiScan_BLE_2026-09-10_131515.log # 증상 A · 가드 도입 전 +adb pull /sdcard/Download/VesiScan_BLE_2026-09-11_090142.log # 증상 B · VBTFW0205 +``` + +| 증상 | 파일 | 폰 | +|---|---|---| +| A (3.1장) | `VesiScan_BLE_2026-09-11_105013.log` | Xiaomi 23021RAA2Y (`d69abfbb`) | +| A (3.2장) | `VesiScan_BLE_2026-09-10_131515.log` | Xiaomi 23021RAA2Y | +| B (4.1장) | `VesiScan_BLE_2026-09-11_090142.log` | FYD IM-H091 (`H09124Y1G00396`) | +| C (5장) | 전체 로그 집계 | Xiaomi 23021RAA2Y | + +### 8.2 재현 절차 + +**증상 A** — 연결 → 측정 없이 [연결 해제] → **1~2초 안에** 다시 연결. +기대: `MTU=247` 이 두 번 찍히고, 그 뒤 `CONN_PRIORITY`·`WATCHDOG_STARTED` 가 없고, +20초 후 `HALF_CONNECTED`. + +**증상 B** — 위를 **5~7회** 반복. 기대: `ADVERT_TIMEOUT`. + +### 8.3 로그 줄 해설 + +| 줄 | 뜻 | +|---|---| +| `CONN CONNECTED` | 링크 수립. **아직 사용 가능하지 않습니다** | +| `MTU=247` | MTU 협상 완료 → 앱이 `discoverServices()` 호출. **두 번 찍히면 이상 신호** | +| `CONN_PRIORITY HIGH` | 서비스 탐색 + CCCD 구독 완료 후 | +| **`WATCHDOG_STARTED`** | **사용 준비 완료** (`isServiceReady = true`) | +| `TX` / `RX` | 실제 명령·응답 | +| `DISCONNECTED ... tx=N rx=M` | 그 세션의 패킷 수. **`tx=0 rx=0` = 아무것도 못 함** | +| `HALF_CONNECTED` | 앱이 반쪽 연결을 감지해 끊었음 | +| `ADVERT_WAIT` / `ADVERT_TIMEOUT` | 앱이 광고를 기다림 / 못 찾음 | +| `UNBOND_REFUSED` | 앱이 본드 비대칭을 막았음 | +| `GATT_ERROR status=N` | OS 가 준 GATT 오류 코드 | + +### 8.4 집계 방법 + +`adb shell cat` 으로 폰의 전체 로그를 읽어, `CONN CONNECTED` 줄을 경계로 연결 에피소드를 +나누고 각 에피소드 안의 `MTU=` 줄 수와 `WATCHDOG_STARTED` 유무를 셌습니다 — 총 464건. +해제→재연결 간격은 각 `CONNECTED` 직전 `DISCONNECTED` 와의 시각 차이입니다(600초를 넘는 +건은 "앱을 다시 켠 경우"로 보고 제외해 167건이 간격 집계에 들어갔습니다). + +--- + +## 9. 관측되지 않은 것 (오해 방지) + +문서의 신뢰를 위해 **확인하지 못한 것**을 명시합니다. + +- **`VBTFW0206` 은 이 로그들에 존재하지 않습니다.** 앱팀 내부 메모에 "0206 freeze" 항목이 + 있었으나, 실제 로그에 있는 펌웨어는 `VBTFW0200`(13) · `VBTFW0203`(138) · `VBTFW0205`(507) + 뿐입니다. **0206 관련 주장은 근거가 없으므로 철회합니다.** +- **MCU 완전 정지(freeze)** 사례는 이 폰의 로그에서 재확인하지 못했습니다. 다른 폰에 남아 + 있을 수 있습니다 — 찾으면 별도로 전달하겠습니다. +- `status=62`·`22`·`19` 는 **건수만 셌고 개별 맥락은 분석하지 않았습니다.** +- 증상 A 와 B 가 **같은 원인인지 다른 원인인지 판단하지 않았습니다.** 3.1장에서 동시에 + 나타났지만, 두 증상은 펌웨어 버전이 다른 기기에서 각각 관측됐습니다. +- **이중 `MTU` 가 원인인지 결과인지 판단하지 않았습니다.** 상관관계만 보고합니다. +- 통계는 **폰 1대**의 로그이고, 기기·펌웨어·Android 버전이 섞여 있습니다. 앱 버전도 + 기간 중 바뀌었습니다(가드 도입 전후). + +--- + +## 10. 앱 측 변경 이력 (참고) + +| 커밋 | 내용 | +|---|---| +| `338ae7a` | 연결 타임아웃을 `isServiceReady` 기준으로 · 20초 | +| `b035134` | 옛 GATT 콜백 차단 · `STATE_CONNECTED` 에서 gatt 재대입 · 쿨다운 600ms | +| `f676bd7` | 반쪽 연결 20초 가드 · "연결됨"=`isServiceReady` · 본드 비대칭 차단 | +| `44460d5` | 광고 확인 후 연결 | +| `ef221a8` | 배터리 폴링을 조용할 때만 | +| `14e4b33` | 폴링 건너뛰기를 파일 로그로 · 광고 없음 문구를 실제 원인에 맞게 | + +저장소: `medithings-rnd/VesiscanBasicAndroid` 브랜치 `demo-final`. +동일 수정이 `vesiscan_pre_product/vesiscan_android_user` 브랜치 `main` 의 `user` 소스셋에도 +이식돼 있습니다(커밋 `5994307`).