From 50da2efedbc684304df0a13ff810bb10af49bf7a Mon Sep 17 00:00:00 2001 From: bohdan-s Date: Thu, 27 Jan 2022 09:59:40 +1100 Subject: [PATCH 1/3] Add dicord link --- README.md | 3 +++ 1 file changed, 3 insertions(+) diff --git a/README.md b/README.md index 554477d..5c3fed5 100644 --- a/README.md +++ b/README.md @@ -23,6 +23,9 @@ ## About The Project + +Join the Discord Server to discuss, suggestions or for any help: SunGather Discord + Access ModBus data from almost any network connected Sungow Inverter. On first connection the tool will query your inverter, retrieve the model and return the correct registers for your device. No more searching registers or creating model files. From da654ec5cece53932cb958bfa21d1cf256a94d89 Mon Sep 17 00:00:00 2001 From: bohdan-s Date: Thu, 27 Jan 2022 14:02:27 +1100 Subject: [PATCH 2/3] 0.3.2: Logging to file, connection handling --- README.md | 5 ++ SunGather/config-example.yaml | 3 +- SunGather/exports/influxdb.py | 2 +- SunGather/exports/mqtt.py | 3 +- SunGather/sungather.py | 93 ++++++++++++++++++++++++----------- SunGather/version.py | 2 +- requirements.txt | 2 +- 7 files changed, 76 insertions(+), 34 deletions(-) diff --git a/README.md b/README.md index 5c3fed5..f1f5ae9 100644 --- a/README.md +++ b/README.md @@ -52,6 +52,11 @@ I have learned a lot from the following projects, THANK YOU * Full Home Assistant integration, as HACS addon ## Updates +**0.3.2** +* Added logging to file +* Hopefully better connection recovery +* Bug fixes + **0.3.0** **IMPORTANT: If updating from v0.1.x or v0.2.x please check config against config-example. some options for MQTT and PVOutput have changed** * Heaps bug fixes diff --git a/SunGather/config-example.yaml b/SunGather/config-example.yaml index 1a6df9c..153edcb 100644 --- a/SunGather/config-example.yaml +++ b/SunGather/config-example.yaml @@ -10,7 +10,8 @@ inverter: # See model list here: https://github.com/bohdan-s/SunGather#supported # smart_meter: True # [Optional] Default is False, Set to true if inverter supports reading grind / house consumption # use_local_time: False # [Optional] Default False, Uses Inventer time, if true it uses PC time when updating timestamps (e.g. PVOutput) - # logging: 30 # [Optional] 10 = Debug, 20 = Info, 30 = Warning (default), 40 = Error + # log_console: INFO # [Optional] Default is WARNING, Options: DEBUG, INFO, WARNING, ERROR + # log_file: DEBUG # [Optional] Default is OFF, Options: OFF, DEBUG, INFO, WARNING, ERROR # level: 1 # [Optional] Set the amount of information to gather # 0 = Model and Solar Generation, # 1 (default) = Useful data, all required for exports, diff --git a/SunGather/exports/influxdb.py b/SunGather/exports/influxdb.py index 528b67d..c0028c2 100644 --- a/SunGather/exports/influxdb.py +++ b/SunGather/exports/influxdb.py @@ -61,7 +61,7 @@ def publish(self, inverter): logging.error(f"InfluxDB: Skipped collecting data, {measurement['register']} missing from last scrape") return False sequence.append(f"{measurement['point']},inverter={inverter.getInverterModel(True)} {measurement['register']}={inverter.getRegisterValue(measurement['register'])}") - logging.debug(f'InfluxDB: Sequence; {sequence}') + logging.debug(f'InfluxDB: Sequence; {sequence}') try: self.write_api.write(self.influxdb_config['bucket'], self.client.org, sequence) diff --git a/SunGather/exports/mqtt.py b/SunGather/exports/mqtt.py index d756c3d..a52134b 100644 --- a/SunGather/exports/mqtt.py +++ b/SunGather/exports/mqtt.py @@ -62,7 +62,7 @@ def on_publish(self, client, userdata, mid): self.mqtt_queue.remove(mid) except Exception as err: pass - logging.info(f"MQTT: Message {mid} Published") + logging.debug(f"MQTT: Message {mid} Published") def cleanName(self, name): return name.lower().replace(' ','_') @@ -75,6 +75,7 @@ def publish(self, inverter): logging.debug(f"MQTT: Publishing: {self.mqtt_config['topic']} : {json.dumps(inverter.latest_scrape)}") self.mqtt_queue.append(self.mqtt_client.publish(self.mqtt_config['topic'], json.dumps(inverter.latest_scrape).replace('"', '\"'), qos=0).mid) + logging.info(f"MQTT: Published") if self.mqtt_config['homeassistant'] and not self.ha_discovery_published: for ha_sensor in self.ha_sensors: diff --git a/SunGather/sungather.py b/SunGather/sungather.py index c9e9ae8..88790ea 100644 --- a/SunGather/sungather.py +++ b/SunGather/sungather.py @@ -14,11 +14,6 @@ import time import os -logging.basicConfig( - format='%(asctime)s %(levelname)-8s %(message)s', - level=20, - datefmt='%Y-%m-%d %H:%M:%S') - class SungrowInverter(): def __init__(self, config_inverter): self.client_config = { @@ -46,17 +41,25 @@ def __init__(self, config_inverter): self.latest_scrape = {} - def connect(self): + def checkConnection(self): + logging.debug("Checking Modbus Connection") if self.client: - if(self.client.connect()): - return True - else: + if not self.client.is_socket_open(): + logging.warning(f'Modbus socket is not connected, attempting to reconnect') self.disconnect() + return self.connect() + else: + logging.debug("Modbus client is still connected") + return True + else: + logging.warning(f'Modbus client is not connected, attempting to reconnect') + return self.connect() + def connect(self): if self.inverter_config['connection'] == "http": self.client_config['port'] = '8082' self.client = SungrowModbusWebClient.SungrowModbusWebClient(**self.client_config) - elif self.config_inverter_configinverter['connection'] == "sungrow": + elif self.inverter_config['connection'] == "sungrow": self.client = SungrowModbusTcpClient.SungrowModbusTcpClient(**self.client_config) elif self.inverter_config['connection'] == "modbus": self.client = ModbusTcpClient(**self.client_config) @@ -65,20 +68,20 @@ def connect(self): return False logging.info("Connection: " + str(self.client)) - retval = self.client.connect() + try: retval = self.client.connect() + except: return False # Wait 3 seconds, fixes timing issues time.sleep(3) - if not self.inverter_config['connection'] == "http": - self.client.close() - return retval - def close(self): - logging.debug("Closed session: " + str(self.client)) - self.client.close() + # Remove the .close, I think this is causing more issues than solving. + #if not self.inverter_config['connection'] == "http": + # self.client.close() + return retval def disconnect(self): logging.info("Disconnected: " + str(self.client)) - self.client.close() + try: self.client.close() + except: pass self.client = None def configure_registers(self,registersfile): @@ -167,11 +170,13 @@ def load_registers(self, register_type, start, count=100): else: raise RuntimeError(f"Unsupported register type: {type}") except Exception as err: - logging.warning(f'No data returned for {register_type}, {start}:{count}\n\t\t\t\t{str(err)}') + logging.warning(f"No data returned for {register_type}, {start}:{count}") + logging.debug(f"{str(err)}')") return False if rr.isError(): - logging.warning(f"Modbus connection failed: {rr}") + logging.warning(f"Modbus connection failed") + logging.debug(f"{rr}") return False if not hasattr(rr, 'registers'): @@ -270,8 +275,11 @@ def getInverterModel(self, clean=False): return self.inverter_config['model'] def scrape(self): + if not self.checkConnection(): + logging.warning(f'Modbus not connected, Scraping Skipped') + return False + scrape_start = datetime.now() - self.connect() # Clear previous inverter values, keep the model and run state if self.latest_scrape.get("run_state"): run_state = self.latest_scrape.get("run_state") @@ -290,12 +298,14 @@ def scrape(self): load_registers_failed +=1 if load_registers_failed == load_registers_count: # If every scrape fails, disconnect the client + logging.warning self.disconnect() return False if load_registers_failed > 0: logging.info(f'Scraping: {load_registers_failed}/{load_registers_count} registers failed to scrape') - self.close() + # Leave connection open, see if helps resolve the connection issues + #self.close() # Create a registers for Power imported and exported to/from Grid if self.inverter_config['level'] >= 1: @@ -445,20 +455,35 @@ def main(): "timeout": configfile['inverter'].get('timeout',10), "retries": configfile['inverter'].get('retries',3), "slave": configfile['inverter'].get('slave',0x01), - "scan_interval": configfile['inverter'].get('scan_interval',15), + "scan_interval": configfile['inverter'].get('scan_interval',30), "connection": configfile['inverter'].get('connection',"modbus"), "model": configfile['inverter'].get('model',None), "smart_meter": configfile['inverter'].get('smart_meter',False), "use_local_time": configfile['inverter'].get('use_local_time',False), - "manual_load": configfile['inverter'].get('manual_load',False), - "logging": configfile['inverter'].get('logging',30), + "log_console": configfile['inverter'].get('log_console','WARNING'), + "log_file": configfile['inverter'].get('log_file','OFF'), "level": configfile['inverter'].get('level',1) } if 'loglevel' in locals(): - logging.getLogger().setLevel(loglevel) + logger.handlers[0].setLevel(loglevel) else: - logging.getLogger().setLevel(config_inverter['logging']) + logger.handlers[0].setLevel(config_inverter['log_console']) + + if not config_inverter['log_file'] == "OFF": + if config_inverter['log_file'] == "DEBUG" or config_inverter['log_file'] == "INFO" or config_inverter['log_file'] == "WARNING" or config_inverter['log_file'] == "ERROR": + logfile = datetime.now().strftime("%Y%m%d_%H%M%S_SunGather.log") + fh = logging.FileHandler(logfile, mode='w', encoding='utf-8') + fh.formatter = logger.handlers[0].formatter + fh.setLevel(config_inverter['log_file']) + logger.addHandler(fh) + else: + logging.warning(f"log_file: Valid options are: DEBUG, INFO, WARNING, ERROR and OFF") + + logging.info(f"Logging to console set to: {logging.getLevelName(logger.handlers[0].level)}") + if logger.handlers.__len__() == 3: + logging.info(f"Logging to file set to: {logging.getLevelName(logger.handlers[2].level)}") + logging.debug(f'Inverter Config Loaded: {config_inverter}') if config_inverter.get('host'): @@ -467,7 +492,7 @@ def main(): logging.error(f"Error: host option in config is required") sys.exit("Error: host option in config is required") - if not inverter.connect(): + if not inverter.checkConnection(): logging.error(f"Error: Connection to inverter failed: {config_inverter.get('host')}:{config_inverter.get('port')}") sys.exit(f"Error: Connection to inverter failed: {config_inverter.get('host')}:{config_inverter.get('port')}") @@ -493,7 +518,7 @@ def main(): while True: loop_start = datetime.now() - inverter.connect() + inverter.checkConnection() # Scrape the inverter success = inverter.scrape() @@ -520,6 +545,16 @@ def main(): logging.info(f'Next scrape in {int(scan_interval - process_time)} secs') time.sleep(scan_interval - process_time) +logging.basicConfig( + format='%(asctime)s %(levelname)-8s %(message)s', + level=logging.DEBUG, + datefmt='%Y-%m-%d %H:%M:%S') + +logger = logging.getLogger('') +ch = logging.StreamHandler() +ch.setLevel(logging.WARNING) +logger.addHandler(ch) + if __name__== "__main__": main() diff --git a/SunGather/version.py b/SunGather/version.py index 9c5adf7..f37c5fa 100644 --- a/SunGather/version.py +++ b/SunGather/version.py @@ -1 +1 @@ -__version__ = '0.3.1' \ No newline at end of file +__version__ = '0.3.2' \ No newline at end of file diff --git a/requirements.txt b/requirements.txt index f0ce8fb..264094e 100644 --- a/requirements.txt +++ b/requirements.txt @@ -1,7 +1,7 @@ PyYAML>=6.0 requests>=2.26.0 paho-mqtt>=1.5.1 -pymodbus>=2.4.0 +pymodbus>=2.5.3 SungrowModbusTcpClient>=0.1.5 SungrowModbusWebClient>=0.2.7 influxdb-client>=1.24.0 From 1a2ca4397c21a08534a4fd25d7da1d4efb112c2a Mon Sep 17 00:00:00 2001 From: bohdan-s Date: Thu, 27 Jan 2022 15:15:45 +1100 Subject: [PATCH 3/3] Missed modbus session being closed --- SunGather/exports/mqtt.py | 5 ++-- SunGather/sungather.py | 58 +++++++++++++++++++++------------------ 2 files changed, 34 insertions(+), 29 deletions(-) diff --git a/SunGather/exports/mqtt.py b/SunGather/exports/mqtt.py index a52134b..ba3685f 100644 --- a/SunGather/exports/mqtt.py +++ b/SunGather/exports/mqtt.py @@ -70,8 +70,9 @@ def cleanName(self, name): def publish(self, inverter): if not self.mqtt_client.is_connected(): logging.warning(f'MQTT: Server Disconnected; {self.mqtt_queue.__len__()} messages queued, will automatically attempt to reconnect') - elif self.mqtt_queue.__len__() > 10: - logging.warning(f'MQTT: {self.mqtt_queue.__len__()} messages queued, this may be due to a MQTT server issue') + # qos=0 is set, so no acknowledgment is sent, rending this check useless + #elif self.mqtt_queue.__len__() > 10: + # logging.warning(f'MQTT: {self.mqtt_queue.__len__()} messages queued, this may be due to a MQTT server issue') logging.debug(f"MQTT: Publishing: {self.mqtt_config['topic']} : {json.dumps(inverter.latest_scrape)}") self.mqtt_queue.append(self.mqtt_client.publish(self.mqtt_config['topic'], json.dumps(inverter.latest_scrape).replace('"', '\"'), qos=0).mid) diff --git a/SunGather/sungather.py b/SunGather/sungather.py index 88790ea..aed06dc 100644 --- a/SunGather/sungather.py +++ b/SunGather/sungather.py @@ -41,21 +41,12 @@ def __init__(self, config_inverter): self.latest_scrape = {} - def checkConnection(self): - logging.debug("Checking Modbus Connection") + def connect(self): if self.client: - if not self.client.is_socket_open(): - logging.warning(f'Modbus socket is not connected, attempting to reconnect') - self.disconnect() - return self.connect() - else: - logging.debug("Modbus client is still connected") - return True - else: - logging.warning(f'Modbus client is not connected, attempting to reconnect') - return self.connect() + try: self.client.connect() + except: return False + return True - def connect(self): if self.inverter_config['connection'] == "http": self.client_config['port'] = '8082' self.client = SungrowModbusWebClient.SungrowModbusWebClient(**self.client_config) @@ -68,18 +59,32 @@ def connect(self): return False logging.info("Connection: " + str(self.client)) - try: retval = self.client.connect() + try: self.client.connect() except: return False - # Wait 3 seconds, fixes timing issues - time.sleep(3) - # Remove the .close, I think this is causing more issues than solving. - #if not self.inverter_config['connection'] == "http": - # self.client.close() - return retval + time.sleep(3) # Wait 3 seconds, fixes timing issues + return True + + def checkConnection(self): + logging.debug("Checking Modbus Connection") + if self.client: + if self.client.is_socket_open(): + logging.debug("Modbus, Session is still connected") + return True + else: + logging.info(f'Modbus, Connecting new session') + return self.connect() + else: + logging.info(f'Modbus client is not connected, attempting to reconnect') + return self.connect() + + def close(self): + logging.info("Closing Session: " + str(self.client)) + try: self.client.close() + except: pass def disconnect(self): - logging.info("Disconnected: " + str(self.client)) + logging.info("Disconnecting: " + str(self.client)) try: self.client.close() except: pass self.client = None @@ -159,6 +164,7 @@ def configure_registers(self,registersfile): continue if register_range_used: self.register_ranges.append(register_range) + return True def load_registers(self, register_type, start, count=100): try: @@ -274,11 +280,7 @@ def getInverterModel(self, clean=False): else: return self.inverter_config['model'] - def scrape(self): - if not self.checkConnection(): - logging.warning(f'Modbus not connected, Scraping Skipped') - return False - + def scrape(self): scrape_start = datetime.now() # Clear previous inverter values, keep the model and run state @@ -497,7 +499,8 @@ def main(): sys.exit(f"Error: Connection to inverter failed: {config_inverter.get('host')}:{config_inverter.get('port')}") inverter.configure_registers(registersfile) - + if not inverter.inverter_config['connection'] == "http": inverter.close() + # Now we know the inverter is working, lets load the exports exports = [] if configfile.get('exports'): @@ -526,6 +529,7 @@ def main(): if(success): for export in exports: export.publish(inverter) + if not inverter.inverter_config['connection'] == "http": inverter.close() else: inverter.disconnect() logging.warning(f"Data collection failed, skipped exporting data. Retying in {scan_interval} secs")