Skip to content

MQTTManager: don't let new messages overtake ones buffered while disconnected - #403

Open
jamesmulcahy wants to merge 2 commits into
NSPManager:develfrom
jamesmulcahy:fix/mqtt-reconnect-order
Open

jamesmulcahy wants to merge 2 commits into
NSPManager:develfrom
jamesmulcahy:fix/mqtt-reconnect-order

Conversation

@jamesmulcahy

Copy link
Copy Markdown
Contributor

Problem

Messages published while MQTTManager is disconnected from MQTT are buffered and sent after it reconnects. But publish() started sending live again as soon as the client reported connected. At that point the reconnect still had to replay the retained values and resubscribe to every topic, waiting 5 ms per topic, before it sent the buffer. Anything published in that window went out first, and was then overwritten by an older buffered message.

Seen on a real install:

  1. At startup, a media player published its first state before the first connection. That state only had the player's ID and name, because Home Assistant hadn't answered yet, so it was buffered.
  2. Half a second later the connection came up, and the player's real state was published live.
  3. The reconnect then sent the buffered placeholder, which replaced the real state on the broker.
  4. The manager saw no change to send after that. Panels showed an empty media player, with every control hidden, for about four hours, until something changed in Home Assistant.

The retained replay had a similar problem. It published from a copy taken earlier, through publish(), so it could send an older value after a newer one, and write the older value back into the retain buffer.

Fix

  • is_connected() now also requires that the buffered messages have been sent. Until then, publish() and clear_retain() keep buffering, behind whatever is already waiting.
  • The reconnect sends everything waiting before resubscribing. Under the client lock throughout, it sends the buffer in the order it was published, then the latest value of every retained topic (in case the broker restarted and lost them), and only then resubscribes.
  • Every message handed to Paho goes through a new _send(). In TEST_MODE it can record messages instead of sending them.

Tests

tests/mqtt_reconnect_test.cpp covers four cases:

  • A message published after reconnecting, but before the buffer is sent, waits behind the buffered ones. This is the bug above.
  • Each retained topic ends on its latest value.
  • Buffered non-retained messages keep their order and aren't replayed.
  • Losing the connection buffers again.

Notes

  • This overlaps with the in-progress manager epoch work, which also touches publish() and the end of _reconnect_mqtt_client(). Whichever lands second will need a small rebase.
  • One gap remains, and it's unchanged by this PR. If Paho's automatic reconnect restores the connection before the consumer loop notices it dropped, _reconnect_mqtt_client() doesn't run. Messages published during the drop then stay buffered until the next full reconnect.

🤖 Generated with Claude Code

jamesmulcahy and others added 2 commits October 17, 2026 13:02
…onnected

Messages published while disconnected from MQTT are buffered and sent
after reconnecting. But publish() went back to sending live as soon as
the client reported connected, while the reconnect still had to replay
the retained values and subscribe to every topic (5 ms each) before it
sent the buffer. Anything published in that window went out first and
was then overwritten by an older buffered message.

On a real install, a media player's state published before the first
connection (only its ID and name, as Home Assistant had not answered
yet) was buffered, the real state was published live half a second
later, and the buffered placeholder then replaced it on the broker. The
manager saw no change to send after that, so panels showed an empty
media player for hours.

The retained replay had the same problem: it published from a copy
taken earlier, through publish(), so it could send an older value after
a newer one and write the older value back into the retain buffer.

is_connected() now also requires that the buffered messages have been
sent. Until then publish() and clear_retain() buffer, behind what is
already waiting. After connecting, the buffer is sent in order, then the
latest value of every retained topic, all under the client lock, and
only then are topics subscribed to again.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
ScopedErrorLog pushed its sink onto, and erased it from, the default
logger's sink vector. spdlog does not lock that vector, and every Room
runs a thread that logs for the rest of the run, so a capture starting
or ending while one of those threads logged could reallocate the vector
under it. That crashed a CI run in spdlog::logger::sink_it_, called from
Room::_update_room_state(), between tests.

main() now adds a single dist_sink to the default logger before any test
runs, and ScopedErrorLog adds and removes its sink through that, which
locks its own list.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

// While set, behave as if connected to the MQTT server, but record what would have been sent to it
// rather than sending it. Clearing it behaves as losing the connection.
static void test_set_broker_connected(bool connected) {

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Should the test_* functions not be in a if defnied(TEST_MODE) && TEST_MODE == 1 clause?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

There's an existing #if starting on line 119 which these are also inside -- since the code just above is TEST specific too.

::testing::InitGoogleTest(&argc, argv);
spdlog::set_level(spdlog::level::warn); // Keep test output readable; raise when debugging.
// Before anything starts a thread that logs, see nspm_test::log_capture_sink().
spdlog::default_logger()->sinks().push_back(nspm_test::log_capture_sink());

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Again, should this not be only defined for TEST_MODE?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

tests/ is only added under if(NSPM_BUILD_TESTS), and that's the same option that sets TEST_MODE=1, so main.cpp is never compiled without it.

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.

2 participants