add log_level support for modbus commands

This commit is contained in:
Stefan Allius
2024-05-28 19:32:20 +02:00
parent ab9e798152
commit 66657888dd
9 changed files with 52 additions and 36 deletions

View File

@@ -122,25 +122,25 @@ class Talent(Message):
f' Ctl: {int(self.ctrl):#02x} Msg: {fnc.__name__!r}') f' Ctl: {int(self.ctrl):#02x} Msg: {fnc.__name__!r}')
return return
def send_modbus_cb(self, modbus_pdu: bytearray, state: str): def send_modbus_cb(self, modbus_pdu: bytearray, log_lvl: int, state: str):
if self.state != self.STATE_UP: if self.state != self.STATE_UP:
return return
self.__build_header(0x70, 0x77) self.__build_header(0x70, 0x77, log_lvl)
self._send_buffer += b'\x00\x01\xa3\x28' # fixme self._send_buffer += b'\x00\x01\xa3\x28' # fixme
self._send_buffer += struct.pack('!B', len(modbus_pdu)) self._send_buffer += struct.pack('!B', len(modbus_pdu))
self._send_buffer += modbus_pdu self._send_buffer += modbus_pdu
self.__finish_send_msg() self.__finish_send_msg()
hex_dump_memory(logging.INFO, f'Send Modbus {state}:{self.addr}:', hex_dump_memory(log_lvl, f'Send Modbus {state}:{self.addr}:',
self._send_buffer, len(self._send_buffer)) self._send_buffer, len(self._send_buffer))
self.writer.write(self._send_buffer) self.writer.write(self._send_buffer)
self._send_buffer = bytearray(0) # self._send_buffer[sent:] self._send_buffer = bytearray(0) # self._send_buffer[sent:]
async def send_modbus_cmd(self, func, addr, val) -> None: async def send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
if self.state != self.STATE_UP: if self.state != self.STATE_UP:
return return
self.mb.build_msg(Modbus.INV_ADDR, func, addr, val) self.mb.build_msg(Modbus.INV_ADDR, func, addr, val, log_lvl)
def _init_new_client_conn(self) -> bool: def _init_new_client_conn(self) -> bool:
contact_name = self.contact_name contact_name = self.contact_name
@@ -217,15 +217,16 @@ class Talent(Message):
self.header_valid = True self.header_valid = True
return return
def __build_header(self, ctrl, msg_id=None) -> None: def __build_header(self, ctrl, msg_id=None,
log_lvl: int = logging.INFO) -> None:
if not msg_id: if not msg_id:
msg_id = self.msg_id msg_id = self.msg_id
self.send_msg_ofs = len(self._send_buffer) self.send_msg_ofs = len(self._send_buffer)
self._send_buffer += struct.pack(f'!l{len(self.id_str)+1}pBB', self._send_buffer += struct.pack(f'!l{len(self.id_str)+1}pBB',
0, self.id_str, ctrl, msg_id) 0, self.id_str, ctrl, msg_id)
fnc = self.switch.get(msg_id, self.msg_unknown) fnc = self.switch.get(msg_id, self.msg_unknown)
logger.info(self.__flow_str(self.server_side, 'tx') + logger.log(log_lvl, self.__flow_str(self.server_side, 'tx') +
f' Ctl: {int(ctrl):#02x} Msg: {fnc.__name__!r}') f' Ctl: {int(ctrl):#02x} Msg: {fnc.__name__!r}')
def __finish_send_msg(self) -> None: def __finish_send_msg(self) -> None:
_len = len(self._send_buffer) - self.send_msg_ofs _len = len(self._send_buffer) - self.send_msg_ofs

View File

@@ -248,15 +248,15 @@ class SolarmanV5(Message):
return True return True
def __build_header(self, ctrl) -> None: def __build_header(self, ctrl, log_lvl: int = logging.INFO) -> None:
'''build header for new transmit message''' '''build header for new transmit message'''
self.send_msg_ofs = len(self._send_buffer) self.send_msg_ofs = len(self._send_buffer)
self._send_buffer += struct.pack( self._send_buffer += struct.pack(
'<BHHHL', 0xA5, 0, ctrl, self.seq.get_send(), self.snr) '<BHHHL', 0xA5, 0, ctrl, self.seq.get_send(), self.snr)
fnc = self.switch.get(ctrl, self.msg_unknown) fnc = self.switch.get(ctrl, self.msg_unknown)
logger.info(self.__flow_str(self.server_side, 'tx') + logger.log(log_lvl, self.__flow_str(self.server_side, 'tx') +
f' Ctl: {int(ctrl):#04x} Msg: {fnc.__name__!r}') f' Ctl: {int(ctrl):#04x} Msg: {fnc.__name__!r}')
def __finish_send_msg(self) -> None: def __finish_send_msg(self) -> None:
'''finish the transmit message, set lenght and checksum''' '''finish the transmit message, set lenght and checksum'''
@@ -302,23 +302,23 @@ class SolarmanV5(Message):
self._heartbeat()) self._heartbeat())
self.__finish_send_msg() self.__finish_send_msg()
def send_modbus_cb(self, pdu: bytearray, state: str): def send_modbus_cb(self, pdu: bytearray, log_lvl: int, state: str):
if self.state != self.STATE_UP: if self.state != self.STATE_UP:
return return
self.__build_header(0x4510) self.__build_header(0x4510, log_lvl)
self._send_buffer += struct.pack('<BHLLL', self.MB_RTU_CMD, self._send_buffer += struct.pack('<BHLLL', self.MB_RTU_CMD,
0x2b0, 0, 0, 0) 0x2b0, 0, 0, 0)
self._send_buffer += pdu self._send_buffer += pdu
self.__finish_send_msg() self.__finish_send_msg()
hex_dump_memory(logging.INFO, f'Send Modbus {state}:{self.addr}:', hex_dump_memory(log_lvl, f'Send Modbus {state}:{self.addr}:',
self._send_buffer, len(self._send_buffer)) self._send_buffer, len(self._send_buffer))
self.writer.write(self._send_buffer) self.writer.write(self._send_buffer)
self._send_buffer = bytearray(0) # self._send_buffer[sent:] self._send_buffer = bytearray(0) # self._send_buffer[sent:]
async def send_modbus_cmd(self, func, addr, val) -> None: async def send_modbus_cmd(self, func, addr, val, log_lvl) -> None:
if self.state != self.STATE_UP: if self.state != self.STATE_UP:
return return
self.mb.build_msg(Modbus.INV_ADDR, func, addr, val) self.mb.build_msg(Modbus.INV_ADDR, func, addr, val, log_lvl)
async def send_at_cmd(self, AT_cmd: str) -> None: async def send_at_cmd(self, AT_cmd: str) -> None:
if self.state != self.STATE_UP: if self.state != self.STATE_UP:

View File

@@ -74,7 +74,8 @@ class Modbus():
0x3029: {'reg': Register.PV4_TOTAL_GENERATION, 'fmt': '!L', 'ratio': 0.01}, # noqa: E501 0x3029: {'reg': Register.PV4_TOTAL_GENERATION, 'fmt': '!L', 'ratio': 0.01}, # noqa: E501
} }
def __init__(self, snd_handler: Callable[[str], None], timeout: int = 1): def __init__(self, snd_handler: Callable[[bytes, int, str], None],
timeout: int = 1):
if not len(self.__crc_tab): if not len(self.__crc_tab):
self.__build_crc_tab(CRC_POLY) self.__build_crc_tab(CRC_POLY)
self.que = asyncio.Queue(100) self.que = asyncio.Queue(100)
@@ -94,6 +95,7 @@ class Modbus():
self.counter['retries'] = {} self.counter['retries'] = {}
for i in range(0, self.max_retries+1): for i in range(0, self.max_retries+1):
self.counter['retries'][f'{i}'] = 0 self.counter['retries'][f'{i}'] = 0
self.last_log_lvl = logging.DEBUG
self.last_addr = 0 self.last_addr = 0
self.last_fcode = 0 self.last_fcode = 0
self.last_len = 0 self.last_len = 0
@@ -106,7 +108,8 @@ class Modbus():
def __del__(self): def __del__(self):
logging.debug(f'Modbus __del__:\n {self.counter}') logging.debug(f'Modbus __del__:\n {self.counter}')
def build_msg(self, addr: int, func: int, reg: int, val: int) -> None: def build_msg(self, addr: int, func: int, reg: int, val: int,
log_lvl=logging.DEBUG) -> None:
"""Build MODBUS RTU request frame and add it to the tx queue """Build MODBUS RTU request frame and add it to the tx queue
Keyword arguments: Keyword arguments:
@@ -118,7 +121,8 @@ class Modbus():
msg = struct.pack('>BBHH', addr, func, reg, val) msg = struct.pack('>BBHH', addr, func, reg, val)
msg += struct.pack('<H', self.__calc_crc(msg)) msg += struct.pack('<H', self.__calc_crc(msg))
self.que.put_nowait({'req': msg, self.que.put_nowait({'req': msg,
'rsp_hdl': None}) 'rsp_hdl': None,
'log_lvl': log_lvl})
if self.que.qsize() == 1: if self.que.qsize() == 1:
self.__send_next_from_que() self.__send_next_from_que()
@@ -140,7 +144,8 @@ class Modbus():
logger.error('Modbus recv: CRC error') logger.error('Modbus recv: CRC error')
return False return False
self.que.put_nowait({'req': buf, self.que.put_nowait({'req': buf,
'rsp_hdl': rsp_handler}) 'rsp_hdl': rsp_handler,
'log_lvl': logging.INFO})
if self.que.qsize() == 1: if self.que.qsize() == 1:
self.__send_next_from_que() self.__send_next_from_que()
@@ -245,7 +250,7 @@ class Modbus():
logger.debug(f'Modbus retrans {self}') logger.debug(f'Modbus retrans {self}')
self.retry_cnt += 1 self.retry_cnt += 1
self.__start_timer() self.__start_timer()
self.snd_handler(self.last_req, state='Retrans') self.snd_handler(self.last_req, self.last_log_lvl, state='Retrans')
else: else:
logger.info(f'Modbus timeout {self}') logger.info(f'Modbus timeout {self}')
self.counter['timeouts'] += 1 self.counter['timeouts'] += 1
@@ -260,6 +265,7 @@ class Modbus():
req = item['req'] req = item['req']
self.last_req = req self.last_req = req
self.rsp_handler = item['rsp_hdl'] self.rsp_handler = item['rsp_hdl']
self.last_log_lvl = item['log_lvl']
self.last_addr = req[0] self.last_addr = req[0]
self.last_fcode = req[1] self.last_fcode = req[1]
@@ -268,7 +274,7 @@ class Modbus():
self.last_len = res[1] self.last_len = res[1]
self.retry_cnt = 0 self.retry_cnt = 0
self.__start_timer() self.__start_timer()
self.snd_handler(self.last_req, state='Command') self.snd_handler(self.last_req, self.last_log_lvl, state='Command')
except asyncio.QueueEmpty: except asyncio.QueueEmpty:
pass pass

View File

@@ -165,7 +165,7 @@ class Mqtt(metaclass=Singleton):
elif params == 2: elif params == 2:
addr = int(res[0], base=16) addr = int(res[0], base=16)
val = int(res[1]) # lenght val = int(res[1]) # lenght
await fnc(func, addr, val) await fnc(func, addr, val, logging.INFO)
async def at_cmd(self, message): async def at_cmd(self, message):
payload = message.payload.decode("UTF-8") payload = message.payload.decode("UTF-8")

View File

@@ -40,8 +40,8 @@ class Schedule:
if m.server_side: if m.server_side:
fnc = getattr(m, "send_modbus_cmd", None) fnc = getattr(m, "send_modbus_cmd", None)
if callable(fnc): if callable(fnc):
await fnc(Modbus.READ_REGS, 0x3008, 21) await fnc(Modbus.READ_REGS, 0x3008, 21, logging.DEBUG)
if 0 == (cls.count % 30): if 0 == (cls.count % 30):
# logging.info("Regular Modbus Status request") # logging.info("Regular Modbus Status request")
await fnc(Modbus.READ_REGS, 0x2007, 2) await fnc(Modbus.READ_REGS, 0x2007, 2, logging.DEBUG)
cls.count += 1 cls.count += 1

View File

@@ -14,7 +14,7 @@ class TestHelper(Modbus):
self.pdu = None self.pdu = None
self.send_calls = 0 self.send_calls = 0
self.recv_responses = 0 self.recv_responses = 0
def send_cb(self, pdu: bytearray, state: str): def send_cb(self, pdu: bytearray, log_lvl: int, state: str):
self.pdu = pdu self.pdu = pdu
self.send_calls += 1 self.send_calls += 1
def resp_handler(self): def resp_handler(self):

View File

@@ -1,6 +1,7 @@
import pytest import pytest
import struct import struct
import time import time
import logging
from datetime import datetime from datetime import datetime
from app.src.gen3plus.solarman_v5 import SolarmanV5 from app.src.gen3plus.solarman_v5 import SolarmanV5
from app.src.config import Config from app.src.config import Config
@@ -1200,7 +1201,7 @@ async def test_msg_build_modbus_req(ConfigTsunInv1, DeviceIndMsg, DeviceRspMsg,
m._send_buffer = bytearray(0) # clear send buffer for next test m._send_buffer = bytearray(0) # clear send buffer for next test
m._forward_buffer = bytearray(0) # clear send buffer for next test m._forward_buffer = bytearray(0) # clear send buffer for next test
await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0) await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0, logging.DEBUG)
assert m._recv_buffer==InverterIndMsg # unhandled next message assert m._recv_buffer==InverterIndMsg # unhandled next message
assert 0 == m.send_msg_ofs assert 0 == m.send_msg_ofs
assert m._forward_buffer == b'' assert m._forward_buffer == b''
@@ -1216,7 +1217,7 @@ async def test_msg_build_modbus_req(ConfigTsunInv1, DeviceIndMsg, DeviceRspMsg,
m._send_buffer = bytearray(0) # clear send buffer for next test m._send_buffer = bytearray(0) # clear send buffer for next test
m._forward_buffer = bytearray(0) # clear send buffer for next test m._forward_buffer = bytearray(0) # clear send buffer for next test
await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0) await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0, logging.DEBUG)
assert 0 == m.send_msg_ofs assert 0 == m.send_msg_ofs
assert m._forward_buffer == b'' assert m._forward_buffer == b''
assert m.writer.sent_pdu == MsgModbusCmd assert m.writer.sent_pdu == MsgModbusCmd
@@ -1224,7 +1225,7 @@ async def test_msg_build_modbus_req(ConfigTsunInv1, DeviceIndMsg, DeviceRspMsg,
m._send_buffer = bytearray(0) # clear send buffer for next test m._send_buffer = bytearray(0) # clear send buffer for next test
m.test_exception_async_write = True m.test_exception_async_write = True
await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0) await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0, logging.DEBUG)
assert 0 == m.send_msg_ofs assert 0 == m.send_msg_ofs
assert m._forward_buffer == b'' assert m._forward_buffer == b''
assert m._send_buffer == b'' assert m._send_buffer == b''

View File

@@ -1091,14 +1091,14 @@ async def test_msg_build_modbus_req(ConfigTsunInv1, MsgModbusCmd):
ConfigTsunInv1 ConfigTsunInv1
m = MemoryStream(b'', (0,), True) m = MemoryStream(b'', (0,), True)
m.id_str = b"R170000000000001" m.id_str = b"R170000000000001"
await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0) await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0, logging.DEBUG)
assert 0 == m.send_msg_ofs assert 0 == m.send_msg_ofs
assert m._forward_buffer == b'' assert m._forward_buffer == b''
assert m._send_buffer == b'' assert m._send_buffer == b''
assert m.writer.sent_pdu == b'' assert m.writer.sent_pdu == b''
m.state = m.STATE_UP m.state = m.STATE_UP
await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0) await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0, logging.DEBUG)
assert 0 == m.send_msg_ofs assert 0 == m.send_msg_ofs
assert m._forward_buffer == b'' assert m._forward_buffer == b''
assert m._send_buffer == b'' assert m._send_buffer == b''
@@ -1106,7 +1106,7 @@ async def test_msg_build_modbus_req(ConfigTsunInv1, MsgModbusCmd):
m.writer.sent_pdu = bytearray(0) # clear send buffer for next test m.writer.sent_pdu = bytearray(0) # clear send buffer for next test
m.test_exception_async_write = True m.test_exception_async_write = True
await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0) await m.send_modbus_cmd(Modbus.WRITE_SINGLE_REG, 0x2008, 0, logging.DEBUG)
assert 0 == m.send_msg_ofs assert 0 == m.send_msg_ofs
assert m._forward_buffer == b'' assert m._forward_buffer == b''
assert m._send_buffer == b'' assert m._send_buffer == b''

View File

@@ -19,6 +19,9 @@ def get_inv_no() -> bytes:
def get_invalid_sn(): def get_invalid_sn():
return b'R170000000000002' return b'R170000000000002'
def correct_checksum(buf):
checksum = sum(buf[1:]) & 0xff
return checksum.to_bytes(length=1)
@pytest.fixture @pytest.fixture
def MsgContactInfo(): # Contact Info message def MsgContactInfo(): # Contact Info message
@@ -61,10 +64,11 @@ def MsgDataInd():
msg += b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' msg += b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
msg += b'\x00\x01\x12\x02\x12\x12\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' msg += b'\x00\x01\x12\x02\x12\x12\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
msg += b'\x40\x10\x08\xd8\x00\x09\x13\x84\x00\x35\x00\x00\x02\x58\x00\xd8' msg += b'\x40\x10\x08\xd8\x00\x09\x13\x84\x00\x35\x00\x00\x02\x58\x00\xd8'
msg += b'\x01\x3f\x00\x17\x00\x4d\x01\x44\x00\x14\x00\x43\x01\x45\x00\x18' msg += b'\x01\x3f\x00\x17\x00\x4d\x01\x44\x00\x14\x00\x43\x01\x45\x00\x18'
msg += b'\x00\x52\x00\x12\x00\x01\x00\x00\x00\x7c\x00\x00\x24\xed\x00\x2c' msg += b'\x00\x52\x00\x12\x00\x01\x00\x00\x00\x7c\x00\x00\x24\xed\x00\x2c'
msg += b'\x00\x00\x0b\x10\x00\x26\x00\x00\x0a\x0f\x00\x30\x00\x00\x0b\x76' msg += b'\x00\x00\x0b\x10\x00\x26\x00\x00\x0a\x0f\x00\x30\x00\x00\x0b\x76'
msg += b'\x00\x00\x00\x00\x06\x16\x00\x00\x00\x00\x55\xaa\x00\x01\x00\x00'
msg += b'\x00\x00\x00\x00\x06\x16\x00\x00\x00\x01\x55\xaa\x00\x01\x00\x00'
msg += b'\x00\x00\x00\x00\xff\xff\x07\xd0\x00\x03\x04\x00\x04\x00\x04\x00' msg += b'\x00\x00\x00\x00\xff\xff\x07\xd0\x00\x03\x04\x00\x04\x00\x04\x00'
msg += b'\x04\x00\x00\x01\xff\xff\x00\x01\x00\x06\x00\x68\x00\x68\x05\x00' msg += b'\x04\x00\x00\x01\xff\xff\x00\x01\x00\x06\x00\x68\x00\x68\x05\x00'
msg += b'\x09\xcd\x07\xb6\x13\x9c\x13\x24\x00\x01\x07\xae\x04\x0f\x00\x41' msg += b'\x09\xcd\x07\xb6\x13\x9c\x13\x24\x00\x01\x07\xae\x04\x0f\x00\x41'
@@ -73,7 +77,9 @@ def MsgDataInd():
msg += b'\x04\x00\x00\x01\x13\x9c\x0f\xa0\x00\x4e\x00\x66\x03\xe8\x04\x00' msg += b'\x04\x00\x00\x01\x13\x9c\x0f\xa0\x00\x4e\x00\x66\x03\xe8\x04\x00'
msg += b'\x09\xce\x07\xa8\x13\x9c\x13\x26\x00\x00\x00\x00\x00\x00\x00\x00' msg += b'\x09\xce\x07\xa8\x13\x9c\x13\x26\x00\x00\x00\x00\x00\x00\x00\x00'
msg += b'\x00\x00\x00\x00\x04\x00\x04\x00\x00\x00\x00\x00\xff\xff\x00\x00' msg += b'\x00\x00\x00\x00\x04\x00\x04\x00\x00\x00\x00\x00\xff\xff\x00\x00'
msg += b'\x00\x00\x00\x00\x24\x15' msg += b'\x00\x00\x00\x00'
msg += correct_checksum(msg)
msg += b'\x15'
return msg return msg
@pytest.fixture @pytest.fixture
@@ -148,3 +154,5 @@ def test_data_ind(ClientConnection,MsgDataInd, MsgDataResp):
pass pass
# time.sleep(2.5) # time.sleep(2.5)
checkResponse(data, MsgDataResp) checkResponse(data, MsgDataResp)