Merge pull request #90 from s-allius/s-allius/issue56

S allius/issue56

.github/workflows/python-app.yml

@@ -5,7 +5,7 @@ name: Python application
 
 on:
   push:
-    branches: [ "main", "dev-*" ]
+    branches: [ "main", "dev-*", "*/issue*" ]
     paths-ignore:
     - '**.md' # Do no build on *.md changes
     - '**.yml' # Do no build on *.yml changes

CHANGELOG.md

@@ -10,6 +10,13 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [0.8.0] - 2024-06-07
 
+- print imgae build time during proxy start
+- add type annotations
+- improve async unit test and fix pytest warnings
+- run github tests even for pulls on issue branches
+
+## [0.8.0] - 2024-06-07
+
 - improve logging: add protocol or node_id to connection logs
 - improve logging: log ignored AT+ or MODBUS commands
 - improve tracelog: log level depends on message type and source

app/Dockerfile

@@ -63,7 +63,7 @@ RUN python -m pip install --no-cache --no-index /root/wheels/* && \
 COPY --chmod=0700 entrypoint.sh /root/entrypoint.sh
 COPY config .
 COPY src .
-
+RUN date > /build-date.txt
 EXPOSE 5005
 
 # command to run on container start

app/entrypoint.sh

@@ -5,6 +5,7 @@ user="$(id -u)"
 echo "######################################################"
 echo "# prepare: '$SERVICE_NAME' Version:$VERSION"
 echo "# for running with UserID:$UID, GroupID:$GID"
+echo "# Image built: $(cat /build-date.txt) "
 echo "#"
 
 if [ "$user" = '0' ]; then

app/src/async_stream.py

@@ -1,5 +1,6 @@
 import logging
 import traceback
+from asyncio import StreamReader, StreamWriter
 from messages import hex_dump_memory
 
 logger = logging.getLogger('conn')
@@ -7,7 +8,8 @@ logger = logging.getLogger('conn')
 
 class AsyncStream():
 
-    def __init__(self, reader, writer, addr) -> None:
+    def __init__(self, reader: StreamReader, writer: StreamWriter,
+                 addr) -> None:
         logger.debug('AsyncStream.__init__')
         self.reader = reader
         self.writer = writer

app/src/gen3/connection_g3.py

@@ -1,5 +1,6 @@
 import logging
 # import gc
+from asyncio import StreamReader, StreamWriter
 from async_stream import AsyncStream
 from gen3.talent import Talent
 
@@ -8,12 +9,13 @@ logger = logging.getLogger('conn')
 
 class ConnectionG3(AsyncStream, Talent):
 
-    def __init__(self, reader, writer, addr, remote_stream, server_side: bool,
+    def __init__(self, reader: StreamReader, writer: StreamWriter,
+                 addr, remote_stream: 'ConnectionG3', server_side: bool,
                  id_str=b'') -> None:
         AsyncStream.__init__(self, reader, writer, addr)
         Talent.__init__(self, server_side, id_str)
 
-        self.remoteStream = remote_stream
+        self.remoteStream: 'ConnectionG3' = remote_stream
 
     '''
     Our puplic methods

app/src/gen3/inverter_g3.py

@@ -1,7 +1,8 @@
-import asyncio
 import logging
 import traceback
 import json
+import asyncio
+from asyncio import StreamReader, StreamWriter
 from config import Config
 from inverter import Inverter
 from gen3.connection_g3 import ConnectionG3
@@ -44,7 +45,7 @@ class InverterG3(Inverter, ConnectionG3):
                  destroyed
     '''
 
-    def __init__(self, reader, writer, addr):
+    def __init__(self, reader: StreamReader, writer: StreamWriter, addr):
         super().__init__(reader, writer, addr, None, True)
         self.__ha_restarts = -1
 

app/src/gen3/talent.py

@@ -41,6 +41,7 @@ class Talent(Message):
         self.id_str = id_str
         self.contact_name = b''
         self.contact_mail = b''
+        self.ts_offset = 0        # time offset between tsun cloud and local
         self.db = InfosG3()
         self.switch = {
             0x00: self.msg_contact_info,
@@ -141,8 +142,8 @@ class Talent(Message):
 
     def send_modbus_cb(self, modbus_pdu: bytearray, log_lvl: int, state: str):
         if self.state != self.STATE_UP:
-            logger.warn(f'[{self.node_id}] ignore MODBUS cmd,'
+            logger.warning(f'[{self.node_id}] ignore MODBUS cmd,'
-                        ' cause the state is not UP anymore')
+                           ' cause the state is not UP anymore')
             return
 
         self.__build_header(0x70, 0x77)
@@ -204,6 +205,24 @@ class Talent(Message):
             ts = (datetime.now() - datetime(1970, 1, 1)).total_seconds()
         return round(ts*1000)
 
+    def _update_header(self, _forward_buffer):
+        '''update header for message before forwarding,
+        add time offset to timestamp'''
+        _len = len(_forward_buffer)
+        result = struct.unpack_from('!lB', _forward_buffer, 0)
+        id_len = result[1]    # len of variable id string
+        if _len < 2*id_len + 21:
+            return
+
+        result = struct.unpack_from('!B', _forward_buffer, id_len+6)
+        msg_code = result[0]
+        if msg_code == 0x71 or msg_code == 0x04:
+            result = struct.unpack_from('!q', _forward_buffer, 13+2*id_len)
+            ts = result[0] + self.ts_offset
+            logger.debug(f'offset: {self.ts_offset:08x}'
+                         f'  proxy-time: {ts:08x}')
+            struct.pack_into('!q', _forward_buffer, 13+2*id_len, ts)
+
     # check if there is a complete header in the buffer, parse it
     # and set
     #   self.header_len
@@ -305,39 +324,35 @@ class Talent(Message):
         return True
 
     def msg_get_time(self):
-        tsun = Config.get('tsun')
+        if self.ctrl.is_ind():
-        if tsun['enabled']:
+            if self.data_len == 0:
-            if self.ctrl.is_ind():
+                ts = self._timestamp()
-                if self.data_len >= 8:
+                logger.debug(f'time: {ts:08x}')
-                    ts = self._timestamp()
+                self.__build_header(0x91)
-                    result = struct.unpack_from('!q', self._recv_buffer,
+                self._send_buffer += struct.pack('!q', ts)
-                                                self.header_len)
+                self.__finish_send_msg()
-                    logger.debug(f'tsun-time: {result[0]:08x}'
+
-                                 f'  proxy-time: {ts:08x}')
+            elif self.data_len >= 8:
-            else:
+                ts = self._timestamp()
-                logger.warning('Unknown Ctrl')
+                result = struct.unpack_from('!q', self._recv_buffer,
-                self.inc_counter('Unknown_Ctrl')
+                                            self.header_len)
-            self.forward(self._recv_buffer, self.header_len+self.data_len)
+                self.ts_offset = result[0]-ts
+                logger.debug(f'tsun-time: {int(result[0]):08x}'
+                             f'  proxy-time: {ts:08x}'
+                             f'  offset: {self.ts_offset}')
+                return  # ignore received response
         else:
-            if self.ctrl.is_ind():
+            logger.warning('Unknown Ctrl')
-                if self.data_len == 0:
+            self.inc_counter('Unknown_Ctrl')
-                    ts = self._timestamp()
-                    logger.debug(f'time: {ts:08x}')
 
-                    self.__build_header(0x91)
+        self.forward(self._recv_buffer, self.header_len+self.data_len)
-                    self._send_buffer += struct.pack('!q', ts)
-                    self.__finish_send_msg()
-
-            else:
-                logger.warning('Unknown Ctrl')
-                self.inc_counter('Unknown_Ctrl')
 
     def parse_msg_header(self):
         result = struct.unpack_from('!lB', self._recv_buffer, self.header_len)
 
         data_id = result[0]    # len of complete message
         id_len = result[1]     # len of variable id string
-        logger.debug(f'Data_ID: {data_id}   id_len:  {id_len}')
+        logger.debug(f'Data_ID: 0x{data_id:08x}   id_len:  {id_len}')
 
         msg_hdr_len = 5+id_len+9
 

app/src/gen3plus/connection_g3p.py

@@ -1,5 +1,6 @@
 import logging
 # import gc
+from asyncio import StreamReader, StreamWriter
 from async_stream import AsyncStream
 from gen3plus.solarman_v5 import SolarmanV5
 
@@ -8,12 +9,13 @@ logger = logging.getLogger('conn')
 
 class ConnectionG3P(AsyncStream, SolarmanV5):
 
-    def __init__(self, reader, writer, addr, remote_stream,
+    def __init__(self, reader: StreamReader, writer: StreamWriter,
+                 addr, remote_stream: 'ConnectionG3P',
                  server_side: bool) -> None:
         AsyncStream.__init__(self, reader, writer, addr)
         SolarmanV5.__init__(self, server_side)
 
-        self.remoteStream = remote_stream
+        self.remoteStream: 'ConnectionG3P' = remote_stream
 
     '''
     Our puplic methods

app/src/gen3plus/inverter_g3p.py

@@ -1,7 +1,8 @@
-import asyncio
 import logging
 import traceback
 import json
+import asyncio
+from asyncio import StreamReader, StreamWriter
 from config import Config
 from inverter import Inverter
 from gen3plus.connection_g3p import ConnectionG3P
@@ -44,7 +45,7 @@ class InverterG3P(Inverter, ConnectionG3P):
                  destroyed
     '''
 
-    def __init__(self, reader, writer, addr):
+    def __init__(self, reader: StreamReader, writer: StreamWriter, addr):
         super().__init__(reader, writer, addr, None, True)
         self.__ha_restarts = -1
 

app/src/gen3plus/solarman_v5.py

@@ -346,8 +346,8 @@ class SolarmanV5(Message):
 
     def send_modbus_cb(self, pdu: bytearray, log_lvl: int, state: str):
         if self.state != self.STATE_UP:
-            logger.warn(f'[{self.node_id}] ignore MODBUS cmd,'
+            logger.warning(f'[{self.node_id}] ignore MODBUS cmd,'
-                        ' cause the state is not UP anymore')
+                           ' cause the state is not UP anymore')
             return
         self.__build_header(0x4510)
         self._send_buffer += struct.pack('<BHLLL', self.MB_RTU_CMD,
@@ -372,8 +372,8 @@ class SolarmanV5(Message):
 
     async def send_at_cmd(self, AT_cmd: str) -> None:
         if self.state != self.STATE_UP:
-            logger.warn(f'[{self.node_id}] ignore AT+ cmd,'
+            logger.warning(f'[{self.node_id}] ignore AT+ cmd,'
-                        ' as the state is not UP')
+                           ' as the state is not UP')
             return
         AT_cmd = AT_cmd.strip()
 
@@ -382,8 +382,7 @@ class SolarmanV5(Message):
             node_id = self.node_id
             key = 'at_resp'
             logger.info(f'{key}: {data_json}')
-            asyncio.ensure_future(
+            await self.mqtt.publish(f'{self.entity_prfx}{node_id}{key}', data_json)  # noqa: E501
-                self.publish_mqtt(f'{self.entity_prfx}{node_id}{key}', data_json))  # noqa: E501
             return
 
         self.forward_at_cmd_resp = False
@@ -511,8 +510,9 @@ class SolarmanV5(Message):
 
         self.__forward_msg()
 
-    async def publish_mqtt(self, key, data):
+    def publish_mqtt(self, key, data):
-        await self.mqtt.publish(key, data)  # pragma: no cover
+        asyncio.ensure_future(
+            self.mqtt.publish(key, data))
 
     def get_cmd_rsp_log_lvl(self) -> int:
         ftype = self._recv_buffer[self.header_len]
@@ -536,8 +536,7 @@ class SolarmanV5(Message):
                 node_id = self.node_id
                 key = 'at_resp'
                 logger.info(f'{key}: {data_json}')
-                asyncio.ensure_future(
+                self.publish_mqtt(f'{self.entity_prfx}{node_id}{key}', data_json)  # noqa: E501
-                    self.publish_mqtt(f'{self.entity_prfx}{node_id}{key}', data_json))  # noqa: E501
                 return
         elif ftype == self.MB_RTU_CMD:
             valid = data[1]

app/src/infos.py

@@ -343,7 +343,7 @@ class Infos:
         dict[counter] -= 1
 
     def ha_proxy_confs(self, ha_prfx: str, node_id: str, snr: str) \
-            -> Generator[tuple[dict, str], None, None]:
+            -> Generator[tuple[str, str, str, str], None, None]:
         '''Generator function yields json register struct for home-assistant
         auto configuration and the unique entity string, for all proxy
         registers

app/src/messages.py

@@ -1,6 +1,6 @@
 import logging
 import weakref
-from typing import Callable
+from typing import Callable, Generator
 
 
 if __name__ == "app.src.messages":
@@ -45,7 +45,7 @@ def hex_dump_memory(level, info, data, num):
 
 
 class IterRegistry(type):
-    def __iter__(cls):
+    def __iter__(cls) -> Generator['Message', None, None]:
         for ref in cls._registry:
             obj = ref()
             if obj is not None:
@@ -59,7 +59,7 @@ class Message(metaclass=IterRegistry):
     STATE_CLOSED = 3
 
     def __init__(self, server_side: bool, send_modbus_cb:
-                 Callable[[bytes, int, str], None], mb_timeout):
+                 Callable[[bytes, int, str], None], mb_timeout: int):
         self._registry.append(weakref.ref(self))
 
         self.server_side = server_side

app/src/server.py

@@ -2,6 +2,7 @@ import logging
 import asyncio
 import signal
 import os
+from asyncio import StreamReader, StreamWriter
 from logging import config  # noqa F401
 from messages import Message
 from inverter import Inverter
@@ -11,14 +12,14 @@ from scheduler import Schedule
 from config import Config
 
 
-async def handle_client(reader, writer):
+async def handle_client(reader: StreamReader, writer: StreamWriter):
     '''Handles a new incoming connection and starts an async loop'''
 
     addr = writer.get_extra_info('peername')
     await InverterG3(reader, writer, addr).server_loop(addr)
 
 
-async def handle_client_v2(reader, writer):
+async def handle_client_v2(reader: StreamReader, writer: StreamWriter):
     '''Handles a new incoming connection and starts an async loop'''
 
     addr = writer.get_extra_info('peername')

app/tests/test_modbus.py

@@ -5,9 +5,9 @@ from app.src.modbus import Modbus
 from app.src.infos import Infos, Register
 
 pytest_plugins = ('pytest_asyncio',)
-pytestmark = pytest.mark.asyncio(scope="module")
+# pytestmark = pytest.mark.asyncio(scope="module")
 
-class TestHelper(Modbus):
+class ModbusTestHelper(Modbus):
     def __init__(self):
         super().__init__(self.send_cb)
         self.db = Infos()
@@ -35,7 +35,7 @@ def test_modbus_crc():
     
 def test_build_modbus_pdu():
     '''Check building and sending a MODBUS RTU'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.build_msg(1,6,0x2000,0x12)
     assert mb.pdu == b'\x01\x06\x20\x00\x00\x12\x02\x07'
     assert mb._Modbus__check_crc(mb.pdu)
@@ -47,7 +47,7 @@ def test_build_modbus_pdu():
 
 def test_recv_req():
     '''Receive a valid request, which must transmitted'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     assert mb.recv_req(b'\x01\x06\x20\x00\x00\x12\x02\x07')
     assert mb.last_fcode == 6
     assert mb.last_reg == 0x2000
@@ -56,7 +56,7 @@ def test_recv_req():
 
 def test_recv_req_crc_err():
     '''Receive a request with invalid CRC, which must be dropped'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     assert not mb.recv_req(b'\x01\x06\x20\x00\x00\x12\x02\x08')
     assert mb.pdu == None
     assert mb.last_fcode == 0   
@@ -66,7 +66,7 @@ def test_recv_req_crc_err():
 
 def test_recv_resp_crc_err():
     '''Receive a response with invalid CRC, which must be dropped'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     # simulate a transmitted request
     mb.req_pend = True
     mb.last_addr = 1
@@ -86,7 +86,7 @@ def test_recv_resp_crc_err():
 
 def test_recv_resp_invalid_addr():
     '''Receive a response with wrong server addr, which must be dropped'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.req_pend = True
     # simulate a transmitted request
     mb.last_addr = 1
@@ -109,7 +109,7 @@ def test_recv_resp_invalid_addr():
 
 def test_recv_recv_fcode():
     '''Receive a response with wrong function code, which must be dropped'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.build_msg(1,4,0x300e,2)
     assert mb.que.qsize() == 0
     assert mb.req_pend
@@ -130,7 +130,7 @@ def test_recv_recv_fcode():
 
 def test_recv_resp_len():
     '''Receive a response with wrong data length, which must be dropped'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.build_msg(1,3,0x300e,3)
     assert mb.que.qsize() == 0
     assert mb.req_pend
@@ -152,7 +152,7 @@ def test_recv_resp_len():
 
 def test_recv_unexpect_resp():
     '''Receive a response when we havb't sent a request'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     assert not mb.req_pend
    
     # check unexpected response, which must be dropped
@@ -167,7 +167,7 @@ def test_recv_unexpect_resp():
 
 def test_parse_resp():
     '''Receive matching response and parse the values'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.build_msg(1,3,0x3007,6)
     assert mb.que.qsize() == 0
     assert mb.req_pend
@@ -191,7 +191,7 @@ def test_parse_resp():
     assert not mb.req_pend
 
 def test_queue():
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.build_msg(1,3,0x3022,4)
     assert mb.que.qsize() == 0
     assert mb.req_pend
@@ -210,7 +210,7 @@ def test_queue():
 
 def test_queue2():
     '''Check queue handling for build_msg() calls'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.build_msg(1,3,0x3007,6)
     mb.build_msg(1,6,0x2008,4)
     assert mb.que.qsize() == 1
@@ -258,7 +258,7 @@ def test_queue2():
 
 def test_queue3():
     '''Check queue handling for recv_req() calls'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     assert mb.recv_req(b'\x01\x03\x30\x07\x00\x06{\t', mb.resp_handler)
     assert mb.recv_req(b'\x01\x06\x20\x08\x00\x04\x02\x0b', mb.resp_handler)
     assert mb.que.qsize() == 1
@@ -315,7 +315,7 @@ def test_queue3():
 async def test_timeout():
     '''Test MODBUS response timeout and RTU retransmitting'''
     assert asyncio.get_running_loop()
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     mb.max_retries = 2
     mb.timeout = 0.1  # 100ms timeout for fast testing, expect a time resolution of at least 10ms
     assert asyncio.get_running_loop() == mb.loop
@@ -363,7 +363,7 @@ async def test_timeout():
 
 def test_recv_unknown_data():
     '''Receive a response with an unknwon register'''
-    mb = TestHelper()
+    mb = ModbusTestHelper()
     assert 0x9000 not in mb.map
     mb.map[0x9000] = {'reg': Register.TEST_REG1,   'fmt': '!H', 'ratio':  1}
 

app/tests/test_solarman.py

@@ -24,12 +24,24 @@ class Writer():
     def write(self, pdu: bytearray):
         self.sent_pdu = pdu
 
+
+class Mqtt():
+    def __init__(self):
+        self.key = ''
+        self.data = ''
+
+    async def publish(self, key, data):
+        self.key = key
+        self.data = data
+
+
 class MemoryStream(SolarmanV5):
     def __init__(self, msg, chunks = (0,), server_side: bool = True):
         super().__init__(server_side)
         if server_side:
             self.mb.timeout = 1   # overwrite for faster testing
         self.writer = Writer()
+        self.mqtt = Mqtt()
         self.__msg = msg
         self.__msg_len = len(msg)
         self.__chunks = chunks
@@ -43,6 +55,8 @@ class MemoryStream(SolarmanV5):
         self.test_exception_async_write = False
         self.entity_prfx = ''
         self.at_acl = {'mqtt': {'allow': ['AT+'], 'block': ['AT+WEBU']}, 'tsun': {'allow': ['AT+Z', 'AT+UPURL', 'AT+SUPDATE', 'AT+TIME'], 'block': ['AT+WEBU']}}
+        self.key = ''
+        self.data = ''
 
     def _timestamp(self):
         return timestamp
@@ -54,6 +68,10 @@ class MemoryStream(SolarmanV5):
         self.__msg += msg
         self.__msg_len += len(msg)    
 
+    def publish_mqtt(self, key, data):
+        self.key = key
+        self.data = data
+
     def _read(self) -> int:
         copied_bytes = 0
         try:    
@@ -478,9 +496,10 @@ def AtCommandIndMsgBlock():  # 0x4510
 
 @pytest.fixture
 def AtCommandRspMsg():  # 0x1510
-    msg  = b'\xa5\x0a\x00\x10\x15\x03\x03' +get_sn()  +b'\x01\x01'
+    msg  = b'\xa5\x11\x00\x10\x15\x03\x03' +get_sn()  +b'\x01\x01'
     msg += total()  
     msg += hb()
+    msg += b'\x00\x00\x00\x00+ok'
     msg += correct_checksum(msg)
     msg += b'\x15'
     return msg
@@ -1243,48 +1262,64 @@ async def test_msg_build_modbus_req(ConfigTsunInv1, DeviceIndMsg, DeviceRspMsg,
     m.close()
 
 @pytest.mark.asyncio
-async def test_AT_cmd(ConfigTsunAllowAll, DeviceIndMsg, DeviceRspMsg, InverterIndMsg, InverterRspMsg, AtCommandIndMsg):
+async def test_AT_cmd(ConfigTsunAllowAll, DeviceIndMsg, DeviceRspMsg, InverterIndMsg, InverterRspMsg, AtCommandIndMsg, AtCommandRspMsg):
     ConfigTsunAllowAll
     m = MemoryStream(DeviceIndMsg, (0,), True)
     m.append_msg(InverterIndMsg)
-    m.read()
+    m.append_msg(AtCommandRspMsg)
+    m.read()   # read device ind
     assert m.control == 0x4110
     assert str(m.seq) == '01:01'
-    assert m._recv_buffer==InverterIndMsg   # unhandled next message
+    assert m._recv_buffer==InverterIndMsg + AtCommandRspMsg  # unhandled next message
     assert m._send_buffer==DeviceRspMsg
     assert m._forward_buffer==DeviceIndMsg
 
     m._send_buffer = bytearray(0) # clear send buffer for next test    
     m._forward_buffer = bytearray(0) # clear send buffer for next test    
     await m.send_at_cmd('AT+TIME=214028,1,60,120')
-    assert m._recv_buffer==InverterIndMsg   # unhandled next message
+    assert m._recv_buffer==InverterIndMsg + AtCommandRspMsg     # unhandled next message
     assert m._send_buffer==b''
     assert m._forward_buffer==b''
     assert str(m.seq) == '01:01'
+    assert m.mqtt.key == ''
+    assert m.mqtt.data == ""
 
-    m.read()
+    m.read() # read inverter ind
     assert m.control == 0x4210
     assert str(m.seq) == '02:02'
-    assert m._recv_buffer==b''
+    assert m._recv_buffer==AtCommandRspMsg   # unhandled next message
     assert m._send_buffer==InverterRspMsg
     assert m._forward_buffer==InverterIndMsg
     
     m._send_buffer = bytearray(0) # clear send buffer for next test    
     m._forward_buffer = bytearray(0) # clear send buffer for next test    
     await m.send_at_cmd('AT+TIME=214028,1,60,120')
-    assert m._recv_buffer==b''
+    assert m._recv_buffer==AtCommandRspMsg   # unhandled next message
     assert m._send_buffer==AtCommandIndMsg
     assert m._forward_buffer==b''
     assert str(m.seq) == '02:03'
+    assert m.mqtt.key == ''
+    assert m.mqtt.data == ""
 
     m._send_buffer = bytearray(0) # clear send buffer for next test    
+    m.read() # read at resp
+    assert m.control == 0x1510
+    assert str(m.seq) == '03:03'
+    assert m._recv_buffer==b''
+    assert m._send_buffer==b''
+    assert m._forward_buffer==b''
+    assert m.key == 'at_resp'
+    assert m.data == "+ok"
+
     m.test_exception_async_write = True
     await m.send_at_cmd('AT+TIME=214028,1,60,120')
     assert m._recv_buffer==b''
     assert m._send_buffer==b''
     assert m._forward_buffer==b''
-    assert str(m.seq) == '02:04'
+    assert str(m.seq) == '03:04'
     assert m.forward_at_cmd_resp == False
+    assert m.mqtt.key == ''
+    assert m.mqtt.data == ""
     m.close()
 
 @pytest.mark.asyncio
@@ -1306,6 +1341,8 @@ async def test_AT_cmd_blocked(ConfigTsunAllowAll, DeviceIndMsg, DeviceRspMsg, In
     assert m._send_buffer==b''
     assert m._forward_buffer==b''
     assert str(m.seq) == '01:01'
+    assert m.mqtt.key == ''
+    assert m.mqtt.data == ""
 
     m.read()
     assert m.control == 0x4210
@@ -1322,6 +1359,8 @@ async def test_AT_cmd_blocked(ConfigTsunAllowAll, DeviceIndMsg, DeviceRspMsg, In
     assert m._forward_buffer==b''
     assert str(m.seq) == '02:02'
     assert m.forward_at_cmd_resp == False
+    assert m.mqtt.key == 'at_resp'
+    assert m.mqtt.data == "'AT+WEBU' is forbidden"
     m.close()
 
 def test_AT_cmd_ind(ConfigTsunInv1, AtCommandIndMsg):
@@ -1386,7 +1425,7 @@ def test_msg_at_command_rsp1(ConfigTsunInv1, AtCommandRspMsg):
     assert m.control == 0x1510
     assert str(m.seq) == '03:03'
     assert m.header_len==11
-    assert m.data_len==10
+    assert m.data_len==17
     assert m._forward_buffer==AtCommandRspMsg
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
@@ -1405,7 +1444,7 @@ def test_msg_at_command_rsp2(ConfigTsunInv1, AtCommandRspMsg):
     assert m.control == 0x1510
     assert str(m.seq) == '03:03'
     assert m.header_len==11
-    assert m.data_len==10
+    assert m.data_len==17
     assert m._forward_buffer==b''
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0

app/tests/test_talent.py

@@ -60,7 +60,8 @@ class MemoryStream(Talent):
         return copied_bytes
     
     def _timestamp(self):
-        return 1700260990000
+        # return 1700260990000
+        return 1691246944000
     
     def createClientStream(self, msg, chunks = (0,)):
         c = MemoryStream(msg, chunks, False)
@@ -129,6 +130,18 @@ def MsgControllerInd(): # Data indication from the controller
     msg +=  b'\x49\x00\x00\x00\x02\x00\x0d\x04\x08\x49\x00\x00\x00\x00\x00\x07\xa1\x84\x49\x00\x00\x00\x01\x00\x0c\x50\x59\x49\x00\x00\x00\x4c\x00\x0d\x1f\x60\x49\x00\x00\x00\x00'
     return msg
 
+@pytest.fixture
+def MsgControllerIndTsOffs(): # Data indication from the controller - offset 0x1000
+    msg  =  b'\x00\x00\x01\x2f\x10R170000000000001\x91\x71\x0e\x10\x00\x00\x10R170000000000001'
+    msg +=  b'\x01\x00\x00\x01\x89\xc6\x63\x45\x50'
+    msg +=  b'\x00\x00\x00\x15\x00\x09\x2b\xa8\x54\x10\x52\x53\x57\x5f\x34\x30\x30\x5f\x56\x31\x2e\x30\x30\x2e\x30\x36\x00\x09\x27\xc0\x54\x06\x52\x61\x79\x6d\x6f'
+    msg +=  b'\x6e\x00\x09\x2f\x90\x54\x0b\x52\x53\x57\x2d\x31\x2d\x31\x30\x30\x30\x31\x00\x09\x5a\x88\x54\x0f\x74\x2e\x72\x61\x79\x6d\x6f\x6e\x69\x6f\x74\x2e\x63\x6f\x6d\x00\x09\x5a\xec\x54'
+    msg +=  b'\x1c\x6c\x6f\x67\x67\x65\x72\x2e\x74\x61\x6c\x65\x6e\x74\x2d\x6d\x6f\x6e\x69\x74\x6f\x72\x69\x6e\x67\x2e\x63\x6f\x6d\x00\x0d\x00\x20\x49\x00\x00\x00\x01\x00\x0c\x35\x00\x49\x00'
+    msg +=  b'\x00\x00\x64\x00\x0c\x96\xa8\x49\x00\x00\x00\x1d\x00\x0c\x7f\x38\x49\x00\x00\x00\x01\x00\x0c\xfc\x38\x49\x00\x00\x00\x01\x00\x0c\xf8\x50\x49\x00\x00\x01\x2c\x00\x0c\x63\xe0\x49'
+    msg +=  b'\x00\x00\x00\x00\x00\x0c\x67\xc8\x49\x00\x00\x00\x00\x00\x0c\x50\x58\x49\x00\x00\x00\x01\x00\x09\x5e\x70\x49\x00\x00\x13\x8d\x00\x09\x5e\xd4\x49\x00\x00\x13\x8d\x00\x09\x5b\x50'
+    msg +=  b'\x49\x00\x00\x00\x02\x00\x0d\x04\x08\x49\x00\x00\x00\x00\x00\x07\xa1\x84\x49\x00\x00\x00\x01\x00\x0c\x50\x59\x49\x00\x00\x00\x4c\x00\x0d\x1f\x60\x49\x00\x00\x00\x00'
+    return msg
+
 @pytest.fixture
 def MsgControllerAck(): # Get Time Request message
     return b'\x00\x00\x00\x14\x10R170000000000001\x99\x71\x01'
@@ -145,6 +158,14 @@ def MsgInverterInd(): # Data indication from the controller
     msg +=  b'\x54\x10T170000000000001\x00\x00\x00\x32\x54\x0a\x54\x53\x4f\x4c\x2d\x4d\x53\x36\x30\x30\x00\x00\x00\x3c\x54\x05\x41\x2c\x42\x2c\x43'
     return msg
 
+@pytest.fixture
+def MsgInverterIndTsOffs(): # Data indication from the controller + offset 256
+    msg  =  b'\x00\x00\x00\x8b\x10R170000000000001\x91\x04\x01\x90\x00\x01\x10R170000000000001'
+    msg +=  b'\x01\x00\x00\x01\x89\xc6\x63\x62\x08'
+    msg +=  b'\x00\x00\x00\x06\x00\x00\x00\x0a\x54\x08\x4d\x69\x63\x72\x6f\x69\x6e\x76\x00\x00\x00\x14\x54\x04\x54\x53\x55\x4e\x00\x00\x00\x1E\x54\x07\x56\x35\x2e\x30\x2e\x31\x31\x00\x00\x00\x28'
+    msg +=  b'\x54\x10T170000000000001\x00\x00\x00\x32\x54\x0a\x54\x53\x4f\x4c\x2d\x4d\x53\x36\x30\x30\x00\x00\x00\x3c\x54\x05\x41\x2c\x42\x2c\x43'
+    return msg
+
 @pytest.fixture
 def MsgInverterAck(): # Get Time Request message
     return b'\x00\x00\x00\x14\x10R170000000000001\x99\x04\x01'
@@ -471,9 +492,10 @@ def test_msg_get_time(ConfigTsunInv1, MsgGetTime):
     assert int(m.ctrl)==145
     assert m.msg_id==34
     assert m.header_len==23
+    assert m.ts_offset==0
     assert m.data_len==0
     assert m._forward_buffer==MsgGetTime
-    assert m._send_buffer==b''
+    assert m._send_buffer==b'\x00\x00\x00\x1b\x10R170000000000001\x91"\x00\x00\x01\x89\xc6,_\x00'
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
     m.close()
 
@@ -489,9 +511,10 @@ def test_msg_get_time_autark(ConfigNoTsunInv1, MsgGetTime):
     assert int(m.ctrl)==145
     assert m.msg_id==34
     assert m.header_len==23
+    assert m.ts_offset==0
     assert m.data_len==0
     assert m._forward_buffer==b''
-    assert m._send_buffer==b'\x00\x00\x00\x1b\x10R170000000000001\x91"\x00\x00\x01\x8b\xdfs\xcc0'
+    assert m._send_buffer==bytearray(b'\x00\x00\x00\x1b\x10R170000000000001\x91"\x00\x00\x01\x89\xc6,_\x00')
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
     m.close()
 
@@ -507,8 +530,9 @@ def test_msg_time_resp(ConfigTsunInv1, MsgTimeResp):
     assert int(m.ctrl)==145
     assert m.msg_id==34
     assert m.header_len==23
+    assert m.ts_offset==3600000
     assert m.data_len==8
-    assert m._forward_buffer==MsgTimeResp
+    assert m._forward_buffer==b''
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
     m.close()
@@ -525,6 +549,7 @@ def test_msg_time_resp_autark(ConfigNoTsunInv1, MsgTimeResp):
     assert int(m.ctrl)==145
     assert m.msg_id==34
     assert m.header_len==23
+    assert m.ts_offset==3600000
     assert m.data_len==8
     assert m._forward_buffer==b''
     assert m._send_buffer==b''
@@ -543,6 +568,7 @@ def test_msg_time_invalid(ConfigTsunInv1, MsgTimeInvalid):
     assert int(m.ctrl)==148
     assert m.msg_id==34
     assert m.header_len==23
+    assert m.ts_offset==0
     assert m.data_len==0
     assert m._forward_buffer==MsgTimeInvalid
     assert m._send_buffer==b''
@@ -560,6 +586,7 @@ def test_msg_time_invalid_autark(ConfigNoTsunInv1, MsgTimeInvalid):
     assert m.unique_id == 'R170000000000001'
     assert int(m.ctrl)==148
     assert m.msg_id==34
+    assert m.ts_offset==0
     assert m.header_len==23
     assert m.data_len==0
     assert m._forward_buffer==b''
@@ -567,7 +594,7 @@ def test_msg_time_invalid_autark(ConfigNoTsunInv1, MsgTimeInvalid):
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 1
     m.close()
 
-def test_msg_cntrl_ind(ConfigTsunInv1, MsgControllerInd, MsgControllerAck):
+def test_msg_cntrl_ind(ConfigTsunInv1, MsgControllerInd, MsgControllerIndTsOffs, MsgControllerAck):
     ConfigTsunInv1
     m = MemoryStream(MsgControllerInd, (0,))
     m.db.stat['proxy']['Unknown_Ctrl'] = 0
@@ -580,7 +607,12 @@ def test_msg_cntrl_ind(ConfigTsunInv1, MsgControllerInd, MsgControllerAck):
     assert m.msg_id==113
     assert m.header_len==23
     assert m.data_len==284
+    m.ts_offset = 0
+    m._update_header(m._forward_buffer)
     assert m._forward_buffer==MsgControllerInd
+    m.ts_offset = -4096
+    m._update_header(m._forward_buffer)
+    assert m._forward_buffer==MsgControllerIndTsOffs
     assert m._send_buffer==MsgControllerAck
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
     m.close()
@@ -616,12 +648,17 @@ def test_msg_cntrl_invalid(ConfigTsunInv1, MsgControllerInvalid):
     assert m.msg_id==113
     assert m.header_len==23
     assert m.data_len==1
+    m.ts_offset = 0
+    m._update_header(m._forward_buffer)
+    assert m._forward_buffer==MsgControllerInvalid
+    m.ts_offset = -4096
+    m._update_header(m._forward_buffer)
     assert m._forward_buffer==MsgControllerInvalid
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 1
     m.close()
 
-def test_msg_inv_ind(ConfigTsunInv1, MsgInverterInd, MsgInverterAck):
+def test_msg_inv_ind(ConfigTsunInv1, MsgInverterInd, MsgInverterIndTsOffs, MsgInverterAck):
     ConfigTsunInv1
     tracer.setLevel(logging.DEBUG)
     m = MemoryStream(MsgInverterInd, (0,))
@@ -635,7 +672,12 @@ def test_msg_inv_ind(ConfigTsunInv1, MsgInverterInd, MsgInverterAck):
     assert m.msg_id==4
     assert m.header_len==23
     assert m.data_len==120
+    m.ts_offset = 0
+    m._update_header(m._forward_buffer)
     assert m._forward_buffer==MsgInverterInd
+    m.ts_offset = +256
+    m._update_header(m._forward_buffer)
+    assert m._forward_buffer==MsgInverterIndTsOffs
     assert m._send_buffer==MsgInverterAck
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
     m.close()
@@ -673,6 +715,11 @@ def test_msg_inv_invalid(ConfigTsunInv1, MsgInverterInvalid):
     assert m.msg_id==4
     assert m.header_len==23
     assert m.data_len==1
+    m.ts_offset = 0
+    m._update_header(m._forward_buffer)
+    assert m._forward_buffer==MsgInverterInvalid
+    m.ts_offset = 256
+    m._update_header(m._forward_buffer)
     assert m._forward_buffer==MsgInverterInvalid
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 1
@@ -692,6 +739,11 @@ def test_msg_ota_req(ConfigTsunInv1, MsgOtaReq):
     assert m.msg_id==19
     assert m.header_len==23
     assert m.data_len==259
+    m.ts_offset = 0
+    m._update_header(m._forward_buffer)
+    assert m._forward_buffer==MsgOtaReq
+    m.ts_offset = 4096
+    m._update_header(m._forward_buffer)
     assert m._forward_buffer==MsgOtaReq
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
@@ -714,6 +766,11 @@ def test_msg_ota_ack(ConfigTsunInv1, MsgOtaAck):
     assert m.msg_id==19
     assert m.header_len==23
     assert m.data_len==1
+    m.ts_offset = 0
+    m._update_header(m._forward_buffer)
+    assert m._forward_buffer==MsgOtaAck
+    m.ts_offset = 256
+    m._update_header(m._forward_buffer)
     assert m._forward_buffer==MsgOtaAck
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 0
@@ -734,7 +791,12 @@ def test_msg_ota_invalid(ConfigTsunInv1, MsgOtaInvalid):
     assert m.msg_id==19
     assert m.header_len==23
     assert m.data_len==1
+    m.ts_offset = 0
+    m._update_header(m._forward_buffer)
     assert m._forward_buffer==MsgOtaInvalid
+    m.ts_offset = 4096
+    assert m._forward_buffer==MsgOtaInvalid
+    m._update_header(m._forward_buffer)
     assert m._send_buffer==b''
     assert m.db.stat['proxy']['Unknown_Ctrl'] == 1
     assert m.db.stat['proxy']['OTA_Start_Msg'] == 0

app/tests/timestamp_old.yuml

@@ -0,0 +1,26 @@
+// {type:sequence}
+// {generate:true}
+
+[Inverter]ContactInd>[Proxy] 
+[Proxy]-[note: store Contact Info in proxy{bg:cornsilk}]
+[Proxy]ContactRsp (Ok).>[Inverter]
+
+[Inverter]getTimeReq>[Proxy]
+[Proxy]ContactInd>[Cloud]
+[Cloud]ContactRsp (Ok).>[Proxy]
+[Proxy]getTimeReq>[Cloud]
+[Cloud]TimeRsp (time).>[Proxy]
+[Proxy]TimeRsp (time).>[Inverter]
+[Inverter]-[note: set clock in inverter{bg:cornsilk}]
+
+[Inverter]DataInd (ts:=time)>[Proxy] 
+[Proxy]DataRsp>[Inverter] 
+[Proxy]DataInd (ts)>>[Cloud] 
+[Proxy]DataInd>>[MQTT-Broker] 
+[Cloud]DataRsp>>[Proxy]
+
+[Inverter]DataInd (ts:=time)>[Proxy] 
+[Proxy]DataRsp>[Inverter] 
+[Proxy]DataInd (ts)>>[Cloud] 
+[Proxy]DataInd>>[MQTT-Broker] 
+[Cloud]DataRsp>>[Proxy]