Companion: race condition leads to duplicate message reads #158

New Issue

2026-10-27T09:35:47+01:00

adam commented

2026-10-27 09:35:47 +01:00

I'm running OpenHop Repeater on a machine that occasionally has long IO waits (~seconds) due to higher-priority IO operations running. That slowness may have made a race condition easier to see, because it makes some asynchronous SQLite writes very slow.

The connected TCP client may read the same message twice because it could be read once from the in-memory queue and then again once from the persisted SQLite queue. This is a bug: it should only read that message once.

The _persist_companion_message fires off an async write to SQLite, and only after that await completes, it removes the corresponding in-memory entry with _remove_queue_entry:

https://github.com/openhop-dev/openhop_repeater/blob/13eb8b2ea8b1cdb4a07ed6e282dc99e3aa8a5a8b/repeater/companion/frame_server.py#L128-L135

The _cmd_sync_next_message method checks the in-memory queue, and then the SQLite storage:

https://github.com/openhop-dev/openhop_repeater/blob/13eb8b2ea8b1cdb4a07ed6e282dc99e3aa8a5a8b/repeater/companion/frame_server.py#L187-L195

If _cmd_sync_next_message is called while the SQLite write is in progress (anytime between the start of the async self.sqlite_handler.companion_push_message and the call to _remove_queue_entry), the _cmd_sync_next_message will return the in-memory copy and remove it from the in-memory queue.

When the SQLite write then completes, its _remove_queue_entry successfully no-ops, because it was already popped from the in-memory queue.

However, the bug is that the next call to _cmd_sync_next_message will retrieve the same message from SQLite and hand it to the client again -- even though it was only received once by the companion. That's the duplicate-message read race.

I think https://github.com/openhop-dev/openhop_repeater/pull/470 is in a related space but not the same issue. My issue here has to do with duplicate deliveries under normal conditions. That PR has to do with zero deliveries under TCP client disconnects.

I'm running OpenHop Repeater on a machine that occasionally has long IO waits (~seconds) due to higher-priority IO operations running. That slowness may have made a race condition easier to see, because it makes some asynchronous SQLite writes very slow. The connected TCP client may read the same message **twice** because it could be read once from the in-memory queue and then again once from the persisted SQLite queue. This is a bug: it should only read that message **once**. The `_persist_companion_message` fires off an async write to SQLite, and only after that await completes, it removes the corresponding in-memory entry with `_remove_queue_entry`: https://github.com/openhop-dev/openhop_repeater/blob/13eb8b2ea8b1cdb4a07ed6e282dc99e3aa8a5a8b/repeater/companion/frame_server.py#L128-L135 The `_cmd_sync_next_message` method checks the in-memory queue, and then the SQLite storage: https://github.com/openhop-dev/openhop_repeater/blob/13eb8b2ea8b1cdb4a07ed6e282dc99e3aa8a5a8b/repeater/companion/frame_server.py#L187-L195 If `_cmd_sync_next_message` is called while the SQLite write is in progress (anytime between the start of the async `self.sqlite_handler.companion_push_message` and the call to `_remove_queue_entry`), the `_cmd_sync_next_message` will return the in-memory copy and remove it from the in-memory queue. When the SQLite write then completes, its `_remove_queue_entry` successfully no-ops, because it was already popped from the in-memory queue. However, the bug is that the **next** call to `_cmd_sync_next_message` will retrieve the **same** message from SQLite and hand it to the client again -- even though it was only received once by the companion. That's the duplicate-message read race. ----- I think https://github.com/openhop-dev/openhop_repeater/pull/470 is in a related space but not the same issue. My issue here has to do with **duplicate** deliveries under normal conditions. That PR has to do with **zero** deliveries under TCP client disconnects.

adam commented

2026-11-02 03:26:56 +01:00

@agessaman

@agessaman

adam commented

2026-11-02 03:26:57 +01:00

I'll take a look this evening.

I'll take a look this evening.

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: adam/pyMC_Repeater#158