adam/meshcore-mqtt
1
0 Fork 0
mirror of https://github.com/ipnet-mesh/meshcore-mqtt.git synced 2026-10-31 03:02:06 +01:00
Code Issues 8 Packages Projects Releases Wiki Activity

ACK received but not recognised? #5

New Issue
Closed
opened 2026-10-05 06:08:42 +02:00 by adam · 2 comments
adam commented 2026-10-05 06:08:42 +02:00
Owner
Copy link
Copy source

The send with retry results in the message being received by the recipient 3 times (as configured in config.json).

Below is the debug log. It seems meshcore library returns the ACK but the bridge does not see it.

2025-10-15 12:05:06,963 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Received PUBLISH (d0, q0, r0, m0), 'meshcore/command/send_msg', ...  (112 bytes)
2025-10-15 12:05:06,964 - meshcore_mqtt.mqtt_worker - INFO - Received MQTT command: send_msg = {"destination":"af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f","message":"Remote alert test"}
2025-10-15 12:05:06,964 - meshcore_mqtt.message_queue.meshcore - DEBUG - Queued mqtt_command from mqtt to meshcore (id: 12532af1)
2025-10-15 12:05:12,090 - meshcore_mqtt.bridge_coordinator - WARNING - Timeout waiting for MQTT connection after 30.0s, proceeding with MeshCore startup
2025-10-15 12:05:12,091 - meshcore_mqtt.bridge_coordinator - INFO - Starting MeshCore worker...
2025-10-15 12:05:12,091 - meshcore_mqtt.bridge_coordinator - INFO - Bridge coordinator started successfully
2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Starting MeshCore worker
2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Setting up MeshCore connection
2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Setting up MeshCore event subscriptions
2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: CONNECTED
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: LOGIN_SUCCESS
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: CONTACT_MSG_RECV
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: BATTERY
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: NEW_CONTACT
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: ADVERTISEMENT
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: DISCONNECTED
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: DEVICE_INFO
2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: CHANNEL_MSG_RECV
2025-10-15 12:05:12,093 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: LOGIN_FAILED
2025-10-15 12:05:12,093 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to NO_MORE_MSGS event for auto-fetch management
2025-10-15 12:05:12,093 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to ACK event for message acknowledgements
2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - Starting coordinator monitoring
2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - === Bridge System Status ===
2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - Total components: 2
2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - MESHCORE: starting | Queue: 1/1000 | Dropped: 0
2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - MQTT: running | Queue: 0/1000 | Dropped: 0
2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - ========================
2025-10-15 12:05:12,165 - meshcore - DEBUG - port opened
2025-10-15 12:05:12,184 - meshcore - INFO - Serial Connection started
2025-10-15 12:05:12,185 - meshcore - DEBUG - Connected successfully: /dev/Daisy
2025-10-15 12:05:12,185 - meshcore - DEBUG - Connected successfully: /dev/Daisy
2025-10-15 12:05:12,185 - meshcore - DEBUG - Sending appstart command
2025-10-15 12:05:12,185 - meshcore - DEBUG - Sending raw data: bytearray(b'\x01\x03      mccli')
2025-10-15 12:05:12,185 - meshcore - DEBUG - sending pkt : b'<\r\x00\x01\x03      mccli'
2025-10-15 12:05:12,185 - meshcore - DEBUG - Waiting for events [<EventType.SELF_INFO: 'self_info'>], timeout=5
2025-10-15 12:05:12,186 - meshcore - DEBUG - Dispatching event: EventType.CONNECTED, {'connection_info': '/dev/Daisy'}, {}
2025-10-15 12:05:12,186 - meshcore_mqtt.meshcore_worker - INFO - MeshCore CONNECTED event received: Event(type=<EventType.CONNECTED: 'connected'>, payload={'connection_info': '/dev/Daisy'}, attributes={})
2025-10-15 12:05:12,186 - meshcore_mqtt.message_queue.mqtt - DEBUG - Queued meshcore_event from meshcore to mqtt (id: e080c848)
2025-10-15 12:05:12,187 - meshcore_mqtt.message_queue.mqtt - DEBUG - Dequeued meshcore_event from meshcore to mqtt (id: e080c848)
2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - Processing message: meshcore_event
2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - Publishing MeshCore event to MQTT topic: meshcore/events/connection
2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - Publishing to MQTT: topic=meshcore/events/connection, qos=1, retain=False, payload_length=95
2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Sending PUBLISH (d0, q1, r0, m2), 'b'meshcore/events/connection'', ... (95 bytes)
2025-10-15 12:05:12,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Received PUBACK (Mid: 2)
2025-10-15 12:05:12,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT message published: 2
2025-10-15 12:05:12,189 - meshcore_mqtt.mqtt_worker - DEBUG - Published MeshCore event to MQTT: meshcore/events/connection
2025-10-15 12:05:17,186 - meshcore_mqtt.meshcore_worker - INFO - Connected to MeshCore device
2025-10-15 12:05:17,186 - meshcore_mqtt.meshcore_worker - DEBUG - Cleared message deduplication cache for fresh connection
2025-10-15 12:05:17,187 - meshcore_mqtt.message_queue - INFO - Component meshcore: starting -> connected
2025-10-15 12:05:17,187 - meshcore_mqtt.message_queue.mqtt - DEBUG - Queued meshcore_status from meshcore to mqtt (id: c77727ed)
2025-10-15 12:05:17,187 - meshcore - DEBUG - Requesting pending messages
2025-10-15 12:05:17,187 - meshcore - DEBUG - Sending raw data: 0a
2025-10-15 12:05:17,187 - meshcore - DEBUG - sending pkt : b'<\x01\x00\n'
2025-10-15 12:05:17,187 - meshcore - DEBUG - Waiting for events [<EventType.CONTACT_MSG_RECV: 'contact_message'>, <EventType.CHANNEL_MSG_RECV: 'channel_message'>, <EventType.ERROR: 'command_error'>, <EventType.NO_MORE_MSGS: 'no_more_messages'>], timeout=5
2025-10-15 12:05:17,188 - meshcore_mqtt.message_queue.mqtt - DEBUG - Dequeued meshcore_status from meshcore to mqtt (id: c77727ed)
2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - DEBUG - Processing message: meshcore_status
2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - INFO - MeshCore status update: connected - connected
2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - DEBUG - Publishing to MQTT: topic=meshcore/status, qos=1, retain=True, payload_length=9
2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Sending PUBLISH (d0, q1, r1, m3), 'b'meshcore/status'', ... (9 bytes)
2025-10-15 12:05:17,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Received PUBACK (Mid: 3)
2025-10-15 12:05:17,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT message published: 3
2025-10-15 12:05:17,191 - meshcore - DEBUG - Received data: 0a
2025-10-15 12:05:17,192 - meshcore - DEBUG - Dispatching event: EventType.NO_MORE_MSGS, {'messages_available': False}, {}
2025-10-15 12:05:17,192 - meshcore_mqtt.meshcore_worker - DEBUG - Received NO_MORE_MSGS event: Event(type=<EventType.NO_MORE_MSGS: 'no_more_messages'>, payload={'messages_available': False}, attributes={})
2025-10-15 12:05:17,192 - meshcore_mqtt.meshcore_worker - INFO - Started auto message fetching
2025-10-15 12:05:17,192 - meshcore_mqtt.message_queue - INFO - Component meshcore: connected -> running
2025-10-15 12:05:17,192 - meshcore_mqtt.meshcore_worker - INFO - MeshCore worker started successfully
2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Starting MeshCore message processor
2025-10-15 12:05:17,193 - meshcore_mqtt.message_queue.meshcore - DEBUG - Dequeued mqtt_command from mqtt to meshcore (id: 12532af1)
2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - DEBUG - Processing message: mqtt_command
2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Processing MQTT command: send_msg
2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Queueing rate-limited command: send_msg
2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Starting MeshCore health monitor
2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Starting auto-fetch monitor
2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Starting message rate limiter
2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Sending message to af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f (attempt 1/6)
2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Rate limiting (send_msg(af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f)): applying initial delay of 15.0s
2025-10-15 12:05:32,196 - meshcore - DEBUG - Sending message to af79b3ba6d91: Remote alert test
2025-10-15 12:05:32,196 - meshcore - DEBUG - Sending raw data: 0200003cd7ee68af79b3ba6d9152656d6f746520616c6572742074657374
2025-10-15 12:05:32,196 - meshcore - DEBUG - sending pkt : b'<\x1e\x00\x02\x00\x00<\xd7\xeeh\xafy\xb3\xbam\x91Remote alert test'
2025-10-15 12:05:32,196 - meshcore - DEBUG - Waiting for events [<EventType.MSG_SENT: 'message_sent'>, <EventType.ERROR: 'command_error'>], timeout=5
2025-10-15 12:05:32,199 - meshcore - DEBUG - Received data: 0600f90aea9b62070000
2025-10-15 12:05:32,200 - meshcore - DEBUG - Dispatching event: EventType.MSG_SENT, {'type': 0, 'expected_ack': b'\xf9\n\xea\x9b', 'suggested_timeout': 1890}, {'type': 0, 'expected_ack': 'f90aea9b'}
2025-10-15 12:05:32,683 - meshcore - DEBUG - Received data: 8834d30e00f90aea9b
2025-10-15 12:05:32,684 - meshcore - DEBUG - Received RF log data: 8834d30e00f90aea9b
2025-10-15 12:05:32,684 - meshcore - DEBUG - Received data: 82f90aea9be3010000
2025-10-15 12:05:32,684 - meshcore - DEBUG - Received ACK
2025-10-15 12:05:32,684 - meshcore - DEBUG - Dispatching event: EventType.RX_LOG_DATA, {'raw_hex': '34d30e00f90aea9b', 'snr': 13.0, 'rssi': -45, 'payload': '0e00f90aea9b', 'payload_length': 6}, {'pubkey_prefix': '34d30e00f90aea9b'}
2025-10-15 12:05:32,684 - meshcore - DEBUG - Dispatching event: EventType.ACK, {'code': 'f90aea9b'}, {'code': 'f90aea9b'}
2025-10-15 12:05:34,091 - meshcore_mqtt.meshcore_worker - DEBUG - Timeout waiting for ack: b'\xf9\n\xea\x9b'
2025-10-15 12:05:34,092 - meshcore_mqtt.meshcore_worker - WARNING - No acknowledgement received for message to af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f
2025-10-15 12:05:34,092 - meshcore_mqtt.meshcore_worker - INFO - Retrying in 7.0 seconds...
The send with retry results in the message being received by the recipient 3 times (as configured in config.json). Below is the debug log. It seems meshcore library returns the ACK but the bridge does not see it. ``` 2025-10-15 12:05:06,963 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Received PUBLISH (d0, q0, r0, m0), 'meshcore/command/send_msg', ... (112 bytes) 2025-10-15 12:05:06,964 - meshcore_mqtt.mqtt_worker - INFO - Received MQTT command: send_msg = {"destination":"af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f","message":"Remote alert test"} 2025-10-15 12:05:06,964 - meshcore_mqtt.message_queue.meshcore - DEBUG - Queued mqtt_command from mqtt to meshcore (id: 12532af1) 2025-10-15 12:05:12,090 - meshcore_mqtt.bridge_coordinator - WARNING - Timeout waiting for MQTT connection after 30.0s, proceeding with MeshCore startup 2025-10-15 12:05:12,091 - meshcore_mqtt.bridge_coordinator - INFO - Starting MeshCore worker... 2025-10-15 12:05:12,091 - meshcore_mqtt.bridge_coordinator - INFO - Bridge coordinator started successfully 2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Starting MeshCore worker 2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Setting up MeshCore connection 2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Setting up MeshCore event subscriptions 2025-10-15 12:05:12,091 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: CONNECTED 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: LOGIN_SUCCESS 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: CONTACT_MSG_RECV 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: BATTERY 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: NEW_CONTACT 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: ADVERTISEMENT 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: DISCONNECTED 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: DEVICE_INFO 2025-10-15 12:05:12,092 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: CHANNEL_MSG_RECV 2025-10-15 12:05:12,093 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to event: LOGIN_FAILED 2025-10-15 12:05:12,093 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to NO_MORE_MSGS event for auto-fetch management 2025-10-15 12:05:12,093 - meshcore_mqtt.meshcore_worker - INFO - Subscribed to ACK event for message acknowledgements 2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - Starting coordinator monitoring 2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - === Bridge System Status === 2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - Total components: 2 2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - MESHCORE: starting | Queue: 1/1000 | Dropped: 0 2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - MQTT: running | Queue: 0/1000 | Dropped: 0 2025-10-15 12:05:12,164 - meshcore_mqtt.bridge_coordinator - INFO - ======================== 2025-10-15 12:05:12,165 - meshcore - DEBUG - port opened 2025-10-15 12:05:12,184 - meshcore - INFO - Serial Connection started 2025-10-15 12:05:12,185 - meshcore - DEBUG - Connected successfully: /dev/Daisy 2025-10-15 12:05:12,185 - meshcore - DEBUG - Connected successfully: /dev/Daisy 2025-10-15 12:05:12,185 - meshcore - DEBUG - Sending appstart command 2025-10-15 12:05:12,185 - meshcore - DEBUG - Sending raw data: bytearray(b'\x01\x03 mccli') 2025-10-15 12:05:12,185 - meshcore - DEBUG - sending pkt : b'<\r\x00\x01\x03 mccli' 2025-10-15 12:05:12,185 - meshcore - DEBUG - Waiting for events [<EventType.SELF_INFO: 'self_info'>], timeout=5 2025-10-15 12:05:12,186 - meshcore - DEBUG - Dispatching event: EventType.CONNECTED, {'connection_info': '/dev/Daisy'}, {} 2025-10-15 12:05:12,186 - meshcore_mqtt.meshcore_worker - INFO - MeshCore CONNECTED event received: Event(type=<EventType.CONNECTED: 'connected'>, payload={'connection_info': '/dev/Daisy'}, attributes={}) 2025-10-15 12:05:12,186 - meshcore_mqtt.message_queue.mqtt - DEBUG - Queued meshcore_event from meshcore to mqtt (id: e080c848) 2025-10-15 12:05:12,187 - meshcore_mqtt.message_queue.mqtt - DEBUG - Dequeued meshcore_event from meshcore to mqtt (id: e080c848) 2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - Processing message: meshcore_event 2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - Publishing MeshCore event to MQTT topic: meshcore/events/connection 2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - Publishing to MQTT: topic=meshcore/events/connection, qos=1, retain=False, payload_length=95 2025-10-15 12:05:12,187 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Sending PUBLISH (d0, q1, r0, m2), 'b'meshcore/events/connection'', ... (95 bytes) 2025-10-15 12:05:12,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Received PUBACK (Mid: 2) 2025-10-15 12:05:12,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT message published: 2 2025-10-15 12:05:12,189 - meshcore_mqtt.mqtt_worker - DEBUG - Published MeshCore event to MQTT: meshcore/events/connection 2025-10-15 12:05:17,186 - meshcore_mqtt.meshcore_worker - INFO - Connected to MeshCore device 2025-10-15 12:05:17,186 - meshcore_mqtt.meshcore_worker - DEBUG - Cleared message deduplication cache for fresh connection 2025-10-15 12:05:17,187 - meshcore_mqtt.message_queue - INFO - Component meshcore: starting -> connected 2025-10-15 12:05:17,187 - meshcore_mqtt.message_queue.mqtt - DEBUG - Queued meshcore_status from meshcore to mqtt (id: c77727ed) 2025-10-15 12:05:17,187 - meshcore - DEBUG - Requesting pending messages 2025-10-15 12:05:17,187 - meshcore - DEBUG - Sending raw data: 0a 2025-10-15 12:05:17,187 - meshcore - DEBUG - sending pkt : b'<\x01\x00\n' 2025-10-15 12:05:17,187 - meshcore - DEBUG - Waiting for events [<EventType.CONTACT_MSG_RECV: 'contact_message'>, <EventType.CHANNEL_MSG_RECV: 'channel_message'>, <EventType.ERROR: 'command_error'>, <EventType.NO_MORE_MSGS: 'no_more_messages'>], timeout=5 2025-10-15 12:05:17,188 - meshcore_mqtt.message_queue.mqtt - DEBUG - Dequeued meshcore_status from meshcore to mqtt (id: c77727ed) 2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - DEBUG - Processing message: meshcore_status 2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - INFO - MeshCore status update: connected - connected 2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - DEBUG - Publishing to MQTT: topic=meshcore/status, qos=1, retain=True, payload_length=9 2025-10-15 12:05:17,188 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Sending PUBLISH (d0, q1, r1, m3), 'b'meshcore/status'', ... (9 bytes) 2025-10-15 12:05:17,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT: Received PUBACK (Mid: 3) 2025-10-15 12:05:17,189 - meshcore_mqtt.mqtt_worker - DEBUG - MQTT message published: 3 2025-10-15 12:05:17,191 - meshcore - DEBUG - Received data: 0a 2025-10-15 12:05:17,192 - meshcore - DEBUG - Dispatching event: EventType.NO_MORE_MSGS, {'messages_available': False}, {} 2025-10-15 12:05:17,192 - meshcore_mqtt.meshcore_worker - DEBUG - Received NO_MORE_MSGS event: Event(type=<EventType.NO_MORE_MSGS: 'no_more_messages'>, payload={'messages_available': False}, attributes={}) 2025-10-15 12:05:17,192 - meshcore_mqtt.meshcore_worker - INFO - Started auto message fetching 2025-10-15 12:05:17,192 - meshcore_mqtt.message_queue - INFO - Component meshcore: connected -> running 2025-10-15 12:05:17,192 - meshcore_mqtt.meshcore_worker - INFO - MeshCore worker started successfully 2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Starting MeshCore message processor 2025-10-15 12:05:17,193 - meshcore_mqtt.message_queue.meshcore - DEBUG - Dequeued mqtt_command from mqtt to meshcore (id: 12532af1) 2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - DEBUG - Processing message: mqtt_command 2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Processing MQTT command: send_msg 2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Queueing rate-limited command: send_msg 2025-10-15 12:05:17,193 - meshcore_mqtt.meshcore_worker - INFO - Starting MeshCore health monitor 2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Starting auto-fetch monitor 2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Starting message rate limiter 2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Sending message to af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f (attempt 1/6) 2025-10-15 12:05:17,194 - meshcore_mqtt.meshcore_worker - INFO - Rate limiting (send_msg(af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f)): applying initial delay of 15.0s 2025-10-15 12:05:32,196 - meshcore - DEBUG - Sending message to af79b3ba6d91: Remote alert test 2025-10-15 12:05:32,196 - meshcore - DEBUG - Sending raw data: 0200003cd7ee68af79b3ba6d9152656d6f746520616c6572742074657374 2025-10-15 12:05:32,196 - meshcore - DEBUG - sending pkt : b'<\x1e\x00\x02\x00\x00<\xd7\xeeh\xafy\xb3\xbam\x91Remote alert test' 2025-10-15 12:05:32,196 - meshcore - DEBUG - Waiting for events [<EventType.MSG_SENT: 'message_sent'>, <EventType.ERROR: 'command_error'>], timeout=5 2025-10-15 12:05:32,199 - meshcore - DEBUG - Received data: 0600f90aea9b62070000 2025-10-15 12:05:32,200 - meshcore - DEBUG - Dispatching event: EventType.MSG_SENT, {'type': 0, 'expected_ack': b'\xf9\n\xea\x9b', 'suggested_timeout': 1890}, {'type': 0, 'expected_ack': 'f90aea9b'} 2025-10-15 12:05:32,683 - meshcore - DEBUG - Received data: 8834d30e00f90aea9b 2025-10-15 12:05:32,684 - meshcore - DEBUG - Received RF log data: 8834d30e00f90aea9b 2025-10-15 12:05:32,684 - meshcore - DEBUG - Received data: 82f90aea9be3010000 2025-10-15 12:05:32,684 - meshcore - DEBUG - Received ACK 2025-10-15 12:05:32,684 - meshcore - DEBUG - Dispatching event: EventType.RX_LOG_DATA, {'raw_hex': '34d30e00f90aea9b', 'snr': 13.0, 'rssi': -45, 'payload': '0e00f90aea9b', 'payload_length': 6}, {'pubkey_prefix': '34d30e00f90aea9b'} 2025-10-15 12:05:32,684 - meshcore - DEBUG - Dispatching event: EventType.ACK, {'code': 'f90aea9b'}, {'code': 'f90aea9b'} 2025-10-15 12:05:34,091 - meshcore_mqtt.meshcore_worker - DEBUG - Timeout waiting for ack: b'\xf9\n\xea\x9b' 2025-10-15 12:05:34,092 - meshcore_mqtt.meshcore_worker - WARNING - No acknowledgement received for message to af79b3ba6d917a4324299c7c56cd125efa3db175c75399ef117b6e9ae306601f 2025-10-15 12:05:34,092 - meshcore_mqtt.meshcore_worker - INFO - Retrying in 7.0 seconds... ``` <!-- github-sync-id:3515794930 -->
adam closed this issue 2026-10-05 06:08:42 +02:00
adam commented 2026-10-05 06:08:43 +02:00
Author
Owner
Copy link
Copy source

#9 Not sure, but this might fix it

#9 Not sure, but this might fix it <!-- github-comment-id:3413036387 -->
adam commented 2026-10-05 06:08:44 +02:00
Author
Owner
Copy link
Copy source

That has fixed it - thanks.
It's looking pretty robust now.

That has fixed it - thanks. It's looking pretty robust now. <!-- github-comment-id:3413153312 -->
Sign in to join this conversation.
No Branch/Tag Specified
Labels
No items
No labels
Milestone
No items
No Milestone
Projects
Clear projects
No projects
Assignees
Clear assignees
adam (Adam Wojcieszonek)
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: adam/meshcore-mqtt#5