search

kbialek / deye-inverter-mqtt

Reads Deye solar inverter metrics and posts them over mqtt
Apache License 2.0
215 stars 50 forks source link

Error if MQTT-Broker not running #109

Closed bismosa closed 1 year ago

bismosa commented 1 year ago

Describe the bug I know this is a duplicate from https://github.com/kbialek/deye-inverter-mqtt/issues/69#issue-1694708457 But the conditions have changed. I now use the official way via Docker.

I get a lot of errors when I restart my raspberry pi:

2023-07-13 17:35:50,545 - DeyeMqttClient - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.
2023-07-13 17:35:50,545 - DeyeDaemon - INFO - Reading completed
2023-07-13 17:36:44,286 - DeyeDaemon - INFO - Reading start
2023-07-13 17:36:44,287 - DeyeDaemon - INFO - Reading registers [metrics group: micro, range: 003c-0074]
2023-07-13 17:36:44,487 - DeyeMqttClient - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.
2023-07-13 17:36:44,488 - DeyeMqttClient - INFO - Logger is online
2023-07-13 17:36:44,488 - DeyeMqttClient - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.
2023-07-13 17:36:44,489 - DeyeMqttClient - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.
2023-07-13 17:36:44,490 - DeyeMqttClient - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.

Every minute 30x "DeyeMqttClient - ERROR - Unknown MQTT pub..." entries in the log.

I use a mqtt server that is built into FHEM. This takes a long time to start. If the client is not yet available, I only get these error messages. Even if the client then becomes available again. Forever (testet for a hour). Only if I restart the docker container when the MQTT server is running, it works again.

To Reproduce Steps to reproduce the behavior:

  1. Stop the MQTT-Broker
  2. Start/Restart the Container
  3. Start the MQTT-Broker
  4. See error

Expected behavior Try to reconnect if not connected. Not so many log entries?

Hardware (please complete the following information):

Software (please complete the following information):

DEYE_LOGGER_IP_ADDRESS=192.168.1.139
DEYE_LOGGER_PORT=8899
DEYE_LOGGER_SERIAL_NUMBER=41xxxxxxxx

MQTT_HOST=192.168.1.3
MQTT_PORT=1883
MQTT_USERNAME=user
MQTT_PASSWORD=password
MQTT_TOPIC_PREFIX=deye

LOG_LEVEL=INFO
DEYE_DATA_READ_INTERVAL=60
DEYE_METRIC_GROUPS=micro

Many thanks for this!

Regards Bismosa

kbialek commented 1 year ago

Every minute 30x "DeyeMqttClient - ERROR - Unknown MQTT pub..." entries in the log.

That's because it logs an error for each observation that can't be published. It can be done better for sure.

I use a mqtt server that is built into FHEM. This takes a long time to start. If the client is not yet available, I only get these error messages. Even if the client then becomes available again. Forever (testet for a hour). Only if I restart the docker container when the MQTT server is running, it works again.

I will test it tomorrow and will come back to you.

kbialek commented 1 year ago

@bismosa Yes, I confirm the behavior that you've observed. Fixes are implemented in this beta image ghcr.io/kbialek/deye-inverter-mqtt:2023.07.2-beta-1. Please test it

bismosa commented 1 year ago

I could finally test now. Works fine now without any problems. This is what the log looks like after a reboot:

2023-07-16 07:22:27,304 - DeyeDaemon - INFO - Please help me build the list of compatible inverters. https://github.com/kbialek/deye-inverter-mqtt/issues/41
2023-07-16 07:22:27,341 - DeyeMqttClient - ERROR - Failed to connect to MQTT Broker located at 192.168.183.3:1883
2023-07-16 07:22:27,342 - DeyeDaemon - INFO - Feature "Report metrics over MQTT": enabled
2023-07-16 07:22:27,343 - DeyeDaemon - INFO - Feature "Set inverter time once online": disabled
2023-07-16 07:22:27,345 - DeyeDaemon - INFO - Reading start
2023-07-16 07:22:27,346 - DeyeDaemon - INFO - Reading registers [metrics group: micro, range: 003c-0074]
2023-07-16 07:22:37,353 - DeyeConnector - WARNING - Could not open socket on IP 192.168.183.10: timed out
2023-07-16 07:22:37,355 - DeyeMqttClient - ERROR - Failed to connect to MQTT Broker located at 192.168.183.3:1883
2023-07-16 07:22:37,356 - DeyeMqttPublisher - ERROR - Unknown MQTT publishing error: Message publish failed: The client is not currently connected.
2023-07-16 07:22:37,356 - DeyeDaemon - INFO - Reading completed
2023-07-16 07:23:37,357 - DeyeDaemon - INFO - Reading start
2023-07-16 07:23:37,358 - DeyeDaemon - INFO - Reading registers [metrics group: micro, range: 003c-0074]
2023-07-16 07:23:37,371 - DeyeConnector - INFO - Re-connected to socket on IP 192.168.183.10
2023-07-16 07:24:17,136 - DeyeMqttClient - INFO - Successfully connected to MQTT Broker located at 192.168.183.3:1883
2023-07-16 07:24:17,557 - DeyeMqttClient - INFO - Logger is online
2023-07-16 07:24:26,708 - DeyeDaemon - INFO - Reading completed
2023-07-16 07:24:37,357 - DeyeDaemon - INFO - Reading start
2023-07-16 07:24:37,358 - DeyeDaemon - INFO - Reading registers [metrics group: micro, range: 003c-0074]
2023-07-16 07:24:52,202 - DeyeMqttClient - INFO - Logger is online
2023-07-16 07:24:52,773 - DeyeDaemon - INFO - Reading completed

Exactly as expected. It just takes a while until everything has started for me.

Many thanks for the fix. Great Job! Regards Bismosa