Record BLE negotiation evidence and retry pre-transfer radio connections

doc/ble_etcp.txt

@@ -232,12 +232,12 @@ tx_limit=1 ограничивает только нашу ll_queue; очеред
 теперь явно указывает отсутствующий Write Without Response/Notification.
 Влияние этих параллельных подключений на скорость отдельно не измерено.
 
-Нужен механизм, ограничивающий нижнюю очередь по фактическому продвижению кадров.
-Вариант для общего BLE-протокола — ограниченное окно кадров с cumulative credits
-от получателя, без возврата DATA к ATT Write Request/Indication. Следует отдельно
-спроектировать таймаут/повтор credit и приоритет control, чтобы само управление
-окном не застревало за DATA. Произвольная задержка между send и смена на AcquireWrite
-не дают гарантии ограниченной очереди. Этот механизм пока не реализован.
+Локальный completion недостаточен для оценки фактического продвижения кадров.
+До изменения wire-протокола необходимо проверять готовность GATT, профиль
+соединения и поведение ETCP при RTT больше секунды. Последующее расследование
+ниже подтвердило ошибки готовности/профиля и воспроизвело очередь без ETCP.
+Произвольная задержка между send и смена на AcquireWrite сами по себе не дают
+гарантии ограниченной очереди. Дополнительный credit-протокол пока не вводился.
 
 Аудит диагностики:
 - Android: ошибки SDK/callback сохраняют status, роль/адрес/link/channel;
@@ -267,3 +267,90 @@ Android BlePeerProbe включает её на время пробы. Ключ
 четыре desktop packet-link/BLE теста и ETCP connect/packet_link/session проходят.
 HCI можно снимать через sudo btmon -w FILE; обычному пользователю monitor запрещён.
 Обычный desktop VibeChat после пробы восстановлен, политика Android восстановлена.
+
+Причина длительного ожидания и исправление входящего HIGH
+---------------------------------------------------------
+Это очередь перед HCI TX, а не единая пауза ожидания PHY negotiation:
+- /tmp/ble-ready-baseline-hci.log: ACL Connected success, MTU517, LL TX/RX=251,
+  PHY TX/RX=2M success до отправки ETCP INIT. Linux central выбрал interval=45ms,
+  latency=0 и supervision timeout=420ms. В этой пробе также был HCI timeout 0x08.
+- В Android HIGH запрашивался только из исходящего BluetoothGatt callback.
+  Входящий GATT server запрашивал 2M, но не connection priority, поэтому Linux
+  central сохранял медленный профиль. PHY2M сам по себе interval не сокращает.
+- /tmp/ble-ready-raw-{hci,desktop}.log: без ETCP и его повторов прошли все 96
+  raw echo; по 45636 байт на направление за 27.585s, суммарно 3309B/s.
+  Все 96 кадров сопоставлены с HCI по seq/длине/отпечатку. Последний исходящий
+  кадр попал в HCI через 26.035s после локального completion, входящие callback
+  следовали за HCI RX через 1..2.7ms. Следовательно, ETCP не является необходимым
+  условием возникновения очереди: стек принимает burst быстрее, чем обслуживает ACL.
+  Контроллер сообщил 6 LE TX-буферов по 251 байту; по Completed Packets они заняты.
+- При изменении interval 45→7.5ms в отдельной пробе частота HCI TX увеличилась
+  примерно в шесть раз. После обновления параметры подтверждены событием
+  LE Connection Update Complete status=0; долговременного pending negotiation нет.
+  hcitool lecup имеет собственные особенности ожидания результата/длины event:
+  вывод команды и её exit недостаточны, согласование проверяется по HCI event.
+- ETCP усиливает перегрузку: INIT вначале повторяется примерно каждые 50ms
+  с padding; DATA RTO ограничен 1s даже при уже измеренном KA RTT=5..6s.
+  В результате повтор может попасть в очередь раньше физической отправки оригинала.
+  Алгоритмы INIT/RTO в этом исправлении не менялись.
+
+Отдельно найден мешающий discovery: D-Bus sender :1.70, PID3047 kdeconnectd,
+каждые 60s устанавливает Transport=bredr. BlueZ объединяет его с нашим Transport=le,
+и контроллер выполняет Inquiry по 10.24s почти непрерывно. Штатное disable-backend
+объявило BluetoothLinkProvider disabled, но не остановило старую discovery-сессию.
+В изолированной пробе потребовался краткий restart KDE Connect с этим backend
+выключенным; отсутствие Inquiry подтверждено HCI до восстановления backend.
+Медленный drain/повторы сохранились и без Inquiry: это дополнительный фактор,
+а не достаточное объяснение всех задержек. Backend KDE Connect затем возвращён
+в enabled; его LAN backend и постоянные настройки Bluetooth не менялись.
+
+Исправления:
+- BlueZ не открывает кешированные UUID до Connected=1 и ServicesResolved=1.
+  После resolve повторно читается snapshot/MTU. Регрессионный private-bus тест
+  с доступным кешем и ServicesResolved=false падал до исправления, теперь проходит;
+  после сигнала resolve используется актуальный MTU517 вместо прежнего MTU23.
+  В аппаратной пробе видны оба snapshot: connected=1/resolved=0, затем resolved=1.
+- Android после первой входящей CCC открывает BluetoothGatt handle к тому же ACL
+  исключительно для requestConnectionPriority(HIGH). У BluetoothGattServer нет
+  соответствующего публичного метода. Новый handle не выполняет discovery/DATA,
+  хранится у входящего Link и закрывается при его teardown. Ошибка настройки
+  логируется WARN и не отменяет работоспособный GATT server.
+- /tmp/ble-ready-priority-fixed-{hci,logcat}.log: incoming HIGH accepted=true;
+  контроллер получил remote request 11.25..15ms, latency=0, timeout=5000ms,
+  Linux ответил success, Update Complete success установил interval=15ms.
+  PHY2M/MTU517 сохранены. Клиентский handle переиспользовал существующий ACL.
+  Ручной HCI настройки и отключения KDE Connect в этой пробе не было.
+- В этой нагрузочной пробе сопоставлены 715 TX кадров: локальный completion→HCI
+  занял до 1.713s вместо ранее измеренных 20..26s. У 684 входящих кадров
+  HCI→callback занял 0.8..2.8ms. Очередь существенно уменьшилась, остаточные
+  задержки и недостаточный для такого RTT RTO требуют отдельной работы.
+  За окно 80s подтверждено 266/512 echo, complete=0, после первого send 70.876s,
+  суммарно 11259B/s. Это неполная нагрузочная проба, не успешные 512/512.
+
+Дополнительные журналы: /tmp/ble-ready-isolated-*, /tmp/ble-ready-quiet-*,
+/tmp/ble-ready-priority-check-*, /tmp/ble-ready-dbus.log.
+Поздние повторения ETCP с HIGH всё ещё нестабильны: 115/128 и 27/128 за разные
+окна; один профиль не устранил проблему ETCP целиком, все такие пробы complete=0.
+
+Чистое радио после HIGH: /tmp/ble-ready-raw-noscan-fresh-* (несмотря на имя файла,
+pauseScan в аргументах этого запуска НЕ было, scanning оставался включённым):
+96/96, по 45636 байт за 4.021s, суммарно 22700B/s. У 96 совпавших исходящих
+кадров очередь до HCI достигала 3.753s: большой burst всё ещё буферизуется.
+/tmp/ble-ready-raw-noscan-valid-*: scanning Android остановлен с явным логом,
+96/96 за 10.620s, суммарно 8594B/s. Остановка scanning не дала ускорения;
+одиночная парная проба не доказывает отсутствие любого его влияния.
+Обе пробы начинались после сброса оставшегося ACL предыдущего теста/GUI.
+Первые две попытки сравнения прервались до передачи с le-connection-abort-by-local
+и не учитываются. Raw probe теперь повторяет discovery после разрыва до первого
+send; разрыв после начала передачи остаётся ошибкой.
+
+Радио-проба умеет выбирать точный node_id, чтобы не подключаться к соседнему
+устройству со старым протоколом:
+  ble_peer_probe connect 80 1657b3ea8281c0a8
+UTUN_TEST_DEBUG=1 включает отпечатки кадров также в raw probe.
+
+Проверки кода: C-ядро, desktop GUI/probes, Android APK/instrumentation arm64/x86_64
+собираются; Android unit tasks, private-bus BlueZ и четыре desktop BLE/packet-link
+теста проходят. Пробы восстанавливают GUI, Android-политику и временное состояние
+KDE Connect. Сборку APK и запуск instrumentation нужно выполнять последовательно:
+одна проба во время установки завершилась Process crashed и не учитывается.

doc/tasks.md

@@ -7,13 +7,22 @@
 [ ] **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.
+    Raw BLE без ETCP также дал очередь до 26 с: 96/96 echo, 3309 B/s; tx_limit ограничивает только свою очередь.
+    Найдены и исправлены преждевременная готовность BlueZ и отсутствие HIGH для incoming Android.
+    HCI подтвердил interval=15ms/timeout=5s/PHY2M; TX-очередь сократилась до 1.713s, но остаточная просадка есть.
+    До изменения BLE-протокола проверить INIT pacing и RTO при RTT >1s; кадры не теряются в сборщике.
+    Дополнительный фактор: KDE Connect запускает непрерывный классический inquiry; он не единственная причина.
     Дополнительно Android повторяет подключения к соседу со старыми GATT DATA-свойствами раз в ~6 с.
     Ошибки Android/JNI/BlueZ/WinRT/ETCP дополнены статусами/контекстом; полный список в диагностике.
     Android central: 512/512 echo и приглашения в обе стороны, суммарный goodput 24897 B/s.
     Результаты, параметры проб и пути диагностических журналов: [ble_etcp.txt](ble_etcp.txt).
 
+[+] **BLE: ждать ServicesResolved и запрашивать HIGH для incoming Android** — 29.10.2026.
+    BlueZ ждёт Connected/ServicesResolved до подписок и перечитывает MTU; регрессия кеша MTU23→517 проходит.
+    Android использует дополнительный BluetoothGatt handle того же ACL только для HIGH, с явным teardown.
+    HCI подтвердил входящий запрос 11.25..15ms и согласование 15ms/latency0/timeout5s без ручной настройки.
+    Desktop и Android собираются, private-bus BlueZ и профильные BLE/packet-link/unit тесты проходят.
+
 [+] **BLE: DATA без ATT ACK и профиль скорости desktop/Android** — 29.10.2026.
     Write Without Response/Notification для DATA в Android/BlueZ/WinRT; INVITE сохраняет Request/Indication.
     Android HIGH/MTU517/2M, Windows ThroughputOptimized с проверкой API и фактическими параметрами.

lib/ble/tests/ble_peer_probe.c

@@ -12,7 +12,7 @@ static struct ble_transport* transport;
 static ble_link_id session;
 static unsigned sent, received_count, blocked;
 static int failed, dial, seen, radio_ready;
-static uint64_t peer, expected_peer, started, verified_bytes;
+static uint64_t peer, expected_peer, started, verified_bytes, retry;
 static const unsigned lengths[] = {1,13,14,20,244,512,1499,1500};
 static unsigned length(unsigned n) { return lengths[n % 8]; }
 static uint8_t probe_byte(unsigned n, unsigned i) { return (uint8_t)(n + i * 37); }
@@ -46,7 +46,13 @@ static void connected(void* arg, ble_link_id id, uint64_t node, enum ble_state s
     (void)arg;
     printf("CONNECTION link=%llu peer=%016llx state=%d reason=%s\n", (unsigned long long)id, (unsigned long long)node, state, reason);
     if (state == BLE_READY) { session = id; peer = node; started = get_time_us(); send_more(NULL, id); }
-    if (state == BLE_CLOSED && received_count < 96) failed = 1;
+    if (state == BLE_CLOSED && received_count < 96) {
+        if (started) failed = 1;
+        else {
+            session = 0; retry = get_time_us() + 1000000;
+            DEBUG_INFO(DEBUG_CATEGORY_DISCOVERY, "BLE probe closed before transfer; retrying discovery");
+        }
+    }
 }
 static void status(void* arg, enum ble_state state, const char* reason) {
     (void)arg; printf("STATUS state=%d reason=%s\n", state, reason);
@@ -63,7 +69,10 @@ static void broadcast(void* arg, const struct ble_endpoint* ep, const uint8_t* d
     if (!seen) printf("DISCOVER node=%016llx name=%s rssi=%d endpoint=%s\n",
         (unsigned long long)identity.node_id, identity.name, rssi, ep->id);
     seen = 1;
-    if (dial && radio_ready && !session) { session = ble_connect(transport, ep, identity.node_id); if (!session) failed = 1; }
+    if (dial && radio_ready && !session && get_time_us() >= retry) {
+        session = ble_connect(transport, ep, identity.node_id);
+        if (!session) { DEBUG_WARN(DEBUG_CATEGORY_DISCOVERY, "BLE probe connect refused; retrying discovery"); retry = get_time_us() + 1000000; }
+    }
 }
 int main(int argc, char** argv) {
     dial = argc < 2 || !strcmp(argv[1], "connect");