fix: read serial frames by wb-mqtt-serial's timeouts, not the JS reply timeout - #98
Merged
Merged
Conversation
… timeout TWASMPort::ReadFrame now follows the TPort contract the way TFileDescriptorPort does: responseTimeout to the first byte, frameTimeout between bytes, frame_complete returning the answer as soon as it is assembled — instead of waiting out serial.js's 250 ms reply timeout on every read. serial.js grows readChunk() with a pending buffer and a bounded drain, stops reopening the USB port on every write (and heals a dead port on the next one), fails fast in open() when the browser has no WebSerial API, and treats a gesture-refused requestPort() as terminal. A timed-out read throws plain runtime_error, deliberately not the TPort-contract TResponseTimeoutException: the transient type sends wb-mqtt-serial's device-session retries under Asyncify into a recursion that crashed the renderer (reproduced and bisected on module builds). Measured on hardware (see #96): one Modbus exchange ~280 ms -> ~12 ms, a bus scan ~20 s -> 4.5 s. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
CI's chromium exposes WebSerial even headless, so the first device access fell through to requestPort() without a user gesture and killed the page; disable Serial/WebUSB so every environment behaves like the specs assume, and give the Pyodide-heavy specs more than Docker's 64 MB /dev/shm. Jenkins keeps Playwright traces of failed runs — locally the suite passes everywhere, so the trace is the only witness. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…port
Two defects found in review, both on the paths this branch makes more
resilient:
- write() rethrew a failed write. Asyncify.handleAsync attaches no catch,
so the rejection left the C++ call suspended forever: the page hung
with no error, and the writer's lock was never released either.
- open() only closed the port when isOpen was set, but every failure path
clears that flag without closing. Chrome then rejected open() on a port
whose state was still 'opened', select() handed back the same object,
and the port stayed dead until a page reload.
Also: the firmware extendedTimeout floor no longer applies to
discardPending's short drain reads (it stretched each SkipNoise to the
reply timeout, seconds per firmware operation), and the e2e launch flags
moved to the top-level use{} so the opt-in system-chrome project
inherits them.
Measured on the bench after the fix: one Modbus exchange 9 ms median,
bus scan 4.5 s.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
evgeny-boger
added a commit
that referenced
this pull request
Sep 1, 2026
Mirrors the two review fixes so this branch and #98 keep identical port sources: write() no longer rejects into Asyncify (which suspended the C++ call forever) and releases its lock in a finally, and open() closes the port object instead of trusting the isOpen flag, which every failure path clears without closing. Also drops the firmware timeout floor from drain reads and hoists the e2e launch flags to top-level use{}. Comments trimmed to a line or two while here. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
evgeny-boger
changed the title
sw-slow-network.spec.ts fails about one run in three on the CI runner at the server's 5000 ms delay -- the SW timeout did not fire and the page came from the network. Retries make it report as `flaky` rather than reddening the whole build while the timeout is investigated. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01BNC4oayJWjJaHMmvM8YMGC
Opening a second device right after the first killed the whole WASM module with "Aborted(RuntimeError: unreachable)", and every request after that was dead. Reproduced on the bench in five seconds: scan, open WB-MSW @64, switch to WB-MR6C @46 while it loads. Asyncify.handleAsync runs the EM_ASM body twice — once on the unwind pass, where handleSleep has no reply yet and returns the value of the PREVIOUS wakeUp, and again on the rewind pass with this call's reply. ReadChunk in wasm_port.cpp copies whatever it gets with no length check: let result = Asyncify.handleAsync(async() => await Module.serial.readChunk($1, $2)); if (!(result instanceof Uint8Array) || result.length == 0) return 0; Module.HEAPU8.set(result, $0); So any read whose buffer is shorter than the previous chunk overflows the heap, and ReadFrame produces that shape constantly: a 129-byte reply arrives as 109 bytes, the next ReadChunk asks for the remaining 20, and 109 stale bytes go into a 20-byte tail. The 89-byte overrun landed on the Asyncify data block malloc had just handed to that very suspension, zeroed its stack_ptr and stack_limit (the stale bytes were a device name padded with NULs), and asyncify_stop_unwind trapped on its bounds check — the "unreachable". Clearing Asyncify.handleSleepReturnValue as the C++ caller suspends makes the unwind pass return 0, so ReadChunk copies nothing until the real reply is there. The proper fix belongs in ReadChunk (`result.length > $1` must return 0), but the module cannot be rebuilt from this side. The rest makes the layer's other Asyncify invariant structural. handleAsync is `startAsync => handleSleep(async wakeUp => wakeUp(await startAsync()))` with no catch: a rejecting Module.serial method leaves the C++ call suspended for good, and a hanging one lets a late wakeUp rewind a stack that has moved on. readChunk, write, discardPending, open, close and setOptions now catch everything and resolve to their neutral value; getReader()/getWriter() moved inside the try, where a locked stream marks the port dead so the next request reopens it; the reader and writer are tracked so open() can give the locks back; and port.close(), reader.cancel() and writer.abort() are bounded, so a wedged USB call fails the request instead of hanging the module forever. Verified on the bench: the crashing sequence now loads both devices, all four devices open with no leaked stream locks, one Modbus exchange still costs 9 ms (min 9, max 13) and a scan 4.5 s. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01BNC4oayJWjJaHMmvM8YMGC
Emscripten runs an EM_ASM body that contains Asyncify.handleAsync twice: once on the unwind pass, where handleAsync returns Asyncify.handleSleepReturnValue — the value the PREVIOUS wakeUp delivered, i.e. the previous call's chunk — and once on the rewind pass with this call's real reply. ReadChunk did its work outside that callback, so on the unwind pass it copied the previous chunk into a buffer sized for this one. The guard rejected only a non-Uint8Array, never a length mismatch, and at every frame boundary the new buffer is the shorter one: 109 stale bytes into a 20-byte tail read overran the heap into the Asyncify data block malloc had just handed to this very suspension and zeroed its header, after which asyncify_stop_unwind trapped with RuntimeError: unreachable. Reproduced on the bench: scan, open a device tab, then switch to the next one while the first is still loading — the renderer aborts within seconds. With this change the same repro survives, both pages load, and so does every other device tab. Everything ReadChunk does now happens inside the callback, which runs exactly once, on the real reply. A reply longer than the buffer returns 0 instead of a truncating copy: serial.js already caps readChunk at count, so a longer array is a broken contract and must not be written. serial.js keeps clearing Asyncify.handleSleepReturnValue before it suspends. That guard leans on an Emscripten internal, so it is not the fix, but it is what protects a page served against an older module build. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01BNC4oayJWjJaHMmvM8YMGC
readChunk took a fresh reader for every call, raced it against a setTimeout and, when the timeout won, awaited reader.cancel() before releasing the lock. Two things were wrong with that. Chrome clamps every timer in a hidden tab to one second. The 5 ms drain read SkipNoise does before each exchange therefore cost a full second, twice per request, while the Modbus exchanges inside took 3-9 ms: a portLoad to a device that answers took 2000 ms flat, and a scan of the four-device bench line took 48.1 s. The same code in a visible tab, on the same adapter, took 14 ms and 4.5 s. This was never adapter-dependent, and reader.cancel() settles in 0 ms here. Cancelling also discards whatever the port had already buffered, so a reply landing just after a drain timed out was thrown away mid-frame. The port now keeps one reader and one outstanding read(). readChunk races that read against its timeout and, when the timeout wins, simply stops waiting: the read stays in flight and its bytes land in pending for the next call, so none are lost and none are read twice. discardPending drops what has already arrived and yields a task turn instead of arming a timer, which costs nothing in either kind of tab. close() and reopen cancel the reader once, bounded at 200 ms. Bench, WB-MSW at 115200 8N2, tab hidden: portLoad median 2000 -> 1000 ms with this commit alone, the serial layer down to 3 ms of the request. The second that is left is the RPC wait loop, fixed in the next commit; the scan of the bench line still took 48.3 s until then. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01BNC4oayJWjJaHMmvM8YMGC
_doRequest waited for the WASM call by re-arming setTimeout(check, 1). Chrome clamps timers in a hidden tab to one second, so every request paid an extra second after its work had already finished: with the serial layer down to 3 ms of actual exchange, portLoad still took 1000 ms. The reply path resolves the waiter directly now. The RPC timeout stays as a single timer that only fires when the call really is stuck, and a call that finished without ever suspending is still handled. Bench, WB-MSW at 115200 8N2, tab hidden: portLoad median 1000 -> 5 ms, scan 48.1 -> 23.1 s against the 2000 ms and 48.1 s this pair started from. Tab visible: 14 -> 4 ms, scan 4.5 -> 4.3 s. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01BNC4oayJWjJaHMmvM8YMGC
…out type
Three follow-ups from the review of the frame-timeout work.
1. GetSendTimeBytes / GetSendTimeBits now round up exactly as TSerialPort does
(src/port/serial_port.cpp:217-230): bits-per-byte times bytes, and
bits * 1e6 / baud, both ceil'd. The old "+ 0.5" rounding and the integer
division truncated instead, under-estimating the send time and so shortening
every frame timeout derived from it, RpcPortScan::TRegisterReader among them.
At 115200 8N2 one byte came out as 95 us instead of 96, and a 3.5-byte gap as
338 us instead of 339. The divisor stays guarded: unlike TSerialPort's, these
settings arrive in a request rather than from an already-open port.
2. ReadByte throws TSerialDeviceTransientErrorException("timeout") on timeout,
the type TFileDescriptorPort::ReadByte uses (file_descriptor_port.cpp:102).
TSerialDeviceException derives from std::runtime_error and not the other way
round, so the plain runtime_error thrown before escaped every
catch (const TSerialDeviceException&) in the drivers. The Uniel device is the
only ReadByte caller.
3. ResetSerialPortSettings still carried a comment claiming there was nothing to
restore, which stopped being true once Settings was cached in C++. Only the
comment changed. The behaviour is deliberately left alone: unlike TSerialPort
(serial_port.cpp:212-215) this port has no InitialSettings to restore to,
because Settings only ever holds what the last request asked for.
ReadFrame keeps throwing a plain std::runtime_error on timeout on purpose. The
transient TResponseTimeoutException is retried by wb-mqtt-serial in a way that
recursed under Asyncify and killed the renderer with a native stack overflow.
The price of that choice is that every catch (TResponseTimeoutException) site is
dead code for this port:
src/rpc/rpc_helpers.cpp:77 RPC register read retry
src/rpc/rpc_helpers.cpp:119 RPC register write retry
src/rpc/rpc_helpers.cpp:135 SetContinuousRead warning
src/rpc/rpc_device_load_config_task.cpp:21 friendly TRPCException conversion
src/rpc/rpc_port_scan_serial_client_task.cpp:172 GetDeviceDetails SN read
src/rpc/rpc_port_load_modbus_serial_client_task.cpp:115 E_RPC_REQUEST_TIMEOUT reply
src/rpc/rpc_fw_get_firmware_info_task.cpp:42 firmware info probe
src/rpc/rpc_fw_update_serial_client_task.cpp:78 firmware update
src/rpc/rpc_fw_update_task.cpp:77 firmware update retry
src/rpc/rpc_fw_update_task.cpp:359 firmware update error report
src/rpc/rpc_fw_restore_task.cpp:110 firmware restore
src/modbus_base.cpp:199 ForceFrameTimeout extra-data drain
src/modbus_ext_common.cpp:650 Fast Modbus ScanStart probe
src/serial_client_events_reader.cpp:319 EnableEvents, the crash path
Those callers see the port's timeout as a plain runtime_error instead, and
port/Load reports the field-known "Port IO error: request timed out".
Verified on the WB-DALI bench over a visible tab (WB-MSW 64, WB-MR6C 46,
WB-MAP3E 35, WB-MDM3 57, all at 115200 8N2):
one portLoad to slave 64 median 5 ms over 10 (min 4, max 5)
scan of the line all four devices found, 4.6 s
all 10 device tabs opened 492 console lines, no Aborted(, no errors
crash repro tab 0 -> tab 1 clean, no Aborted( in 180 s
wasm/public/module.wasm md5 5f910094b741b6e3eff7e0d6626cd497
npm test 30 tests in 6 files, green
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01BNC4oayJWjJaHMmvM8YMGC
evgeny-boger
marked this pull request as ready for review
September 2, 2026 21:27
At 9600 a 51-byte reply needs 58 ms on the wire while the scan asks for a 5 ms timeout, so frames were cut in half and their tails read as the next answer. The receive path is now dropped before every write: the tail sits in the port's stream, not in pending.
50 commits, f9474943..a8ac2ec3. rpc_config_handler now takes the group names and MakeDeviceTypeJson from the new rpc_device_type_json.cpp, so it joins the build.
u236
approved these changes
Sep 3, 2026
Member
Author
|
Написано иишечкой (Claude Code). Прогон на стенде 2026-09-03, сборка Проблема на 9600 — воспроизведена и закрыта
|
2c0b1d1 |
3a8ce38 (до фикса) |
|
|---|---|---|
| самое длинное рабочее чтение | 125 регистров (255 Б, 292 мс на проводе) | 60 регистров; 100 и 125 падают всегда |
| 20× чтение длинного блока | 20/20, медиана 311 мс | 18/20, 2 CRC-ошибки |
| скан | все 4 за 9,2 с | найдено 3 из 4 + unhandledrejection |
| страницы устройств | 1,0–2,1 с | зависали по ~300 с, 0 записей в порт |
Механизм: до фикса ReadFrame после первого чанка ждал каждый следующий не дольше max(frameTimeout, 25 мс); на 9600 ответ приходит USB-пачками с паузами больше 25 мс — кадр обрывался, CRC не сходился. Зависит от длины кадра: короткие чтения работали, страницы устройств — нет. Новый бюджет «30 мс + время кадра на проводе, не более 500 мс» на 255-байтный ответ (292 мс) размерен верно.
Все скорости, все устройства
Обмен (10× чтение reg 110, медиана; ошибок 0 на всех скоростях):
| baud | MSW @64 | MR6C @46 | MAP3E @35 | MDM3 @57 |
|---|---|---|---|---|
| 9600 | 26 мс | 26 мс | 25,5 мс | 26 мс |
| 19200 | 16 | 15 | 14 | 14 |
| 38400 | 8 | 8 | 8 | 8 |
| 57600 | 6 | 6 | 6 | 7 |
| 115200 | 4 | 4 | 4 | 4 |
Скан и страницы (все четыре найдены на каждой скорости, консоль без ошибок):
| baud | скан | MSW | MR6C | MAP3E | MDM3 | Reload parameters |
|---|---|---|---|---|---|---|
| 9600 | 9,2 с | 1,0 с | 2,1 с | 1,0 с | 1,6 с | 2,0 с |
| 19200 | 8,4 с | 0,5 | 1,5 | 0,5 | 1,0 | 1,0 |
| 38400 | 8,2 с | 0,5 | 1,0 | 0,5 | 0,5 | 0,5 |
| 57600 | 8,2 с | 0,5 | 0,5 | 0,5 | 0,5 | 0,5 |
| 115200 | 7,9 с | 0,5 | 0,5 | 0,5 | 0,5 | 0,5 |
Смесь скоростей на одной линии и паритеты
MSW@9600, MR6C@19200, MAP3E@57600, MDM3@115200: скан 8,1 с, все четыре найдены; страницы 1,0/1,5/0,5/0,5 с; 5 чередований страниц 9600↔115200 — 10/10 без ошибок; быстрое открытие всех четырёх подряд — без Aborted(.
MSW @64 на 9600: 8N1, 8E1, 8O1, 8E2, 8N2 — обмен 26–28 мс 10/10, скан 8,9–9,3 с, страница 1–2 с, ошибок нет.
Точечные проверки
- Неубранный поздний ответ: 25 чужих байт оставлены в буфере, затем обычный запрос к другому slave — 10/10 верных ответов (
discardPendingперед записью работает). - Неотвеченный запрос стоит ~503 мс независимо от запрошенной длины (1/10/60/125 регистров) — цикл выходит на первом пустом чтении.
- Переоткрытие порта на каждой смене настроек (8N2↔8N1 на каждом запросе): 20/20, +7 мс, байты не теряются.
- Открытие второго устройства во время загрузки первого — без
Aborted(RuntimeError: unreachable); снятый JS-guardhandleSleepReturnValueне понадобился, C++-сторона держит.
Устройства возвращены на исходные 115200 8N2 (проверено чтением регистров 110–112), финальный скан 4/4.
Замечание по стенду: до прогона на линии сидел второй Modbus-мастер (wb-mqtt-serial, 39 % занятости провода) — давал 23 % CRC-ошибок и на 9600 выглядит ровно как баг таймаутов; матрица снята после его отключения.
🤖 Generated with Claude Code
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Порт-слой WASM-редактора не соблюдал таймауты wb-mqtt-serial: каждое чтение ждало весь 250-мс JS-таймаут ответа, порт переоткрывался на каждую запись. Отсюда ~280 мс на любой Modbus-обмен, скан ~20 с, страница DALI-устройства — минуты. SOFT-7421.
wasm/src/wasm_port.cppReadFrameследует контрактуTPort: responseTimeout — до первого байта, frameTimeout — на паузу между байтами, предикат «кадр собран» отдаёт ответ сразу; полы 30/25 мс заложены под латентность WebSerial.ReadChunkдержит все побочные эффекты внутри async-колбэкаAsyncify.handleAsyncи проверяет длину. ТелоEM_ASMисполняется дважды, и на unwind-проходеhandleAsyncвозвращает значение предыдущегоwakeUp; копирование этого чужого чанка в более короткий буфер затирало блок данных Asyncify — отсюдаRuntimeError: unreachableпри открытии второго устройства во время загрузки первого.Таймаут
ReadFrameбросаетstd::runtime_error, а неTResponseTimeoutException, — намеренно: retry-путь транзиентного типа под Asyncify уходил в рекурсию и ронял рендерер. Цена: 14catch (TResponseTimeoutException)в wb-mqtt-serial (RPC-ретраи чтения регистров,GetDeviceDetailsпри скане и др.) для этого порта мертвы.ReadByteбросаетTSerialDeviceTransientErrorException, какTFileDescriptorPort;GetSendTimeBytes/Bitsсчитают черезstd::ceil, какTSerialPort.wasm/public/serial.jsОдин долгоживущий reader на открытый порт и одно чтение в полёте: таймаут просто перестаёт ждать, поздние байты ложатся в
pendingдля следующего вызова — безcancel()на каждое чтение и без потери байтов на границе кадра; дренаж без таймеров, тиком черезMessageChannel. Порт переоткрывается только при смене настроек или смерти.Инвариант: ни один метод, который ждёт C++ через
Asyncify.handleAsync, не отклоняет промис — иначе C++-вызов подвисает навсегда.write/readChunk/discardPending/open/close/setOptionsловят всё, локи освобождаются вfinally,open()закрывает объект порта, а не полагается на флаг. Без WebSerial APIopen()падает сразу;requestPortбез жеста — терминально;Asyncify.handleSleepReturnValueсбрасывается перед suspend как страховка для старых сборок модуля.wasm/public/script.jsОжидание ответа WASM резолвится по самому ответу, а не 1-мс опросом
setTimeout: в фоновой вкладке Chrome клампит таймеры до 1 с, и каждый запрос стоил 2 с.e2e/CI
В CI-chromium отключены WebSerial/WebUSB (иначе первый доступ уходит в
requestPort()без жеста и убивает страницу) и--disable-dev-shm-usage— на верхнем уровнеuse{}. Добавленыretries: CI ? 2 : 0и сохранение с архивацией трейсов упавших прогонов.Цифры
Реальные устройства на стенде, видимая вкладка: обмен ~280 мс → 4–9 мс медиана, скан 4 устройств ~20 с → 4,3–4,6 с, страница устройства — секунды. Фоновая вкладка: запрос 2000 мс → 5 мс, скан 48 → 23 с (остаток — таймаут ответа, который тоже клампится до 1 с; без busy-wait не убрать).
Как проверить вручную
CI-сборка PR, адаптер с несколькими Modbus-устройствами:
Aborted(RuntimeError: unreachable)в консоли нет, обе страницы открываются.Известные ограничения (не в этом PR)
Чужой лок потока WebSerial (другая вкладка или расширение) не снимается до перезагрузки страницы: запросы падают честно, но медленно.
SkipNoiseне эскалирует при непрерывном шуме.🤖 Generated with Claude Code
https://claude.ai/code/session_01BNC4oayJWjJaHMmvM8YMGC