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