jblance / mpp-solar

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

New DALY 8S 200A BMS does not work with MPP-Solar #162

Closed cyborgxxl closed 1 year ago

cyborgxxl commented 3 years ago

I have two DALY 8S 200A BMS. An older one and a brand new one. The old one works good with mpp-solar, the new one doesn't. It seems that some parameters have changed?

Output from old one:

sudo mpp-solar -p /dev/ttyUSB0 -b 9600 -P DALY40 -c SOC,cellVoltages,cellTemperatures

MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
Command: SOC - State of Charge
------------------------------------------------------------
Parameter                       Value           Unit
battery_bank_voltage            26.1            V
acquistion                      0.0             V
current                         5.5             A
soc                             35.0            %
Command: cellVoltages - Cell Voltages Information
------------------------------------------------------------
Parameter                       Value           Unit
cell_01_voltage                 3.264           V
cell_02_voltage                 3.273           V
cell_03_voltage                 3.272           V
cell_04_voltage                 3.273           V
cell_05_voltage                 3.272           V
cell_06_voltage                 3.273           V
cell_07_voltage                 3.273           V
cell_08_voltage                 3.27            V
cell_09_voltage                 3.273           V
Command: cellTemperatures - Cell Temperature Information
------------------------------------------------------------
Parameter                       Value           Unit
cell_01_temperature             17              °C
cell_02_temperature             -40             °C
cell_03_temperature             -40             °C
cell_04_temperature             -40             °C
cell_05_temperature             -40             °C
cell_06_temperature             -40             °C
cell_07_temperature             -40             °C
cell_08_temperature             -40             °C
cell_09_temperature             -40             °C
cell_10_temperature             -40             °C
cell_11_temperature             -40             °C
cell_12_temperature             -40             °C
cell_13_temperature             -40             °C
cell_14_temperature             -40             °C

Output from new one:

sudo mpp-solar -p /dev/ttyUSB1 -b 9600 -P DALY40  -c SOC,cellVoltages,cellTemperatures

MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
Command: SOC - State of Charge
------------------------------------------------------------
Parameter                       Value           Unit
battery_bank_voltage            27.0            V
acquistion                      0.0             V
current                         -1.6            A
soc                             100.0           %
Parameter                       Value           Unit
error                           DALY checksum did not match for response b'\xa5\x01\x95\x08\x01\r'
Parameter                       Value           Unit
error                           DALY checksum did not match for response b'\xa5\x01\x96\x08\x0176\r'

Any ideas how to fix that?

After I asked DALY whether anything has changed in the protocols, I received a sheet with the updated Communications Protocols (v1.2):

Daly UART_485 Communications Protocol V1.2.pdf

jblance commented 3 years ago

can you run just the cellVoltages command with the debug flag added -D

cyborgxxl commented 3 years ago

DALY checksum did not match for response...

mpp-solar -p /dev/ttyUSB1 -b 9600 -P DALY40 -c cellVoltages -D

2021-10-07 08:06:54,493:INFO:__init__:main@195: Solar Device Command Utility, version: 0.7.82, add missing libs
MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
2021-10-07 08:06:54,493:INFO:__init__:main@299: Creating device "unnamed" (type: "mppsolar") on port "/dev/ttyUSB1 (porttype=None)" using protocol "DALY40"
2021-10-07 08:06:54,497:DEBUG:__init__:main@302: device_class <class 'mppsolar.devices.mppsolar.mppsolar'>
2021-10-07 08:06:54,497:DEBUG:device:__init__@31: __init__ args ()
2021-10-07 08:06:54,497:DEBUG:device:__init__@32: __init__ kwargs {'name': 'unnamed', 'port': '/dev/ttyUSB1', 'protocol': 'DALY40', 'baud': 9600, 'porttype': None, 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')}
2021-10-07 08:06:54,498:DEBUG:device:get_port_type@86: port matches ttyusb
2021-10-07 08:06:54,498:INFO:device:set_port@160: Using serialio for communications
2021-10-07 08:06:54,509:DEBUG:device:set_protocol@96: Protocol DALY40
2021-10-07 08:06:54,515:DEBUG:device:__init__@36: __init__ name unnamed, port <mppsolar.io.serialio.SerialIO object at 0x75ef0db0>, protocol <mppsolar.protocols.daly40.daly40 object at 0x75ef0f90>
2021-10-07 08:06:54,515:DEBUG:__init__:main@349: Commands [(<mppsolar.devices.mppsolar.mppsolar object at 0x75ef0d30>, 'cellVoltages', 'cellVoltages', 'screen', None, None)]
2021-10-07 08:06:54,516:INFO:__init__:main@354: Looping 1 commands
2021-10-07 08:06:54,516:INFO:__init__:main@365: Getting results from device: mppsolar device - name: unnamed, port: <mppsolar.io.serialio.SerialIO object at 0x75ef0db0>, protocol: <mppsolar.protocols.daly40.daly40 object at 0x75ef0f90> for command: cellVoltages, tag: cellVoltages, outputs: screen
2021-10-07 08:06:54,516:INFO:device:run_command@268: Running command cellVoltages
2021-10-07 08:06:54,516:INFO:daly:get_full_command@211: Using protocol b'DALY40' with 7 commands
2021-10-07 08:06:54,517:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'cellVoltages'
2021-10-07 08:06:54,517:DEBUG:abstractprotocol:get_command_defn@45: Found command cellVoltages in protocol b'DALY40'
2021-10-07 08:06:54,517:DEBUG:daly:get_full_command@228: full command: b'\xa5@\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\x82\n'
2021-10-07 08:06:54,518:INFO:device:run_command@294: full command b'\xa5@\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\x82\n' for command cellVoltages
2021-10-07 08:06:54,518:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'cellVoltages'
2021-10-07 08:06:54,518:DEBUG:abstractprotocol:get_command_defn@45: Found command cellVoltages in protocol b'DALY40'
2021-10-07 08:06:54,518:DEBUG:serialio:send_and_receive@19: port /dev/ttyUSB1, baudrate 9600
2021-10-07 08:06:54,520:DEBUG:serialio:send_and_receive@22: Executing command via serialio...
2021-10-07 08:06:54,621:DEBUG:serialio:send_and_receive@30: serial response was: b'j\r'
2021-10-07 08:06:54,622:DEBUG:device:run_command@313: Send and Receive Response b'j\r'
2021-10-07 08:06:54,623:INFO:abstractprotocol:decode@179: response passed to decode: b'j\r'
2021-10-07 08:06:54,623:DEBUG:daly:check_response_valid@247: checking validity of b'j\r'
2021-10-07 08:06:54,623:INFO:abstractprotocol:decode@183: DALY checksum did not match for response b'j\r'
2021-10-07 08:06:54,623:INFO:device:run_command@332: Decoded response {'ERROR': ["DALY checksum did not match for response b'j\\r'", '']}
2021-10-07 08:06:54,624:DEBUG:__init__:main@368: results: {'ERROR': ["DALY checksum did not match for response b'j\\r'", '']}
2021-10-07 08:06:54,624:INFO:helpers:get_outputs@64: attempting to create output processor: screen
2021-10-07 08:06:54,627:DEBUG:screen:__init__@16: processor.screen __init__ kwargs {}
2021-10-07 08:06:54,627:DEBUG:__init__:main@374: Using output filter: None
2021-10-07 08:06:54,627:INFO:screen:output@19: Using output processor: screen
2021-10-07 08:06:54,628:DEBUG:screen:output@20: kwargs {'data': {'ERROR': ["DALY checksum did not match for response b'j\\r'", '']}, 'tag': 'cellVoltages', 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar'), 'filter': None, 'excl_filter': None, 'keep_case': False}
Parameter                       Value           Unit
error                           DALY checksum did not match for response b'j\r'
2021-10-07 08:06:54,628:DEBUG:__init__:main@394: Not daemon, so not looping

But this works:

mpp-solar -p /dev/ttyUSB1 -b 9600 -P DALY40 -c SOC -D

2021-10-07 08:10:11,746:INFO:__init__:main@195: Solar Device Command Utility, version: 0.7.82, add missing libs
MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
2021-10-07 08:10:11,746:INFO:__init__:main@299: Creating device "unnamed" (type: "mppsolar") on port "/dev/ttyUSB1 (porttype=None)" using protocol "DALY40"
2021-10-07 08:10:11,749:DEBUG:__init__:main@302: device_class <class 'mppsolar.devices.mppsolar.mppsolar'>
2021-10-07 08:10:11,750:DEBUG:device:__init__@31: __init__ args ()
2021-10-07 08:10:11,750:DEBUG:device:__init__@32: __init__ kwargs {'name': 'unnamed', 'port': '/dev/ttyUSB1', 'protocol': 'DALY40', 'baud': 9600, 'porttype': None, 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')}
2021-10-07 08:10:11,751:DEBUG:device:get_port_type@86: port matches ttyusb
2021-10-07 08:10:11,751:INFO:device:set_port@160: Using serialio for communications
2021-10-07 08:10:11,762:DEBUG:device:set_protocol@96: Protocol DALY40
2021-10-07 08:10:11,768:DEBUG:device:__init__@36: __init__ name unnamed, port <mppsolar.io.serialio.SerialIO object at 0x75e9eeb0>, protocol <mppsolar.protocols.daly40.daly40 object at 0x75e9eef0>
2021-10-07 08:10:11,768:DEBUG:__init__:main@349: Commands [(<mppsolar.devices.mppsolar.mppsolar object at 0x75e9ee30>, 'SOC', 'SOC', 'screen', None, None)]
2021-10-07 08:10:11,768:INFO:__init__:main@354: Looping 1 commands
2021-10-07 08:10:11,769:INFO:__init__:main@365: Getting results from device: mppsolar device - name: unnamed, port: <mppsolar.io.serialio.SerialIO object at 0x75e9eeb0>, protocol: <mppsolar.protocols.daly40.daly40 object at 0x75e9eef0> for command: SOC, tag: SOC, outputs: screen
2021-10-07 08:10:11,769:INFO:device:run_command@268: Running command SOC
2021-10-07 08:10:11,769:INFO:daly:get_full_command@211: Using protocol b'DALY40' with 7 commands
2021-10-07 08:10:11,770:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'SOC'
2021-10-07 08:10:11,770:DEBUG:abstractprotocol:get_command_defn@45: Found command SOC in protocol b'DALY40'
2021-10-07 08:10:11,770:DEBUG:daly:get_full_command@228: full command: b'\xa5@\x90\x08\x00\x00\x00\x00\x00\x00\x00\x00}\n'
2021-10-07 08:10:11,770:INFO:device:run_command@294: full command b'\xa5@\x90\x08\x00\x00\x00\x00\x00\x00\x00\x00}\n' for command SOC
2021-10-07 08:10:11,771:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'SOC'
2021-10-07 08:10:11,771:DEBUG:abstractprotocol:get_command_defn@45: Found command SOC in protocol b'DALY40'
2021-10-07 08:10:11,771:DEBUG:serialio:send_and_receive@19: port /dev/ttyUSB1, baudrate 9600
2021-10-07 08:10:11,774:DEBUG:serialio:send_and_receive@22: Executing command via serialio...
2021-10-07 08:10:12,877:DEBUG:serialio:send_and_receive@30: serial response was: b'\xa5\x01\x90\x08\x01\x12\x00\x00u0\x03\xe8\xe1'
2021-10-07 08:10:12,879:DEBUG:device:run_command@313: Send and Receive Response b'\xa5\x01\x90\x08\x01\x12\x00\x00u0\x03\xe8\xe1'
2021-10-07 08:10:12,879:INFO:abstractprotocol:decode@179: response passed to decode: b'\xa5\x01\x90\x08\x01\x12\x00\x00u0\x03\xe8\xe1'
2021-10-07 08:10:12,880:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x90\x08\x01\x12\x00\x00u0\x03\xe8\xe1'
2021-10-07 08:10:12,880:DEBUG:daly:check_response_valid@260: DALY Checksum matches response 'b'\xa5\x01\x90\x08\x01\x12\x00\x00u0\x03\xe8\xe1'' checksum:225
2021-10-07 08:10:12,881:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'SOC'
2021-10-07 08:10:12,881:DEBUG:abstractprotocol:get_command_defn@45: Found command SOC in protocol b'DALY40'
2021-10-07 08:10:12,882:INFO:abstractprotocol:decode@219: Processing response of type POSITIONAL
2021-10-07 08:10:12,882:DEBUG:abstractprotocol:decode@223: trimmed and split responses: [b'\xa5', b'\x01', b'\x90', b'\x08', b'\x01\x12', b'\x00\x00', b'u0', b'\x03\xe8', b'\xe1']
2021-10-07 08:10:12,883:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,883:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'start flag', '']
2021-10-07 08:10:12,884:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: start flag, raw_value b'\xa5'
2021-10-07 08:10:12,884:DEBUG:abstractprotocol:process_response@94: Discarding start flag:b'\xa5'
2021-10-07 08:10:12,884:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,885:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'module address', '']
2021-10-07 08:10:12,885:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: module address, raw_value b'\x01'
2021-10-07 08:10:12,886:DEBUG:abstractprotocol:process_response@94: Discarding module address:b'\x01'
2021-10-07 08:10:12,886:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,887:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'command id', '']
2021-10-07 08:10:12,887:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: command id, raw_value b'\x90'
2021-10-07 08:10:12,887:DEBUG:abstractprotocol:process_response@94: Discarding command id:b'\x90'
2021-10-07 08:10:12,888:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,888:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'data length', '']
2021-10-07 08:10:12,889:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: data length, raw_value b'\x08'
2021-10-07 08:10:12,889:DEBUG:abstractprotocol:process_response@94: Discarding data length:b'\x08'
2021-10-07 08:10:12,890:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,890:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/10', 2, 'Battery Bank Voltage', 'V']
2021-10-07 08:10:12,891:DEBUG:abstractprotocol:process_response@85: Got template r/10 for Battery Bank Voltage b'\x01\x12'
2021-10-07 08:10:12,891:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: Battery Bank Voltage, raw_value b'\x01\x12'
2021-10-07 08:10:12,891:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-07 08:10:12,892:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x01\x12' 2 byte decoded to 274
2021-10-07 08:10:12,893:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,893:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/10', 2, 'acquistion', 'V']
2021-10-07 08:10:12,894:DEBUG:abstractprotocol:process_response@85: Got template r/10 for acquistion b'\x00\x00'
2021-10-07 08:10:12,894:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: acquistion, raw_value b'\x00\x00'
2021-10-07 08:10:12,894:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-07 08:10:12,895:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x00\x00' 2 byte decoded to 0
2021-10-07 08:10:12,896:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,896:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:(r-30000)/10', 2, 'Current', 'A']
2021-10-07 08:10:12,897:DEBUG:abstractprotocol:process_response@85: Got template (r-30000)/10 for Current b'u0'
2021-10-07 08:10:12,897:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: Current, raw_value b'u0'
2021-10-07 08:10:12,898:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-07 08:10:12,898:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'u0' 2 byte decoded to 30000
2021-10-07 08:10:12,899:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,899:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/10', 2, 'SOC', '%']
2021-10-07 08:10:12,900:DEBUG:abstractprotocol:process_response@85: Got template r/10 for SOC b'\x03\xe8'
2021-10-07 08:10:12,900:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: SOC, raw_value b'\x03\xe8'
2021-10-07 08:10:12,901:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-07 08:10:12,901:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x03\xe8' 2 byte decoded to 1000
2021-10-07 08:10:12,902:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-07 08:10:12,903:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'checksum', '']
2021-10-07 08:10:12,903:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: checksum, raw_value b'\xe1'
2021-10-07 08:10:12,903:DEBUG:abstractprotocol:process_response@94: Discarding checksum:b'\xe1'
2021-10-07 08:10:12,904:INFO:device:run_command@332: Decoded response {'raw_response': ['¥\x01\x90\x08\x01\x12\x00\x00u0\x03èá', ''], '_command': 'SOC', '_command_description': 'State of Charge', 'Battery Bank Voltage': [27.4, 'V'], 'acquistion': [0.0, 'V'], 'Current': [0.0, 'A'], 'SOC': [100.0, '%']}
2021-10-07 08:10:12,905:DEBUG:__init__:main@368: results: {'raw_response': ['¥\x01\x90\x08\x01\x12\x00\x00u0\x03èá', ''], '_command': 'SOC', '_command_description': 'State of Charge', 'Battery Bank Voltage': [27.4, 'V'], 'acquistion': [0.0, 'V'], 'Current': [0.0, 'A'], 'SOC': [100.0, '%']}
2021-10-07 08:10:12,905:INFO:helpers:get_outputs@64: attempting to create output processor: screen
2021-10-07 08:10:12,911:DEBUG:screen:__init__@16: processor.screen __init__ kwargs {}
2021-10-07 08:10:12,911:DEBUG:__init__:main@374: Using output filter: None
2021-10-07 08:10:12,912:INFO:screen:output@19: Using output processor: screen
2021-10-07 08:10:12,912:DEBUG:screen:output@20: kwargs {'data': {'raw_response': ['¥\x01\x90\x08\x01\x12\x00\x00u0\x03èá', ''], '_command': 'SOC', '_command_description': 'State of Charge', 'Battery Bank Voltage': [27.4, 'V'], 'acquistion': [0.0, 'V'], 'Current': [0.0, 'A'], 'SOC': [100.0, '%']}, 'tag': 'SOC', 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar'), 'filter': None, 'excl_filter': None, 'keep_case': False}
Command: SOC - State of Charge
------------------------------------------------------------
Parameter                       Value           Unit
battery_bank_voltage            27.4            V
acquistion                      0.0             V
current                         0.0             A
soc                             100.0           %
2021-10-07 08:10:12,913:DEBUG:__init__:main@394: Not daemon, so not looping
cyborgxxl commented 3 years ago

A small update... I tested daly-bms-cli with my new BMS and it looks like reading out the values ​​works here.

daly-bms-cli  -d /dev/ttyUSB0 --cell-voltages
{
  "1": 3.568,
  "2": 3.57,
  "3": 3.569,
  "4": 3.57,
  "5": 3.57,
  "6": 3.57,
  "7": 3.568,
  "8": 3.57
}

or

daly-bms-cli  -d /dev/ttyUSB0 --soc
{
  "total_voltage": 28.5,
  "current": 0.0,
  "soc_percent": 100.0
}

It would be great if you could update the query in your project jblance .

jblance commented 3 years ago

Thought usb1 was the one that didn't work?

On Fri, 15 Oct 2021, 7:12 am cyborgxxl, @.***> wrote:

A small update... I tested daly-bms-cli with my new BMS and it looks like reading out the values ​​works here.

daly-bms-cli -d /dev/ttyUSB0 --cell-voltages

{

"1": 3.568,

"2": 3.57,

"3": 3.569,

"4": 3.57,

"5": 3.57,

"6": 3.57,

"7": 3.568,

"8": 3.57

}

or

daly-bms-cli -d /dev/ttyUSB0 --soc

{

"total_voltage": 28.5,

"current": 0.0,

"soc_percent": 100.0

}

It would be great if you could update the query in your project jblance .

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/jblance/mpp-solar/issues/162#issuecomment-943600772, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAJVKNSD7UIQ6Y7EIUWQJPTUG4MQDANCNFSM5FLAMJDQ .

cyborgxxl commented 3 years ago

In the meantime, I changed and mixed around the USB ports as a test. /dev/ttyUSB1 is now /dev/ttyUSB0. Sorry for the confusion. ;-)

/dev/ttyUSB0 is the new DALY BMS /dev/ttyUSB1 is the older DALY BMS

mpp-solar -p /dev/ttyUSB0 -b 9600 -P DALY40 -c cellVoltages -D

2021-10-15 10:02:43,346:INFO:__init__:main@195: Solar Device Command Utility, version: 0.7.82, add missing libs
MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
2021-10-15 10:02:43,347:INFO:__init__:main@299: Creating device "unnamed" (type: "mppsolar") on port "/dev/ttyUSB0 (porttype=None)" using protocol "DALY40"
2021-10-15 10:02:43,350:DEBUG:__init__:main@302: device_class <class 'mppsolar.devices.mppsolar.mppsolar'>
2021-10-15 10:02:43,350:DEBUG:device:__init__@31: __init__ args ()
2021-10-15 10:02:43,351:DEBUG:device:__init__@32: __init__ kwargs {'name': 'unnamed', 'port': '/dev/ttyUSB0', 'protocol': 'DALY40', 'baud': 9600, 'porttype': None, 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')}
2021-10-15 10:02:43,351:DEBUG:device:get_port_type@86: port matches ttyusb
2021-10-15 10:02:43,351:INFO:device:set_port@160: Using serialio for communications
2021-10-15 10:02:43,362:DEBUG:device:set_protocol@96: Protocol DALY40
2021-10-15 10:02:43,368:DEBUG:device:__init__@36: __init__ name unnamed, port <mppsolar.io.serialio.SerialIO object at 0x75eb78f0>, protocol <mppsolar.protocols.daly40.daly40 object at 0x75eb7530>
2021-10-15 10:02:43,368:DEBUG:__init__:main@349: Commands [(<mppsolar.devices.mppsolar.mppsolar object at 0x75eb7990>, 'cellVoltages', 'cellVoltages', 'screen', None, None)]
2021-10-15 10:02:43,368:INFO:__init__:main@354: Looping 1 commands
2021-10-15 10:02:43,369:INFO:__init__:main@365: Getting results from device: mppsolar device - name: unnamed, port: <mppsolar.io.serialio.SerialIO object at 0x75eb78f0>, protocol: <mppsolar.protocols.daly40.daly40 object at 0x75eb7530> for command: cellVoltages, tag: cellVoltages, outputs: screen
2021-10-15 10:02:43,369:INFO:device:run_command@268: Running command cellVoltages
2021-10-15 10:02:43,369:INFO:daly:get_full_command@211: Using protocol b'DALY40' with 7 commands
2021-10-15 10:02:43,369:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'cellVoltages'
2021-10-15 10:02:43,370:DEBUG:abstractprotocol:get_command_defn@45: Found command cellVoltages in protocol b'DALY40'
2021-10-15 10:02:43,370:DEBUG:daly:get_full_command@228: full command: b'\xa5@\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\x82\n'
2021-10-15 10:02:43,370:INFO:device:run_command@294: full command b'\xa5@\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\x82\n' for command cellVoltages
2021-10-15 10:02:43,371:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'cellVoltages'
2021-10-15 10:02:43,371:DEBUG:abstractprotocol:get_command_defn@45: Found command cellVoltages in protocol b'DALY40'
2021-10-15 10:02:43,371:DEBUG:serialio:send_and_receive@19: port /dev/ttyUSB0, baudrate 9600
2021-10-15 10:02:43,374:DEBUG:serialio:send_and_receive@22: Executing command via serialio...
2021-10-15 10:02:44,478:DEBUG:serialio:send_and_receive@30: serial response was: b'\xa5\x01\x95\x08\x01\x0c\xed\x0c\xeb\x0c\xedX\x85\xa5\x01\x95\x08\x02\x0c\xed\x0c\xed\x0c\xebX\x86\xa5\x01\x95\x08\x03\x0c\xeb\x0c\xed\x0c\xebX\x85'
2021-10-15 10:02:44,480:DEBUG:device:run_command@313: Send and Receive Response b'\xa5\x01\x95\x08\x01\x0c\xed\x0c\xeb\x0c\xedX\x85\xa5\x01\x95\x08\x02\x0c\xed\x0c\xed\x0c\xebX\x86\xa5\x01\x95\x08\x03\x0c\xeb\x0c\xed\x0c\xebX\x85'
2021-10-15 10:02:44,481:INFO:abstractprotocol:decode@179: response passed to decode: b'\xa5\x01\x95\x08\x01\x0c\xed\x0c\xeb\x0c\xedX\x85\xa5\x01\x95\x08\x02\x0c\xed\x0c\xed\x0c\xebX\x86\xa5\x01\x95\x08\x03\x0c\xeb\x0c\xed\x0c\xebX\x85'
2021-10-15 10:02:44,482:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x95\x08\x01\x0c\xed\x0c\xeb\x0c\xedX\x85\xa5\x01\x95\x08\x02\x0c\xed\x0c\xed\x0c\xebX\x86\xa5\x01\x95\x08\x03\x0c\xeb\x0c\xed\x0c\xebX\x85'
2021-10-15 10:02:44,482:INFO:daly:check_response_valid@251: is multiframe response - assuming ok for now
2021-10-15 10:02:44,483:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'cellVoltages'
2021-10-15 10:02:44,484:DEBUG:abstractprotocol:get_command_defn@45: Found command cellVoltages in protocol b'DALY40'
2021-10-15 10:02:44,484:INFO:abstractprotocol:decode@219: Processing response of type MULTIFRAME-POSITIONAL
2021-10-15 10:02:44,485:INFO:daly:get_responses@282: Multi frame response with 3 frames
2021-10-15 10:02:44,485:DEBUG:abstractprotocol:decode@223: trimmed and split responses: [[b'\xa5', b'\x01', b'\x95', b'\x08', b'\x01', b'\x0c\xed', b'\x0c\xeb', b'\x0c\xed', b'X', b'\x85'], [b'\xa5', b'\x01', b'\x95', b'\x08', b'\x02', b'\x0c\xed', b'\x0c\xed', b'\x0c\xeb', b'X', b'\x86'], [b'\xa5', b'\x01', b'\x95', b'\x08', b'\x03', b'\x0c\xeb', b'\x0c\xed', b'\x0c\xeb', b'X', b'\x85']]
2021-10-15 10:02:44,486:DEBUG:abstractprotocol:decode@336: Processing MULTIFRAME-POSITIONAL type responses
2021-10-15 10:02:44,486:DEBUG:abstractprotocol:decode@340: got 3 frames
2021-10-15 10:02:44,487:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,488:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'start flag', '']
2021-10-15 10:02:44,488:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: start flag, raw_value b'\xa5'
2021-10-15 10:02:44,489:DEBUG:abstractprotocol:process_response@94: Discarding start flag:b'\xa5'
2021-10-15 10:02:44,489:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,490:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'module address', '']
2021-10-15 10:02:44,490:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: module address, raw_value b'\x01'
2021-10-15 10:02:44,491:DEBUG:abstractprotocol:process_response@94: Discarding module address:b'\x01'
2021-10-15 10:02:44,491:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,492:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'command id', '']
2021-10-15 10:02:44,492:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: command id, raw_value b'\x95'
2021-10-15 10:02:44,493:DEBUG:abstractprotocol:process_response@94: Discarding command id:b'\x95'
2021-10-15 10:02:44,493:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,494:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'data length', '']
2021-10-15 10:02:44,494:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: data length, raw_value b'\x08'
2021-10-15 10:02:44,495:DEBUG:abstractprotocol:process_response@94: Discarding data length:b'\x08'
2021-10-15 10:02:44,495:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,496:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, "f'Frame Number {f:02d}'", '']
2021-10-15 10:02:44,496:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: f'Frame Number {f:02d}', raw_value b'\x01'
2021-10-15 10:02:44,497:DEBUG:abstractprotocol:process_response@94: Discarding f'Frame Number {f:02d}':b'\x01'
2021-10-15 10:02:44,497:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,498:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+1:02d} Voltage'", 'V']
2021-10-15 10:02:44,498:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+1:02d} Voltage' b'\x0c\xed'
2021-10-15 10:02:44,499:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+1:02d} Voltage', raw_value b'\x0c\xed'
2021-10-15 10:02:44,499:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,500:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xed' 2 byte decoded to 3309
2021-10-15 10:02:44,501:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,502:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+2:02d} Voltage'", 'V']
2021-10-15 10:02:44,503:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+2:02d} Voltage' b'\x0c\xeb'
2021-10-15 10:02:44,503:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+2:02d} Voltage', raw_value b'\x0c\xeb'
2021-10-15 10:02:44,504:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,504:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xeb' 2 byte decoded to 3307
2021-10-15 10:02:44,505:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,506:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+3:02d} Voltage'", 'V']
2021-10-15 10:02:44,507:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+3:02d} Voltage' b'\x0c\xed'
2021-10-15 10:02:44,507:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+3:02d} Voltage', raw_value b'\x0c\xed'
2021-10-15 10:02:44,508:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,509:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xed' 2 byte decoded to 3309
2021-10-15 10:02:44,510:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,510:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'Reserved', '']
2021-10-15 10:02:44,511:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: Reserved, raw_value b'X'
2021-10-15 10:02:44,511:DEBUG:abstractprotocol:process_response@94: Discarding Reserved:b'X'
2021-10-15 10:02:44,512:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,512:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'checksum', '']
2021-10-15 10:02:44,513:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: checksum, raw_value b'\x85'
2021-10-15 10:02:44,513:DEBUG:abstractprotocol:process_response@94: Discarding checksum:b'\x85'
2021-10-15 10:02:44,514:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,514:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'start flag', '']
2021-10-15 10:02:44,515:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: start flag, raw_value b'\xa5'
2021-10-15 10:02:44,515:DEBUG:abstractprotocol:process_response@94: Discarding start flag:b'\xa5'
2021-10-15 10:02:44,516:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,516:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'module address', '']
2021-10-15 10:02:44,517:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: module address, raw_value b'\x01'
2021-10-15 10:02:44,517:DEBUG:abstractprotocol:process_response@94: Discarding module address:b'\x01'
2021-10-15 10:02:44,518:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,519:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'command id', '']
2021-10-15 10:02:44,519:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: command id, raw_value b'\x95'
2021-10-15 10:02:44,520:DEBUG:abstractprotocol:process_response@94: Discarding command id:b'\x95'
2021-10-15 10:02:44,520:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,521:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'data length', '']
2021-10-15 10:02:44,521:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: data length, raw_value b'\x08'
2021-10-15 10:02:44,522:DEBUG:abstractprotocol:process_response@94: Discarding data length:b'\x08'
2021-10-15 10:02:44,522:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,523:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, "f'Frame Number {f:02d}'", '']
2021-10-15 10:02:44,523:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: f'Frame Number {f:02d}', raw_value b'\x02'
2021-10-15 10:02:44,524:DEBUG:abstractprotocol:process_response@94: Discarding f'Frame Number {f:02d}':b'\x02'
2021-10-15 10:02:44,524:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,525:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+1:02d} Voltage'", 'V']
2021-10-15 10:02:44,525:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+1:02d} Voltage' b'\x0c\xed'
2021-10-15 10:02:44,526:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+1:02d} Voltage', raw_value b'\x0c\xed'
2021-10-15 10:02:44,526:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,527:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xed' 2 byte decoded to 3309
2021-10-15 10:02:44,528:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,529:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+2:02d} Voltage'", 'V']
2021-10-15 10:02:44,529:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+2:02d} Voltage' b'\x0c\xed'
2021-10-15 10:02:44,530:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+2:02d} Voltage', raw_value b'\x0c\xed'
2021-10-15 10:02:44,530:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,531:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xed' 2 byte decoded to 3309
2021-10-15 10:02:44,532:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,533:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+3:02d} Voltage'", 'V']
2021-10-15 10:02:44,533:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+3:02d} Voltage' b'\x0c\xeb'
2021-10-15 10:02:44,534:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+3:02d} Voltage', raw_value b'\x0c\xeb'
2021-10-15 10:02:44,534:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,535:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xeb' 2 byte decoded to 3307
2021-10-15 10:02:44,536:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,537:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'Reserved', '']
2021-10-15 10:02:44,537:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: Reserved, raw_value b'X'
2021-10-15 10:02:44,538:DEBUG:abstractprotocol:process_response@94: Discarding Reserved:b'X'
2021-10-15 10:02:44,538:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,539:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'checksum', '']
2021-10-15 10:02:44,539:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: checksum, raw_value b'\x86'
2021-10-15 10:02:44,540:DEBUG:abstractprotocol:process_response@94: Discarding checksum:b'\x86'
2021-10-15 10:02:44,540:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,541:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'start flag', '']
2021-10-15 10:02:44,541:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: start flag, raw_value b'\xa5'
2021-10-15 10:02:44,542:DEBUG:abstractprotocol:process_response@94: Discarding start flag:b'\xa5'
2021-10-15 10:02:44,542:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,542:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'module address', '']
2021-10-15 10:02:44,543:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: module address, raw_value b'\x01'
2021-10-15 10:02:44,543:DEBUG:abstractprotocol:process_response@94: Discarding module address:b'\x01'
2021-10-15 10:02:44,543:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,543:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'command id', '']
2021-10-15 10:02:44,543:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: command id, raw_value b'\x95'
2021-10-15 10:02:44,544:DEBUG:abstractprotocol:process_response@94: Discarding command id:b'\x95'
2021-10-15 10:02:44,544:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,544:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'data length', '']
2021-10-15 10:02:44,544:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: data length, raw_value b'\x08'
2021-10-15 10:02:44,545:DEBUG:abstractprotocol:process_response@94: Discarding data length:b'\x08'
2021-10-15 10:02:44,545:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,545:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, "f'Frame Number {f:02d}'", '']
2021-10-15 10:02:44,545:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: f'Frame Number {f:02d}', raw_value b'\x03'
2021-10-15 10:02:44,546:DEBUG:abstractprotocol:process_response@94: Discarding f'Frame Number {f:02d}':b'\x03'
2021-10-15 10:02:44,546:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,546:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+1:02d} Voltage'", 'V']
2021-10-15 10:02:44,546:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+1:02d} Voltage' b'\x0c\xeb'
2021-10-15 10:02:44,547:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+1:02d} Voltage', raw_value b'\x0c\xeb'
2021-10-15 10:02:44,547:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,547:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xeb' 2 byte decoded to 3307
2021-10-15 10:02:44,548:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,548:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+2:02d} Voltage'", 'V']
2021-10-15 10:02:44,549:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+2:02d} Voltage' b'\x0c\xed'
2021-10-15 10:02:44,549:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+2:02d} Voltage', raw_value b'\x0c\xed'
2021-10-15 10:02:44,549:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,549:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xed' 2 byte decoded to 3309
2021-10-15 10:02:44,550:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,550:DEBUG:abstractprotocol:decode@414: Got defn ['BigHex2Short:r/1000', 2, "f'Cell {3*f+3:02d} Voltage'", 'V']
2021-10-15 10:02:44,551:DEBUG:abstractprotocol:process_response@85: Got template r/1000 for f'Cell {3*f+3:02d} Voltage' b'\x0c\xeb'
2021-10-15 10:02:44,551:DEBUG:abstractprotocol:process_response@87: Processing data_type: BigHex2Short for data_name: f'Cell {3*f+3:02d} Voltage', raw_value b'\x0c\xeb'
2021-10-15 10:02:44,551:DEBUG:abstractprotocol:process_response@158: Processing format string BigHex2Short(raw_value)
2021-10-15 10:02:44,551:DEBUG:protocol_helpers:BigHex2Short@151: Hex b'\x0c\xeb' 2 byte decoded to 3307
2021-10-15 10:02:44,552:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,552:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'Reserved', '']
2021-10-15 10:02:44,553:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: Reserved, raw_value b'X'
2021-10-15 10:02:44,553:DEBUG:abstractprotocol:process_response@94: Discarding Reserved:b'X'
2021-10-15 10:02:44,553:DEBUG:abstractprotocol:decode@392: Processing POSITIONAL type responses
2021-10-15 10:02:44,553:DEBUG:abstractprotocol:decode@414: Got defn ['discard', 1, 'checksum', '']
2021-10-15 10:02:44,554:DEBUG:abstractprotocol:process_response@87: Processing data_type: discard for data_name: checksum, raw_value b'\x85'
2021-10-15 10:02:44,554:DEBUG:abstractprotocol:process_response@94: Discarding checksum:b'\x85'
2021-10-15 10:02:44,554:INFO:device:run_command@332: Decoded response {'raw_response': ['¥\x01\x95\x08\x01\x0cí\x0cë\x0cíX\x85¥\x01\x95\x08\x02\x0cí\x0cí\x0cëX\x86¥\x01\x95\x08\x03\x0cë\x0cí\x0cëX\x85', ''], '_command': 'cellVoltages', '_command_description': 'Cell Voltages Information', 'Cell 01 Voltage': [3.309, 'V'], 'Cell 02 Voltage': [3.307, 'V'], 'Cell 03 Voltage': [3.309, 'V'], 'Cell 04 Voltage': [3.309, 'V'], 'Cell 05 Voltage': [3.309, 'V'], 'Cell 06 Voltage': [3.307, 'V'], 'Cell 07 Voltage': [3.307, 'V'], 'Cell 08 Voltage': [3.309, 'V'], 'Cell 09 Voltage': [3.307, 'V']}
2021-10-15 10:02:44,555:DEBUG:__init__:main@368: results: {'raw_response': ['¥\x01\x95\x08\x01\x0cí\x0cë\x0cíX\x85¥\x01\x95\x08\x02\x0cí\x0cí\x0cëX\x86¥\x01\x95\x08\x03\x0cë\x0cí\x0cëX\x85', ''], '_command': 'cellVoltages', '_command_description': 'Cell Voltages Information', 'Cell 01 Voltage': [3.309, 'V'], 'Cell 02 Voltage': [3.307, 'V'], 'Cell 03 Voltage': [3.309, 'V'], 'Cell 04 Voltage': [3.309, 'V'], 'Cell 05 Voltage': [3.309, 'V'], 'Cell 06 Voltage': [3.307, 'V'], 'Cell 07 Voltage': [3.307, 'V'], 'Cell 08 Voltage': [3.309, 'V'], 'Cell 09 Voltage': [3.307, 'V']}
2021-10-15 10:02:44,555:INFO:helpers:get_outputs@64: attempting to create output processor: screen
2021-10-15 10:02:44,558:DEBUG:screen:__init__@16: processor.screen __init__ kwargs {}
2021-10-15 10:02:44,558:DEBUG:__init__:main@374: Using output filter: None
2021-10-15 10:02:44,559:INFO:screen:output@19: Using output processor: screen
2021-10-15 10:02:44,559:DEBUG:screen:output@20: kwargs {'data': {'raw_response': ['¥\x01\x95\x08\x01\x0cí\x0cë\x0cíX\x85¥\x01\x95\x08\x02\x0cí\x0cí\x0cëX\x86¥\x01\x95\x08\x03\x0cë\x0cí\x0cëX\x85', ''], '_command': 'cellVoltages', '_command_description': 'Cell Voltages Information', 'Cell 01 Voltage': [3.309, 'V'], 'Cell 02 Voltage': [3.307, 'V'], 'Cell 03 Voltage': [3.309, 'V'], 'Cell 04 Voltage': [3.309, 'V'], 'Cell 05 Voltage': [3.309, 'V'], 'Cell 06 Voltage': [3.307, 'V'], 'Cell 07 Voltage': [3.307, 'V'], 'Cell 08 Voltage': [3.309, 'V'], 'Cell 09 Voltage': [3.307, 'V']}, 'tag': 'cellVoltages', 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar'), 'filter': None, 'excl_filter': None, 'keep_case': False}
Command: cellVoltages - Cell Voltages Information
------------------------------------------------------------
Parameter                       Value           Unit
cell_01_voltage                 3.309           V
cell_02_voltage                 3.307           V
cell_03_voltage                 3.309           V
cell_04_voltage                 3.309           V
cell_05_voltage                 3.309           V
cell_06_voltage                 3.307           V
cell_07_voltage                 3.307           V
cell_08_voltage                 3.309           V
cell_09_voltage                 3.307           V
2021-10-15 10:02:44,560:DEBUG:__init__:main@394: Not daemon, so not looping
mpp-solar -p /dev/ttyUSB1 -b 9600 -P DALY40 -c cellVoltages -D

2021-10-15 10:03:59,191:INFO:__init__:main@195: Solar Device Command Utility, version: 0.7.82, add missing libs
MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
2021-10-15 10:03:59,191:INFO:__init__:main@299: Creating device "unnamed" (type: "mppsolar") on port "/dev/ttyUSB1 (porttype=None)" using protocol "DALY40"
2021-10-15 10:03:59,195:DEBUG:__init__:main@302: device_class <class 'mppsolar.devices.mppsolar.mppsolar'>
2021-10-15 10:03:59,195:DEBUG:device:__init__@31: __init__ args ()
2021-10-15 10:03:59,195:DEBUG:device:__init__@32: __init__ kwargs {'name': 'unnamed', 'port': '/dev/ttyUSB1', 'protocol': 'DALY40', 'baud': 9600, 'porttype': None, 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')}
2021-10-15 10:03:59,196:DEBUG:device:get_port_type@86: port matches ttyusb
2021-10-15 10:03:59,196:INFO:device:set_port@160: Using serialio for communications
2021-10-15 10:03:59,207:DEBUG:device:set_protocol@96: Protocol DALY40
2021-10-15 10:03:59,212:DEBUG:device:__init__@36: __init__ name unnamed, port <mppsolar.io.serialio.SerialIO object at 0x75eea870>, protocol <mppsolar.protocols.daly40.daly40 object at 0x75eea4b0>
2021-10-15 10:03:59,212:DEBUG:__init__:main@349: Commands [(<mppsolar.devices.mppsolar.mppsolar object at 0x75eea910>, 'cellVoltages', 'cellVoltages', 'screen', None, None)]
2021-10-15 10:03:59,213:INFO:__init__:main@354: Looping 1 commands
2021-10-15 10:03:59,213:INFO:__init__:main@365: Getting results from device: mppsolar device - name: unnamed, port: <mppsolar.io.serialio.SerialIO object at 0x75eea870>, protocol: <mppsolar.protocols.daly40.daly40 object at 0x75eea4b0> for command: cellVoltages, tag: cellVoltages, outputs: screen
2021-10-15 10:03:59,213:INFO:device:run_command@268: Running command cellVoltages
2021-10-15 10:03:59,214:INFO:daly:get_full_command@211: Using protocol b'DALY40' with 7 commands
2021-10-15 10:03:59,214:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'cellVoltages'
2021-10-15 10:03:59,214:DEBUG:abstractprotocol:get_command_defn@45: Found command cellVoltages in protocol b'DALY40'
2021-10-15 10:03:59,214:DEBUG:daly:get_full_command@228: full command: b'\xa5@\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\x82\n'
2021-10-15 10:03:59,215:INFO:device:run_command@294: full command b'\xa5@\x95\x08\x00\x00\x00\x00\x00\x00\x00\x00\x82\n' for command cellVoltages
2021-10-15 10:03:59,215:DEBUG:abstractprotocol:get_command_defn@43: Processing command 'cellVoltages'
2021-10-15 10:03:59,215:DEBUG:abstractprotocol:get_command_defn@45: Found command cellVoltages in protocol b'DALY40'
2021-10-15 10:03:59,215:DEBUG:serialio:send_and_receive@19: port /dev/ttyUSB1, baudrate 9600
2021-10-15 10:03:59,218:DEBUG:serialio:send_and_receive@22: Executing command via serialio...
2021-10-15 10:03:59,344:DEBUG:serialio:send_and_receive@30: serial response was: b'\xa5\x01\x95\x08\x01\r'
2021-10-15 10:03:59,345:DEBUG:device:run_command@313: Send and Receive Response b'\xa5\x01\x95\x08\x01\r'
2021-10-15 10:03:59,346:INFO:abstractprotocol:decode@179: response passed to decode: b'\xa5\x01\x95\x08\x01\r'
2021-10-15 10:03:59,346:DEBUG:daly:check_response_valid@247: checking validity of b'\xa5\x01\x95\x08\x01\r'
2021-10-15 10:03:59,346:INFO:abstractprotocol:decode@183: DALY checksum did not match for response b'\xa5\x01\x95\x08\x01\r'
2021-10-15 10:03:59,347:INFO:device:run_command@332: Decoded response {'ERROR': ["DALY checksum did not match for response b'\\xa5\\x01\\x95\\x08\\x01\\r'", '']}
2021-10-15 10:03:59,347:DEBUG:__init__:main@368: results: {'ERROR': ["DALY checksum did not match for response b'\\xa5\\x01\\x95\\x08\\x01\\r'", '']}
2021-10-15 10:03:59,347:INFO:helpers:get_outputs@64: attempting to create output processor: screen
2021-10-15 10:03:59,350:DEBUG:screen:__init__@16: processor.screen __init__ kwargs {}
2021-10-15 10:03:59,350:DEBUG:__init__:main@374: Using output filter: None
2021-10-15 10:03:59,351:INFO:screen:output@19: Using output processor: screen
2021-10-15 10:03:59,351:DEBUG:screen:output@20: kwargs {'data': {'ERROR': ["DALY checksum did not match for response b'\\xa5\\x01\\x95\\x08\\x01\\r'", '']}, 'tag': 'cellVoltages', 'mqtt_broker': MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar'), 'filter': None, 'excl_filter': None, 'keep_case': False}
Parameter                       Value           Unit
error                           DALY checksum did not match for response b'\xa5\x01\x95\x08\x01\r'
2021-10-15 10:03:59,351:DEBUG:__init__:main@394: Not daemon, so not looping

I'm a bit confused because the output on /dev/ttyUSB0 now seems to work, but not on /dev/ ttyUSB1 ....

Test 2:

mpp-solar -p /dev/ttyUSB0 -b 9600 -P DALY40 -c SOC,cellVoltages,cellTemperatures

MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
Command: SOC - State of Charge
------------------------------------------------------------
Parameter                       Value           Unit
battery_bank_voltage            26.4            V
acquistion                      0.0             V
current                         14.3            A
soc                             85.8            %
Command: cellVoltages - Cell Voltages Information
------------------------------------------------------------
Parameter                       Value           Unit
cell_01_voltage                 3.309           V
cell_02_voltage                 3.308           V
cell_03_voltage                 3.309           V
cell_04_voltage                 3.309           V
cell_05_voltage                 3.309           V
cell_06_voltage                 3.307           V
cell_07_voltage                 3.307           V
cell_08_voltage                 3.309           V
cell_09_voltage                 3.307           V
Command: cellTemperatures - Cell Temperature Information
------------------------------------------------------------
Parameter                       Value           Unit
cell_01_temperature             15              °C
cell_02_temperature             195             °C
cell_03_temperature             -28             °C
cell_04_temperature             197             °C
cell_05_temperature             -28             °C
cell_06_temperature             195             °C
cell_07_temperature             50              °C
mpp-solar -p /dev/ttyUSB1 -b 9600 -P DALY40 -c SOC,cellVoltages,cellTemperatures

MqttBroker(name='localhost', port=1883, username=None, password=None, results_topic='mpp-solar')
Parameter                       Value           Unit
error                           DALY checksum did not match for response b'\xa5\x01\x90\x08\x01\r'
Parameter                       Value           Unit
error                           DALY checksum did not match for response b'\xa5\x01\x95\x08\x01\r'
Parameter                       Value           Unit
error                           DALY checksum did not match for response b'\xa5\x01\x95\x08\x02\r'

but

daly-bms-cli  -d /dev/ttyUSB0 --cell-voltages --soc
{
  "total_voltage": 26.4,
  "current": 14.3,
  "soc_percent": 85.5
}
{
  "1": 3.309,
  "2": 3.308,
  "3": 3.309,
  "4": 3.31,
  "5": 3.309,
  "6": 3.307,
  "7": 3.307,
  "8": 3.309
}

and

daly-bms-cli  -d /dev/ttyUSB1 --cell-voltages --soc
{
  "total_voltage": 26.9,
  "current": -27.6,
  "soc_percent": 66.4
}
{
  "1": 3.367,
  "2": 3.374,
  "3": 3.375,
  "4": 3.374,
  "5": 3.381,
  "6": 3.374,
  "7": 3.375,
  "8": 3.372
}

...works perfect.

It looks to me as if the script does not generally provide any usable data on USB1, regardless of which BMS is connected here. Does that make any sense? Apparently the communication on USB1 works without any problems, otherwise the daly-bms-cli would not work either. Very strange...

jblance commented 3 years ago

The debug just showed that it didn't get back much in the way of a response

Can you run it a couple of times and post the output

On Fri, 15 Oct 2021, 9:51 pm cyborgxxl, @.***> wrote:

In the meantime, I changed the USB port as a test. /dev/ttyUSB1 is now /dev/ttyUSB0. Sorry for the confusion. ;-)

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/jblance/mpp-solar/issues/162#issuecomment-944119239, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAJVKNVHV2UEOE2YUIQMWNLUG7TRTANCNFSM5FLAMJDQ .

cyborgxxl commented 3 years ago

I'll go crazy. For weeks only one BMS has been working and out of sheer desperation I wrote a sh logging script that records the output for ttyUSB0 and ttyUSB1. Both suddenly work fine. I do not understand that....

mppt-test-ttyUSB0.txt mppt-test-ttyUSB1.txt