From da654ec5cece53932cb958bfa21d1cf256a94d89 Mon Sep 17 00:00:00 2001 From: bohdan-s Date: Thu, 27 Jan 2022 14:02:27 +1100 Subject: [PATCH] 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 @@ class export_influxdb(object): 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 @@ class export_mqtt(object): 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 @@ class export_mqtt(object): 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 yaml 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 @@ class SungrowInverter(): 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 @@ class SungrowInverter(): 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 @@ class SungrowInverter(): 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 @@ class SungrowInverter(): 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 @@ class SungrowInverter(): 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