From 083495986ec61ed29afe321ad48a450a96824181 Mon Sep 17 00:00:00 2001 From: evgeny Date: Thu, 29 Oct 2026 19:10:13 +0100 Subject: [PATCH] Document HCI queue delays and explain incompatible GATT properties --- doc/ble_etcp.txt | 68 +++++++++++++++++++ doc/tasks.md | 12 ++-- .../main/java/com/utun/chat/data/BleRadio.kt | 17 +++-- 3 files changed, 87 insertions(+), 10 deletions(-) diff --git a/doc/ble_etcp.txt b/doc/ble_etcp.txt index 78d1f985..31dee85d 100644 --- a/doc/ble_etcp.txt +++ b/doc/ble_etcp.txt @@ -199,3 +199,71 @@ BLE ASAN/UBSAN: 3/3; Android app/router unit tests: 770/770. /tmp/ble-speed-desktop-central-serial-live-logcat.log. После аппаратных проб обычный desktop VibeChat перезапущен новой сборкой; Android instrumentation восстановила обычную Bluetooth-политику в finally. + +Диагностика очередей и аудит ошибок 2026-10-29 +--------------------------------------------- +Последующие пробы уточнили причину просадки desktop central. Локальный completion +WriteValue(type=command) означает приём фрагмента стеком, а не его передачу по радио. +tx_limit=1 ограничивает только нашу ll_queue; очередь BlueZ/ядра этим не ограничена. + +Доказательства по журналам, без сравнения часов разных устройств: +- /tmp/ble-errors-final-hci.btsnoop и /tmp/ble-speed-errors-final-desktop.log: + сопоставлены 882 исходящих целых кадра по seq/размеру/FNV-отпечатку ciphertext. + От локального BLE completion до последнего ACL-фрагмента в HCI проходит + 3.548..20.167 с; следовательно, очередь находится перед границей HCI TX. + Для 675 совпавших входящих кадров HCI RX → BLE callback занимает 0.6..32.9 мс, + обычно 1..2 мс. Часовой сдвиг форматов времени исключён по HCI RX/callback. +- ETCP в этой пробе повторяет DATA по RTO=1000000 us, пока исходные кадры + ещё находятся в нижней очереди. Повторные копии увеличивают задержку. + Начальный INIT также повторяется примерно через 50 мс и содержит padding. +- Результат контрольного запуска: 42/128 echo по 1500 байт, window=16, + 63000 подтверждённых байт на направление за 65.730 с после первого send, + complete=0; общий лимит запуска 75 с. drops=0 и missing=0 на BLE-сборщике. +- Более ранний cause-load1: desktop локально завершил 233 кадра, Android получил + только первые 40; обратно завершено 262, получены первые 76. У полученных + кадров совпали размеры/отпечатки, внутренних разрывов нет — отсутствуют хвосты. + Дополнительная задержка относительно первого кадра выросла на 15.982/10.012 с. +- Сбой перемежающийся: отдельная проба desktop central window=1 прошла 32/32 + за 11.148 с, суммарно 8612 B/s. Это не подтверждает устойчивость под нагрузкой. + +В контрольной пробе Android также каждые ~6 с подключался к соседу +4A:2F:B0:6D:A6:35 со старыми свойствами RX=8 (Write), TX=32 (Indicate). +Сервис найден со status=0, но не поддерживает новые DATA-свойства. Причина отказа +теперь явно указывает отсутствующий Write Without Response/Notification. +Влияние этих параллельных подключений на скорость отдельно не измерено. + +Нужен механизм, ограничивающий нижнюю очередь по фактическому продвижению кадров. +Вариант для общего BLE-протокола — ограниченное окно кадров с cumulative credits +от получателя, без возврата DATA к ATT Write Request/Indication. Следует отдельно +спроектировать таймаут/повтор credit и приоритет control, чтобы само управление +окном не застревало за DATA. Произвольная задержка между send и смена на AcquireWrite +не дают гарантии ограниченной очереди. Этот механизм пока не реализован. + +Аудит диагностики: +- Android: ошибки SDK/callback сохраняют status, роль/адрес/link/channel; + отказы CCC сохраняют код API33, MTU — requested/reported/effective; + неожиданные закрытия/отклонённые чтения/записи имеют WARN, потерянный callback + или таймер Handler — ERROR, timeout server writer содержит его состояние. +- JNI: переполнение mailbox содержит generation/capacity/discarded; + поздние события удалённого link видны на TRACE. Тестовые уровни discovery/debug + восстанавливаются при detach и не остаются включёнными после instrumentation. +- BLE common: разрывы последовательности целых кадров учитываются отдельно + как missing; partial/drop не смешивается с ними. Некорректные фрагменты, + замена неполного кадра, отказ allocation и completion имеют контекст ошибки. +- BlueZ: ошибки recv/reply/socketpair сохраняют errno/текст; D-Bus ошибки + сохраняют имя и сообщение. WinRT: HRESULT и ATT_error/status доступны при + WARN, включая discovery/subscription, без необходимости включать DEBUG. +- ETCP: проверяются RNG salt/sc_encrypt и фактические результаты отправки + INIT/keepalive; busy — DEBUG, отказ — WARN/ERROR. Успешный лог называется + submitted, поскольку он не подтверждает доставку получателю. + +Для сопоставления кадров: discovery=debug, debug=trace; для RTO/ACK — etcp=trace, +connection=debug, keepalive=debug. Обычный профиль не включает пофрагментный TRACE. +На desktop UTUN_TEST_DEBUG=1 включает trace диагностической категории; +Android BlePeerProbe включает её на время пробы. Ключи/ссылки приглашений не выводятся. + +Проверки после аудита: C-ядро, desktop GUI/probe, Android APK/instrumentation +для arm64-v8a/x86_64 и WinRT cross-build собираются. BLE transport/identity/BlueZ, +четыре desktop packet-link/BLE теста и ETCP connect/packet_link/session проходят. +HCI можно снимать через sudo btmon -w FILE; обычному пользователю monitor запрещён. +Обычный desktop VibeChat после пробы восстановлен, политика Android восстановлена. diff --git a/doc/tasks.md b/doc/tasks.md index 5cc7c6d2..4163074e 100644 --- a/doc/tasks.md +++ b/doc/tasks.md @@ -4,11 +4,13 @@ ## Текущие задачи -[ ] **BLE/ETCP: повторные INIT и отсутствие DATA ACK при desktop central** — 29.10.2026. - После включения Write Without Response/Notification GATT/MTU517 и PHY2M работают, - но desktop central подтвердил 20/512 echo за 85 с; повтор window=1 — 0/32 за 65 с. - На desktop повторяются INIT/INIT_RESPONSE и DATA RTO с DATA_RTT_us=0; - BLE-сборщик не регистрирует потерь фрагментов. Точная причина не установлена. +[ ] **BLE/ETCP: ограничить очередь ниже локального completion Write Without Response** — 29.10.2026. + HCI и desktop trace: 882 кадра совпали по seq/размеру/отпечатку, но local completion → HCI TX + занимает 3.548..20.167 с. ETCP RTO ограничен 1 с и повторяет ещё не переданные кадры. + tx_limit=1 ограничивает только нашу очередь. Контроль: 42/128 echo за окно 75 с, drops=missing=0. + Нужен контроль объёма кадров в нижней очереди; вариант — ограниченное окно/credits общего BLE. + Дополнительно Android повторяет подключения к соседу со старыми GATT DATA-свойствами раз в ~6 с. + Ошибки Android/JNI/BlueZ/WinRT/ETCP дополнены статусами/контекстом; полный список в диагностике. Android central: 512/512 echo и приглашения в обе стороны, суммарный goodput 24897 B/s. Результаты, параметры проб и пути диагностических журналов: [ble_etcp.txt](ble_etcp.txt). diff --git a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/BleRadio.kt b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/BleRadio.kt index 90260ac0..9672725a 100644 --- a/tools/chatgui-android/app/src/main/java/com/utun/chat/data/BleRadio.kt +++ b/tools/chatgui-android/app/src/main/java/com/utun/chat/data/BleRadio.kt @@ -339,11 +339,18 @@ object BleRadio { link.invite = service?.getCharacteristic(inviteUuid) log("DEBUG", "Client discovery link=$token status=$status service=${service != null} " + "rx_properties=${link.rx?.properties} tx_properties=${characteristic?.properties} invite_properties=${link.invite?.properties}") - if (status != 0 || ccc == null || link.rx == null || link.invite == null || - link.rx!!.properties and BluetoothGattCharacteristic.PROPERTY_WRITE_NO_RESPONSE == 0 || - characteristic.properties and BluetoothGattCharacteristic.PROPERTY_NOTIFY == 0 || - !gatt.setCharacteristicNotification(characteristic, true)) { - close(link, "service discovery/subscription failed status=$status"); return@dispatch + if (status != 0 || ccc == null || link.rx == null || link.invite == null) { + close(link, "service discovery failed status=$status service=${service != null} CCC=${ccc != null} " + + "RX=${link.rx != null} INVITE=${link.invite != null}"); return@dispatch + } + if (link.rx!!.properties and BluetoothGattCharacteristic.PROPERTY_WRITE_NO_RESPONSE == 0) { + close(link, "RX lacks Write Without Response properties=${link.rx!!.properties}"); return@dispatch + } + if (characteristic.properties and BluetoothGattCharacteristic.PROPERTY_NOTIFY == 0) { + close(link, "TX lacks Notification properties=${characteristic.properties}"); return@dispatch + } + if (!gatt.setCharacteristicNotification(characteristic, true)) { + close(link, "DATA local subscription refused characteristic=${characteristic.uuid}"); return@dispatch } log("INFO", "Client DATA configured link=$token write=without_response receive=notification mtu=${link.mtu}") val result = if (Build.VERSION.SDK_INT >= 33) gatt.writeDescriptor(ccc, BluetoothGattDescriptor.ENABLE_NOTIFICATION_VALUE)