dw.jang/VesiscanClinicalAndroid
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix(ble): 서비스 탐색을 500ms 늦춘다 — 반쪽 연결의 진짜 원인 · 스캔 빈도 제한도 앱에서 막는다

Browse Source 
## ① 반쪽 연결 — 원인은 MTU 협상 타이밍이었다

성공과 실패를 가르는 것은 두 번째 `onMtuChanged` 가 **언제** 오는지 하나였다.
2026-09-15 Xiaomi 23021RAA2Y · VBT2607R300 · 9건에 예외가 없었다:

    두 번째 콜백 +1~2ms     → WATCHDOG_STARTED   3/3
    두 번째 콜백 +297~342ms → HALF_CONNECTED     6/6

+1ms 는 탐색이 시작도 안 했을 때라 살아남고, +300ms 는 탐색 한가운데라 깨진다.
프로브가 연결 뒤 ~300ms 에 자기 쪽에서 MTU 협상을 걸고(폰 GATT 서버 로그의
`gatts_process_mtu_req: MTU 247 request from remote`), 그 ATT 트랜잭션이 진행 중인
서비스 탐색을 깨뜨려 `onServicesDiscovered` 가 오지 않는 것으로 보인다.

**중복 호출을 막는 것으로는 고쳐지지 않았다.** 직전 커밋(8b42996)에서 막아 봤고
`DISCOVER_SKIPPED` 가 발동한 5회 중 3회가 여전히 반쪽이었다 — 깨뜨리는 것은 우리
호출이 아니라 프로브의 ATT 요청이고 앱이 막을 수 없다. 그래서 **피한다**:
탐색을 500ms 뒤에 시작해 협상 창을 지나 보낸다.

실측: 수정 전 6/6 실패 → 수정 후 **4/4 성공**(전부 MTU 2회였다).

대가는 연결 완료가 0.5초 늦는 것뿐이고, 실패하면 20초 `armHalfConnectedGuard` 가
그대로 잡는다. 지연 중 끊기면 `cancelPendingDiscover()` 로 취소한다(정리 경로 10곳).

⚠ 근본 원인은 프로브가 연결 직후 MTU 협상을 거는 것이다. 펌웨어에서 없애거나 연결
  직후 즉시 끝내면 이 지연은 필요 없어진다 — 문의 예정.

## ② "광고가 없습니다" 의 정체는 안드로이드 스캔 제한이었다

연결/해제를 연타한 뒤 앱이 기기를 못 찾았다. 그런데 **프로브 LED 는 광고 중이었고
다른 폰에서는 잡혔다.** 시스템 로그에 근거가 그대로 있었다:

    E/BtGatt.GattService: App 'com.medithings.vesiscan.demo' is scanning too frequently

안드로이드는 30초에 5회를 넘기면 스캔을 **조용히** 막는다. 빈 결과가 오므로 앱은
"광고가 없습니다" 로 보고하고, 사용자는 기기를 의심하게 된다 — 실제로 그랬다.

OS 가 막기 전에 앱에서 먼저 막는다. 30초 창에 4회(한도 5 에서 하나 남김)를 넘으면
스캔하지 않고 `SCAN_THROTTLED:<남은 초>` 로 알린다. 화면에 남은 초와 함께 "기기 문제가
아닙니다" 를 적었다.

스캔 시작 세 경로 전부 가드를 거친다 — `startScan`, `waitForAdvertThenConnect`,
자동 재연결 스캔(이쪽은 재시도 경로라 건너뛰고 다음 차례로 넘긴다).

광고 확인(`ADVERT_WAIT`)을 생략하는 선택지는 택하지 않았다. 광고하지 않거나 먼 기기에
붙으려다 오류가 났던 이력이 있어 그 확인을 넣은 것이다 — 스캔을 줄이려고 그걸 빼면
예전 문제가 돌아온다(사용자 지적).

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
jjangddu
2026-09-15 11:49:32 +09:00
parent 50a2d4bb6a
commit 6c5e38080c
4 changed files with 142 additions and 18 deletions
Download Patch File Download Diff File Expand all files Collapse all files
app/src/main/java/com/medithings/vesiscan/ble/BleManager.kt
+131 -18
View File
@@ -380,11 +380,66 @@ class BleManager private constructor(private val context: Context) {
val isBluetoothReady: Boolean get() = bluetoothAdapter?.isEnabled == true
// Scanning
// ── 스캔 빈도 제한 ────────────────────────────────────────────────────
//
// 안드로이드는 앱이 **30초에 5회** 이상 스캔을 시작하면 그 뒤 스캔을 **조용히**
// 막는다. 결과가 빈 채로 돌아오므로 앱에는 "광고가 없습니다" 로 보이고, 실제로는
// 기기가 멀쩡히 광고하는 중이다 (2026-09-15 실기: LED 는 광고 중이고 다른 폰에서는
// 잡히는데 이 폰만 못 봤다. 시스템 로그에 근거가 그대로 남는다 —
// `E/BtGatt.GattService: App '...' is scanning too frequently`).
//
// 연결/해제를 빠르게 반복하면 `waitForAdvertThenConnect` 가 매번 스캔을 걸어 네다섯
// 번에 걸린다. OS 가 막기 전에 **앱에서 먼저 막고 남은 시간을 알려 준다** — 막힌 채로
// "광고가 없습니다" 를 보여 주면 사용자가 기기를 의심하게 되고, 실제로 그랬다.
private val SCAN_QUOTA_WINDOW_MS = 30_000L
/** OS 한도는 5 다. 하나를 남겨 둬야 자동 재연결 같은 내부 경로가 굶지 않는다. */
private val SCAN_QUOTA_MAX = 4
/** 최근 스캔 시작 시각 — [SCAN_QUOTA_WINDOW_MS] 안의 것만 들고 있는다. */
private val scanStarts = ArrayDeque<Long>()
/**
* 지금 스캔해도 되는가. 0 이면 가능, 아니면 **남은 대기 ms**.
* 창을 벗어난 기록은 여기서 버린다.
*/
private fun scanQuotaWaitMs(): Long {
val now = System.currentTimeMillis()
while (scanStarts.isNotEmpty() && now - scanStarts.first() > SCAN_QUOTA_WINDOW_MS) {
scanStarts.removeFirst()
}
if (scanStarts.size < SCAN_QUOTA_MAX) return 0L
return SCAN_QUOTA_WINDOW_MS - (now - scanStarts.first())
}
/** 스캔을 실제로 시작했을 때 부른다. */
private fun noteScanStart() {
scanStarts.addLast(System.currentTimeMillis())
}
/**
* 제한에 걸렸으면 사용자에게 알리고 true 를 돌려준다(= 스캔하지 말 것).
* `connectionError` 는 `SCAN_THROTTLED:<남은 초>` 형태다 — 화면이 초를 읽어 쓴다.
*/
private fun blockedByScanQuota(where: String): Boolean {
val wait = scanQuotaWaitMs()
if (wait <= 0L) return false
val sec = (wait / 1000L) + 1L
logw { "scan blocked at $where — quota, ${wait}ms left" }
debugLogger.warn("SCAN_QUOTA at=$where — 스캔 빈도 제한, ${sec}초 뒤 가능")
isScanning.value = false
isConnecting.value = false
connectionError.value = "SCAN_THROTTLED:$sec"
return true
}
fun startScan() {
if (bluetoothAdapter?.isEnabled != true) {
bluetoothEnabled.value = false
return
}
if (blockedByScanQuota("startScan")) return
bluetoothEnabled.value = true
discoveredDevices.clear()
isScanning.value = true
@@ -402,6 +457,7 @@ class BleManager private constructor(private val context: Context) {
try {
bluetoothLeScanner?.startScan(null, settings, scanCallback)
noteScanStart()
logd { "BLE scan started" }
} catch (e: Exception) {
loge { "Failed to start scan: ${e.message}" }
@@ -551,26 +607,42 @@ class BleManager private constructor(private val context: Context) {
private var serviceDiscoveryStarted = false
/**
* 서비스 탐색을 **이 연결에서 한 번만** 시작한다.
* 프로브의 MTU 협상이 지나갈 때까지 서비스 탐색을 늦추는 시간.
*
* ## 왜 필요한가 (2026-09-15 실측으로 원인 확정)
* 프로브가 연결 직후 **자기 쪽에서 MTU 협상을 한 번 더 걸어온다** — 폰의 GATT
* 서버 로그에 `gatts_process_mtu_req: MTU 247 request from remote` 로 찍히고,
* 첫 협상 뒤 **일관되게 약 343ms** 시점이다. 그러면 안드로이드가 `onMtuChanged`
* 를 두 번 전달하고, 탐색을 그 콜백에서 시작하던 이 코드가 `discoverServices()`
* 를 두 번 불렀다. 앞의 탐색이 진행 중인데 다시 부르면 탐색이 끝나지 않고,
* 그 결과가 반쪽 연결이다 — 링크는 붙었는데 `txCharacteristic == null`.
* 프로브는 연결 뒤 **~300ms 시점에 자기 쪽에서 MTU 협상을 건다**(폰 GATT 서버
* 로그의 `gatts_process_mtu_req: MTU 247 request from remote`). 그 ATT 트랜잭션이
* **진행 중인 서비스 탐색을 깨뜨린다** — `onServicesDiscovered` 가 영원히 오지 않고
* 반쪽 연결이 된다. 500ms 를 기다리면 협상이 끝난 뒤에 탐색이 시작되므로 깨질
* 탐색이 없다.
*/
private val DISCOVER_DELAY_MS = 500L
/** 지연 중인 탐색 — 연결이 끊기면 취소한다. */
private var discoverPending: Runnable? = null
/**
* 서비스 탐색을 **이 연결에서 한 번만**, 그리고 [DISCOVER_DELAY_MS] **뒤에** 시작한다.
*
* 실측 상관관계가 깔끔하게 갈린다:
* · `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회였다.
* ## 실측 (2026-09-15 · Xiaomi 23021RAA2Y · VBT2607R300)
* 성공/실패를 가르는 것은 두 번째 `onMtuChanged` 가 **언제** 오는지 하나였다.
* 오늘 9건에 예외가 없었다:
*
* 프로브가 규격을 어기는 것은 아니다(MTU 재협상은 BLE 에서 허용된다). 콜백이 몇
* 번 오든 탐색을 한 번만 시작하는 것은 **중앙 쪽 책임**이라, 펌웨어 배포를 기다리지
* 않고 여기서 막는다.
* 두 번째 콜백 +1~2ms → WATCHDOG_STARTED 3/3
* 두 번째 콜백 +297~342ms → HALF_CONNECTED 6/6
*
* +1ms 는 탐색이 아직 시작도 안 했을 때라 살아남고, +300ms 는 탐색 한가운데라
* 깨진다. 그래서 **중복 호출을 막는 것으로는 고쳐지지 않았다** — 실제로 막아 봤고
* (`DISCOVER_SKIPPED`) 발동한 5회 중 3회가 여전히 반쪽이었다. 깨뜨리는 것은 우리
* 호출이 아니라 프로브의 ATT 요청이고, 그건 앱이 막을 수 없다.
*
* 막을 수 없으니 **피한다** — 협상이 오는 창을 지나서 탐색을 시작한다.
*
* 대가는 연결 완료가 0.5초 늦는 것뿐이고, 실패하면 20초 `armHalfConnectedGuard` 가
* 그대로 잡는다. 464건 전수의 "MTU 2회 → 22.6% 성공" 도 같은 현상을 다른 각도에서
* 본 것이다(docs/FIRMWARE_BLE_FINDINGS.md).
*
* ⚠ 근본 원인은 프로브가 연결 직후 MTU 협상을 거는 것이다. 펌웨어에서 그것을
* 없애거나 연결 직후 즉시 끝내면 이 지연은 필요 없어진다.
*/
private fun discoverServicesOnce(gatt: BluetoothGatt, where: String) {
if (serviceDiscoveryStarted) {
@@ -579,7 +651,24 @@ class BleManager private constructor(private val context: Context) {
return
}
serviceDiscoveryStarted = true
gatt.discoverServices()
val r = Runnable {
discoverPending = null
// 지연 중에 끊겼거나 다른 연결로 바뀌었으면 그만둔다.
if (gatt !== bluetoothGatt) {
handler.post { debugLogger.info("DISCOVER_CANCELLED 연결이 바뀌었습니다") }
return@Runnable
}
handler.post { debugLogger.info("DISCOVER_START at=$where (+${DISCOVER_DELAY_MS}ms)") }
gatt.discoverServices()
}
discoverPending = r
handler.postDelayed(r, DISCOVER_DELAY_MS)
}
/** 지연 중인 탐색을 취소한다 — 연결 정리 경로에서 부른다. */
private fun cancelPendingDiscover() {
discoverPending?.let { handler.removeCallbacks(it) }
discoverPending = null
}
private fun armHalfConnectedGuard(gatt: BluetoothGatt) {
@@ -600,6 +689,7 @@ class BleManager private constructor(private val context: Context) {
rxCharacteristic = null
}
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
isConnecting.value = false
connectionError.value = "HALF_CONNECTED"
@@ -708,6 +798,7 @@ class BleManager private constructor(private val context: Context) {
serialNumber.value = ""
batteryLevel.value = 0
connectedDeviceName.value = ""
cancelPendingDiscover()
isServiceReady.value = false
val idx = discoveredDevices.indexOfFirst { it.address == bleDevice.address }
@@ -766,6 +857,7 @@ class BleManager private constructor(private val context: Context) {
txCharacteristic = null
rxCharacteristic = null
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
isConnecting.value = false
connectionError.value = "Connection timed out. Try again."
@@ -914,6 +1006,10 @@ class BleManager private constructor(private val context: Context) {
return
}
cancelAdvertWait()
// 광고 확인은 스캔이다 — 제한에 걸리면 여기서 멈춘다. 확인 없이 연결하면
// 광고하지 않는 기기에 붙으려다 오류가 나므로(ADVERT_WAIT 를 둔 이유) 그냥
// 기다리게 하는 것이 맞다.
if (blockedByScanQuota("waitForAdvert")) return
isConnecting.value = true
connectionError.value = null
debugLogger.info("ADVERT_WAIT $name ($address) — 광고 확인 후 연결 (최대 ${ADVERT_WAIT_MS}ms)")
@@ -946,6 +1042,7 @@ class BleManager private constructor(private val context: Context) {
.build()
try {
scanner.startScan(filters, settings, cb)
noteScanStart()
} catch (e: Exception) {
logw { "waitForAdvert: startScan 실패 ${e.message} — 확인 없이 연결" }
waitAdvertCallback = null
@@ -1061,6 +1158,7 @@ class BleManager private constructor(private val context: Context) {
txCharacteristic = null
rxCharacteristic = null
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
connectedDeviceName.value = ""
batteryLevel.value = 0
@@ -1115,6 +1213,7 @@ class BleManager private constructor(private val context: Context) {
serialNumber.value = ""
batteryLevel.value = 0
connectedDeviceName.value = ""
cancelPendingDiscover()
isServiceReady.value = false
isReconnecting.value = true
@@ -1695,6 +1794,7 @@ class BleManager private constructor(private val context: Context) {
reason = "watchdog zombie",
)
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
connectedDeviceName.value = ""
onUnexpectedDisconnect?.invoke()
@@ -1719,6 +1819,7 @@ class BleManager private constructor(private val context: Context) {
commandQueue.clear("disconnect")
stopWatchdog()
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
bluetoothGatt?.let { gatt ->
@@ -1790,6 +1891,13 @@ class BleManager private constructor(private val context: Context) {
scheduleAutoReconnect()
return
}
// 제한에 걸렸으면 지금 긁지 않는다 — OS 가 막으면 빈 결과가 와서 "못 찾음" 으로
// 오해하게 된다. 재시도 경로이므로 다음 차례로 넘기면 된다.
if (scanQuotaWaitMs() > 0L) {
debugLogger.warn("SCAN_QUOTA at=reconnect — 스캔을 건너뛰고 다음 시도로")
scheduleAutoReconnect()
return
}
// Stop any previous reconnect scan
reconnectScanCallback?.let {
@@ -1835,6 +1943,7 @@ class BleManager private constructor(private val context: Context) {
txCharacteristic = null
rxCharacteristic = null
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
// 사용자가 끊은 게 아니다 — 계속 되살려야 한다.
scheduleAutoReconnect()
@@ -1849,6 +1958,7 @@ class BleManager private constructor(private val context: Context) {
try {
scanner.startScan(callback)
noteScanStart()
} catch (e: Exception) {
debugLogger.error("RECONNECT_SCAN_FAIL ${e.message}")
scheduleAutoReconnect()
@@ -1912,6 +2022,7 @@ class BleManager private constructor(private val context: Context) {
txCharacteristic = null
rxCharacteristic = null
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
val idx = discoveredDevices.indexOfFirst { it.address == gatt.device.address }
@@ -1962,6 +2073,7 @@ class BleManager private constructor(private val context: Context) {
BluetoothProfile.STATE_CONNECTED -> {
logd { "Connected to ${gatt.device.address}" }
// 새 연결이므로 서비스 탐색을 아직 시작하지 않았다 ([discoverServicesOnce]).
cancelPendingDiscover()
serviceDiscoveryStarted = false
// 반쪽 연결 감시. 링크가 붙은 시점부터 재는 상한이다 —
// connect() 의 타임아웃은 사용자가 시작한 경로에만 걸리므로, 재연결·
@@ -2036,6 +2148,7 @@ class BleManager private constructor(private val context: Context) {
txCharacteristic = null
rxCharacteristic = null
isConnected.value = false
cancelPendingDiscover()
isServiceReady.value = false
connectedDeviceName.value = ""
firmwareVersion.value = ""