bohdan-s / SunGather

GNU General Public License v3.0
151 stars 63 forks source link

Random failure MQTT: Server Error; Server not configured #51

Open dbonnell opened 2 years ago

dbonnell commented 2 years ago

SunGather 0.3.7 was running happily for the past few days and then this morning I noticed Grafana was empty. On checking the Docker instance I found it had terminated and the last entries in the log were the following:

2022-05-12 06:32:21 INFO     Inverter: Successfully scraped in 1.433464 secs
2022-05-12 06:32:21 WARNING  MQTT: Server Error; Server not configured
MQTT: Server Error; Server not configured
Traceback (most recent call last):
  File "/usr/src/sungather/sungather.py", line 566, in <module>
    main()
  File "/usr/src/sungather/sungather.py", line 534, in main
    export.publish(inverter)
  File "/usr/src/sungather/exports/mqtt.py", line 80, in publish
    logging.debug(f"MQTT: Publishing: {self.mqtt_config['topic']} : {json.dumps(inverter.latest_scrape)}")
AttributeError: 'export_mqtt' object has no attribute 'mqtt_config'

There was no change to either the configuration or instance, so not sure how or why it suddenly lost the MQTT config. Started the instance again and it is working again.

2022-05-13 10:33:00 INFO     Modbus client is not connected, attempting to reconnect
2022-05-13 10:33:00 INFO     Connection: ModbusTcpClient(11.11.11.1:502)
2022-05-13 10:33:03 INFO     Detected Model: SG8K-D
2022-05-13 10:33:03 INFO     Closing Session: ModbusTcpClient(11.11.11.1:502)
2022-05-13 10:33:03 INFO     Loading Export: exports\webserver
2022-05-13 10:33:03 INFO     Webserver: Configured
2022-05-13 10:33:03 INFO     Loading Export: exports\mqtt
2022-05-13 10:33:03 INFO     Loading Export: exports\pvoutput
2022-05-13 10:33:03 INFO     MQTT: Connected to mosquitto:1883
2022-05-13 10:33:04 INFO     PVOutput: Configured export to 7 Eastlake Ave every 5 minutes
2022-05-13 10:33:04 INFO     Modbus, Connecting new session
2022-05-13 10:33:06 INFO     Inverter: Successfully scraped in 1.524352 secs
2022-05-13 10:33:06 INFO     MQTT: Published
2022-05-13 10:33:06 INFO     MQTT: Published Home Assistant Discovery messages
gstallworthy commented 1 year ago

I have a similar problem. unfortunately it crashes every few days. Modbus is working fine, but MQTT has the same server error. "Server error: Server not configured" If i restart the add-on it fires backup.

MQTT: Server Error; Server not configured 2023-03-15 11:39:12 INFO Closing Session: ModbusTcpClient(192.168.0.191:502) 2023-03-15 11:39:12 INFO Next scrape in 8 secs 2023-03-15 11:39:20 INFO Modbus, Connecting new session 2023-03-15 11:39:22 INFO Inverter: Successfully scraped in 1.912248 secs 2023-03-15 11:39:22 WARNING MQTT: Server Error; Server not configured

bohdan-s commented 1 year ago

Yup. I know what the issue is. new version should resolve it. long story short if a register fails to read it breaks MQTT

revilo951 commented 1 year ago

Any update on this one? Still seems to be happening for me.

gstallworthy commented 1 year ago

It's not a problem for me anymore (assume the update fixed it). No more errors and definitely more stable.

revilo951 commented 1 year ago

I'm running it in docker, most recent image I can see in docker hub is from January. Is that the version with the fix?

gstallworthy commented 1 year ago

I'm running it on Synology virtual machine via VMM. My Version is 0.5.1.

revilo951 commented 1 year ago

Are you building from source in the VM?

gstallworthy commented 1 year ago

within Home Assistant - I go to settings -> add-ons -> SunGather. It installs and you can configure it within the GUI.

florianbrede-ayet commented 1 year ago

If anyone else still has the issue and is also too lazy to look into it. The following script executed every minute via cron will scan the most recent log entries from all declared containers and restart them if the MQTT bug is present:

#!/bin/bash

CONTAINER_NAMES=("sungather_master" "sungather_slave")
SEARCH_STRING="MQTT: Server Error; Server not configured"
LOG_LINES=100 # number of lines to tail
WAIT_TIME_AFTER_RESTART=120  # give containers a warm-up period of 2 minutes to "flush" the old logs

# Check if the script is already running
for pid in $(pidof -x $(basename $0)); do
    if [ $pid != $$ ]; then
        echo "[$(date)] : $(basename $0) : Process is already running with PID $pid"
        exit 1
    fi
done

container_restarted=false

# loop through each container
for CONTAINER_NAME in "${CONTAINER_NAMES[@]}"; do

    # check the last n lines of the logs for the string
    if docker logs --tail $LOG_LINES $CONTAINER_NAME 2>&1 | grep --quiet "$SEARCH_STRING"; then
        # restart the docker container
        echo "[$(date)] : Restarting the Docker container ($CONTAINER_NAME) because the string \"$SEARCH_STRING\" was found in logs"
        docker restart $CONTAINER_NAME
        container_restarted=true
    fi

done

# if any container was restarted, wait for n minutes before the next check (by keeping the PID alive)
if [ "$container_restarted" = true ]; then
    sleep $WAIT_TIME_AFTER_RESTART
fi
michbeck100 commented 1 year ago

I was going to implement a health check for the Dockerfile but I'm still waiting for the next version. @bohdan-s will it be a problem if the Dockerfile gets updated?

HubertusH commented 6 months ago

Hello, I still have the error with the mqtt export. I have tested all the suggestions I have found so far - unfortunately without success. I even have a local mosquitto running on the same raspberry pi - that doesn't work either.

Debug:

| model | SH8.0RT | | serial_number | A233117179 | | level | 2 | | scan_interval | 60 | | use_local_time | False | | smart_meter | True | | connection | modbus | | slave | 1 | | start_time | | +----------------------------------------------+ 2024-02-22 11:08:08 INFO Loading Export: exports\webserver 2024-02-22 11:08:08 INFO Webserver: Configured 2024-02-22 11:08:15 INFO Loading Export: exports\influxdb 2024-02-22 11:08:15 INFO InfluxDB: Configured: http://10.67.77.96:8086 2024-02-22 11:08:15 INFO Loading Export: exports\mqtt 2024-02-22 11:08:15 ERROR Failed loading export: Unsupported callback API version: version 2.0 added a callback_api_version, see migrations.md for details Please make sure mqtt.py exists in the exports folder Failed loading export: Unsupported callback API version: version 2.0 added a callback_api_version, see migrations.md for details Please make sure mqtt.py exists in the exports folder 2024-02-22 11:08:15 DEBUG Checking Modbus Connection 2024-02-22 11:08:15 INFO Modbus, Connecting new session ... ... later ... Logged 107 registers to Console 2024-02-22 11:08:18 INFO InfluxDB: Published 2024-02-22 11:08:18 WARNING MQTT: Server Error; Server not configured MQTT: Server Error; Server not configured 2024-02-22 11:08:18 INFO Closing Session: ModbusTcpClient(192.168.179.10:502) 2024-02-22 11:08:18 DEBUG Processing Time: 2.46 secs

the registers are read out correctly without errors as a workaround I now write all data to the influxDB and read it out again with node-red. But it is terribly slow and cumbersome.

I hope the problem can be solved - please help. SunGather itself is great for reading out the Sungrow inverters.

Greetings Hubertus

michbeck100 commented 6 months ago

This sounds like the wrong version of MQTT server. What type of MQTT server are you using?

HubertusH commented 6 months ago

mosquitto version 2.0.11

ludifu commented 6 months ago

paho-mqtt changed the API since V2.0.0 (out 10th of February.) Either fix paho-mqtt to the latest version before 2.0.0 in requirements.txt.

Or change the code. :-)

michbeck100 commented 6 months ago

Oh great. Yes that's the problem. See https://github.com/bohdan-s/SunGather/blob/main/requirements.txt#L3. paho-mqtt>=1.5.1 includes also 2.0.0 🤦‍♂️

ludifu commented 6 months ago

Easiest change: In mqtt.py turn this:

self.mqtt_client = mqtt.Client(client_id)

into this:

self.mqtt_client = mqtt.Client(callback_api_version=mqtt.CallbackAPIVersion.VERSION1, client_id=client_id)

HubertusH commented 6 months ago

Thanks to all - yes the version paho-mqtt 1.6 works. I will try again with the program change. It works too, Perfect!

Greetings Hubertus