FlashMQ reset: dbus_watch_handle() returns false, so is out of memory

Question

question

christiangurk asked Feb 19, '24

FlashMQ reset: dbus_watch_handle() returns false, so is out of memory

Hi,
I have a problem with my VenusOS 3.20 on a Raspberry Pi 4 (2GB): I'm connecting with an external client (FHEM MQTT2_CLIENT) to the new FlashMQ-MQTT-Broker of Venus. But I see my client reconnecting every 2-3h. I looked into the logfiles in /var/log/current and found the following problem:

... a lot more of the following lines ...
@4000000065d2fd6234736fd4 [2024-02-19 07:03:52.879] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6234757374 [2024-02-19 07:03:52.879] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6234775bbc [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6234776f44 [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6234798a54 [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62347b8624 [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62347b99ac [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62347d9964 [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62347f9534 [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62347fa8bc [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623481ac5c [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6234844c3c [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6234845fc4 [2024-02-19 07:03:52.880] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623485e664 [2024-02-19 07:03:52.881] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623487e234 [2024-02-19 07:03:52.881] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623487f5bc [2024-02-19 07:03:52.881] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62348993cc [2024-02-19 07:03:52.881] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6234c1ddf4 terminate called after throwing an instance of 'std::bad_alloc'
@4000000065d2fd6234c2fb1c   what():  std::bad_alloc
@4000000065d2fd62355c2ddc [2024-02-19 07:03:52.881] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62355c454c [2024-02-19 07:03:52.881] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62355c54ec [2024-02-19 07:03:52.881] [WARNING] dbus_watch_handle() returns false, so is out of memory.
... a lot more of these lines ...
@4000000065d2fd623574bb04 [2024-02-19 07:03:52.883] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6235752094 [2024-02-19 07:03:52.883] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6235753034 [2024-02-19 07:03:52.883] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6235753fd4 [2024-02-19 07:03:52.883] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd6235762264 [2024-02-19 07:03:52.883] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6235763204 [2024-02-19 07:03:52.884] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6235763dbc [2024-02-19 07:03:52.884] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6235764d5c [2024-02-19 07:03:52.884] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd63085d4dd4 *** starting flashmq ***
@4000000065d2fd6310de2b2c RSA key ok
@4000000065d2fd6311ea827c /data/keys/mosquitto.crt: OK
@4000000065d2fd6312de6414 Certificate will not expire
@4000000065d2fd6313a3560c [2024-02-19 07:03:53.328] [NOTICE] Loading config. Reload: false.
@4000000065d2fd631527d714 [2024-02-19 07:03:53.354] [NOTICE] Creating IPv4 non-SSL TCP listener on [0.0.0.0]:1883
@4000000065d2fd63152a8a7c [2024-02-19 07:03:53.354] [NOTICE] Creating IPv6 non-SSL TCP listener on [::]:1883
@4000000065d2fd63153c2264 [2024-02-19 07:03:53.356] [NOTICE] Creating IPv4 SSL TCP listener on [0.0.0.0]:8883
@4000000065d2fd631540f8ac [2024-02-19 07:03:53.356] [NOTICE] Creating IPv6 SSL TCP listener on [::]:8883
@4000000065d2fd6315420634 [2024-02-19 07:03:53.356] [NOTICE] Creating IPv4 non-SSL websocket listener on [0.0.0.0]:9001
@4000000065d2fd6315446b7c [2024-02-19 07:03:53.356] [NOTICE] Creating IPv6 non-SSL websocket listener on [::]:9001
@4000000065d2fd6315475d64 [2024-02-19 07:03:53.356] [INFO] Setting rlimit nofile to 1000000.
@4000000065d2fd6315507584 [2024-02-19 07:03:53.357] [NOTICE] 1 threads specified by 'thread_count'.
@4000000065d2fd63155449fc [2024-02-19 07:03:53.357] [NOTICE] Starting FlashMQ version 1.9.1, release build without SSE support.
@4000000065d2fd6315553c2c [2024-02-19 07:03:53.357] [NOTICE] Loading auth plugin /usr/libexec/flashmq/libflashmq-dbus-plugin.so
@4000000065d2fd6315d95494 [2024-02-19 07:03:53.366] [NOTICE] Thread 0 doing auth init.
@4000000065d2fd631631b97c [2024-02-19 07:03:53.372] [NOTICE] Initiating bridge registration.
@4000000065d2fd6316b00d54 [2024-02-19 07:03:53.380] [NOTICE] SetValue on /Mqtt/RegisterOnVrm seemingly successful.
@4000000065d2fd6316c67f6c [2024-02-19 07:03:53.381] [INFO] Unhandled signal: 'ItemsChanged' by ':1.42'
@4000000065d2fd631cdcb1dc [2024-02-19 07:03:53.484] [NOTICE] Accepting connection from: address='192.168.100.47', transport='TCP/Non-SSL', fd=18
@4000000065d2fd631dca32a4 [2024-02-19 07:03:53.499] [NOTICE] Client '[ClientID='fhemVenusMqtt', username='', fd=18, keepalive=30s, transport='TCP/Non-SSL', address='192.168.100.47', >
@4000000065d2fd633444e1dc [2024-02-19 07:03:53.876] [NOTICE] Connecting brige: [Bridge ClientID='GXdbus_zoV58oLATd', username='', fd=19, keepalive=60s, transport='TCP/SSL', address='>
@4000000065d2fd6337cf9edc [2024-02-19 07:03:53.936] [NOTICE] Bridge '[Bridge ClientID='GXdbus_zoV58oLATd', username='', fd=19, keepalive=60s, transport='TCP/SSL', address='mqtt118.vi>
@4000000065d2fd64079c20b4 [2024-02-19 07:03:54.127] [NOTICE] Accepting connection from: address='::1', transport='TCP/Non-SSL', fd=20
@4000000065d2fd6407ab8dec [2024-02-19 07:03:54.128] [NOTICE] Client '[ClientID='VenusRPC_dca632079210_1531404ddbb531fc', username='', fd=20, keepalive=60s, transport='TCP/Non-SSL', a>
@4000000065d2fd64167d781c [2024-02-19 07:03:54.377] [NOTICE] Bridge 'GXrpc' disconnect detected. We will initiate a re-registration in 305692 ms.
@4000000065d2fd68071a88ec [2024-02-19 07:03:58.118] [NOTICE] Accepting connection from: address='127.0.0.1', transport='TCP/Non-SSL', fd=21
@4000000065d2fd680738f214 [2024-02-19 07:03:58.119] [NOTICE] Client '[ClientID='dbus_mqtt_device_manager', username='', fd=21, keepalive=60s, transport='TCP/Non-SSL', address='127.0.>
@4000000065d2fd6812cfa2bc [2024-02-19 07:03:58.315] [NOTICE] Accepting connection from: address='192.168.100.69', transport='TCP/Non-SSL', fd=22
@4000000065d2fd6812d9571c [2024-02-19 07:03:58.316] [NOTICE] Client '[ClientID='pvStromSensor', username='', fd=22, keepalive=60s, transport='TCP/Non-SSL', address='192.168.100.69', >
@4000000065d2fd68168b0cac [2024-02-19 07:03:58.378] [ERROR] Error creating bridge 'GXrpc': DNS query for 'mqtt-rpc.victronenergy.com' timed out.
@4000000065d2fd683355f5cc [2024-02-19 07:03:58.861] [NOTICE] Bridge 'GXrpc' connection failure count: 1. Increasing reconnect interval to 33 seconds.
@4000000065d2fd8b33dc737c [2024-02-19 07:04:33.869] [NOTICE] Connecting brige: [Bridge ClientID='GXrpc_lqfQP4SGRX', username='', fd=17, keepalive=60s, transport='TCP/SSL', address='m>
@4000000065d2fd8b36d22824 [2024-02-19 07:04:33.919] [NOTICE] Bridge '[Bridge ClientID='GXrpc_lqfQP4SGRX', username='', fd=17, keepalive=60s, transport='TCP/SSL', address='mqtt-rpc.v

I found this block also in one of the @4000....s files (maybe that helps to find the problem):

@4000000065d2fd6233519c84 [2024-02-19 07:03:52.858] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623351ac24 [2024-02-19 07:03:52.858] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623351bbc4 [2024-02-19 07:03:52.858] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623351cb64 [2024-02-19 07:03:52.858] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd62335234dc [2024-02-19 07:03:52.858] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd623352447c [2024-02-19 07:03:52.858] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6233525034 [2024-02-19 07:03:52.859] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6233525fd4 [2024-02-19 07:03:52.859] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6233533a94 [2024-02-19 07:03:52.859] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6233534a34 [2024-02-19 07:03:52.859] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6233542cc4 [2024-02-19 07:03:52.859] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6233543c64 [2024-02-19 07:03:52.859] [ERROR] In 'flashmq_plugin_poll_event_v1(): '
@4000000065d2fd6233544c04 [2024-02-19 07:03:52.860] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd62335457bc [2024-02-19 07:03:52.860] [WARNING] dbus_watch_handle() returns false, so is out of memory.
@4000000065d2fd623354675c [2024-02-19 07:03:52.860] [WARNING] dbus_watch_handle() returns false, so is out of memory.

This was from the last reconnect this morning. Does anyone else see these "out of memory" messages in the logfiles? The reconnect is rather quick, so it might be, that it's not visible in normal operation.

Any ideas?

Thx, Christian

MQTT

2 |3000

Attachments: Up to 8 attachments (including images) can be used with a maximum of 190.8 MiB each and 286.6 MiB total.

mvader (Victron Energy) answered · Feb 27 at 08:57 AM

Hey all, today we did the official release of Venus OS v3.22, which amongst other things fixes the last known issue for systems doing many MQTT writes to the GX.

Thank you again for helping to get all rock solid!

Details:

https://professional.victronenergy.com/news/detail/239/

2 |3000

Attachments: Up to 8 attachments (including images) can be used with a maximum of 190.8 MiB each and 286.6 MiB total.

Modifications Space

Node Red Space

Answer 1 · 2024-02-19T08:05:50Z

mvader (Victron Energy) answered · Feb 19 at 08:05 AM

Hey @christian.gurk , is it OK if we login to diagnose? Is it the tripower system?

1

2 |3000

Attachments: Up to 8 attachments (including images) can be used with a maximum of 190.8 MiB each and 286.6 MiB total.

christiangurk commented · Feb 19 at 08:07 AM

Yes shure! thx

1 ·

Answer 2 · 2024-02-19T21:27:05Z

mvader (Victron Energy) answered · Feb 19 at 09:27 PM

Hi again @christian.gurk , fixed per v3.30~7, more details here: https://community.victronenergy.com/questions/262520/venus-os-v3304-available-for-testing.html.

Thank you!

2

2 |3000

Attachments: Up to 8 attachments (including images) can be used with a maximum of 190.8 MiB each and 286.6 MiB total.

christiangurk commented · Feb 20 at 08:23 AM

Hi @mvader (Victron Energy)

checked this morning and everythings runs smooth, no restarts of flashMQ seen. Thx again!

Christian

1 ·

christiangurk commented · Feb 19 at 09:59 PM

Hi mvader!

Thx a lot for the quick update! I just installed 3.30~7, update went well. I will check tomorrow morning for reconnects over night. Will report!

Christian

0 ·

question