jblance / mpp-solar

Python package to communicate to MPP Solar PIP-4048MS inverters (and similar)
MIT License
364 stars 151 forks source link

Lot of checksum error since update in the Daly MQTT response #125

Closed firemen027 closed 3 years ago

firemen027 commented 3 years ago

Hello Mr Blance

I update the code this week to the latest and i got bunch of checksum error showing in mqtt.

Digging command I found then mosStatus seem the problem

pi@rpichalet:/etc/mpp-solar $ mpp-solar -p /dev/ttyUSB0 -b 9600 -P DALY --protocol DALY -c SOC Command: SOC - State of Charge

Parameter Value Unit battery_bank_voltage 52.7 V acquistion 0.0 V current -1.6 A soc 56.4 %

Doing this with other command work but When I try with mosStatus, here what I get.

pi@rpichalet:/etc/mpp-solar $ mpp-solar -p /dev/ttyUSB0 -b 9600 -P DALY --protocol DALY -c mosStatus Traceback (most recent call last): File "/usr/local/bin/mpp-solar", line 33, in sys.exit(load_entry_point('mpp-solar', 'console_scripts', 'mpp-solar')()) File "/etc/mpp-solar/src/mpp-solar/mppsolar/init.py", line 407, in main results = _device.run_command(command=_command) File "/etc/mpp-solar/src/mpp-solar/mppsolar/devices/device.py", line 333, in run_command decoded_response = self._protocol.decode(raw_response, command) File "/etc/mpp-solar/src/mpp-solar/mppsolar/protocols/abstractprotocol.py", line 417, in decode frame_number=frame_number, File "/etc/mpp-solar/src/mpp-solar/mppsolar/protocols/abstractprotocol.py", line 95, in process_response key = int(raw_value) ValueError: invalid literal for int() with base 10: b'\x01'

I dunno if the trouble is on my side, but I suspect something in the code.

My best regards

jblance commented 3 years ago

Hi

It looks like I broke something Can you do a full debug run and post the output (add -D flag to the command)

firemen027 commented 3 years ago

pi@rpichalet:~ $ mpp-solar -p /dev/ttyUSB0 -b 9600 -P DALY --protocol DALY -c mosStatus -D

2021-06-27 17:28:57,188:INFO:__init__:main@235: Solar Device Command Utility, version: 0.7.67, move jk04 to new processing, add lookup functionality
2021-06-27 17:28:57,189:INFO:__init__:main@339: Creating device "unnamed" (type: "mppsolar") on port "/dev/ttyUSB0 (porttype=None)" using protocol "DALY"
2021-06-27 17:28:57,191:DEBUG:__init__:main@342: device_class <class 'mppsolar.devices.mppsolar.mppsolar'>
2021-06-27 17:28:57,192:DEBUG:device:__init__@31: __init__ args ()
2021-06-27 17:28:57,192:DEBUG:device:__init__@32: __init__ kwargs {'name': 'unnamed', 'port': '/dev/ttyUSB0', 'protocol': 'DALY', 'baud': 9600, 'porttype': None, 'mqtt_broker': 'localhost', 'mqtt_port': 1883, 'mqtt_user': None, 'mqtt_pass': None}
2021-06-27 17:28:57,192:DEBUG:device:get_port_type@86: port matches ttyusb
2021-06-27 17:28:57,192:INFO:device:set_port@160: Using serialio for communications
2021-06-27 17:28:57,199:DEBUG:device:set_protocol@96: Protocol DALY
2021-06-27 17:28:57,208:DEBUG:device:__init__@36: __init__ name unnamed, port <mppsolar.io.serialio.SerialIO object at 0xb5f38730>, protocol <mppsolar.protocols.daly.daly object at 0xb5f28270>
2021-06-27 17:28:57,209:DEBUG:__init__:main@389: Commands [(<mppsolar.devices.mppsolar.mppsolar object at 0xb5f283d0>, 'mosStatus', 'mosStatus', 'screen', None, None)]
2021-06-27 17:28:57,209:INFO:__init__:main@394: Looping 1 commands
2021-06-27 17:28:57,209:INFO:__init__:main@405: Getting results from device: mppsolar device - name: unnamed, port: <mppsolar.io.serialio.SerialIO object at 0xb5f38730>, protocol: <mppsolar.protocols.daly.daly object at 0xb5f28270> for command: mosStatus, tag: mosStatus, outputs: screen
2021-06-27 17:28:57,209:INFO:device:run_command@270: Running command mosStatus
2021-06-27 17:28:57,209:INFO:daly:get_full_command@208: Using protocol b'DALY' with 7 commands
2021-06-27 17:28:57,209:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'mosStatus'
2021-06-27 17:28:57,210:DEBUG:abstractprotocol:get_command_defn@43: Found command mosStatus in protocol b'DALY'
2021-06-27 17:28:57,210:DEBUG:daly:get_full_command@225: full command: b'\xa5\x80\x93\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc0\n'
2021-06-27 17:28:57,210:INFO:device:run_command@296: full command b'\xa5\x80\x93\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc0\n' for command mosStatus
2021-06-27 17:28:57,210:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'mosStatus'
2021-06-27 17:28:57,210:DEBUG:abstractprotocol:get_command_defn@43: Found command mosStatus in protocol b'DALY'
2021-06-27 17:28:57,211:DEBUG:serialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600
2021-06-27 17:28:57,218:DEBUG:serialio:send_and_receive@22: Executing command via serialio...
2021-06-27 17:28:58,320:DEBUG:serialio:send_and_receive@30: serial response was: b'\xa5\x01\x93\x08\x00\x01\x01\x9a\x00\x02\xa2\xd8Y'
2021-06-27 17:28:58,323:DEBUG:device:run_command@315: Send and Receive Response b'\xa5\x01\x93\x08\x00\x01\x01\x9a\x00\x02\xa2\xd8Y'
2021-06-27 17:28:58,324:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x93\x08\x00\x01\x01\x9a\x00\x02\xa2\xd8Y'
2021-06-27 17:28:58,324:DEBUG:daly:check_response_valid@244: checking validity of b'\xa5\x01\x93\x08\x00\x01\x01\x9a\x00\x02\xa2\xd8Y'
2021-06-27 17:28:58,324:DEBUG:daly:check_response_valid@257: DALY Checksum matches response 'b'\xa5\x01\x93\x08\x00\x01\x01\x9a\x00\x02\xa2\xd8Y'' checksum:89
2021-06-27 17:28:58,325:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'mosStatus'
2021-06-27 17:28:58,325:DEBUG:abstractprotocol:get_command_defn@43: Found command mosStatus in protocol b'DALY'
2021-06-27 17:28:58,325:INFO:abstractprotocol:decode@214: Processing response of type POSITIONAL
2021-06-27 17:28:58,326:DEBUG:abstractprotocol:decode@218: trimmed and split responses: [b'\xa5', b'\x01', b'\x93', b'\x08', b'\x00', b'\x01', b'\x01', b'\x9a', b'\x00\x02\xa2\xd8', b'Y']
2021-06-27 17:28:58,326:DEBUG:abstractprotocol:decode@375: Processing POSITIONAL type responses
2021-06-27 17:28:58,326:DEBUG:abstractprotocol:decode@392: Got defn ['discard', 1, 'start flag', '']
2021-06-27 17:28:58,327:DEBUG:abstractprotocol:process_response@85: Processing data_type: discard for data_name: start flag, raw_value b'\xa5'
2021-06-27 17:28:58,327:DEBUG:abstractprotocol:process_response@92: Discarding start flag:b'\xa5'
2021-06-27 17:28:58,327:DEBUG:abstractprotocol:decode@375: Processing POSITIONAL type responses
2021-06-27 17:28:58,328:DEBUG:abstractprotocol:decode@392: Got defn ['discard', 1, 'module address', '']
2021-06-27 17:28:58,328:DEBUG:abstractprotocol:process_response@85: Processing data_type: discard for data_name: module address, raw_value b'\x01'
2021-06-27 17:28:58,328:DEBUG:abstractprotocol:process_response@92: Discarding module address:b'\x01'
2021-06-27 17:28:58,328:DEBUG:abstractprotocol:decode@375: Processing POSITIONAL type responses
2021-06-27 17:28:58,329:DEBUG:abstractprotocol:decode@392: Got defn ['discard', 1, 'command id', '']
2021-06-27 17:28:58,329:DEBUG:abstractprotocol:process_response@85: Processing data_type: discard for data_name: command id, raw_value b'\x93'
2021-06-27 17:28:58,329:DEBUG:abstractprotocol:process_response@92: Discarding command id:b'\x93'
2021-06-27 17:28:58,330:DEBUG:abstractprotocol:decode@375: Processing POSITIONAL type responses
2021-06-27 17:28:58,330:DEBUG:abstractprotocol:decode@392: Got defn ['discard', 1, 'data length', '']
2021-06-27 17:28:58,330:DEBUG:abstractprotocol:process_response@85: Processing data_type: discard for data_name: data length, raw_value b'\x08'
2021-06-27 17:28:58,330:DEBUG:abstractprotocol:process_response@92: Discarding data length:b'\x08'
2021-06-27 17:28:58,331:DEBUG:abstractprotocol:decode@375: Processing POSITIONAL type responses
2021-06-27 17:28:58,331:DEBUG:abstractprotocol:decode@392: Got defn ['option', 1, 'Charge Status', ['stationary', 'charged', 'discharged']]
2021-06-27 17:28:58,332:DEBUG:abstractprotocol:process_response@85: Processing data_type: option for data_name: Charge Status, raw_value b'\x00'
Traceback (most recent call last):
  File "/usr/local/bin/mpp-solar", line 33, in <module>
    sys.exit(load_entry_point('mpp-solar', 'console_scripts', 'mpp-solar')())
  File "/etc/mpp-solar/src/mpp-solar/mppsolar/__init__.py", line 407, in main
    results = _device.run_command(command=_command)
  File "/etc/mpp-solar/src/mpp-solar/mppsolar/devices/device.py", line 333, in run_command
    decoded_response = self._protocol.decode(raw_response, command)
  File "/etc/mpp-solar/src/mpp-solar/mppsolar/protocols/abstractprotocol.py", line 417, in decode
    frame_number=frame_number,
  File "/etc/mpp-solar/src/mpp-solar/mppsolar/protocols/abstractprotocol.py", line 95, in process_response
    key = int(raw_value)
ValueError: invalid literal for int() with base 10: b'\x00'
jblance commented 3 years ago

Wow, the only command in the DALY protocol that didnt have a test... v0.7.69 should have fixed the error

firemen027 commented 3 years ago

Wow!! you're so fast.

When I pas the command in manual mode: it work

When I run in deamon : I received some error

image

Here My conf file section for Daly image

When I add more command to the conf file: many more error happen.

Stil trying to locate the problem

Thank you

jblance commented 3 years ago

you can test the config file output on the command line, e.g. mpp-solar -C /path/to/config.file -I

firemen027 commented 3 years ago

pi@rpichalet:/etc/mpp-solar $ mpp-solar -C /path/to/config.file -I 2021-06-27 22:23:47,678:INFO:init:main@235: Solar Device Command Utility, version: 0.7.69, fix error in daly protocol mosStatus 2021-06-27 22:23:47,686:ERROR:init:main@279: Config File '/path/to/config.file' is missing the required 'SETUP' section

jblance commented 3 years ago

err, you'll need to use the correct path to the config file...

firemen027 commented 3 years ago

Humm and how I solve that ?

Something happen since last update!

jblance commented 3 years ago

where is the config file?

firemen027 commented 3 years ago

My bad: I just understand what you asking: sorry

pi@rpichalet:/etc/mpp-solar $ mpp-solar -C /etc/mpp-solar/mpp-solar.conf -I

2021-06-27 22:35:33,708:INFO:__init__:main@235: Solar Device Command Utility, version: 0.7.69, fix error in daly protocol mosStatus
2021-06-27 22:35:33,719:INFO:device:set_port@142: Using hidrawio for communications
2021-06-27 22:35:33,730:INFO:__init__:main@330: Config file: /etc/mpp-solar/mpp-solar.conf
2021-06-27 22:35:33,730:INFO:__init__:main@331: Config setting - pause: 5
2021-06-27 22:35:33,730:INFO:__init__:main@332: Config setting - mqtt_broker: localhost, port: 1883
2021-06-27 22:35:33,730:INFO:__init__:main@333: Config setting - command sections found: 2
2021-06-27 22:35:33,731:INFO:device:set_port@130: Port overide - using port 'DALY'
2021-06-27 22:35:33,731:INFO:device:set_port@166: Using dalyserialio for communications
2021-06-27 22:35:33,738:INFO:__init__:main@330: Config file: /etc/mpp-solar/mpp-solar.conf
2021-06-27 22:35:33,738:INFO:__init__:main@331: Config setting - pause: 5
2021-06-27 22:35:33,738:INFO:__init__:main@332: Config setting - mqtt_broker: localhost, port: 1883
2021-06-27 22:35:33,738:INFO:__init__:main@333: Config setting - command sections found: 2
2021-06-27 22:35:33,739:INFO:__init__:main@394: Looping 6 commands
2021-06-27 22:35:33,739:INFO:__init__:main@405: Getting results from device: mppsolar device - name: PIP3048, port: <mppsolar.io.hidrawio.HIDRawIO object at 0xb5ee1d50>, protocol: <mppsolar.protocols.pi30.pi30 object at 0xb5ec7e70> for command: QPIGS, tag: PIP3048, outputs: mqtt
2021-06-27 22:35:33,739:INFO:device:run_command@270: Running command QPIGS
2021-06-27 22:35:33,739:INFO:abstractprotocol:get_full_command@30: Using protocol b'PI30' with 36 commands
2021-06-27 22:35:33,739:INFO:device:run_command@296: full command b'QPIGS\xb7\xa9\r' for command QPIGS
2021-06-27 22:35:37,585:INFO:abstractprotocol:decode@174: response passed to decode: b'(000.0 00.0 120.8 60.0 0120 0113 004 204 52.30 000 041 0030 0000 000.0 00.00 00002 01010000 00 00 00000 010\x87R\r'
2021-06-27 22:35:37,587:INFO:abstractprotocol:decode@214: Processing response of type DEFAULT
2021-06-27 22:35:37,587:INFO:abstractprotocol:decode@225: Processing DEFAULT type responses
2021-06-27 22:35:37,588:INFO:device:run_command@334: Decoded response {'raw_response': ['(000.0 00.0 120.8 60.0 0120 0113 004 204 52.30 000 041 0030 0000 000.0 00.00 00002 01010000 00 00 00000 010\x87R\r', ''], '_command': 'QPIGS', '_command_description': 'General Status Parameters inquiry', 'AC Input Voltage': [0.0, 'V'], 'AC Input Frequency': [0.0, 'Hz'], 'AC Output Voltage': [120.8, 'V'], 'AC Output Frequency': [60.0, 'Hz'], 'AC Output Apparent Power': [120, 'VA'], 'AC Output Active Power': [113, 'W'], 'AC Output Load': [4, '%'], 'BUS Voltage': [204, 'V'], 'Battery Voltage': [52.3, 'V'], 'Battery Charging Current': [0, 'A'], 'Battery Capacity': [41, '%'], 'Inverter Heat Sink Temperature': [30, '°C'], 'PV Input Current for Battery': [0.0, 'A'], 'PV Input Voltage': [0.0, 'V'], 'Battery Voltage from SCC': [0.0, 'V'], 'Battery Discharge Current': [2, 'A'], 'Is SBU Priority Version Added': [0, 'bool'], 'Is Configuration Changed': [1, 'bool'], 'Is SCC Firmware Updated': [0, 'bool'], 'Is Load On': [1, 'bool'], 'Is Battery Voltage to Steady While Charging': [0, 'bool'], 'Is Charging On': [0, 'bool'], 'Is SCC Charging On': [0, 'bool'], 'Is AC Charging On': [0, 'bool'], 'RSV1': [0, 'A'], 'RSV2': [0, 'A'], 'PV Input Power': [0, 'W'], 'Is Charging to Float': [0, 'bool'], 'Is Switched On': [1, 'bool'], 'Is Reserved': [0, 'bool']}
2021-06-27 22:35:37,589:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 22:35:37,659:INFO:mqtt:output@59: Using output processor: mqtt
2021-06-27 22:35:37,692:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5eed910>, protocol: <mppsolar.protocols.daly.daly object at 0xb5eac050> for command: SOC, tag: DALYtest, outputs: mqtt
2021-06-27 22:35:37,693:INFO:device:run_command@270: Running command SOC
2021-06-27 22:35:37,693:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 22:35:37,693:INFO:device:run_command@296: full command b'\xa5\x80\x90\x08\x00\x00\x00\x00\x00\x00\x00\x00\xbd\n' for command SOC
2021-06-27 22:35:37,800:INFO:abstractprotocol:decode@174: response passed to decode: b''
2021-06-27 22:35:37,800:INFO:abstractprotocol:decode@178: No response
2021-06-27 22:35:37,800:INFO:device:run_command@334: Decoded response {'ERROR': ['No response', '']}
2021-06-27 22:35:37,800:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 22:35:37,800:INFO:mqtt:output@59: Using output processor: mqtt
2021-06-27 22:35:37,803:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5eed910>, protocol: <mppsolar.protocols.daly.daly object at 0xb5eac050> for command: mosStatus, tag: DALYtest, outputs: mqtt
2021-06-27 22:35:37,803:INFO:device:run_command@270: Running command mosStatus
2021-06-27 22:35:37,803:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 22:35:37,803:INFO:device:run_command@296: full command b'\xa5\x80\x93\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc0\n' for command mosStatus
2021-06-27 22:35:37,907:INFO:abstractprotocol:decode@174: response passed to decode: b''
2021-06-27 22:35:37,907:INFO:abstractprotocol:decode@178: No response
2021-06-27 22:35:37,907:INFO:device:run_command@334: Decoded response {'ERROR': ['No response', '']}
2021-06-27 22:35:37,907:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 22:35:37,908:INFO:mqtt:output@59: Using output processor: mqtt
2021-06-27 22:35:37,910:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5eed910>, protocol: <mppsolar.protocols.daly.daly object at 0xb5eac050> for command: status, tag: DALYtest, outputs: mqtt
2021-06-27 22:35:37,910:INFO:device:run_command@270: Running command status
2021-06-27 22:35:37,910:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 22:35:37,910:INFO:device:run_command@296: full command b'\xa5\x80\x94\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc1\n' for command status
2021-06-27 22:35:38,017:INFO:abstractprotocol:decode@174: response passed to decode: b''
2021-06-27 22:35:38,017:INFO:abstractprotocol:decode@178: No response
2021-06-27 22:35:38,017:INFO:device:run_command@334: Decoded response {'ERROR': ['No response', '']}
2021-06-27 22:35:38,018:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 22:35:38,018:INFO:mqtt:output@59: Using output processor: mqtt
2021-06-27 22:35:38,020:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5eed910>, protocol: <mppsolar.protocols.daly.daly object at 0xb5eac050> for command: cellMinMaxVoltages, tag: DALYtest, outputs: mqtt
2021-06-27 22:35:38,020:INFO:device:run_command@270: Running command cellMinMaxVoltages
2021-06-27 22:35:38,020:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 22:35:38,021:INFO:device:run_command@296: full command b'\xa5\x80\x91\x08\x00\x00\x00\x00\x00\x00\x00\x00\xbe\n' for command cellMinMaxVoltages
2021-06-27 22:35:38,832:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x95\x08\r\x00\x00\x00\x00\x00\x00X\xa8\xa5\x01\x95\x08\x0e\x00\x00\x00\x00\x00\x00X\xa9\xa5\x01\x95\x08\x0f\x00\x00\x00\x00\x00\x00X\xaa\xa5\x01\x95\x08\x10\x00\x00\x00\x00\x00\x00X\xab\xa5\x01\x90\x08\x02\x0c\x00\x00uA\x029=\xa5\x01\x93\x08\x02\x01\x01{\x00\x02nX\x88\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08X\xb3'
2021-06-27 22:35:38,832:INFO:abstractprotocol:decode@178: DALY checksum did not match for response b'\xa5\x01\x95\x08\r\x00\x00\x00\x00\x00\x00X\xa8\xa5\x01\x95\x08\x0e\x00\x00\x00\x00\x00\x00X\xa9\xa5\x01\x95\x08\x0f\x00\x00\x00\x00\x00\x00X\xaa\xa5\x01\x95\x08\x10\x00\x00\x00\x00\x00\x00X\xab\xa5\x01\x90\x08\x02\x0c\x00\x00uA\x029=\xa5\x01\x93\x08\x02\x01\x01{\x00\x02nX\x88\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08X\xb3'
2021-06-27 22:35:38,833:INFO:device:run_command@334: Decoded response {'ERROR': ["DALY checksum did not match for response b'\\xa5\\x01\\x95\\x08\\r\\x00\\x00\\x00\\x00\\x00\\x00X\\xa8\\xa5\\x01\\x95\\x08\\x0e\\x00\\x00\\x00\\x00\\x00\\x00X\\xa9\\xa5\\x01\\x95\\x08\\x0f\\x00\\x00\\x00\\x00\\x00\\x00X\\xaa\\xa5\\x01\\x95\\x08\\x10\\x00\\x00\\x00\\x00\\x00\\x00X\\xab\\xa5\\x01\\x90\\x08\\x02\\x0c\\x00\\x00uA\\x029=\\xa5\\x01\\x93\\x08\\x02\\x01\\x01{\\x00\\x02nX\\x88\\xa5\\x01\\x94\\x08\\x10\\x01\\x00\\x00\\x00\\x00\\x08X\\xb3'", '']}
2021-06-27 22:35:38,833:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 22:35:38,834:INFO:mqtt:output@59: Using output processor: mqtt
2021-06-27 22:35:38,839:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5eed910>, protocol: <mppsolar.protocols.daly.daly object at 0xb5eac050> for command: cellVoltages, tag: DALYtest, outputs: mqtt
2021-06-27 22:35:38,839:INFO:device:run_command@270: Running command cellVoltages
2021-06-27 22:35:38,839:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 22:35:38,840:INFO:device:run_command@296: full command b'\xa5\x80\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc2\n' for command cellVoltages
2021-06-27 22:35:40,558:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x95\x08\x01\x0c\xc6\x0c\xce\x0c\xceX"\xa5\x01\x95\x08\x02\x0c\xce\x0c\xce\x0c\xceX+\xa5\x01\x95\x08\x03\x0c\xce\x0c\xcf\x0c\xcdX,\xa5\x01\x95\x08\x04\x0c\xcc\x0c\xcb\x0c\xceX(\xa5\x01\x95\x08\x05\x0c\xcd\x0c\xce\x0c\xcdX,\xa5\x01\x95\x08\x06\x0c\xcb\x00\x00\x00\x00Xx\xa5\x01\x95\x08\x07\x00\x00\x00\x00\x00\x00X\xa2\xa5\x01\x95\x08\x08\x00\x00\x00\x00\x00\x00X\xa3\xa5\x01\x95\x08\t\x00\x00\x00\x00\x00\x00X\xa4\xa5\x01\x95\x08\n\x00\x00\x00\x00\x00\x00X\xa5\xa5\x01\x95\x08\x0b\x00\x00\x00\x00\x00\x00X\xa6\xa5\x01\x95\x08\x0c\x00\x00\x00\x00\x00\x00X\xa7\xa5\x01\x95\x08\r\x00\x00\x00\x00\x00\x00X\xa8\xa5\x01\x95\x08\x0e\x00\x00\x00\x00\x00\x00X\xa9\xa5\x01\x95\x08\x0f\x00\x00\x00\x00\x00\x00X\xaa\xa5\x01\x95\x08\x10\x00\x00\x00\x00\x00\x00X\xab'
2021-06-27 22:35:40,559:INFO:daly:check_response_valid@251: is multiframe response - assuming ok for now
2021-06-27 22:35:40,560:INFO:abstractprotocol:decode@214: Processing response of type MULTIFRAME-POSITIONAL
2021-06-27 22:35:40,560:INFO:daly:get_responses@282: Multi frame response with 16 frames
2021-06-27 22:35:40,583:INFO:device:run_command@334: Decoded response {'raw_response': ['¥\x01\x95\x08\x01\x0cÆ\x0cÎ\x0cÎX"¥\x01\x95\x08\x02\x0cÎ\x0cÎ\x0cÎX+¥\x01\x95\x08\x03\x0cÎ\x0cÏ\x0cÍX,¥\x01\x95\x08\x04\x0cÌ\x0cË\x0cÎX(¥\x01\x95\x08\x05\x0cÍ\x0cÎ\x0cÍX,¥\x01\x95\x08\x06\x0cË\x00\x00\x00\x00Xx¥\x01\x95\x08\x07\x00\x00\x00\x00\x00\x00X¢¥\x01\x95\x08\x08\x00\x00\x00\x00\x00\x00X£¥\x01\x95\x08\t\x00\x00\x00\x00\x00\x00X¤¥\x01\x95\x08\n\x00\x00\x00\x00\x00\x00X¥¥\x01\x95\x08\x0b\x00\x00\x00\x00\x00\x00X¦¥\x01\x95\x08\x0c\x00\x00\x00\x00\x00\x00X§¥\x01\x95\x08\r\x00\x00\x00\x00\x00\x00X¨¥\x01\x95\x08\x0e\x00\x00\x00\x00\x00\x00X©¥\x01\x95\x08\x0f\x00\x00\x00\x00\x00\x00Xª¥\x01\x95\x08\x10\x00\x00\x00\x00\x00\x00X«', ''], '_command': 'cellVoltages', '_command_description': 'Cell Voltages Information', 'Cell 01 Voltage': [3.27, 'V'], 'Cell 02 Voltage': [3.278, 'V'], 'Cell 03 Voltage': [3.278, 'V'], 'Cell 04 Voltage': [3.278, 'V'], 'Cell 05 Voltage': [3.278, 'V'], 'Cell 06 Voltage': [3.278, 'V'], 'Cell 07 Voltage': [3.278, 'V'], 'Cell 08 Voltage': [3.279, 'V'], 'Cell 09 Voltage': [3.277, 'V'], 'Cell 10 Voltage': [3.276, 'V'], 'Cell 11 Voltage': [3.275, 'V'], 'Cell 12 Voltage': [3.278, 'V'], 'Cell 13 Voltage': [3.277, 'V'], 'Cell 14 Voltage': [3.278, 'V'], 'Cell 15 Voltage': [3.277, 'V'], 'Cell 16 Voltage': [3.275, 'V'], 'Cell 17 Voltage': [0.0, 'V'], 'Cell 18 Voltage': [0.0, 'V'], 'Cell 19 Voltage': [0.0, 'V'], 'Cell 20 Voltage': [0.0, 'V'], 'Cell 21 Voltage': [0.0, 'V'], 'Cell 22 Voltage': [0.0, 'V'], 'Cell 23 Voltage': [0.0, 'V'], 'Cell 24 Voltage': [0.0, 'V'], 'Cell 25 Voltage': [0.0, 'V'], 'Cell 26 Voltage': [0.0, 'V'], 'Cell 27 Voltage': [0.0, 'V'], 'Cell 28 Voltage': [0.0, 'V'], 'Cell 29 Voltage': [0.0, 'V'], 'Cell 30 Voltage': [0.0, 'V'], 'Cell 31 Voltage': [0.0, 'V'], 'Cell 32 Voltage': [0.0, 'V'], 'Cell 33 Voltage': [0.0, 'V'], 'Cell 34 Voltage': [0.0, 'V'], 'Cell 35 Voltage': [0.0, 'V'], 'Cell 36 Voltage': [0.0, 'V'], 'Cell 37 Voltage': [0.0, 'V'], 'Cell 38 Voltage': [0.0, 'V'], 'Cell 39 Voltage': [0.0, 'V'], 'Cell 40 Voltage': [0.0, 'V'], 'Cell 41 Voltage': [0.0, 'V'], 'Cell 42 Voltage': [0.0, 'V'], 'Cell 43 Voltage': [0.0, 'V'], 'Cell 44 Voltage': [0.0, 'V'], 'Cell 45 Voltage': [0.0, 'V'], 'Cell 46 Voltage': [0.0, 'V'], 'Cell 47 Voltage': [0.0, 'V'], 'Cell 48 Voltage': [0.0, 'V']}
2021-06-27 22:35:40,584:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 22:35:40,585:INFO:mqtt:output@59: Using output processor: mqtt
jblance commented 3 years ago

hmm, that looked like it worked? try changing the mqttbroker to mqtt_broker=screen in the [SETUP] section of the config file and re-run the command without -I i.e. mpp-solar -C /etc/mpp-solar/mpp-solar.conf

firemen027 commented 3 years ago

pi@rpichalet:/etc/mpp-solar $ mpp-solar -C /etc/mpp-solar/mpp-solar.conf {'topic': 'PIP3048/status/ac_input_voltage/value', 'payload': 0.0} {'topic': 'PIP3048/status/ac_input_voltage/unit', 'payload': 'V'} {'topic': 'PIP3048/status/ac_input_frequency/value', 'payload': 0.0} {'topic': 'PIP3048/status/ac_input_frequency/unit', 'payload': 'Hz'} {'topic': 'PIP3048/status/ac_output_voltage/value', 'payload': 118.9} {'topic': 'PIP3048/status/ac_output_voltage/unit', 'payload': 'V'} {'topic': 'PIP3048/status/ac_output_frequency/value', 'payload': 59.9} {'topic': 'PIP3048/status/ac_output_frequency/unit', 'payload': 'Hz'} {'topic': 'PIP3048/status/ac_output_apparent_power/value', 'payload': 118} {'topic': 'PIP3048/status/ac_output_apparent_power/unit', 'payload': 'VA'} {'topic': 'PIP3048/status/ac_output_active_power/value', 'payload': 116} {'topic': 'PIP3048/status/ac_output_active_power/unit', 'payload': 'W'} {'topic': 'PIP3048/status/ac_output_load/value', 'payload': 3} {'topic': 'PIP3048/status/ac_output_load/unit', 'payload': '%'} {'topic': 'PIP3048/status/bus_voltage/value', 'payload': 204} {'topic': 'PIP3048/status/bus_voltage/unit', 'payload': 'V'} {'topic': 'PIP3048/status/battery_voltage/value', 'payload': 52.3} {'topic': 'PIP3048/status/battery_voltage/unit', 'payload': 'V'} {'topic': 'PIP3048/status/battery_charging_current/value', 'payload': 0} {'topic': 'PIP3048/status/battery_charging_current/unit', 'payload': 'A'} {'topic': 'PIP3048/status/battery_capacity/value', 'payload': 41} {'topic': 'PIP3048/status/battery_capacity/unit', 'payload': '%'} {'topic': 'PIP3048/status/inverter_heat_sink_temperature/value', 'payload': 30} {'topic': 'PIP3048/status/inverter_heat_sink_temperature/unit', 'payload': '°C'} {'topic': 'PIP3048/status/pv_input_current_for_battery/value', 'payload': 0.0} {'topic': 'PIP3048/status/pv_input_current_for_battery/unit', 'payload': 'A'} {'topic': 'PIP3048/status/pv_input_voltage/value', 'payload': 0.0} {'topic': 'PIP3048/status/pv_input_voltage/unit', 'payload': 'V'} {'topic': 'PIP3048/status/battery_voltage_from_scc/value', 'payload': 0.0} {'topic': 'PIP3048/status/battery_voltage_from_scc/unit', 'payload': 'V'} {'topic': 'PIP3048/status/battery_discharge_current/value', 'payload': 2} {'topic': 'PIP3048/status/battery_discharge_current/unit', 'payload': 'A'} {'topic': 'PIP3048/status/is_sbu_priority_version_added/value', 'payload': 0} {'topic': 'PIP3048/status/is_sbu_priority_version_added/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_configuration_changed/value', 'payload': 1} {'topic': 'PIP3048/status/is_configuration_changed/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_scc_firmware_updated/value', 'payload': 0} {'topic': 'PIP3048/status/is_scc_firmware_updated/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_load_on/value', 'payload': 1} {'topic': 'PIP3048/status/is_load_on/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_battery_voltage_to_steady_while_charging/value', 'payload': 0} {'topic': 'PIP3048/status/is_battery_voltage_to_steady_while_charging/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_charging_on/value', 'payload': 0} {'topic': 'PIP3048/status/is_charging_on/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_scc_charging_on/value', 'payload': 0} {'topic': 'PIP3048/status/is_scc_charging_on/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_ac_charging_on/value', 'payload': 0} {'topic': 'PIP3048/status/is_ac_charging_on/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/rsv1/value', 'payload': 0} {'topic': 'PIP3048/status/rsv1/unit', 'payload': 'A'} {'topic': 'PIP3048/status/rsv2/value', 'payload': 0} {'topic': 'PIP3048/status/rsv2/unit', 'payload': 'A'} {'topic': 'PIP3048/status/pv_input_power/value', 'payload': 0} {'topic': 'PIP3048/status/pv_input_power/unit', 'payload': 'W'} {'topic': 'PIP3048/status/is_charging_to_float/value', 'payload': 0} {'topic': 'PIP3048/status/is_charging_to_float/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_switched_on/value', 'payload': 1} {'topic': 'PIP3048/status/is_switched_on/unit', 'payload': 'bool'} {'topic': 'PIP3048/status/is_reserved/value', 'payload': 0} {'topic': 'PIP3048/status/is_reserved/unit', 'payload': 'bool'} {'topic': 'DALYtest/status/battery_bank_voltage/value', 'payload': 52.4} {'topic': 'DALYtest/status/battery_bank_voltage/unit', 'payload': 'V'} {'topic': 'DALYtest/status/acquistion/value', 'payload': 0.0} {'topic': 'DALYtest/status/acquistion/unit', 'payload': 'V'} {'topic': 'DALYtest/status/current/value', 'payload': 1.7} {'topic': 'DALYtest/status/current/unit', 'payload': 'A'} {'topic': 'DALYtest/status/soc/value', 'payload': 56.6} {'topic': 'DALYtest/status/soc/unit', 'payload': '%'} {'topic': 'DALYtest/status/charge_status/value', 'payload': 'discharged'} {'topic': 'DALYtest/status/charging_mos_tube_status/value', 'payload': '01'} {'topic': 'DALYtest/status/discharging_mos_tube_status/value', 'payload': '01'} {'topic': 'DALYtest/status/bms_life/value', 'payload': 17} {'topic': 'DALYtest/status/bms_life/unit', 'payload': 'cycles'} {'topic': 'DALYtest/status/residual_capacity/value', 'payload': 158.48} {'topic': 'DALYtest/status/residual_capacity/unit', 'payload': 'AH'} {'topic': 'DALYtest/status/number_of_cells/value', 'payload': 16} {'topic': 'DALYtest/status/number_of_temperature_sensors/value', 'payload': 1} {'topic': 'DALYtest/status/charger_status/value', 'payload': 'disconnected'} {'topic': 'DALYtest/status/loadstatus/value', 'payload': 'disconnected'} {'topic': 'DALYtest/status/flags(todo)/value', 'payload': '00'} {'topic': 'DALYtest/status/charge/discharge_cycles/value', 'payload': 8} {'topic': 'DALYtest/status/charge/discharge_cycles/unit', 'payload': 'cycles'} {'topic': 'DALYtest/status/reserved/value', 'payload': '10'} {'topic': 'DALYtest/status/maximum_cell_voltage/value', 'payload': 3.279} {'topic': 'DALYtest/status/maximum_cell_voltage/unit', 'payload': 'V'} {'topic': 'DALYtest/status/maximum_cell_number/value', 'payload': 14} {'topic': 'DALYtest/status/minimum_cell_voltage/value', 'payload': 3.27} {'topic': 'DALYtest/status/minimum_cell_voltage/unit', 'payload': 'V'} {'topic': 'DALYtest/status/minimum_cell_number/value', 'payload': 1} {'topic': 'DALYtest/status/error/value', 'payload': 'No response'} pi@rpichalet:/etc/mpp-solar $

jblance commented 3 years ago

weird can you run with full debug on (add -D )

jblance commented 3 years ago

actually looks like we are not getting all the responses before sending another command

firemen027 commented 3 years ago

Oki now a Big paste:

Last login: Sun Jun 27 22:56:58 2021 pi@rpichalet:~ $ mpp-solar -C /etc/mpp-solar/mpp-solar.conf -D

2021-06-27 23:01:32,379:INFO:__init__:main@235: Solar Device Command Utility, version: 0.7.69, fix error in daly protocol mosStatus
2021-06-27 23:01:32,386:DEBUG:__init__:main@268: args.configfile is true: /etc/mpp-solar/mpp-solar.conf
2021-06-27 23:01:32,391:DEBUG:__init__:main@303: device_class <class 'mppsolar.devices.mppsolar.mppsolar'>
2021-06-27 23:01:32,391:DEBUG:device:__init__@31: __init__ args ()
2021-06-27 23:01:32,392:DEBUG:device:__init__@32: __init__ kwargs {'name': 'PIP3048', 'port': '/dev/hidraw0', 'protocol': 'PI30', 'outputs': 'mqtt', 'baud': '2400', 'porttype': None, 'mqtt_broker': 'screen', 'mqtt_port': 1883, 'mqtt_user': None, 'mqtt_pass': None}
2021-06-27 23:01:32,392:DEBUG:device:get_port_type@59: port matches hidraw
2021-06-27 23:01:32,392:INFO:device:set_port@142: Using hidrawio for communications
2021-06-27 23:01:32,394:DEBUG:device:set_protocol@96: Protocol PI30
2021-06-27 23:01:32,403:DEBUG:device:__init__@36: __init__ name PIP3048, port <mppsolar.io.hidrawio.HIDRawIO object at 0xb5e9ae90>, protocol <mppsolar.protocols.pi30.pi30 object at 0xb5e7ee90>
2021-06-27 23:01:32,404:DEBUG:__init__:main@322: Commands from config file [(<mppsolar.devices.mppsolar.mppsolar object at 0xb5e9a290>, 'QPIGS', 'PIP3048', 'mqtt', None, None)]
2021-06-27 23:01:32,404:INFO:__init__:main@330: Config file: /etc/mpp-solar/mpp-solar.conf
2021-06-27 23:01:32,404:INFO:__init__:main@331: Config setting - pause: 5
2021-06-27 23:01:32,405:INFO:__init__:main@332: Config setting - mqtt_broker: screen, port: 1883
2021-06-27 23:01:32,405:INFO:__init__:main@333: Config setting - command sections found: 2
2021-06-27 23:01:32,405:DEBUG:__init__:main@303: device_class <class 'mppsolar.devices.mppsolar.mppsolar'>
2021-06-27 23:01:32,406:DEBUG:device:__init__@31: __init__ args ()
2021-06-27 23:01:32,406:DEBUG:device:__init__@32: __init__ kwargs {'name': 'DALY', 'port': '/dev/ttyUSB0', 'protocol': 'DALY', 'outputs': 'mqtt', 'baud': '9600', 'porttype': 'DALY', 'mqtt_broker': 'screen', 'mqtt_port': 1883, 'mqtt_user': None, 'mqtt_pass': None}
2021-06-27 23:01:32,406:INFO:device:set_port@130: Port overide - using port 'DALY'
2021-06-27 23:01:32,407:DEBUG:device:get_port_type@77: port matches daly
2021-06-27 23:01:32,407:INFO:device:set_port@166: Using dalyserialio for communications
2021-06-27 23:01:32,413:DEBUG:device:set_protocol@96: Protocol DALY
2021-06-27 23:01:32,414:DEBUG:device:__init__@36: __init__ name DALY, port <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5ea5970>, protocol <mppsolar.protocols.daly.daly object at 0xb5e640b0>
2021-06-27 23:01:32,415:DEBUG:__init__:main@322: Commands from config file [(<mppsolar.devices.mppsolar.mppsolar object at 0xb5e9a290>, 'QPIGS', 'PIP3048', 'mqtt', None, None), (<mppsolar.devices.mppsolar.mppsolar object at 0xb5ea5790>, 'SOC', 'DALYtest', 'mqtt', None, None), (<mppsolar.devices.mppsolar.mppsolar object at 0xb5ea5790>, 'mosStatus', 'DALYtest', 'mqtt', None, None), (<mppsolar.devices.mppsolar.mppsolar object at 0xb5ea5790>, 'status', 'DALYtest', 'mqtt', None, None), (<mppsolar.devices.mppsolar.mppsolar object at 0xb5ea5790>, 'cellMinMaxVoltages', 'DALYtest', 'mqtt', None, None), (<mppsolar.devices.mppsolar.mppsolar object at 0xb5ea5790>, 'cellVoltages', 'DALYtest', 'mqtt', None, None)]
2021-06-27 23:01:32,415:INFO:__init__:main@330: Config file: /etc/mpp-solar/mpp-solar.conf
2021-06-27 23:01:32,415:INFO:__init__:main@331: Config setting - pause: 5
2021-06-27 23:01:32,416:INFO:__init__:main@332: Config setting - mqtt_broker: screen, port: 1883
2021-06-27 23:01:32,417:INFO:__init__:main@333: Config setting - command sections found: 2
2021-06-27 23:01:32,417:INFO:__init__:main@394: Looping 6 commands
2021-06-27 23:01:32,417:INFO:__init__:main@405: Getting results from device: mppsolar device - name: PIP3048, port: <mppsolar.io.hidrawio.HIDRawIO object at 0xb5e9ae90>, protocol: <mppsolar.protocols.pi30.pi30 object at 0xb5e7ee90> for command: QPIGS, tag: PIP3048, outputs: mqtt
[...snip...]
2021-06-27 23:01:35,251:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5ea5970>, protocol: <mppsolar.protocols.daly.daly object at 0xb5e640b0> for command: SOC, tag: DALYtest, outputs: mqtt
2021-06-27 23:01:35,251:INFO:device:run_command@270: Running command SOC
2021-06-27 23:01:35,251:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 23:01:35,251:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'SOC'
2021-06-27 23:01:35,252:DEBUG:abstractprotocol:get_command_defn@43: Found command SOC in protocol b'DALY'
2021-06-27 23:01:35,252:DEBUG:daly:get_full_command@228: full command: b'\xa5\x80\x90\x08\x00\x00\x00\x00\x00\x00\x00\x00\xbd\n'
2021-06-27 23:01:35,252:INFO:device:run_command@296: full command b'\xa5\x80\x90\x08\x00\x00\x00\x00\x00\x00\x00\x00\xbd\n' for command SOC
2021-06-27 23:01:35,253:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'SOC'
2021-06-27 23:01:35,253:DEBUG:abstractprotocol:get_command_defn@43: Found command SOC in protocol b'DALY'
2021-06-27 23:01:35,253:DEBUG:dalyserialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600
2021-06-27 23:01:35,262:DEBUG:dalyserialio:send_and_receive@22: Executing command via dalyserialio...
2021-06-27 23:01:35,363:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:35,463:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 0
2021-06-27 23:01:35,464:DEBUG:dalyserialio:send_and_receive@38: serial response was: b'\xa5\x01\x90\x08\x02\x0c\x00\x00uC\x024:'
2021-06-27 23:01:35,465:DEBUG:device:run_command@315: Send and Receive Response b'\xa5\x01\x90\x08\x02\x0c\x00\x00uC\x024:'
2021-06-27 23:01:35,466:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x90\x08\x02\x0c\x00\x00uC\x024:'
2021-06-27 23:01:35,466:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x90\x08\x02\x0c\x00\x00uC\x024:'
2021-06-27 23:01:35,466:DEBUG:daly:check_response_valid@260: DALY Checksum matches response 'b'\xa5\x01\x90\x08\x02\x0c\x00\x00uC\x024:'' checksum:58
[...snip...]
{'topic': 'DALYtest/status/battery_bank_voltage/value', 'payload': 52.4}
{'topic': 'DALYtest/status/battery_bank_voltage/unit', 'payload': 'V'}
{'topic': 'DALYtest/status/acquistion/value', 'payload': 0.0}
{'topic': 'DALYtest/status/acquistion/unit', 'payload': 'V'}
{'topic': 'DALYtest/status/current/value', 'payload': 1.9}
{'topic': 'DALYtest/status/current/unit', 'payload': 'A'}
{'topic': 'DALYtest/status/soc/value', 'payload': 56.4}
{'topic': 'DALYtest/status/soc/unit', 'payload': '%'}

2021-06-27 23:01:35,476:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5ea5970>, protocol: <mppsolar.protocols.daly.daly object at 0xb5e640b0> for command: mosStatus, tag: DALYtest, outputs: mqtt
2021-06-27 23:01:35,476:INFO:device:run_command@270: Running command mosStatus
2021-06-27 23:01:35,476:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 23:01:35,476:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'mosStatus'
2021-06-27 23:01:35,476:DEBUG:abstractprotocol:get_command_defn@43: Found command mosStatus in protocol b'DALY'
2021-06-27 23:01:35,476:DEBUG:daly:get_full_command@228: full command: b'\xa5\x80\x93\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc0\n'
2021-06-27 23:01:35,476:INFO:device:run_command@296: full command b'\xa5\x80\x93\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc0\n' for command mosStatus
2021-06-27 23:01:35,477:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'mosStatus'
2021-06-27 23:01:35,477:DEBUG:abstractprotocol:get_command_defn@43: Found command mosStatus in protocol b'DALY'
2021-06-27 23:01:35,477:DEBUG:dalyserialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600
2021-06-27 23:01:35,483:DEBUG:dalyserialio:send_and_receive@22: Executing command via dalyserialio...
2021-06-27 23:01:35,583:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:35,684:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 0
2021-06-27 23:01:35,684:DEBUG:dalyserialio:send_and_receive@38: serial response was: b'\xa5\x01\x93\x08\x02\x01\x01\x90\x00\x02h\xe0\x1f'
2021-06-27 23:01:35,686:DEBUG:device:run_command@315: Send and Receive Response b'\xa5\x01\x93\x08\x02\x01\x01\x90\x00\x02h\xe0\x1f'
2021-06-27 23:01:35,686:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x93\x08\x02\x01\x01\x90\x00\x02h\xe0\x1f'
2021-06-27 23:01:35,686:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x93\x08\x02\x01\x01\x90\x00\x02h\xe0\x1f'
2021-06-27 23:01:35,686:DEBUG:daly:check_response_valid@260: DALY Checksum matches response 'b'\xa5\x01\x93\x08\x02\x01\x01\x90\x00\x02h\xe0\x1f'' checksum:31
[...snip...]
{'topic': 'DALYtest/status/charge_status/value', 'payload': 'discharged'}
{'topic': 'DALYtest/status/charging_mos_tube_status/value', 'payload': '01'}
{'topic': 'DALYtest/status/discharging_mos_tube_status/value', 'payload': '01'}
{'topic': 'DALYtest/status/bms_life/value', 'payload': 144}
{'topic': 'DALYtest/status/bms_life/unit', 'payload': 'cycles'}
{'topic': 'DALYtest/status/residual_capacity/value', 'payload': 157.92}
{'topic': 'DALYtest/status/residual_capacity/unit', 'payload': 'AH'}
2021-06-27 23:01:35,696:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5ea5970>, protocol: <mppsolar.protocols.daly.daly object at 0xb5e640b0> for command: status, tag: DALYtest, outputs: mqtt
2021-06-27 23:01:35,696:INFO:device:run_command@270: Running command status
2021-06-27 23:01:35,696:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 23:01:35,696:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'status'
2021-06-27 23:01:35,696:DEBUG:abstractprotocol:get_command_defn@43: Found command status in protocol b'DALY'
2021-06-27 23:01:35,697:DEBUG:daly:get_full_command@228: full command: b'\xa5\x80\x94\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc1\n'
2021-06-27 23:01:35,697:INFO:device:run_command@296: full command b'\xa5\x80\x94\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc1\n' for command status
2021-06-27 23:01:35,697:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'status'
2021-06-27 23:01:35,697:DEBUG:abstractprotocol:get_command_defn@43: Found command status in protocol b'DALY'
2021-06-27 23:01:35,697:DEBUG:dalyserialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600

2021-06-27 23:01:35,703:DEBUG:dalyserialio:send_and_receive@22: Executing command via dalyserialio...
2021-06-27 23:01:35,803:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 0
2021-06-27 23:01:35,804:DEBUG:dalyserialio:send_and_receive@38: serial response was: b''

2021-06-27 23:01:35,806:DEBUG:device:run_command@315: Send and Receive Response b''
2021-06-27 23:01:35,806:INFO:abstractprotocol:decode@174: response passed to decode: b''
2021-06-27 23:01:35,806:INFO:abstractprotocol:decode@178: No response
2021-06-27 23:01:35,806:INFO:device:run_command@334: Decoded response {'ERROR': ['No response', '']}
2021-06-27 23:01:35,806:DEBUG:__init__:main@408: results: {'ERROR': ['No response', '']}
2021-06-27 23:01:35,807:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 23:01:35,807:DEBUG:mqtt:__init__@17: __init__: kwargs {}
2021-06-27 23:01:35,807:DEBUG:__init__:main@414: Using output filter: None
2021-06-27 23:01:35,807:INFO:mqtt:output@59: Using output processor: mqtt
2021-06-27 23:01:35,807:DEBUG:mqtt:output@60: kwargs {'data': {'ERROR': ['No response', '']}, 'tag': 'DALYtest', 'mqtt_broker': 'screen', 'mqtt_port': 1883, 'mqtt_user': None, 'mqtt_pass': None, 'mqtt_topic': 'mpp-solar', 'filter': None, 'excl_filter': None, 'keep_case': False}
2021-06-27 23:01:35,807:DEBUG:mqtt:output@90: No mqtt authentication used
2021-06-27 23:01:35,808:DEBUG:helpers:key_wanted@22: key_wanted: No filter and key error not excluded by excl_filter None so key wanted
2021-06-27 23:01:35,808:DEBUG:mqtt:build_msgs@47: build_msgs: tag DALYtest, key error, value No response, unit
2021-06-27 23:01:35,808:DEBUG:mqtt:build_msgs@55: build_msgs: [{'topic': 'DALYtest/status/error/value', 'payload': 'No response'}]
2021-06-27 23:01:35,808:DEBUG:mqtt:output@94: mqtt.output msgs [{'topic': 'DALYtest/status/error/value', 'payload': 'No response'}]
{'topic': 'DALYtest/status/error/value', 'payload': 'No response'}

2021-06-27 23:01:35,808:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5ea5970>, protocol: <mppsolar.protocols.daly.daly object at 0xb5e640b0> for command: cellMinMaxVoltages, tag: DALYtest, outputs: mqtt
2021-06-27 23:01:35,808:INFO:device:run_command@270: Running command cellMinMaxVoltages
2021-06-27 23:01:35,808:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 23:01:35,809:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'cellMinMaxVoltages'
2021-06-27 23:01:35,809:DEBUG:abstractprotocol:get_command_defn@43: Found command cellMinMaxVoltages in protocol b'DALY'
2021-06-27 23:01:35,809:DEBUG:daly:get_full_command@228: full command: b'\xa5\x80\x91\x08\x00\x00\x00\x00\x00\x00\x00\x00\xbe\n'
2021-06-27 23:01:35,809:INFO:device:run_command@296: full command b'\xa5\x80\x91\x08\x00\x00\x00\x00\x00\x00\x00\x00\xbe\n' for command cellMinMaxVoltages
2021-06-27 23:01:35,809:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'cellMinMaxVoltages'
2021-06-27 23:01:35,809:DEBUG:abstractprotocol:get_command_defn@43: Found command cellMinMaxVoltages in protocol b'DALY'
2021-06-27 23:01:35,809:DEBUG:dalyserialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600
2021-06-27 23:01:35,815:DEBUG:dalyserialio:send_and_receive@22: Executing command via dalyserialio...
2021-06-27 23:01:35,916:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,016:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,117:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 0
2021-06-27 23:01:36,118:DEBUG:dalyserialio:send_and_receive@38: serial response was: b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,121:DEBUG:device:run_command@315: Send and Receive Response b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,121:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,121:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,122:INFO:abstractprotocol:decode@178: DALY checksum did not match for response b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,122:INFO:device:run_command@334: Decoded response {'ERROR': ["DALY checksum did not match for response b'\\xa5\\x01\\x94\\x08\\x10\\x01\\x00\\x00\\x00\\x00\\x08\\xe0;\\xa5\\x01\\x91\\x08\\x0c\\xcf\\x0c\\x0c\\xc6\\x01\\x08\\xe0\\xe1'", '']}
2021-06-27 23:01:36,122:DEBUG:__init__:main@408: results: {'ERROR': ["DALY checksum did not match for response b'\\xa5\\x01\\x94\\x08\\x10\\x01\\x00\\x00\\x00\\x00\\x08\\xe0;\\xa5\\x01\\x91\\x08\\x0c\\xcf\\x0c\\x0c\\xc6\\x01\\x08\\xe0\\xe1'", '']}
2021-06-27 23:01:36,123:INFO:__init__:get_outputs@26: attempting to create output processor: mqtt
2021-06-27 23:01:36,123:DEBUG:mqtt:__init__@17: __init__: kwargs {}
2021-06-27 23:01:36,124:DEBUG:__init__:main@414: Using output filter: None
2021-06-27 23:01:36,124:INFO:mqtt:output@59: Using output processor: mqtt
2021-06-27 23:01:36,124:DEBUG:mqtt:output@60: kwargs {'data': {'ERROR': ["DALY checksum did not match for response b'\\xa5\\x01\\x94\\x08\\x10\\x01\\x00\\x00\\x00\\x00\\x08\\xe0;\\xa5\\x01\\x91\\x08\\x0c\\xcf\\x0c\\x0c\\xc6\\x01\\x08\\xe0\\xe1'", '']}, 'tag': 'DALYtest', 'mqtt_broker': 'screen', 'mqtt_port': 1883, 'mqtt_user': None, 'mqtt_pass': None, 'mqtt_topic': 'mpp-solar', 'filter': None, 'excl_filter': None, 'keep_case': False}
2021-06-27 23:01:36,124:DEBUG:mqtt:output@90: No mqtt authentication used
2021-06-27 23:01:36,125:DEBUG:helpers:key_wanted@22: key_wanted: No filter and key error not excluded by excl_filter None so key wanted
2021-06-27 23:01:36,125:DEBUG:mqtt:build_msgs@47: build_msgs: tag DALYtest, key error, value DALY checksum did not match for response b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1', unit
2021-06-27 23:01:36,125:DEBUG:mqtt:build_msgs@55: build_msgs: [{'topic': 'DALYtest/status/error/value', 'payload': "DALY checksum did not match for response b'\\xa5\\x01\\x94\\x08\\x10\\x01\\x00\\x00\\x00\\x00\\x08\\xe0;\\xa5\\x01\\x91\\x08\\x0c\\xcf\\x0c\\x0c\\xc6\\x01\\x08\\xe0\\xe1'"}]
2021-06-27 23:01:36,126:DEBUG:mqtt:output@94: mqtt.output msgs [{'topic': 'DALYtest/status/error/value', 'payload': "DALY checksum did not match for response b'\\xa5\\x01\\x94\\x08\\x10\\x01\\x00\\x00\\x00\\x00\\x08\\xe0;\\xa5\\x01\\x91\\x08\\x0c\\xcf\\x0c\\x0c\\xc6\\x01\\x08\\xe0\\xe1'"}]
{'topic': 'DALYtest/status/error/value', 'payload': "DALY checksum did not match for response b'\\xa5\\x01\\x94\\x08\\x10\\x01\\x00\\x00\\x00\\x00\\x08\\xe0;\\xa5\\x01\\x91\\x08\\x0c\\xcf\\x0c\\x0c\\xc6\\x01\\x08\\xe0\\xe1'"}
2021-06-27 23:01:36,126:INFO:__init__:main@405: Getting results from device: mppsolar device - name: DALY, port: <mppsolar.io.dalyserialio.DalySerialIO object at 0xb5ea5970>, protocol: <mppsolar.protocols.daly.daly object at 0xb5e640b0> for command: cellVoltages, tag: DALYtest, outputs: mqtt
2021-06-27 23:01:36,126:INFO:device:run_command@270: Running command cellVoltages
2021-06-27 23:01:36,127:INFO:daly:get_full_command@211: Using protocol b'DALY' with 7 commands
2021-06-27 23:01:36,127:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'cellVoltages'
2021-06-27 23:01:36,127:DEBUG:abstractprotocol:get_command_defn@43: Found command cellVoltages in protocol b'DALY'
2021-06-27 23:01:36,128:DEBUG:daly:get_full_command@228: full command: b'\xa5\x80\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc2\n'
2021-06-27 23:01:36,128:INFO:device:run_command@296: full command b'\xa5\x80\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\xc2\n' for command cellVoltages
2021-06-27 23:01:36,128:DEBUG:abstractprotocol:get_command_defn@41: Processing command 'cellVoltages'
2021-06-27 23:01:36,129:DEBUG:abstractprotocol:get_command_defn@43: Found command cellVoltages in protocol b'DALY'
2021-06-27 23:01:36,129:DEBUG:dalyserialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600
2021-06-27 23:01:36,136:DEBUG:dalyserialio:send_and_receive@22: Executing command via dalyserialio...
2021-06-27 23:01:36,237:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,337:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,438:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,539:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,640:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,740:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,841:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 0
2021-06-27 23:01:36,841:DEBUG:dalyserialio:send_and_receive@38: serial response was: b'\xa5\x01\x95\x08\x01\x0c\xc6\x0c\xcf\x0c\xcf\xe0\xac\xa5\x01\x95\x08\x02\x0c\xcf\x0c\xcf\x0c\xce\xe0\xb5\xa5\x01\x95\x08\x03\x0c\xcf\x0c\xce\x0c\xcd\xe0\xb4\xa5\x01\x95\x08\x04\x0c\xcd\x0c\xcb\x0c\xcf\xe0\xb2\xa5\x01\x95\x08\x05\x0c\xce\x0c\xcf\x0c\xce\xe0\xb7\xa5\x01\x95\x08\x06\x0c\xcb\x00\x00\x00\x00\xe0\x00'
2021-06-27 23:01:36,845:DEBUG:device:run_command@315: Send and Receive Response b'\xa5\x01\x95\x08\x01\x0c\xc6\x0c\xcf\x0c\xcf\xe0\xac\xa5\x01\x95\x08\x02\x0c\xcf\x0c\xcf\x0c\xce\xe0\xb5\xa5\x01\x95\x08\x03\x0c\xcf\x0c\xce\x0c\xcd\xe0\xb4\xa5\x01\x95\x08\x04\x0c\xcd\x0c\xcb\x0c\xcf\xe0\xb2\xa5\x01\x95\x08\x05\x0c\xce\x0c\xcf\x0c\xce\xe0\xb7\xa5\x01\x95\x08\x06\x0c\xcb\x00\x00\x00\x00\xe0\x00'
2021-06-27 23:01:36,845:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x95\x08\x01\x0c\xc6\x0c\xcf\x0c\xcf\xe0\xac\xa5\x01\x95\x08\x02\x0c\xcf\x0c\xcf\x0c\xce\xe0\xb5\xa5\x01\x95\x08\x03\x0c\xcf\x0c\xce\x0c\xcd\xe0\xb4\xa5\x01\x95\x08\x04\x0c\xcd\x0c\xcb\x0c\xcf\xe0\xb2\xa5\x01\x95\x08\x05\x0c\xce\x0c\xcf\x0c\xce\xe0\xb7\xa5\x01\x95\x08\x06\x0c\xcb\x00\x00\x00\x00\xe0\x00'
2021-06-27 23:01:36,846:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x95\x08\x01\x0c\xc6\x0c\xcf\x0c\xcf\xe0\xac\xa5\x01\x95\x08\x02\x0c\xcf\x0c\xcf\x0c\xce\xe0\xb5\xa5\x01\x95\x08\x03\x0c\xcf\x0c\xce\x0c\xcd\xe0\xb4\xa5\x01\x95\x08\x04\x0c\xcd\x0c\xcb\x0c\xcf\xe0\xb2\xa5\x01\x95\x08\x05\x0c\xce\x0c\xcf\x0c\xce\xe0\xb7\xa5\x01\x95\x08\x06\x0c\xcb\x00\x00\x00\x00\xe0\x00'
2021-06-27 23:01:36,846:INFO:daly:check_response_valid@251: is multiframe response - assuming ok for now
[...snip...]
jblance commented 3 years ago

OK, so getting somewhere, First, this one got nothing back (for command status 0x94)

2021-06-27 23:01:35,703:DEBUG:dalyserialio:send_and_receive@22: Executing command via dalyserialio...
2021-06-27 23:01:35,803:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 0
2021-06-27 23:01:35,804:DEBUG:dalyserialio:send_and_receive@38: serial response was: b''

Then later we get 2x 13 bytes but fail the checksum, coz we also got a response for command 0x94....

2021-06-27 23:01:35,809:DEBUG:abstractprotocol:get_command_defn@43: Found command cellMinMaxVoltages in protocol b'DALY'
2021-06-27 23:01:35,809:DEBUG:dalyserialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600
2021-06-27 23:01:35,815:DEBUG:dalyserialio:send_and_receive@22: Executing command via dalyserialio...
2021-06-27 23:01:35,916:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,016:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 13
2021-06-27 23:01:36,117:DEBUG:dalyserialio:send_and_receive@32: bytes waiting 0
2021-06-27 23:01:36,118:DEBUG:dalyserialio:send_and_receive@38: serial response was: b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,121:DEBUG:device:run_command@315: Send and Receive Response b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,121:INFO:abstractprotocol:decode@174: response passed to decode: b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,121:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'
2021-06-27 23:01:36,122:INFO:abstractprotocol:decode@178: DALY checksum did not match for response b'\xa5\x01\x94\x08\x10\x01\x00\x00\x00\x00\x08\xe0;\xa5\x01\x91\x08\x0c\xcf\x0c\x0c\xc6\x01\x08\xe0\xe1'

The code waits 0.1 seconds for a response, it looms like this is too short - let me extend it to 0.25 and see if that sorts the problem (though this will slow the code a bit)

jblance commented 3 years ago

try v0.7.70 (also I have 2 DALYs and some LiFePO4 cells on order so will have something to test with soon :-)

firemen027 commented 3 years ago

The code waits 0.1 seconds for a response, it looms like this is too short - let me extend it to 0.25 and see if that sorts the problem (though this will slow the code a bit)

Maybe I have a part of explication: last week I replace my generic SDCARD for a samsung EVO , mixing that with the error mosStatus from the update: 2 differents problems one from the code and one from the speed of the hardware.

Presently: eveything run smooth here no more error since v0.7.70. So Solve for me.

Mr Blance you're a great one. Next step for me: plugging and testing JK balancer on my setup.

Thank you again

jblance commented 3 years ago

ok good news