docs(ble): 펌웨어팀 전달용 — 실측 로그와 앱 방어기제
연결 에피소드 464건을 전수 집계해, 반쪽 연결의 서명이 **MTU 응답 중복**임을 찾았다. MTU 1회: 433건 중 420건 성공 (97.0%) MTU 2회: 31건 중 7건 성공 (22.6%) 그리고 해제→재연결 간격이 짧을수록 이중 MTU 가 잦고 성공률이 낮다. 2초 미만 재연결은 5건 전부 실패(이중 MTU 60%), 60초 이상은 95.9% 성공(이중 MTU 5.4%). n=5 는 작지만 단조 추세라 방향은 분명하다. 실패가 "느린 것"이 아니라는 근거도 같이 담았다 — 정상 준비 시간은 중앙 0.836초 · 최대 2.624초(n=420)인데, 실패한 연결은 20~25초를 기다려도 오지 않았다. 중간이 없다. 타이밍이 아니라 상태 문제로 보인다. 날짜와 앱 버전이 다른 두 사례가 같은 서명을 보인다는 점도 축자 로그로 실었다. 09-11 10:50 은 HALF_CONNECTED 두 번, 09-10 13:39 은 status=8 인데 둘 다 해제 직후 재연결 → 이중 MTU → 장시간 침묵 → tx=0 rx=0 이다. 후자는 가드 도입 전이라 OS 의 link supervision timeout 이 먼저 끊었을 뿐 같은 증상이다. 즉 종전에 status=8 로 보고된 건 중 tx=0 rx=0 인 것들은 실제로는 서비스 탐색 무응답이다. 우리 쪽 가드 값(쿨다운 600ms, 가드 20초)이 근거 없이 정한 값이라는 점을 문서에 명시하고, 펌웨어의 정상 회복 시간을 물었다. 증상 A 의 실측 회복이 48초라 20초로는 첫 재시도가 못 붙는다. 숨기지 않는 편이 답을 받는 데 낫다. 내부 메모의 VBTFW0206 freeze 주장은 철회한다. 로그에 있는 펌웨어는 0200(13)/0203(138)/ 0205(507) 뿐이고, 0206 은 로그 파일명의 숫자 110206 을 오독한 것이었다. 근거 없는 주장을 펌웨어팀에 보낼 수는 없다. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
@@ -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`).
|
||||||
Reference in New Issue
Block a user