Skip to content

Survive a serial port that is absent at startup or disappears while running - #85

Open
ssharma0704 wants to merge 4 commits into
flynneva:mainfrom
ssharma0704:fix-startup-race
Open

ssharma0704 wants to merge 4 commits into
flynneva:mainfrom
ssharma0704:fix-startup-race

Conversation

@ssharma0704

@ssharma0704 ssharma0704 commented Sep 28, 2026 •

Copy link
Copy Markdown

The serial device can be briefly absent after boot or a USB re-enumeration, and it can also disappear while the node is running. This PR handles both, and fixes two faults that made the first attempt at it ineffective. All of it is measured on hardware (FT232H bridge, UART, Jetson, Humble); details under each commit.

connect() and main() retry instead of exiting (first commit)

connect() called sys.exit(1) on the first failed open, and main() then referenced node before assignment in its except and finally blocks, masking the real error with an UnboundLocalError. Under a launch file with on_exit=Shutdown() this took the whole stack down and the service restart-looped it.

  • UART connect: retry the serial open for up to 30 s, then raise ConnectionError instead of sys.exit(1).
  • main(): retry node.setup() up to 6 times, 2 s apart, then raise.
  • main(): initialise node to None and guard the except/finally cleanup so a failed startup reports its real cause.

Make that retry actually reach its later attempts (second commit)

Testing the above on hardware showed the retry loop could never succeed, for two independent reasons:

  • setup() began by constructing NodeParameters, which declares all 25 parameters, so attempt 2 onwards always failed with Parameter(s) already declared — and that error also pushed the real cause off the top of the log.
  • SensorService.configure() called sys.exit(1) on the first failed chip-ID read. SystemExit derives from BaseException, so except Exception in the retry loop never saw it and the process left at attempt 1, without retrying at all.

Parameters are now declared once in __init__, configure() raises ConnectionError and lets the caller decide, and the connector and SensorService are constructed once so a later attempt re-runs configure() alone rather than creating a second set of publishers and services.

This matters most straight after a USB re-enumeration: the BNO055 needs about a second after power is restored, and a node that opened the port too early used to die instead of waiting two seconds and asking again.

Measured: against a port that never answers, the node now makes 6 real attempts 2 s apart, each reporting did not answer the chip-ID read: Unexpected length of READ-request response: 0, then exits 1. Before, it exited at attempt 1.

Exit after a run of failed reads instead of publishing nothing (third commit)

This one is a different failure and is separable, so please say if you would rather it came as its own PR.

read_data() caught every exception, logged a warning and returned, so a node whose sensor had gone away stayed alive at the query rate forever, publishing nothing. Nothing escalated, and a supervisor configured to restart on exit cannot help a process that never exits.

It now counts consecutive failed reads and exits 1 after roughly 3 s of them, derived from data_query_frequency so no new parameter is needed. BusOverRunException and ZeroDivisionError keep their early return and deliberately do not count, because "data fusion not ready" is normal on a cold start and must not be mistaken for a missing sensor.

Measured by unbinding ftdi_sio under the running node: reads failed with TransmissionException, the node exited after 3.0 s, and its supervisor had it publishing again 11 s after the port disappeared. Before this commit the topic stayed silent indefinitely. 60 s of normal running produces no spurious exit, so the counter resets correctly on good reads.

Report a run of failed reads as one event (fourth commit)

Also separable; say if you would rather it came on its own.

The commit above is correct but noisy: a sensor that has gone away fails every read until the threshold, which at a 100 Hz query rate meant about 300 near-identical warnings in 3 s, and 403 journal lines for a single event. On a machine whose journal turns over in hours that is noise competing with the evidence.

The first failure, every fiftieth, and the last one before giving up are now reported; the rest are counted silently. The error line and the exit are unchanged, so recovery behaves exactly as before.

Measured on the same hardware by unbinding ftdi_sio under the running node: 7 warnings, at failures 1, 50, 100, 150, 200, 250 and 300, then the same error and the same recovery - one restart, port reset, publishing again. The whole event costs 61 journal lines instead of 403.

A note on data_query_frequency, which may interest you more than these commits

While testing the above I measured this node's actual timing, and the default configuration is worse than it looks. With data_query_frequency: 100 and uart_timeout: 0.1, the timer is asked to fire every 10 ms while each read takes about 20 ms, so the loop never catches up and a single serial read timeout adds its full 100 ms to the next gap instead of being absorbed. Measured on a BNO055 over an FT232H at 115200 baud, stationary and healthy, differencing the publisher's own header stamps over 150 s and 7403 messages: p50 gap 16 ms, p99 128 ms, p99.9 224 ms, worst 720 ms, with 279 gaps over 100 ms. The long gaps are quantised in 100 ms units, which is the uart_timeout value.

Setting data_query_frequency: 40 and uart_timeout: 0.03 gave a worst gap of 96 ms with no gap over 100 ms across 11,636 messages, no failed reads and no restarts, reproduced on a second robot to within 0.1 ms on every percentile. The published rate falls from 49 to 39 Hz and the median gap doubles, which is a good trade for anything fusing the data. For completeness: uart_timeout: 0.02 is too tight and breaks it outright - 6.3 Hz, gaps over 8 s, repeated read failures.

That is a configuration change rather than a code one, so it is not in this PR, but the upstream comment near the timer already warns that "frequencies around 30Hz and above might cause performance impacts" and cites ros2/rclpy#520. The shipped default of 100 is well past that, and it may be worth revisiting the recommended value.

After boot or a USB re-enumeration the serial device can be briefly
absent. connect() called sys.exit(1) on the first failed open, and
main() then referenced node before assignment in the except and
finally blocks, masking the real error with an UnboundLocalError.
Under a launch file with on_exit=Shutdown() this took the whole
stack down and systemd restart-looped it.

- UART connect: retry the serial open for up to 30 s, then raise
  ConnectionError instead of calling sys.exit(1).
- main(): retry node.setup() up to 6 times, 2 s apart, then raise.
- main(): initialise node to None and guard the except/finally
  cleanup so a failed startup reports its real cause.

@github-actions github-actions Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thankyou for creating your first PR! Contributions like yours is what it is all about. Keep it up!

The retry loop added in e8b0a5e could never work. Two reasons, both
measured on hardware:

- setup() began by constructing NodeParameters, which declares all 25
  parameters, so attempt 2 onwards always failed with "Parameter(s)
  already declared" and the real cause scrolled off above five
  misleading errors. Parameters are now declared once in __init__.
- SensorService.configure() called sys.exit(1) on the first failed
  chip-ID read. SystemExit is a BaseException, so "except Exception" in
  the retry loop never saw it and the process left at attempt 1. It now
  raises ConnectionError and lets the caller decide.

A retry must also not build a second set of publishers and services, so
the connector and SensorService are created once and a later attempt
re-runs configure() alone.

This matters most right after the port reset that rover-bno055.service
runs before every start: the BNO055 needs about a second after power is
restored, and a node that opens the port too early used to die instead
of waiting two seconds and asking again.

Verified on a MITI: against a port that never answers the node now makes
6 real attempts 2 s apart, each reporting "did not answer the chip-ID
read", then exits 1 for the service to restart.
read_data() caught every exception, logged a warning and returned, so a
node whose sensor had gone away stayed alive at the query rate forever,
publishing nothing. Nothing escalated, and because Restart=always only
acts when a process exits, the service could not help either: an
external watchdog was the only thing that noticed, 30 to 75 s later.

It now counts consecutive failed reads and exits 1 after about 3 s of
them, derived from data_query_frequency so no new parameter is needed.
BusOverRunException and ZeroDivisionError keep their early return and do
not count, because "data fusion not ready" is normal on a cold start and
must not be mistaken for a missing sensor.

Verified on a MITI by unbinding ftdi_sio under the running node: reads
failed with TransmissionException, the node exited at 300/300 after 3.0 s,
and the service restarted it, reset the port and had the IMU publishing
again 11 s after the port disappeared. The driver was untouched
throughout.
@ssharma0704 ssharma0704 changed the title Retry the UART connect and sensor setup instead of exiting at startup Survive a serial port that is absent at startup or disappears while running Oct 8, 2026
A sensor that goes away fails every read until the threshold, which at
100 Hz meant 300 near-identical warnings in about 3 s and 403 journal
lines for a single event. On a robot whose journal already turns over in
hours, that is noise competing with the evidence.

The first failure, every 50th, and the last one before giving up are
reported; the rest are counted silently. The error line and the exit are
unchanged, so recovery behaves exactly as before.

Verified on a MITI by unbinding ftdi_sio under the running node: 7
warnings at failures 1, 50, 100, 150, 200, 250 and 300, then the same
error and the same recovery - one restart, port reset, publishing again.
The whole event now costs 61 journal lines instead of 403.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant