From 60aca91324f5c9090e4cac3d8ffaca4e1fa31e27 Mon Sep 17 00:00:00 2001 From: fabianhu Date: Fri, 5 Jan 2024 10:48:43 +0100 Subject: [PATCH] cleanup (see details) - a lot of fixme's are gone - better logging - handle all sungrow communication in one thread - remember last set state for sungrow battery to not send unnecessary commands. - avoid exceptions on missing data - better thread supervision (check, if medhods from class instance is called in same thread) - avoid exception, if Tibber does not provide price - tesla wattage scaling fix - switched to amp-based charging instead of watts. --- efb_main.py | 71 ++++++++---------- lib/intervaltask/intervaltask.py | 54 +++++++++---- lib/logger/logger.py | 35 ++++++--- lib/parameters/parameters.py | 5 +- lib/tesla_api | 2 +- lib/tibber/tibber.py | 54 +++++++++---- sungrow.py | 125 ++++++++++++++++++------------- task_tibber.py | 37 +++++---- tasmota.py | 4 +- tesla_interface.py | 66 ++++++++-------- 10 files changed, 266 insertions(+), 187 deletions(-) diff --git a/efb_main.py b/efb_main.py index 12ff9a7..6b76103 100644 --- a/efb_main.py +++ b/efb_main.py @@ -32,7 +32,6 @@ import config import modbus -import task_tibber import tesla_interface import lib.tesla_api.tesla_api_2024 import lib.tibber @@ -106,17 +105,12 @@ def __init__(self): self.myTesla = tesla_interface.TeslaCar(config.tesla_vin, lib.tesla_api.tesla_api_2024.TeslaAPI()) # timing stuff - #self.last_car_update = time.time() - # self.last_car_charge_update = time.time() self.last_car_charge_current_sync = time.time() - #self.last_heater_update = time.time() - #self.last_tasmota_update = time.time() self.EMERGENCY_HEATER_OFF = False self.sg = sungrow.SungrowSH(sungrow_ip, 502) - RS485_bus = modbus.Bus("/dev/ttyUSB0") self.temperatures_heating = modbus.Nt18b07TemperatureIn(RS485_bus, 1) self.rel1 = modbus.Bestep2Relays(RS485_bus, 0xff) @@ -128,7 +122,6 @@ def __init__(self): self.heatpower = 0 self.car_charge_amp = 0 #fixme move to Tesla! - self.car_charging_phases = 3 #fixme move to Tesla! self.last_tibber_schedule = datetime.now()-timedelta(days=2) # set to the past @@ -136,9 +129,6 @@ def __init__(self): self.dtu = openDTU.OpenDTU(openDTU_ip) - logger.info("Start ####################################################################") - logger.log("Start ####################################################################") - taskctl = lib.intervaltask.TaskController() taskctl.add_task("tesla", self.do_car_update, 5*60,30) taskctl.add_task("tesla_charge", self.do_car_charge, 30, 20) @@ -190,6 +180,17 @@ def do_car_update(self): # every 5 min def do_sungrow_update(self): self.sg.update() # get values from Wechselrichter + car_charge_power = self.myTesla.car_db_data.get_value_filtered('CAR_charge_W') + # battery_soc = self.sg.measurements.get_value('ELE Battery level') + # fixme batrecommend = task_tibber.check_battery(battery_soc) + + # stop DISCHARGING the battery on high load from car and control battery at same point. + if self.myTesla.is_here_and_connected() and car_charge_power > 10000: # fixme check this decision!! + self.sg.set_forced_charge(0) + else: + self.sg.set_forced_charge(None) + + def do_temperature_update(self): # every 2s self.temperatures_heating.get_temperatures() @@ -199,9 +200,12 @@ def do_temperature_update(self): # every 2s self.heating_measurements.update_value("Pi Temp", measure_pi_temp()) - boiler_temp_sum = (self.heating_measurements.get_value("HEAT Boiler Oben") + self.heating_measurements.get_value("HEAT Boiler Unten") + self.heating_measurements.get_value( - "HEAT Boiler 3")) / 3.0 - self.heating_measurements.update_value("HEAT Water prc", map_to_percentage(boiler_temp_sum, (35 + 30 + 25) / 3.0, temp_setpoint)) + try: + boiler_temp_sum = (self.heating_measurements.get_value("HEAT Boiler Oben") + self.heating_measurements.get_value("HEAT Boiler Unten") + self.heating_measurements.get_value( + "HEAT Boiler 3")) / 3.0 + self.heating_measurements.update_value("HEAT Water prc", map_to_percentage(boiler_temp_sum, (35 + 30 + 25) / 3.0, temp_setpoint)) + except TypeError: # catch exception if value is None ! (RTU init error) + logger.error("Water heater values not present.") # prepare values: boiler_temp_bot = self.heating_measurements.get_value('HEAT Boiler Unten') @@ -247,31 +251,19 @@ def do_car_charge(self): export_power = self.sg.measurements.get_value_filtered('ELE Export power') battery_power = self.sg.measurements.get_value_filtered('ELE Battery power c') battery_soc = self.sg.measurements.get_value('ELE Battery level') - car_charge_power = self.myTesla.car_db_data.get_value_filtered('CAR_charge_W') - - batrecommend = task_tibber.check_battery(battery_soc) - - # stop DISCHARGING the battery on high load from car and control battery at same point. - if self.myTesla.is_here_and_connected() and car_charge_power > 10000: - if batrecommend is None: - self.sg.set_forced_charge(0) - else: - self.sg.set_forced_charge(batrecommend) - else: - self.sg.set_forced_charge(batrecommend) # ready for solar overflow charging - if self.myTesla.is_here_and_connected() and not self.stop_tesla and not self.myTesla.current_request == 16 and not ( + if self.myTesla.is_here_and_connected() and not self.stop_tesla and not self.myTesla.last_current_request == 16 and not ( export_power is None or battery_power is None or battery_soc is None ): # avoid charging with wrong value for too long # actual_set_charger_W = self.myTesla.charge_actual_W - if self.myTesla.current_actual > self.car_charge_amp and time.time() - self.last_car_charge_current_sync > 6 * 60: - logger.info(f"CAR charge current sync: was {self.car_charge_amp}, now {self.myTesla.current_actual}") - self.car_charge_amp = self.myTesla.current_actual # fixme at least one should not exist + if self.myTesla.last_current_actual > self.car_charge_amp and time.time() - self.last_car_charge_current_sync > 6 * 60: + logger.info(f"CAR charge current sync: was {self.car_charge_amp}, now {self.myTesla.last_current_actual}") + self.car_charge_amp = self.myTesla.last_current_actual # fixme at least one should not exist self.last_car_charge_current_sync = time.time() if battery_soc > 30 and battery_power > -4000 and export_power > (-4500 if self.island_mode else -200): # only allow charging over x% battery @@ -288,12 +280,12 @@ def do_car_charge(self): if (export_power + battery_power + phantasy_power) > 750 and self.car_charge_amp < 15: self.car_charge_amp += 1 - self.myTesla.set_charge(True, self.car_charge_amp * 230 * self.car_charging_phases) + self.myTesla.set_charge(True, self.car_charge_amp) # logger.info("Tesla inc", self.car_charge_amp) if (export_power + battery_power + phantasy_power) < (-500 if self.island_mode else 0) and self.car_charge_amp > 0: self.car_charge_amp -= 1 - self.myTesla.set_charge(True, self.car_charge_amp * 230 * self.car_charging_phases) + self.myTesla.set_charge(True, self.car_charge_amp) # logger.info("Tesla dec", self.car_charge_amp) @@ -308,7 +300,7 @@ def do_car_charge(self): self.car_charge_amp = 0 # Tesla not ready # logger.info("Car not ready") - self.heating_measurements.update_value("CAR Charge command", self.car_charge_amp * 230 * self.car_charging_phases) + self.heating_measurements.update_value("CAR Charge command", self.car_charge_amp * 230 * self.myTesla.last_charging_phases) if self.car_charge_amp > 0 or self.myTesla.is_charging: self.allowHeater = False @@ -427,7 +419,10 @@ def do_tesla_tibber_planning(self): TIBBER_CAR_CHARGE_CURRENT = 16 # todo parameter - must be the same value as the decision, if solar overflow charging!! now = datetime.now() - #fixme take into account the time of last connection? + + if not self.myTesla.is_here_and_connected(): + self.last_tibber_schedule = now - timedelta(days=2) # set to the past + if now-self.last_tibber_schedule > timedelta(hours=2) and self.myTesla.is_here_and_connected(): soc = self.myTesla.car_db_data.get_value("CAR_battery_level") soclim = self.myTesla.car_db_data.get_value("CAR_charge_limit_soc") @@ -439,18 +434,18 @@ def do_tesla_tibber_planning(self): return if soc is None or soclim is None: - logger.error("Tibber Charge Plan no info from Tesla") + logger.error("Tibber Car Charge Plan no info from Tesla") return mins = lib.tibber.tibber.datetime_to_minutes_after_midnight(myTibber.cheapest_charging_time(soc,soclim)) if mins is None: - logger.error(f"Tibber we had no result from {myTibber.prices}") + logger.error(f"Tibber we had no result from {myTibber.prices} with SOC: {soc} and limit: {soclim}") return self.myTesla.tesla_api.cmd_charge_set_schedule(self.myTesla.vin, mins) self.last_tibber_schedule = now - logger.debug(f"Tibbering {mins/60} h") + logger.info(f"Tibber Car charge plan is start at {mins/60} h") @@ -458,6 +453,6 @@ def do_tesla_tibber_planning(self): if __name__ == '__main__': efb = ElectronFluxBalancer() while True: - efb.do_temperature_update() + efb.do_temperature_update() # fixme we do not have a watchdog here! efb.do_heater_update() - time.sleep(2) + time.sleep(2) \ No newline at end of file diff --git a/lib/intervaltask/intervaltask.py b/lib/intervaltask/intervaltask.py index 173b923..0f11a4c 100644 --- a/lib/intervaltask/intervaltask.py +++ b/lib/intervaltask/intervaltask.py @@ -1,20 +1,43 @@ +import functools +import logging import threading import time -from datetime import datetime from ..logger import Logger -logger = Logger() +logger = Logger(log_level=logging.DEBUG, log_path="tasks.log") import traceback # fixme think about multiprocessing +def thread_alert(func): + """ + Check, if methods of class are executed in same thread. + Add self.init_thread_id = None to the class you want to check. + add @lib.intervaltask.intervaltask.thread_alert decorator to method. and import lib.intervaltask + :param func: + :return: + """ + @functools.wraps(func) + def wrapper(instance, *args, **kwargs): + class_name = instance.__class__.__name__ + current_thread_id = threading.get_ident() + if instance.init_thread_id is None: + instance.init_thread_id = current_thread_id + logger.info(f"Initialising '{func.__name__}()' for class {class_name} in thread '{threading.current_thread().name}'.") + if instance.init_thread_id != current_thread_id: + logger.error(f"Alarm: Method '{func.__name__}()' in class {class_name} executed in another Thread '{threading.current_thread().name}' than the Initialisation thread.") + + return func(instance, *args, **kwargs) + + return wrapper + class TaskController: def __init__(self): self.tasks = {} self.lock = threading.Lock() def add_task(self, name, func, interval, watchdog_timeout): - t = threading.Thread(target=self._run_task, args=(name,)) + t = threading.Thread(target=self._run_task, name=name, args=(name,)) self.tasks[name] = { 'func': func, 'original_func': func, # Store a copy of the original function @@ -41,7 +64,7 @@ def _run_task(self, name): start_time = time.time() if not callable(func): - logger.log(f"Task {name} not callable: {func}, {self.tasks[name]}") # fixme check, how to recover + logger.error(f"Task {name} not callable: {func}, {self.tasks[name]}") # fixme check, how to recover self.log_func_details(func, name) self.tasks[name]['func'] = self.tasks[name]['original_func'] # Restore original function else: @@ -50,8 +73,8 @@ def _run_task(self, name): except Exception as e: tb = traceback.extract_tb(e.__traceback__) filename, line, func, text = tb[-1] - logger.log(f"Exception occurred in task {name} in file {filename} at line {line}: Exception : {e}") - logger.log(f"Traceback: {traceback.format_exc()}") + logger.error(f"Exception occurred in task {name} in file {filename} at line {line}: Exception : {e}") + logger.debug(f"Traceback: {traceback.format_exc()}") end_time = time.time() @@ -66,25 +89,26 @@ def _run_task(self, name): def _restart_task(self, name): with self.lock: - logger.log(f"Watchdog activated for task {name}.") + logger.error(f"Watchdog activated for task {name}.") task_data = self.tasks[name] if self.is_task_running(name): # check if task is still running logger.error(f"Task {name} is still running and the timeout of {self.tasks[name]['watchdog_timeout']}s is over") # fixme we did not kill it! - raise Exception(f"Task {name} is hanging") + raise Exception(f"Task {name} is hanging with data: {task_data}") else: - logger.log(f"Task {name} died on the way - restarting") + logger.error(f"Task {name} died on the way - restarting") t = threading.Thread(target=self._run_task, args=(name,)) self.tasks[name]['thread'] = t t.start() - def log_func_details(self, func, task_name): - logger.log(f"Details of non-callable task '{task_name}':") - logger.log(f"Type: {type(func)}") - logger.log(f"String representation: {func}") - logger.log(f"Attributes: {dir(func)}") + @staticmethod + def log_func_details(func, task_name): + logger.debug(f"Details of non-callable task '{task_name}':") + logger.debug(f"Type: {type(func)}") + logger.debug(f"String representation: {func}") + logger.debug(f"Attributes: {dir(func)}") if hasattr(func, '__dict__'): - logger.log(f"Object dictionary: {func.__dict__}") + logger.debug(f"Object dictionary: {func.__dict__}") # Example usage def task1(): diff --git a/lib/logger/logger.py b/lib/logger/logger.py index 1ef0f5b..05b72a8 100644 --- a/lib/logger/logger.py +++ b/lib/logger/logger.py @@ -1,18 +1,33 @@ +import datetime import logging import inspect class Logger: def __init__(self, log_level=logging.ERROR, log_path='log.log'): + """ + Initializes a Logger object for module-specific logging. + This method configures a logger with a file handler, suitable for logging messages from the calling module. The logger + captures all messages (level DEBUG), while the file handler records messages based on `log_level`. + The logger's name is automatically set to the calling module's name, allowing distinct log outputs for different modules. + Log messages are formatted to include timestamp, logger name, level, and message. + + Parameters: + - log_level (logging.Level, optional): Minimum level of log messages to be recorded. Defaults to logging.ERROR. + - log_path (str, optional): File path for the log output. Defaults to 'log.log'. + + Note: + - The logger level and file handler level are independent; the file handler may filter out lower-severity messages. + """ + # Retrieve the caller's module name using inspect - #caller_frame = inspect.stack()[1] - #module_name = inspect.getmodule(caller_frame[0]).__name__ caller_frame = inspect.currentframe().f_back module_name = caller_frame.f_globals['__name__'] + self.log_handler = logging.FileHandler(log_path) + self.logger = logging.getLogger(module_name) self.logger.setLevel(logging.DEBUG) # Set to the lowest level to capture all messages by default - self.log_handler = logging.FileHandler(log_path) self.log_handler.setLevel(log_level) formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') @@ -20,15 +35,8 @@ def __init__(self, log_level=logging.ERROR, log_path='log.log'): self.logger.addHandler(self.log_handler) - def get_logger(self, module_name, log_level=logging.ERROR): - module_logger = logging.getLogger(module_name) - module_logger.setLevel(log_level) - module_logger.propagate = False # Prevent logs from propagating up the hierarchy - - if not any(isinstance(handler, logging.FileHandler) for handler in module_logger.handlers): - module_logger.addHandler(self.log_handler) # Add the file handler if not already present - - return module_logger + self.logint(f"Logger created from {module_name} logging to {log_path}") + self.logger.info("############### START ############################################") def debug(self, message): self.logger.debug(message) @@ -48,6 +56,9 @@ def error(self, message): def critical(self, message): self.logger.critical(message) + @staticmethod + def logint(message): + with open("logger_internal.log", "a") as f: f.write(f"{datetime.datetime.now()} {message}\n") diff --git a/lib/parameters/parameters.py b/lib/parameters/parameters.py index 525fe07..8b519e3 100644 --- a/lib/parameters/parameters.py +++ b/lib/parameters/parameters.py @@ -73,11 +73,14 @@ def __init__(self, host='0.0.0.0', port=5000): self.host = host self.port = port + def add_parameter(self, _name:str, _min:float, _max:float, _unit:str, _type:str, _step:float, _value ): + self.central_parameters[_name] = {'min': _min, 'max': _max, 'unit': _unit, 'type': _type, 'step': _step, 'value': _value} + def run_server(self): self.app.run(host=self.host, port=self.port) - def index(self): + def index(self): # the html representation if request.method == 'POST': print("post") for key, param in self.central_parameters.items(): diff --git a/lib/tesla_api b/lib/tesla_api index a414bb5..689c82c 160000 --- a/lib/tesla_api +++ b/lib/tesla_api @@ -1 +1 @@ -Subproject commit a414bb5979153dab991b50f29b9d50912961d94a +Subproject commit 689c82c7ef804b86ab1a35bee2d2e52fd7385fd2 diff --git a/lib/tibber/tibber.py b/lib/tibber/tibber.py index cfc1b72..afddde3 100644 --- a/lib/tibber/tibber.py +++ b/lib/tibber/tibber.py @@ -125,22 +125,45 @@ def update_price_info(self): data = json.loads(response.text) # Extract current and tomorrow's price - current_price = data['data']['viewer']['homes'][0]['currentSubscription']['priceInfo']['current']['total'] - prices_today = data['data']['viewer']['homes'][0]['currentSubscription']['priceInfo']['today'] - prices_tomorrow = data['data']['viewer']['homes'][0]['currentSubscription']['priceInfo']['tomorrow'] + try: + current_price = data['data']['viewer']['homes'][0]['currentSubscription']['priceInfo']['current']['total'] + except (KeyError, IndexError) as e: + current_price = None + logger.error(f"No current price exception {e}") + self.prices = None + self.price_time = datetime.now() - timedelta(days=2) # old!! + return False + + try: + prices_today = data['data']['viewer']['homes'][0]['currentSubscription']['priceInfo']['today'] + except (KeyError, IndexError) as e: + current_price = None + logger.error(f"No prices today exception {e}") + self.prices = None + self.price_time = datetime.now() - timedelta(days=2) # old!! + return False + + try: + prices_tomorrow = data['data']['viewer']['homes'][0]['currentSubscription']['priceInfo']['tomorrow'] + except (KeyError, IndexError) as e: + current_price = None + logger.error(f"No prices tomorrow exception {e}") + self.prices = None + self.price_time = datetime.now() - timedelta(days=2) # old!! + return False '''print(f"Current Price: {current_price}") - - # Loop through and display tomorrow's prices - print("Today's Prices:") - for price in prices_today: - dt = tibber_time_to_datetime(price['startsAt']) - print(f"Starts At: {dt}, Total: {price['total']}") - - print("Tomorrow's Prices:") - for price in prices_tomorrow: - dt = tibber_time_to_datetime(price['startsAt']) - print(f"Starts At: {dt}, Total: {price['total']}")''' + + # Loop through and display tomorrow's prices + print("Today's Prices:") + for price in prices_today: + dt = tibber_time_to_datetime(price['startsAt']) + print(f"Starts At: {dt}, Total: {price['total']}") + + print("Tomorrow's Prices:") + for price in prices_tomorrow: + dt = tibber_time_to_datetime(price['startsAt']) + print(f"Starts At: {dt}, Total: {price['total']}")''' # If prices for tomorrow are None, replace them with today's maximum prices if prices_tomorrow is None or prices_tomorrow == []: @@ -164,6 +187,7 @@ def update_price_info(self): self.price_time = datetime.now()-timedelta(days=2) # old!! return False + def post_request(self, query): # Create the header headers = { @@ -369,4 +393,4 @@ def get_price(self): }, ... -''' +''' \ No newline at end of file diff --git a/sungrow.py b/sungrow.py index bb580ac..85ffd7c 100644 --- a/sungrow.py +++ b/sungrow.py @@ -1,11 +1,12 @@ # Sungrow modbus TCP interface # works with SH10RT import datetime - +import logging +import lib.intervaltask from pymodbus.client import ModbusTcpClient from lib.measurementlist import MeasurementList from lib.logger import Logger -logger = Logger() +logger = Logger(log_level=logging.ERROR, log_path="sungrow.log") def checked_multiply(a,b): if a is not None and b is not None: @@ -13,15 +14,17 @@ def checked_multiply(a,b): else: return None - class SungrowSH: def __init__(self, ip, port): + self.init_thread_id = None self.call_counter = 0 logger.info(f"Start SungrowSH, {ip}") self.measurements = MeasurementList() self.client = ModbusTcpClient(ip, port, timeout=2, retries=1) + self.forced_charge = 0 # remember the last forced charge state to avoid sending all the time. init with zero, as this requires reactivation. + r = self.client.read_input_registers(address=4949, count=2 + 2 + 15 + 15, slave=1) # 4968 ver = ''.join(f' {reg:04x}' for reg in r.registers[0:4]) sw_ARM = extract_string_from_data(r.registers, 4, 15) @@ -71,7 +74,7 @@ def decode_array(self, data, startaddress): all_zero = False break if all_zero: - logger.log("All elements are zero") # Thanks Sungrow! + logger.error("All elements are zero") # Thanks Sungrow! return # proceed through address list and fissle out the data from the data. @@ -96,17 +99,18 @@ def decode_array(self, data, startaddress): decoded = (data[index + 1] << 16) | (data[index] & 0xFFFF) if decoded is None: - logger.log(f"Sungrow decoding error, {data_type}, {i}") + logger.error(f"Sungrow decoding error, {data_type}, {i}") else: scaled = decoded * self.measurements.get_source(i)['factor'] self.measurements.update_value(i, scaled) + @lib.intervaltask.intervaltask.thread_alert def update(self, _test=False): try: # Connect to the device - connection closed in "finally" self.client.connect() except Exception as e: - logger.log(f'Modbus TCP connect {type(e)}: {e}') + logger.error(f'Modbus TCP connect {type(e)}: {e}') return try: @@ -120,7 +124,7 @@ def update(self, _test=False): self.call_counter = 0 except Exception as e: - logger.log(f'Modbus TCP error: {type(e)}: {e}') + logger.error(f'Modbus TCP error: {type(e)}: {e}') finally: @@ -140,126 +144,145 @@ def update(self, _test=False): enable_log = False # log all (expected) modbus errors + @lib.intervaltask.intervaltask.thread_alert def read_and_process_registers(self, start, count): # yes, a lot of hardcoded numbers in here. try: result = self.client.read_input_registers(start, count=count, slave=1) if result.isError(): - logger.log(f"Modbus TCP error: {result}") + logger.error(f"Modbus TCP error: {result}") return registers = result.registers if start == 4999: if registers[0] != 0x0E0F: - if self.enable_log: logger.log("Modbus-TCP: Not the correct ID") + if self.enable_log: logger.error("Modbus-TCP: Not the correct ID") hex_string = ''.join(f'{reg:04x} ' for reg in registers) - if self.enable_log: logger.log(f"Modbus-TCP: malformed data {start} (hex): {hex_string}") + if self.enable_log: logger.info(f"Modbus-TCP: malformed data {start} (hex): {hex_string}") return if registers[5000-start] != 100: - if self.enable_log: logger.log("Modbus-TCP: Nominal output power is not as expected") + if self.enable_log: logger.error("Modbus-TCP: Nominal output power is not as expected") hex_string = ''.join(f'{reg:04x} ' for reg in registers) - if self.enable_log: logger.log(f"Modbus-TCP: malformed data {start} (hex): {hex_string}") + if self.enable_log: logger.info(f"Modbus-TCP: malformed data {start} (hex): {hex_string}") return if registers[5007-start] == 0: - if self.enable_log: logger.log("Modbus-TCP: internal temperature is Zero") + if self.enable_log: logger.error("Modbus-TCP: internal temperature is Zero") hex_string = ''.join(f'{reg:04x} ' for reg in registers) - if self.enable_log: logger.log(f"Modbus-TCP: malformed data {start} (hex): {hex_string}") + if self.enable_log: logger.info(f"Modbus-TCP: malformed data {start} (hex): {hex_string}") return self.decode_array(registers, start) elif start == 13007: if registers[13038 - start] != 960: - if self.enable_log: logger.log("Modbus-TCP: Received not my battery capacity") + if self.enable_log: logger.error("Modbus-TCP: Received not my battery capacity") hex_string = ''.join(f'{reg:04x} ' for reg in registers) - if self.enable_log: logger.log(f"Modbus-TCP: malformed data {start + count - 1} (hex): {hex_string}") + if self.enable_log: logger.info(f"Modbus-TCP: malformed data {start + count - 1} (hex): {hex_string}") return if 950 > registers[13023 - start] > 1000: - if self.enable_log: logger.log("Modbus-TCP: Battery SOH not as expected.") + if self.enable_log: logger.error("Modbus-TCP: Battery SOH not as expected.") hex_string = ''.join(f'{reg:04x} ' for reg in registers) - if self.enable_log: logger.log(f"Modbus-TCP: malformed data {start + count - 1} (hex): {hex_string}") + if self.enable_log: logger.info(f"Modbus-TCP: malformed data {start + count - 1} (hex): {hex_string}") return self.decode_array(registers, start) except Exception as e: - logger.log(f'Modbus TCP error {type(e)}: {e}') - + logger.error(f'Modbus TCP error {type(e)}: {e}') + @lib.intervaltask.intervaltask.thread_alert def set_forced_charge(self, _power): - # command the battery to do stuff. None is back to work. """ - 13049: EMS mode selection - 0: Self-consumption mode (Default); - 2: Forced mode(charge/discharge/stop); - 3: External EMS mode - 13050: Charge/discharge command - 0xAA: Charge; - 0xBB:Discharge; - 0xCC: Stop ( Default ); - 13051: Charge/discharge power [W] 0-5000 - """ + Command the battery to charge or discharge with set power. + Only writes, if different from actual setting. + :param _power: Charge Watts. Negative is discharge. None is back to work. + :return: + """ + if self.forced_charge == _power: # avoid execution, when wanted status is equal to the desired state. + return try: self.client.connect() except Exception as e: - logger.log(f'Modbus TCP connect {type(e)}: {e}') + logger.error(f'Modbus TCP connect {type(e)}: {e}') return else: # write power command - but only if it has changed! try: r = self.client.read_holding_registers(13049, 3, 1) if not hasattr(r, 'registers'): - logger.log("Modbus read error on set charge") + logger.error(f"Modbus read error on set charge to {_power} W") return read_registers = r.registers + """ + 13049: EMS mode selection + 0: Self-consumption mode (Default); + 2: Forced mode(charge/discharge/stop); + 3: External EMS mode + 13050: Charge/discharge command + 0xAA: Charge; + 0xBB: Discharge; + 0xCC: Stop ( Default ); + 13051: Charge/discharge power [W] 0-5000 + """ if _power is None: # normal op at None values - logger.info("Battery set to normal operation") + log_info_txt="Battery set to normal operation" set_registers = [0, 0xCC, 0] elif _power == 0: # stop - logger.info(f"Battery set to stop operation") + log_info_txt=f"Battery set to stop operation" set_registers = [2, 0xCC, 0] elif 5000 >= _power > 0: # charge - logger.info(f"Battery set to charge operation with {_power} W") + log_info_txt=f"Battery set to charge operation with {_power} W" set_registers = [2, 0xAA, abs(_power)] elif -5000 <= _power < 0: # discharge - logger.info(f"Battery set to discharge operation with {_power} W") + log_info_txt=f"Battery set to discharge operation with {_power} W" set_registers = [2, 0xBB, abs(_power)] else: - logger.log(f"Battery power request out of range with {_power} W!") + logger.error(f"Battery power request out of range with {_power} W!") # normal op at abnormal values - logger.info("Battery set to normal operation on error") + log_info_txt="Battery set to normal operation on error" set_registers = [0, 0xCC, 0] + _power = None + + if set_registers != read_registers: + logger.info(log_info_txt) + self.client.write_registers(13049, set_registers, 1) - for i in range(3): - if set_registers[i] != read_registers[i]: - self.client.write_register(13049+i, set_registers[i] , 1) + ''' for i in range(3): + if set_registers[i] != read_registers[i]: + self.client.write_register(13049+i, set_registers[i] , 1)''' + self.forced_charge = _power except Exception as e: - logger.log(f'Modbus write error {type(e)}: {e}') + logger.error(f'Modbus write error on set charge {type(e)}: {e}') return - + @lib.intervaltask.intervaltask.thread_alert def set_soc_reserve(self,prc): + """ + Set SOC reserve for battery + :param prc: Percentage + :return: - + """ # set the minimum state of charge during grid operation if prc < 5: prc = 5 - logger.log(f'Set discharge min SOC to 5 %, not {prc} %, which is lower than allowed!') + logger.warning(f'Set discharge min SOC to 5 %, not {prc} %, which is lower than allowed!') elif prc < 10: - logger.log(f'Set discharge min SOC to {prc} %, which is lower than recommended!') + logger.warning(f'Set discharge min SOC to {prc} %, which is lower than recommended!') try: self.client.connect() except Exception as e: - logger.log(f'Modbus TCP connect {type(e)}: {e}') + logger.error(f'Modbus TCP connect {type(e)}: {e}') return else: r = self.client.read_holding_registers(13099, 1, 1) if not hasattr(r, 'registers'): - logger.log("Modbus read error on set soc reserve") + logger.error(f"Modbus read error on set soc reserve to {prc}") return soc = r.registers[0] if soc != prc: @@ -268,7 +291,7 @@ def set_soc_reserve(self,prc): self.client.write_register(13099, prc, 1) logger.info(f'Battery discharge min SOC set to {prc} %') except Exception as e: - logger.log(f'Modbus write error {type(e)}: {e}') + logger.error(f'Modbus write error {type(e)}: {e}') return @@ -294,12 +317,14 @@ def extract_string_from_data(data, position, length): if __name__ == '__main__': from config import sungrow_test_ip + logger.logger.setLevel(logging.DEBUG) + sg = SungrowSH(sungrow_test_ip, 502) #sg.update(_test=True) #sg.update(_test=True) # call twice to process all data! #sg.set_forced_charge(None) - #sg.set_soc_reserve(25) + sg.set_soc_reserve(10) '''r= sg.client.read_holding_registers(13049,3,1) registers = r.registers diff --git a/task_tibber.py b/task_tibber.py index 61b0364..a86d315 100644 --- a/task_tibber.py +++ b/task_tibber.py @@ -50,21 +50,21 @@ def do_tibber_to_influx(): else: logger.error("Tibber data could not be obtained") -charge_start_dt = None +charge_start_plan_dt = None is_battery_planning_init = True -def check_battery(_house_soc): +def check_battery(_house_soc): # fixme this has to go to sungrow or main. global myTibber - global charge_start_dt + global charge_start_plan_dt global is_battery_planning_init if _house_soc is None: return None - PLANNING_SCHEDULE_HOUR = 21 + PLANNING_SCHEDULE_HOURS = [21, 2] LOOK_HOURS_FORWARD = 12 # how far to plan the next charge LOOK_HOURS_SPREAD = LOOK_HOURS_FORWARD + 6 # how far to look for the spread e.g. 21 + 12 = 9 +6 = 15 h SPREAD_FOR_CHARGE = 0.065 - SOC_TARGET = 50 + SOC_TARGET = 60 capacity_kWh = 10 max_power_kW = 5 @@ -73,7 +73,7 @@ def check_battery(_house_soc): current_time = datetime.now(timezone) # we plan at start of hour PLANNING_SCHEDULE_HOUR - if current_time.minute == 0 and current_time.minute == PLANNING_SCHEDULE_HOUR or is_battery_planning_init: # avoid to do twice at 30s interval (but nevermind, should not bother) + if current_time.minute == 0 and current_time.hour in PLANNING_SCHEDULE_HOURS or is_battery_planning_init: # avoid to do twice at 30s interval (but nevermind, should not bother) # calculate the best charging time is_battery_planning_init = False @@ -89,35 +89,34 @@ def check_battery(_house_soc): logger.info(f"Price spread in the next {LOOK_HOURS_SPREAD} hours: {spread}") if spread > SPREAD_FOR_CHARGE and _house_soc < SOC_TARGET: # set start time of planned charge - charge_start_dt = myTibber.cheapest_charging_time(_house_soc, SOC_TARGET, capacity_kWh, max_power_kW) - logger.info(f"Ok, it may be useful to charge the batt at {charge_start_dt}") + charge_start_plan_dt = myTibber.cheapest_charging_time(_house_soc, SOC_TARGET, capacity_kWh, max_power_kW) + logger.info(f"Ok, it may be useful to charge the batt at {charge_start_plan_dt}") else: - charge_start_dt = None + charge_start_plan_dt = None else: logger.error(f"No prices available in the next {LOOK_HOURS_SPREAD} hours.") - charge_start_dt = None + charge_start_plan_dt = None - if charge_start_dt is None: + if charge_start_plan_dt is None: return None #safety timer if 5 < current_time.hour < 21: - logger.debug("outside of business hours") - return None + logger.warning("Tibber based house batt charge outside of business hours") - # Calculate required energy to charge to 100% - required_kWh = (100 - _house_soc) / 100 * capacity_kWh + # Calculate required energy to charge + required_kWh = (100 - _house_soc) / 100 * capacity_kWh * 1.10 # Calculate the expected end time based on current charge percent hours_required = required_kWh / max_power_kW - calculated_end_time = charge_start_dt + timedelta(hours=hours_required) + calculated_end_time = charge_start_plan_dt + timedelta(hours=hours_required) # If current time is near the ideal start time and we're not already charging, start charging - if calculated_end_time >= current_time >= charge_start_dt and _house_soc < SOC_TARGET: + if calculated_end_time >= current_time >= charge_start_plan_dt and _house_soc < SOC_TARGET: return max_power_kW*1000 else: # Stop the charging process - charge_start_dt = None + charge_start_plan_dt = None return None @@ -132,4 +131,4 @@ def check_battery(_house_soc): soclim = 80 #dt = myTibber.cheapest_charging_time(soc, soclim) - #print( dt) + #print( dt) \ No newline at end of file diff --git a/tasmota.py b/tasmota.py index 9a4ea07..5200935 100644 --- a/tasmota.py +++ b/tasmota.py @@ -10,11 +10,13 @@ import imagelogger from config import tasmota_ips, tasmota_meter_ip +# fixme Exception: Task tasmota is hanging + lastImageTime = time.time() class Tasmotas: def __init__(self): - logger.log("Start Tasmota client") + logger.info("Start Tasmota client") self.iterator = 0 diff --git a/tesla_interface.py b/tesla_interface.py index 6ebdc31..2bcad7d 100644 --- a/tesla_interface.py +++ b/tesla_interface.py @@ -10,7 +10,7 @@ import math import time from lib.logger import Logger -logger = Logger(logging.INFO, "tesla.log") +logger = Logger(logging.ERROR, "tesla.log") from config import home @@ -57,8 +57,9 @@ def __init__(self, _vin, _api: tesla_api_2024.TeslaAPI): ### stuff to remember from last input for "is_ready" self.last_distance = 0 # ok - self.current_request = 0 # ok - self.current_actual = 0 # ok + self.last_current_request = 0 # ok + self.last_current_actual = 0 # ok + self.last_charging_phases = 3 self.is_charging = False # ok self.car_db_data = MeasurementList() @@ -72,8 +73,8 @@ def __init__(self, _vin, _api: tesla_api_2024.TeslaAPI): self.car_db_data.add_item(name="CAR_charger_actual_current", source=('charge_state', 'charger_actual_current'), unit="A", filter_jump=1, send_min_diff=1) self.car_db_data.add_item(name="CAR_charge_current_request", source=('charge_state', 'charge_current_request'), unit="A", filter_jump=1, send_min_diff=1) self.car_db_data.add_item(name="CAR_charge_limit_soc", source=('charge_state', 'charge_limit_soc'), unit="%", filter_jump=1, send_min_diff=1) - self.car_db_data.add_item(name="CAR_charger_phases", source=('charge_state', 'charger_phases'), unit="n", filter_jump=1, send_min_diff=1) - self.car_db_data.add_item(name="CAR_charger_power", source=('charge_state', 'charger_power'), unit="W", filter_jump=100, send_min_diff=100) + self.car_db_data.add_item(name="CAR_charger_phases", source=('charge_state', 'charger_phases'), unit="n", filter_jump=1, send_min_diff=1) # can be null while not charging + self.car_db_data.add_item(name="CAR_charger_power", source=('charge_state', 'charger_power'), unit="kW", filter_jump=1, send_min_diff=1) self.car_db_data.add_item(name="CAR_charger_voltage", source=('charge_state', 'charger_voltage'), unit="V", filter_jump=5, send_min_diff=1) self.car_db_data.add_item(name="CAR_charging_state", source=('charge_state', 'charging_state'), unit="") # can be 'Disconnected', 'Charging', 'Stopped', 'Complete', 'Starting' self.car_db_data.add_item(name="CAR_minutes_to_full_charge", source=('charge_state', 'minutes_to_full_charge'), unit="min") @@ -102,7 +103,7 @@ def __init__(self, _vin, _api: tesla_api_2024.TeslaAPI): def get_car_life_data(self): - r = self.tesla_api.get_vehicle_data(self.vin, 'charge_state;drive_state;location_data;vehicle_state') # requests LIVE data only -> None if asleep! + r = self.tesla_api.get_vehicle_data(self.vin, 'charge_state;drive_state;location_data;vehicle_state;climate_state') # requests LIVE data only -> None if asleep! if r is None: if self.car_data_cache is not None: self.car_data_cache['state']="asleep" # fake the state @@ -134,10 +135,12 @@ def refresh(self, _my_car_data=None): # this is 3 phase charging if _my_car_data['charge_state']['charger_phases'] == 2: charge_actual_W = _my_car_data['charge_state']['charger_actual_current'] * _my_car_data['charge_state']['charger_voltage'] * 3 + self.last_charging_phases = 3 elif _my_car_data['charge_state']['charger_phases'] == 1: charge_actual_W = _my_car_data['charge_state']['charger_actual_current'] * _my_car_data['charge_state']['charger_voltage'] + self.last_charging_phases = 1 else: - logger.log(f"Phases are hard, {_my_car_data['charge_state']['charger_phases']}") + logger.error(f"Phases are hard, {_my_car_data['charge_state']['charger_phases']}") charge_actual_W = 0 else: self.is_charging = False @@ -157,8 +160,8 @@ def refresh(self, _my_car_data=None): self.car_db_data.update_value("CAR_seen_ago", last_seen_s) # update member values - self.current_request = _my_car_data['charge_state']['charge_current_request'] # avoid control at 16A - self.current_actual = _my_car_data['charge_state']['charger_actual_current'] + self.last_current_request = _my_car_data['charge_state']['charge_current_request'] # avoid control at 16A + self.last_current_actual = _my_car_data['charge_state']['charger_actual_current'] # update all values with a defined source for i in self.car_db_data.get_name_list(): @@ -168,10 +171,12 @@ def refresh(self, _my_car_data=None): v = get_item(_my_car_data, s) if v is not None: # do not update None values as this is completely normal for e.g. "drive_state" to not be in the data self.car_db_data.update_value(i, v) - # logger.info(i,v,s) + # logger.debug(f"Updated item: {i}, Source {s}, Value: {v}") else: - pass - # logger.info(i, "NONE", s) + logger.debug(f"Missing item: {i}, Source {s}") + else: + pass + # logger.debug(f"Skipped item: {i}") self.car_db_data.write_measurements() @@ -183,7 +188,6 @@ def is_here_and_connected(self): # check, if car is ready according last data - # Car is not here if self.last_distance > 0.3: logger.debug(f"Tesla is {self.last_distance}km away") - # todo something like self.last_tibber_schedule = datetime.now()-timedelta(days=2) # set to the past return False if self.car_data_cache is None or not 'charge_state' in self.car_data_cache: @@ -196,37 +200,28 @@ def is_here_and_connected(self): # check, if car is ready according last data - return False if not self.car_data_cache['charge_state']['charging_state'] in ['Charging', 'Stopped']: # not 'Complete' - logger.debug("Tesla is not in right mood") + logger.debug("Tesla is connected, but not in right mood") return False return True - def set_charge(self, _do_charge, _req_power_w): # fixme check, if really useful to charge in W, when we calculate A before?!? + def set_charge(self, _do_charge, _req_amps): if not self.is_here_and_connected(): - logger.info("Tesla is not ready, but should be!") + logger.warning("Tesla is not ready, but should be!") return False - if self.car_data_cache['state'] == "asleep" and _do_charge and _req_power_w > 500: + if self.car_data_cache['state'] == "asleep" and _do_charge and _req_amps > 0: logger.info("Tesla - Wake up car, cos I want to charge") self.tesla_api.cmd_wakeup(self.vin) #leave here and set the commanded value later - so we will have a re-entry. return - # I = P / U - if self.car_data_cache['charge_state']['charger_phases'] == 2: - amps = _req_power_w / (230 * 3) - elif self.car_data_cache['charge_state']['charger_phases'] == 1: - amps = _req_power_w / 230 - else: - logger.error("Tesla: Unexpected value: charging phases are weird.") - return False - maxamps = self.car_data_cache['charge_state']['charge_current_request_max'] - if amps > maxamps: - logger.error(f"Tesla: prevent to charge more than {maxamps} A. - {amps} A requested.") - amps = maxamps + if _req_amps > maxamps: + logger.error(f"Tesla: prevent to charge more than {maxamps} A. - {_req_amps} A requested.") + _req_amps = maxamps - ampere_rounded = round(amps, 0) + ampere_rounded = round(_req_amps, 0) if ampere_rounded < 1: _do_charge = False @@ -236,22 +231,23 @@ def set_charge(self, _do_charge, _req_power_w): # fixme check, if really useful logger.info(f"charging stopped at {self.car_data_cache['charge_state']['charger_actual_current']} A") try: self.tesla_api.cmd_charge_stop(self.vin) - self.tesla_api.cmd_charge_set_amps(self.vin, 5) # fixme why? + self.tesla_api.cmd_charge_set_amps(self.vin, 5) # reset to lowest "legal" value to be starting low at next start. except Exception as e: - logger.log(f"Exception during stopping charge {type(e)}: {e}") + logger.error(f"Exception during stopping charge {type(e)}: {e}") self.car_data_cache['charge_state']['charging_state'] = 'Stopped' # remember the state! self.refresh(self.car_data_cache) # publish again return True # finished here, as all else is related to setting the current - if _req_power_w > 11000: - logger.log(f"WATT is wrong with you, {_req_power_w}") + req_power_w = _req_amps * self.last_charging_phases * 230 + if req_power_w > 11000: + logger.error(f"WATT is wrong with you, {req_power_w} W") return False if self.car_data_cache['charge_state']['charging_state'] == 'Stopped' and _do_charge: try: self.tesla_api.cmd_charge_start(self.vin) except Exception as e: - logger.log(f'Exception during starting charge {type(e)}: {e}') + logger.error(f'Exception during starting charge {type(e)}: {e}') logger.info("car charging started")