search

tillsteinbach / WeConnect-mqtt

MQTT Client that publishes data from Volkswagen WeConnect
MIT License
63 stars 13 forks source link

Frequent "RuntimeError: OrderedDict mutated during iteration" errors #331

Open guyeeba opened 3 months ago

guyeeba commented 3 months ago

Hi all,

I encounter the above error in every few days, and it causes weconnect-mqtt to stop running, and systemd does not restart it even with Restart=on-failure

I use v0.49.0 on Ubuntu 22.04.3 LTS with parameters

--username my@email.address --password mypassword --mqttbroker 127.0.0.1 --mqtt-username weconnectuser --mqtt-password weconnectpassword --prefix weconnect -i 300 --update-on-connect

Call stack:

Mar 23 00:22:38 app1 python[446752]: Exception in thread paho-mqtt-client-:
Mar 23 00:22:38 app1 python[446752]: Traceback (most recent call last):
Mar 23 00:22:38 app1 python[446752]:   File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
Mar 23 00:22:38 app1 python[446752]:     self.run()
Mar 23 00:22:38 app1 python[446752]:   File "/usr/lib/python3.10/threading.py", line 953, in run
Mar 23 00:22:38 app1 python[446752]:     self._target(*self._args, **self._kwargs)
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4517, i>
Mar 23 00:22:38 app1 python[446752]:     self.loop_forever(retry_first_connection=True)
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 2291, i>
Mar 23 00:22:38 app1 python[446752]:     rc = self._loop(timeout)
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 1680, i>
Mar 23 00:22:38 app1 python[446752]:     rc = self.loop_read()
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 2094, i>
Mar 23 00:22:38 app1 python[446752]:     rc = self._packet_read()
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 3137, i>
Mar 23 00:22:38 app1 python[446752]:     rc = self._packet_handle()
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 3799, i>
Mar 23 00:22:38 app1 python[446752]:     return self._handle_pubackcomp("PUBACK")
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4457, i>
Mar 23 00:22:38 app1 python[446752]:     rc = self._do_on_publish(mid, reasonCode, properties)
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4427, i>
Mar 23 00:22:38 app1 python[446752]:     rc = self._update_inflight()
Mar 23 00:22:38 app1 python[446752]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4226, i>
Mar 23 00:22:38 app1 python[446752]:     for m in self._out_messages.values():
Mar 23 00:22:38 app1 python[446752]: RuntimeError: OrderedDict mutated during iteration

Any ideas how to resolve it?

Thanks in advance

UPDATE: The exception occurs (every single time, it seems) when charging is started, but only when started. The software does not crash (obviously this is why it is not restarted by systemd), seemingly keeps doing its job, but no updates are published to MQTT anymore.

Mar 31 14:09:07 app1 python[7967]: 2024-03-31T14:09:07+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
Mar 31 14:14:15 app1 python[7967]: 2024-03-31T14:14:15+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
Mar 31 14:14:21 app1 python[7967]: Exception in thread paho-mqtt-client-:
Mar 31 14:14:21 app1 python[7967]: Traceback (most recent call last):
Mar 31 14:14:21 app1 python[7967]:   File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
Mar 31 14:14:21 app1 python[7967]:     self.run()
Mar 31 14:14:21 app1 python[7967]:   File "/usr/lib/python3.10/threading.py", line 953, in run
Mar 31 14:14:21 app1 python[7967]:     self._target(*self._args, **self._kwargs)
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4517, in _thread_main
Mar 31 14:14:21 app1 python[7967]:     self.loop_forever(retry_first_connection=True)
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 2291, in loop_forever
Mar 31 14:14:21 app1 python[7967]:     rc = self._loop(timeout)
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 1680, in _loop
Mar 31 14:14:21 app1 python[7967]:     rc = self.loop_read()
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 2094, in loop_read
Mar 31 14:14:21 app1 python[7967]:     rc = self._packet_read()
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 3137, in _packet_read
Mar 31 14:14:21 app1 python[7967]:     rc = self._packet_handle()
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 3799, in _packet_handle
Mar 31 14:14:21 app1 python[7967]:     return self._handle_pubackcomp("PUBACK")
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4457, in _handle_pubackcomp
Mar 31 14:14:21 app1 python[7967]:     rc = self._do_on_publish(mid, reasonCode, properties)
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4427, in _do_on_publish
Mar 31 14:14:21 app1 python[7967]:     rc = self._update_inflight()
Mar 31 14:14:21 app1 python[7967]:   File "/usr/local/lib/python3.10/dist-packages/paho/mqtt/client.py", line 4226, in _update_inflight
Mar 31 14:14:21 app1 python[7967]:     for m in self._out_messages.values():
Mar 31 14:14:21 app1 python[7967]: RuntimeError: OrderedDict mutated during iteration
Mar 31 14:19:27 app1 python[7967]: 2024-03-31T14:19:27+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
Mar 31 14:24:35 app1 python[7967]: 2024-03-31T14:24:35+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
Mar 31 14:29:39 app1 python[7967]: 2024-03-31T14:29:39+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
Mar 31 14:34:42 app1 python[7967]: 2024-03-31T14:34:42+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
Mar 31 14:39:51 app1 python[7967]: 2024-03-31T14:39:51+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
Mar 31 14:39:51 app1 python[7967]: 2024-03-31T14:39:51+0200:INFO:openid_session:Token expired
Mar 31 14:39:51 app1 python[7967]: 2024-03-31T14:39:51+0200:INFO:we_connect_session:Refreshing tokens
Mar 31 14:45:01 app1 python[7967]: 2024-03-31T14:45:01+0200:INFO:weconnect_mqtt_base:Update data from WeConnect
skvist60 commented 2 months ago

Hi,

I have this same issue, it started showing up about a week ago. It appears to happen at random times for me.

I tried updating paho-mqtt to the latest version, which is newer than the version required by reconnect-mqtt, but with the same result.