S allius/issue111 (#112)

Synchronize regular MODBUS commands with the status of the inverter to prevent the inverter from crashing due to unexpected packets.

* inital checkin

* remove crontab entry for regular MODBUS cmds

* add timer for regular MODBUS polling

* fix Stop method call for already stopped timer

* optimize MB_START_TIMEOUT value

* cleanup

* update changelog

CHANGELOG.md

@@ -7,6 +7,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [unreleased]
 
+- Synchronize regular MODBUS commands with the status of the inverter to prevent the inverter from crashing due to
+  unexpected packets. [#111](https://github.com/s-allius/tsun-gen3-proxy/issues/111)
 - GEN3: avoid sending MODBUS commands to the inverter during the inverter's reporting phase
 - GEN3: determine the connection timeout based on the connection state
 - GEN3: support more data encodings for DSP version V5.0.17 [#108](https://github.com/s-allius/tsun-gen3-proxy/issues/108)

app/src/gen3/talent.py

@@ -6,11 +6,13 @@ from datetime import datetime
 if __name__ == "app.src.gen3.talent":
     from app.src.messages import hex_dump_memory, Message, State
     from app.src.modbus import Modbus
+    from app.src.my_timer import Timer
     from app.src.config import Config
     from app.src.gen3.infos_g3 import InfosG3
 else:  # pragma: no cover
     from messages import hex_dump_memory, Message, State
     from modbus import Modbus
+    from my_timer import Timer
     from config import Config
     from gen3.infos_g3 import InfosG3
 
@@ -35,6 +37,9 @@ class Control:
 
 
 class Talent(Message):
+    MB_START_TIMEOUT = 40
+    MB_REGULAR_TIMEOUT = 60
+
     def __init__(self, server_side: bool, id_str=b''):
         super().__init__(server_side, self.send_modbus_cb, mb_timeout=11)
         self.await_conn_resp_cnt = 0
@@ -65,7 +70,7 @@ class Talent(Message):
         }
         self.modbus_elms = 0    # for unit tests
         self.node_id = 'G3'     # will be overwritten in __set_serial_no
-        # self.forwarding = Config.get('tsun')['enabled']
+        self.mb_timer = Timer(self.mb_timout_cb, self.node_id)
 
     '''
     Our puplic methods
@@ -78,6 +83,7 @@ class Talent(Message):
         self.switch.clear()
         self.log_lvl.clear()
         self.state = State.closed
+        del self.mb_timer
         super().close()
 
     def __set_serial_no(self, serial_no: str):
@@ -160,13 +166,25 @@ class Talent(Message):
         self.writer.write(self._send_buffer)
         self._send_buffer = bytearray(0)  # self._send_buffer[sent:]
 
-    async def send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
+    def _send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
         if self.state != State.up:
             logger.log(log_lvl, f'[{self.node_id}] ignore MODBUS cmd,'
                        ' as the state is not UP')
             return
         self.mb.build_msg(Modbus.INV_ADDR, func, addr, val, log_lvl)
 
+    async def send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
+        self._send_modbus_cmd(func, addr, val, log_lvl)
+
+    def mb_timout_cb(self, exp_cnt):
+        self.mb_timer.start(self.MB_REGULAR_TIMEOUT)
+
+        if 0 == (exp_cnt % 30):
+            # logging.info("Regular Modbus Status request")
+            self._send_modbus_cmd(Modbus.READ_REGS, 0x2007, 2, logging.DEBUG)
+        else:
+            self._send_modbus_cmd(Modbus.READ_REGS, 0x3008, 21, logging.DEBUG)
+
     def _init_new_client_conn(self) -> bool:
         contact_name = self.contact_name
         contact_mail = self.contact_mail
@@ -331,6 +349,7 @@ class Talent(Message):
         if self.ctrl.is_ind():
             if self.data_len == 0:
                 self.state = State.pend     # block MODBUS cmds
+                self.mb_timer.start(self.MB_START_TIMEOUT)
                 ts = self._timestamp()
                 logger.debug(f'time: {ts:08x}')
                 self.__build_header(0x91)

app/src/gen3plus/solarman_v5.py

@@ -8,6 +8,7 @@ from datetime import datetime
 if __name__ == "app.src.gen3plus.solarman_v5":
     from app.src.messages import hex_dump_memory, Message, State
     from app.src.modbus import Modbus
+    from app.src.my_timer import Timer
     from app.src.config import Config
     from app.src.gen3plus.infos_g3p import InfosG3P
     from app.src.infos import Register
@@ -15,6 +16,7 @@ else:  # pragma: no cover
     from messages import hex_dump_memory, Message, State
     from config import Config
     from modbus import Modbus
+    from my_timer import Timer
     from gen3plus.infos_g3p import InfosG3P
     from infos import Register
 # import traceback
@@ -51,6 +53,8 @@ class Sequence():
 class SolarmanV5(Message):
     AT_CMD = 1
     MB_RTU_CMD = 2
+    MB_START_TIMEOUT = 40
+    MB_REGULAR_TIMEOUT = 60
 
     def __init__(self, server_side: bool):
         super().__init__(server_side, self.send_modbus_cb, mb_timeout=5)
@@ -123,7 +127,7 @@ class SolarmanV5(Message):
             self.at_acl = g3p_cnf['at_acl']
 
         self.node_id = 'G3P'  # will be overwritten in __set_serial_no
-        # self.forwarding = Config.get('solarman')['enabled']
+        self.mb_timer = Timer(self.mb_timout_cb, self.node_id)
 
     '''
     Our puplic methods
@@ -136,6 +140,7 @@ class SolarmanV5(Message):
         self.switch.clear()
         self.log_lvl.clear()
         self.state = State.closed
+        del self.mb_timer
         super().close()
 
     def __set_serial_no(self, snr: int):
@@ -362,13 +367,25 @@ class SolarmanV5(Message):
         self.writer.write(self._send_buffer)
         self._send_buffer = bytearray(0)  # self._send_buffer[sent:]
 
-    async def send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
+    def _send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
         if self.state != State.up:
             logger.log(log_lvl, f'[{self.node_id}] ignore MODBUS cmd,'
                        ' as the state is not UP')
             return
         self.mb.build_msg(Modbus.INV_ADDR, func, addr, val, log_lvl)
 
+    async def send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
+        self._send_modbus_cmd(func, addr, val, log_lvl)
+
+    def mb_timout_cb(self, exp_cnt):
+        self.mb_timer.start(self.MB_REGULAR_TIMEOUT)
+
+        self._send_modbus_cmd(Modbus.READ_REGS, 0x3008, 21, logging.DEBUG)
+
+        if 0 == (exp_cnt % 30):
+            # logging.info("Regular Modbus Status request")
+            self._send_modbus_cmd(Modbus.READ_REGS, 0x2007, 2, logging.DEBUG)
+
     def at_cmd_forbidden(self, cmd: str, connection: str) -> bool:
         return not cmd.startswith(tuple(self.at_acl[connection]['allow'])) or \
                 cmd.startswith(tuple(self.at_acl[connection]['block']))
@@ -474,7 +491,9 @@ class SolarmanV5(Message):
         self.__process_data(ftype)
         self.__forward_msg()
         self.__send_ack_rsp(0x1210, ftype)
-        self.state = State.up
+        if self.state is not State.up:
+            self.state = State.up
+            self.mb_timer.start(self.MB_START_TIMEOUT)
 
     def msg_sync_start(self):
         data = self._recv_buffer[self.header_len:]
@@ -571,7 +590,9 @@ class SolarmanV5(Message):
 
         self.__forward_msg()
         self.__send_ack_rsp(0x1710, ftype)
-        self.state = State.up
+        if self.state is not State.up:
+            self.state = State.up
+            self.mb_timer.start(self.MB_START_TIMEOUT)
 
     def msg_sync_end(self):
         data = self._recv_buffer[self.header_len:]

app/src/my_timer.py

@@ -0,0 +1,35 @@
+import asyncio
+import logging
+from itertools import count
+
+
+class Timer:
+    def __init__(self, cb, id_str: str = ''):
+        self.__timeout_cb = cb
+        self.loop = asyncio.get_event_loop()
+        self.tim = None
+        self.id_str = id_str
+        self.exp_count = count(0)
+
+    def start(self, timeout: float) -> None:
+        '''Start timer with timeout seconds'''
+        if self.tim:
+            self.tim.cancel()
+        self.tim = self.loop.call_later(timeout, self.__timeout)
+        logging.debug(f'[{self.id_str}]Start timer')
+
+    def stop(self) -> None:
+        '''Stop timer'''
+        logging.debug(f'[{self.id_str}]Stop timer')
+        if self.tim:
+            self.tim.cancel()
+            self.tim = None
+
+    def __timeout(self) -> None:
+        '''timer expired handler'''
+        logging.debug(f'[{self.id_str}]Timer expired')
+        self.__timeout_cb(next(self.exp_count))
+
+    def __del__(self) -> None:
+        self.stop()
+        self.__timeout_cb = None

app/src/scheduler.py

@@ -3,8 +3,6 @@ import json
 from mqtt import Mqtt
 from aiocron import crontab
 from infos import ClrAtMidnight
-from modbus import Modbus
-from messages import Message
 
 logger_mqtt = logging.getLogger('mqtt')
 
@@ -21,9 +19,6 @@ class Schedule:
 
         crontab('0 0 * * *', func=cls.atmidnight, start=True)
 
-        # every minute
-        crontab('* * * * *', func=cls.regular_modbus_cmds, start=True)
-
     @classmethod
     async def atmidnight(cls) -> None:
         '''Clear daily counters at midnight'''
@@ -33,15 +28,3 @@ class Schedule:
             logger_mqtt.debug(f'{key}: {data}')
             data_json = json.dumps(data)
             await cls.mqtt.publish(f"{key}", data_json)
-
-    @classmethod
-    async def regular_modbus_cmds(cls):
-        for m in Message:
-            if m.server_side:
-                fnc = getattr(m, "send_modbus_cmd", None)
-                if callable(fnc):
-                    await fnc(Modbus.READ_REGS, 0x3008, 21, logging.DEBUG)
-                    # if 0 == (cls.count % 30):
-                    #     # logging.info("Regular Modbus Status request")
-                    #     await fnc(Modbus.READ_REGS, 0x2007, 2, logging.DEBUG)
-        cls.count += 1