search

nmakel / solaredge_meterproxy

Modbus proxy for SolarEdge inverters and unsupported kWh meters
MIT License
29 stars 20 forks source link

Timeout error #2

Closed Maikel-K closed 3 years ago

Maikel-K commented 3 years ago

Hi Niels,

So with your solaredge_modbus script and SDM_modbus script i checked that these RS485 connection work. I have run semp-rtu.py and get the following error first:

Traceback (most recent call last): File "/usr/local/lib/python3.7/dist-packages/serial/serialutil.py", line 361, in timeout timeout + 1 # test if it's a number, will throw a TypeError if not... TypeError: can only concatenate str (not "int") to str

In semp.conf:

//# Serving serial timeout, depends on line speed. //# optional, default: 0.1 timeout = 1.0

The next error it raises in the same go:

Traceback (most recent call last): File "semp-rtu.py", line 268, in timeout=confparser["server"].get("timeout", fallback=default_config["server"]["timeout"]) File "/home/pi/.local/lib/python3.7/site-packages/pymodbus/server/sync.py", line 686, in StartSerialServer server = ModbusSerialServer(context, framer, identity, **kwargs) File "/home/pi/.local/lib/python3.7/site-packages/pymodbus/server/sync.py", line 541, in init if self._connect(): File "/home/pi/.local/lib/python3.7/site-packages/pymodbus/server/sync.py", line 557, in _connect parity=self.parity) File "/usr/local/lib/python3.7/dist-packages/serial/serialutil.py", line 223, in init self.timeout = timeout File "/usr/local/lib/python3.7/dist-packages/serial/serialutil.py", line 363, in timeout raise ValueError("Not a valid timeout: {!r}".format(timeout)) ValueError: Not a valid timeout: '1.0'

What could this be?

nmakel commented 3 years ago

Remove the config for timeout. It's not required.

I'm guessing the parameter is being read as an integer, and you're providing a float. The pymodbus library expects an int, which I will add to the example configuration file.

nmakel commented 3 years ago

Seems like the value is also set incorrectly in semp-rtu.py. I've uploaded a new version.

Maikel-K commented 3 years ago

I downloaded the latest files and uploaded it to my RPI.

With the hashtag before the timeout of the server it works fine. When removing the hashtag the following error still occurs, could it be because there are two timeouts mentioned in the conf file?

Traceback (most recent call last): File "/usr/local/lib/python3.7/dist-packages/serial/serialutil.py", line 361, in timeout timeout + 1 # test if it's a number, will throw a TypeError if not... TypeError: can only concatenate str (not "int") to str

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "semp-rtu.py", line 249, in timeout=confparser["server"].get("timeout", fallback=default_config["server"]["timeout"]) File "/home/pi/.local/lib/python3.7/site-packages/pymodbus/server/sync.py", line 686, in StartSerialServer server = ModbusSerialServer(context, framer, identity, **kwargs) File "/home/pi/.local/lib/python3.7/site-packages/pymodbus/server/sync.py", line 541, in init if self._connect(): File "/home/pi/.local/lib/python3.7/site-packages/pymodbus/server/sync.py", line 557, in _connect parity=self.parity) File "/usr/local/lib/python3.7/dist-packages/serial/serialutil.py", line 223, in init self.timeout = timeout File "/usr/local/lib/python3.7/dist-packages/serial/serialutil.py", line 363, in timeout raise ValueError("Not a valid timeout: {!r}".format(timeout)) ValueError: Not a valid timeout: '1'

EDIT: i put a # before the timeout of the meter, no difference.

Maikel-K commented 3 years ago

The script is running. On the inverter i got the error it's missing the meter.

My SE3500HD with display is setup as follows: RS485-1 CONF then next screen Device type Meter 1 <SE, 2> then next screen Device Type Protocol Device ID <2> Meter Func. <E+I> Topology

The error i get on the inverter is: Error code 3x6e Meter Comm. Error.

This is a snippet of the DEBUG log in Putty:

2020-11-24 18:56:44 DEBUG: Getting Frame - 0x4 0x18 0x40 0xb1 0xb9 0xee 0x45 0x37 0x7c 0x45 0x40 0xb1 0xb9 0xee 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x7c 0x45 2020-11-24 18:56:44 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 18:56:44 DEBUG: Frame advanced, resetting header!! 2020-11-24 18:56:44 DEBUG: Adding transaction 1 2020-11-24 18:56:44 DEBUG: Getting transaction 1 2020-11-24 18:56:44 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 18:56:44 DEBUG: [16561, 47598, 17719, 31813, 16561, 47598, 16864, 57657, 0, 0, 17719, 31813] 2020-11-24 18:56:44 DEBUG: [b'@\xb1', b'\xb9\xee'] 2020-11-24 18:56:44 DEBUG: [b'E7', b'|E'] 2020-11-24 18:56:44 DEBUG: [b'@\xb1', b'\xb9\xee'] 2020-11-24 18:56:44 DEBUG: [b'A\xe0', b'\xe19'] 2020-11-24 18:56:44 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 18:56:44 DEBUG: [b'E7', b'|E'] 2020-11-24 18:56:44 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 18:56:44 DEBUG: Running transaction 63 2020-11-24 18:56:44 DEBUG: SEND: 0x1 0x4 0x1 0x2 0x0 0x8 0x51 0xf0 2020-11-24 18:56:44 DEBUG: Changing state to IDLE - Last Frame End - 1606240604.287161, Current Time stamp - 1606240604.300381 2020-11-24 18:56:44 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 18:56:44 DEBUG: New Transaction state 'SENDING' 2020-11-24 18:56:44 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 18:56:44 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 18:56:44 DEBUG: RECV: 0x1 0x4 0x10 0x3e 0x4c 0x26 0xc 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 0x14 0xb8 2020-11-24 18:56:44 DEBUG: Getting Frame - 0x4 0x10 0x3e 0x4c 0x26 0xc 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 2020-11-24 18:56:44 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 18:56:44 DEBUG: Frame advanced, resetting header!! 2020-11-24 18:56:44 DEBUG: Adding transaction 1 2020-11-24 18:56:44 DEBUG: Getting transaction 1 2020-11-24 18:56:44 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 18:56:44 DEBUG: [15948, 9740, 0, 0, 0, 0, 16707, 5819] 2020-11-24 18:56:44 DEBUG: [b'>L', b'&\x0c'] 2020-11-24 18:56:44 DEBUG: [b'AC', b'\x16\xbb'] 2020-11-24 18:56:44 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 18:56:44 DEBUG: Running transaction 64 2020-11-24 18:56:44 DEBUG: SEND: 0x1 0x4 0x1 0x56 0x0 0x4 0x10 0x25 2020-11-24 18:56:44 DEBUG: Changing state to IDLE - Last Frame End - 1606240604.538689, Current Time stamp - 1606240604.549344 2020-11-24 18:56:44 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 18:56:44 DEBUG: New Transaction state 'SENDING' 2020-11-24 18:56:44 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 18:56:44 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 18:56:44 DEBUG: RECV: 0x1 0x4 0x8 0x45 0xef 0x79 0x7f 0x44 0x62 0x8d 0x50 0x30 0xed 2020-11-24 18:56:44 DEBUG: Getting Frame - 0x4 0x8 0x45 0xef 0x79 0x7f 0x44 0x62 0x8d 0x50 2020-11-24 18:56:44 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 18:56:44 DEBUG: Frame advanced, resetting header!! 2020-11-24 18:56:44 DEBUG: Adding transaction 1 2020-11-24 18:56:44 DEBUG: Getting transaction 1 2020-11-24 18:56:44 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 18:56:44 DEBUG: [17903, 31103, 17506, 36176] 2020-11-24 18:56:44 DEBUG: [b'E\xef', b'y\x7f'] 2020-11-24 18:56:44 DEBUG: [b'Db', b'\x8dP'] 2020-11-24 18:56:44 DEBUG: [31103, 17903, 51380, 17002, 31103, 17903, 51380, 17002, 0, 16528, 0, 16528, 0, 0, 0, 0, 39322, 17253, 39322, 17253, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 16968] 2020-11-24 18:56:44 DEBUG: setValues[3] 1001:34 2020-11-24 18:56:44 DEBUG: [31103, 17903, 0, 0, 0, 0, 51380, 17002, 0, 0, 0, 0, 41966, 17901, 41966, 17901, 41966, 17901, 0, 0, 0, 0, 36176, 17506, 36176, 17506, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 56696, 15813, 56696, 15813, 0, 0, 0, 0, 26214, 49722, 26214, 49722, 0, 0, 0, 0, 44395, 16955, 44395, 16955, 0, 0, 0, 0, 52429, 15948, 0, 0, 0, 0, 47598, 16561, 0, 0, 31813, 17719, 0, 0, 47598, 16561, 0, 0, 0, 0] 2020-11-24 18:56:44 DEBUG: setValues[3] 1101:82 2020-11-24 18:56:46 DEBUG: CRC invalid, discarding header!! 2020-11-24 18:56:46 DEBUG: Resetting frame - Current Frame in buffer - 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 2020-11-24 18:56:46 DEBUG: Frame check failed, ignoring!! 2020-11-24 18:56:46 DEBUG: Resetting frame - Current Frame in buffer - 2020-11-24 18:56:48 DEBUG: CRC invalid, discarding header!! 2020-11-24 18:56:48 DEBUG: Resetting frame - Current Frame in buffer - 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 2020-11-24 18:56:48 DEBUG: Frame check failed, ignoring!! 2020-11-24 18:56:48 DEBUG: Resetting frame - Current Frame in buffer - 2020-11-24 18:56:49 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 18:56:49 DEBUG: Running transaction 65 2020-11-24 18:56:49 DEBUG: SEND: 0x1 0x4 0x0 0x0 0x0 0x50 0xf0 0x36 2020-11-24 18:56:49 DEBUG: Changing state to IDLE - Last Frame End - 1606240604.75947, Current Time stamp - 1606240609.776096 2020-11-24 18:56:49 DEBUG: New Transaction state 'SENDING' 2020-11-24 18:56:49 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 18:56:50 DEBUG: CRC invalid, discarding header!! 2020-11-24 18:56:50 DEBUG: Resetting frame - Current Frame in buffer - 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 2020-11-24 18:56:50 DEBUG: Frame check failed, ignoring!! 2020-11-24 18:56:50 DEBUG: Resetting frame - Current Frame in buffer - 2020-11-24 18:56:50 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 18:56:50 DEBUG: RECV: 0x1 0x4 0xa0 0x43 0x65 0x80 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3e 0x4a 0xc0 0x83 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0x8c 0xcc 0xcd 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x3b 0x9d 0xd2 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xc2 0x3a 0x66 0x66 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xc3 0x75 0x29 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x48 0x28 0xf6 0x42 0x6a 0xc8 0xb4 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x50 0x31 0x43 0xe5 2020-11-24 18:56:50 DEBUG: Getting Frame - 0x4 0xa0 0x43 0x65 0x80 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3e 0x4a 0xc0 0x83 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0x8c 0xcc 0xcd 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x3b 0x9d 0xd2 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xc2 0x3a 0x66 0x66 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xc3 0x75 0x29 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x48 0x28 0xf6 0x42 0x6a 0xc8 0xb4 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x50 0x31 2020-11-24 18:56:50 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 18:56:50 DEBUG: Frame advanced, resetting header!! 2020-11-24 18:56:50 DEBUG: Adding transaction 1 2020-11-24 18:56:50 DEBUG: Getting transaction 1 2020-11-24 18:56:50 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 18:56:50 DEBUG: [17253, 32768, 0, 0, 0, 0, 15946, 49283, 0, 0, 0, 0, 16524, 52429, 0, 0, 0, 0, 16955, 40402, 0, 0, 0, 0, 49722, 26214, 0, 0, 0, 0, 15811, 29993, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 16968, 10486, 17002, 51380, 17901, 41966, 17097, 59638, 17481, 20529] 2020-11-24 18:56:50 DEBUG: [b'Ce', b'\x80\x00'] 2020-11-24 18:56:50 DEBUG: [b'>J', b'\xc0\x83'] 2020-11-24 18:56:50 DEBUG: [b'@\x8c', b'\xcc\xcd'] 2020-11-24 18:56:50 DEBUG: [b'B;', b'\x9d\xd2'] 2020-11-24 18:56:50 DEBUG: [b'\xc2:', b'ff'] 2020-11-24 18:56:50 DEBUG: [b'=\xc3', b'u)'] 2020-11-24 18:56:50 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 18:56:50 DEBUG: [b'BH', b'(\xf6'] 2020-11-24 18:56:50 DEBUG: [b'Bj', b'\xc8\xb4'] 2020-11-24 18:56:50 DEBUG: [b'E\xed', b'\xa3\xee'] 2020-11-24 18:56:50 DEBUG: [b'B\xc9', b'\xe8\xf6'] 2020-11-24 18:56:50 DEBUG: [b'DI', b'P1'] 2020-11-24 18:56:50 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 18:56:50 DEBUG: Running transaction 66 2020-11-24 18:56:50 DEBUG: SEND: 0x1 0x4 0x0 0x54 0x0 0xc 0xb1 0xdf 2020-11-24 18:56:50 DEBUG: Changing state to IDLE - Last Frame End - 1606240610.7396, Current Time stamp - 1606240610.759772 2020-11-24 18:56:50 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 18:56:50 DEBUG: New Transaction state 'SENDING' 2020-11-24 18:56:50 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 18:56:51 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 18:56:51 DEBUG: RECV: 0x1 0x4 0x18 0x40 0xb1 0xb9 0xee 0x45 0x37 0x7c 0x45 0x40 0xb1 0xb9 0xee 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x7c 0x45 0x6f 0x1f

Maikel-K commented 3 years ago

or this is the output just after a start of the script:

pi@raspberrypi4:~/eastronsolaredge $ python3 semp-rtu.py 2020-11-24 19:07:13 DEBUG: [1234, 0, 5, 5, 5, 5, 0, 0, 0, 15, 1, 10000, 10000, 10000, 64536, 64536, 64536, 1500, 120, 0, 0, 20000, 0] 2020-11-24 19:07:13 DEBUG: setValues[3] 1601:23 2020-11-24 19:07:13 DEBUG: [0, 2, 4, 0, 0, 5] 2020-11-24 19:07:13 DEBUG: setValues[3] 1651:6 2020-11-24 19:07:13 DEBUG: [4614, 15, 0, 0, 0, 0, 0, 25, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] 2020-11-24 19:07:13 DEBUG: setValues[3] 1701:23 2020-11-24 19:07:13 INFO: Created <Thread(t_update_2, initial)>: meter1 sdm120 SDM120(/dev/serial/by-id/usb-1a86_USB2.0-Serial-if00-port0, connectionType.RTU: stopbits=1, parity=N, baud=2400, timeout=1, retries=3, unit=0x1) 2020-11-24 19:07:14 INFO: Starting <Thread(t_update_2, started 3052954720)> 2020-11-24 19:07:14 DEBUG: Client Connected [/dev/ttyUSB0:/dev/ttyUSB0] 2020-11-24 19:07:14 DEBUG: Started thread to serve client 2020-11-24 19:07:14 DEBUG: Current transaction state - IDLE 2020-11-24 19:07:14 DEBUG: Running transaction 1 2020-11-24 19:07:14 DEBUG: SEND: 0x1 0x4 0x0 0x0 0x0 0x50 0xf0 0x36 2020-11-24 19:07:14 DEBUG: New Transaction state 'SENDING' 2020-11-24 19:07:14 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 19:07:15 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 19:07:15 DEBUG: RECV: 0x1 0x4 0xa0 0x43 0x66 0x19 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3e 0x4f 0xdf 0x3b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0xb6 0x66 0x66 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x3d 0x3d 0x92 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xc2 0x3b 0x99 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xf8 0xd6 0x40 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x47 0xcc 0xcd 0x42 0x6a 0xc9 0xba 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x50 0xb4 0x93 0x54 2020-11-24 19:07:15 DEBUG: Getting Frame - 0x4 0xa0 0x43 0x66 0x19 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3e 0x4f 0xdf 0x3b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0xb6 0x66 0x66 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x3d 0x3d 0x92 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xc2 0x3b 0x99 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xf8 0xd6 0x40 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x47 0xcc 0xcd 0x42 0x6a 0xc9 0xba 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x50 0xb4 2020-11-24 19:07:15 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 19:07:15 DEBUG: Frame advanced, resetting header!! 2020-11-24 19:07:15 DEBUG: Adding transaction 1 2020-11-24 19:07:15 DEBUG: Getting transaction 1 2020-11-24 19:07:15 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 19:07:15 DEBUG: [17254, 6554, 0, 0, 0, 0, 15951, 57147, 0, 0, 0, 0, 16566, 26214, 0, 0, 0, 0, 16957, 15762, 0, 0, 0, 0, 49723, 39322, 0, 0, 0, 0, 15864, 54848, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 16967, 52429, 17002, 51642, 17901, 41966, 17097, 59638, 17481, 20660] 2020-11-24 19:07:15 DEBUG: [b'Cf', b'\x19\x9a'] 2020-11-24 19:07:15 DEBUG: [b'>O', b'\xdf;'] 2020-11-24 19:07:15 DEBUG: [b'@\xb6', b'ff'] 2020-11-24 19:07:15 DEBUG: [b'B=', b'=\x92'] 2020-11-24 19:07:15 DEBUG: [b'\xc2;', b'\x99\x9a'] 2020-11-24 19:07:15 DEBUG: [b'=\xf8', b'\xd6@'] 2020-11-24 19:07:15 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 19:07:15 DEBUG: [b'BG', b'\xcc\xcd'] 2020-11-24 19:07:15 DEBUG: [b'Bj', b'\xc9\xba'] 2020-11-24 19:07:15 DEBUG: [b'E\xed', b'\xa3\xee'] 2020-11-24 19:07:15 DEBUG: [b'B\xc9', b'\xe8\xf6'] 2020-11-24 19:07:15 DEBUG: [b'DI', b'P\xb4'] 2020-11-24 19:07:15 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 19:07:15 DEBUG: Running transaction 2 2020-11-24 19:07:15 DEBUG: SEND: 0x1 0x4 0x0 0x54 0x0 0xc 0xb1 0xdf 2020-11-24 19:07:15 DEBUG: Changing state to IDLE - Last Frame End - 1606241235.746215, Current Time stamp - 1606241235.750252 2020-11-24 19:07:15 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 19:07:15 DEBUG: New Transaction state 'SENDING' 2020-11-24 19:07:15 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 19:07:16 DEBUG: RECV: 0x1 0x4 0x18 0x40 0xb1 0x21 0x2 0x45 0x37 0x7c 0x45 0x40 0xb1 0x21 0x2 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x7c 0x45 0xb3 0x8b 2020-11-24 19:07:16 DEBUG: Getting Frame - 0x4 0x18 0x40 0xb1 0x21 0x2 0x45 0x37 0x7c 0x45 0x40 0xb1 0x21 0x2 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x7c 0x45 2020-11-24 19:07:16 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 19:07:16 DEBUG: Frame advanced, resetting header!! 2020-11-24 19:07:16 DEBUG: Adding transaction 1 2020-11-24 19:07:16 DEBUG: Getting transaction 1 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 19:07:16 DEBUG: [16561, 8450, 17719, 31813, 16561, 8450, 16864, 57657, 0, 0, 17719, 31813] 2020-11-24 19:07:16 DEBUG: [b'@\xb1', b'!\x02'] 2020-11-24 19:07:16 DEBUG: [b'E7', b'|E'] 2020-11-24 19:07:16 DEBUG: [b'@\xb1', b'!\x02'] 2020-11-24 19:07:16 DEBUG: [b'A\xe0', b'\xe19'] 2020-11-24 19:07:16 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 19:07:16 DEBUG: [b'E7', b'|E'] 2020-11-24 19:07:16 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 19:07:16 DEBUG: Running transaction 3 2020-11-24 19:07:16 DEBUG: SEND: 0x1 0x4 0x1 0x2 0x0 0x8 0x51 0xf0 2020-11-24 19:07:16 DEBUG: Changing state to IDLE - Last Frame End - 1606241236.020907, Current Time stamp - 1606241236.02448 2020-11-24 19:07:16 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 19:07:16 DEBUG: New Transaction state 'SENDING' 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 19:07:16 DEBUG: RECV: 0x1 0x4 0x10 0x3e 0x4c 0x30 0x63 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 0x96 0xc1 2020-11-24 19:07:16 DEBUG: Getting Frame - 0x4 0x10 0x3e 0x4c 0x30 0x63 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 2020-11-24 19:07:16 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 19:07:16 DEBUG: Frame advanced, resetting header!! 2020-11-24 19:07:16 DEBUG: Adding transaction 1 2020-11-24 19:07:16 DEBUG: Getting transaction 1 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 19:07:16 DEBUG: [15948, 12387, 0, 0, 0, 0, 16707, 5819] 2020-11-24 19:07:16 DEBUG: [b'>L', b'0c'] 2020-11-24 19:07:16 DEBUG: [b'AC', b'\x16\xbb'] 2020-11-24 19:07:16 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 19:07:16 DEBUG: Running transaction 4 2020-11-24 19:07:16 DEBUG: SEND: 0x1 0x4 0x1 0x56 0x0 0x4 0x10 0x25 2020-11-24 19:07:16 DEBUG: Changing state to IDLE - Last Frame End - 1606241236.261941, Current Time stamp - 1606241236.268902 2020-11-24 19:07:16 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 19:07:16 DEBUG: New Transaction state 'SENDING' 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 19:07:16 DEBUG: RECV: 0x1 0x4 0x8 0x45 0xef 0x79 0x81 0x44 0x62 0x8d 0xd3 0x58 0x98 2020-11-24 19:07:16 DEBUG: Getting Frame - 0x4 0x8 0x45 0xef 0x79 0x81 0x44 0x62 0x8d 0xd3 2020-11-24 19:07:16 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 19:07:16 DEBUG: Frame advanced, resetting header!! 2020-11-24 19:07:16 DEBUG: Adding transaction 1 2020-11-24 19:07:16 DEBUG: Getting transaction 1 2020-11-24 19:07:16 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 19:07:16 DEBUG: [17903, 31105, 17506, 36307] 2020-11-24 19:07:16 DEBUG: [b'E\xef', b'y\x81'] 2020-11-24 19:07:16 DEBUG: [b'Db', b'\x8d\xd3'] 2020-11-24 19:07:16 DEBUG: [31105, 17903, 51642, 17002, 31105, 17903, 51642, 17002, 26214, 16566, 26214, 16566, 0, 0, 0, 0, 6554, 17254, 6554, 17254, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 52429, 16967] 2020-11-24 19:07:16 DEBUG: setValues[3] 1001:34 2020-11-24 19:07:16 DEBUG: [31105, 17903, 0, 0, 0, 0, 51642, 17002, 0, 0, 0, 0, 41966, 17901, 41966, 17901, 41966, 17901, 0, 0, 0, 0, 36307, 17506, 36307, 17506, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 54848, 15864, 54848, 15864, 0, 0, 0, 0, 39322, 49723, 39322, 49723, 0, 0, 0, 0, 15762, 16957, 15762, 16957, 0, 0, 0, 0, 57147, 15951, 0, 0, 0, 0, 8450, 16561, 0, 0, 31813, 17719, 0, 0, 8450, 16561, 0, 0, 0, 0] 2020-11-24 19:07:16 DEBUG: setValues[3] 1101:82 2020-11-24 19:07:16 DEBUG: CRC invalid, discarding header!! 2020-11-24 19:07:16 DEBUG: Resetting frame - Current Frame in buffer - 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 2020-11-24 19:07:16 DEBUG: Frame check failed, ignoring!! 2020-11-24 19:07:16 DEBUG: Resetting frame - Current Frame in buffer -

nmakel commented 3 years ago

Ok, could you please paste your entire configuration?

Maikel-K commented 3 years ago

[server]

Serving serial device, connected to the SolarEdge inverter.

optional, default: /dev/ttyUSB0

device = /dev/ttyUSB0

Serving serial baud rate.

optional, default: 9600

baud = 115200

Serving serial timeout, depends on line speed.

optional, integer, default: 1

timeout = 1

Logging level, CRITICAL, ERROR, WARNING, INFO, DEBUG

optional, default: INFO

log_level = DEBUG

Masqueraded meters, comma separated.

optional, default: ''

meters = meter1, meter2

meters = meter1

Meters defined in [server] need a config section, one per meter.

Depending on the type of meter that is to be masqueraded, you can

define a number of generic and type specific variables.

Modbus address of the meter as defined in the SolarEdge inverter.

This value needs to be unique.

optional, default: 2

dst_address = 2

Source meter type, which corresponds to a script in /devices.

The generic.py device returns null values.

optional, default: generic

type = generic

Masqueraded serial number.

Need not be correct, must be unique, must be an integer.

optional, default: 987654

serial_numer = 987654

Current transformer amperage rating.

optional, default: 5

ct_current = 50

Current transformer direction inversion, set to 1 if required.

optional, default: 0

ct_inverted = 0

Offset between phases, set to 0, 90, 120 or 180.

optional, default: 0

phase_offset = 120

Number of seconds between value refreshes.

optional, default: 5

refresh_rate = 5

An SDM120 over ModbusRTU, for example:

[meter1] extended = False dst_address = 2 src_address = 1 type = sdm120 serial_number = 987654 device = /dev/serial/by-id/usb-1a86_USB2.0-Serial-if00-port0 stopbits = 1 parity = N baud = 2400 timeout = 1

refresh_rate = 10

nmakel commented 3 years ago

I'm not entirely sure your inverter is correctly configured (I have a model without a display, so am unable to test this), but I would like you to change your config to the one below. I have removed a lot of unecessary options, and most importantly the baud rate of your inverter. You set this to 115200, but I believe the default SolarEdge uses is 9600.

Change your config to:

[server]
device = /dev/ttyUSB0
log_level = DEBUG
meters = meter1

[meter1]
dst_address = 2
src_address = 1
type = sdm120
device = /dev/serial/by-id/usb-1a86_USB2.0-Serial-if00-port0

You should also have a look at this document from SolarEdge, specifically page 24, to see how you should configure your inverter. The example shown should work with the above configuration. Keeping in mind the inverter thinks the meter has modbus ID 2.

Maikel-K commented 3 years ago

before i changed to the meter setup i set the baud at 115200 but i will try

python3 semp-rtu.py Traceback (most recent call last): File "semp-rtu.py", line 154, in meter_device = meter_module.device(confparser[meter]) File "/home/pi/eastronsolaredge/devices/sdm120.py", line 32, in device parity = config.get("parity", fallback=False).upper() AttributeError: 'bool' object has no attribute 'upper'

nmakel commented 3 years ago

Oh boy :) Still lots of little errors.

Add parity=N back to your [meter1] configuration.

Maikel-K commented 3 years ago

python3 semp-rtu.py 2020-11-24 20:11:03 DEBUG: [1234, 0, 5, 5, 5, 5, 0, 0, 0, 15, 1, 10000, 10000, 1 0000, 64536, 64536, 64536, 1500, 120, 0, 0, 20000, 0] 2020-11-24 20:11:03 DEBUG: setValues[3] 1601:23 2020-11-24 20:11:03 DEBUG: [0, 2, 4, 0, 0, 5] 2020-11-24 20:11:03 DEBUG: setValues[3] 1651:6 2020-11-24 20:11:03 DEBUG: [4614, 15, 0, 0, 0, 0, 0, 25, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] 2020-11-24 20:11:03 DEBUG: setValues[3] 1701:23 2020-11-24 20:11:03 INFO: Created <Thread(t_update_2, initial)>: meter1 sdm120 S DM120(/dev/serial/by-id/usb-1a86_USB2.0-Serial-if00-port0, connectionType.RTU: s topbits=1, parity=N, baud=2400, timeout=1, retries=3, unit=0x1) 2020-11-24 20:11:04 INFO: Starting <Thread(t_update_2, started 3053823072)> 2020-11-24 20:11:04 DEBUG: Client Connected [/dev/ttyUSB0:/dev/ttyUSB0] 2020-11-24 20:11:04 DEBUG: Started thread to serve client 2020-11-24 20:11:04 DEBUG: Current transaction state - IDLE 2020-11-24 20:11:04 DEBUG: Running transaction 1 2020-11-24 20:11:04 DEBUG: SEND: 0x1 0x4 0x0 0x0 0x0 0x50 0xf0 0x36 2020-11-24 20:11:04 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:04 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 20:11:05 DEBUG: Changing transaction state from 'WAITING FOR REPLY' t o 'PROCESSING REPLY' 2020-11-24 20:11:05 DEBUG: RECV: 0x1 0x4 0xa0 0x43 0x6a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3e 0x4f 0xdf 0x3b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0xb3 0x 33 0x33 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x43 0x5c 0xa9 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xc2 0x42 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xee 0xf9 0x7 6 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x 0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x 0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x 0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x48 0x0 0x0 0x42 0x6a 0xcf 0xdf 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x53 0 xf8 0x1e 0xa2 2020-11-24 20:11:05 DEBUG: Getting Frame - 0x4 0xa0 0x43 0x6a 0x0 0x0 0x0 0x0 0x 0 0x0 0x0 0x0 0x0 0x0 0x3e 0x4f 0xdf 0x3b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0 xb3 0x33 0x33 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x43 0x5c 0xa9 0x0 0x0 0x0 0x 0 0x0 0x0 0x0 0x0 0xc2 0x42 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xee 0x f9 0x76 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x4 8 0x0 0x0 0x42 0x6a 0xcf 0xdf 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x53 0xf8 2020-11-24 20:11:05 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:05 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:05 DEBUG: Adding transaction 1 2020-11-24 20:11:05 DEBUG: Getting transaction 1 2020-11-24 20:11:05 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:05 DEBUG: [17258, 0, 0, 0, 0, 0, 15951, 57147, 0, 0, 0, 0, 1656 3, 13107, 0, 0, 0, 0, 16963, 23721, 0, 0, 0, 0, 49730, 0, 0, 0, 0, 0, 15854, 638 62, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 , 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 16968, 0, 17002, 53215, 17901, 41966, 1709 7, 59638, 17481, 21496] 2020-11-24 20:11:05 DEBUG: [b'Cj', b'\x00\x00'] 2020-11-24 20:11:05 DEBUG: [b'>O', b'\xdf;'] 2020-11-24 20:11:05 DEBUG: [b'@\xb3', b'33'] 2020-11-24 20:11:05 DEBUG: [b'BC', b'\\xa9'] 2020-11-24 20:11:05 DEBUG: [b'\xc2B', b'\x00\x00'] 2020-11-24 20:11:05 DEBUG: [b'=\xee', b'\xf9v'] 2020-11-24 20:11:05 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 20:11:05 DEBUG: [b'BH', b'\x00\x00'] 2020-11-24 20:11:05 DEBUG: [b'Bj', b'\xcf\xdf'] 2020-11-24 20:11:05 DEBUG: [b'E\xed', b'\xa3\xee'] 2020-11-24 20:11:05 DEBUG: [b'B\xc9', b'\xe8\xf6'] 2020-11-24 20:11:05 DEBUG: [b'DI', b'S\xf8'] 2020-11-24 20:11:05 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 20:11:05 DEBUG: Running transaction 2 2020-11-24 20:11:05 DEBUG: SEND: 0x1 0x4 0x0 0x54 0x0 0xc 0xb1 0xdf 2020-11-24 20:11:05 DEBUG: Changing state to IDLE - Last Frame End - 1606245065. 491891, Current Time stamp - 1606245065.502246 2020-11-24 20:11:05 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 20:11:05 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:05 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 20:11:05 DEBUG: Getting Frame - 0x3 0x6 0x40 0x0 0x17 2020-11-24 20:11:05 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:05 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:05 DEBUG: validate: fc-[3] address-1601: count-23 2020-11-24 20:11:05 DEBUG: getValues fc-[3] address-1601: count-23 2020-11-24 20:11:05 DEBUG: send: [ReadRegisterResponse (23)]- b'02032e04d2000000 05000500050005000000000000000f0001271027102710fc18fc18fc1805dc0078000000004e2000 007700' 2020-11-24 20:11:05 DEBUG: Changing transaction state from 'WAITING FOR REPLY' t o 'PROCESSING REPLY' 2020-11-24 20:11:05 DEBUG: RECV: 0x1 0x4 0x18 0x40 0xb6 0x9b 0xa7 0x45 0x37 0x7c 0x45 0x40 0xb6 0x9b 0xa7 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x7c 0x4 5 0xd9 0xbe 2020-11-24 20:11:05 DEBUG: Getting Frame - 0x4 0x18 0x40 0xb6 0x9b 0xa7 0x45 0x3 7 0x7c 0x45 0x40 0xb6 0x9b 0xa7 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x 7c 0x45 2020-11-24 20:11:05 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:05 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:05 DEBUG: Adding transaction 1 2020-11-24 20:11:05 DEBUG: Getting transaction 1 2020-11-24 20:11:05 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:05 DEBUG: [16566, 39847, 17719, 31813, 16566, 39847, 16864, 576 57, 0, 0, 17719, 31813] 2020-11-24 20:11:05 DEBUG: [b'@\xb6', b'\x9b\xa7'] 2020-11-24 20:11:05 DEBUG: [b'E7', b'|E'] 2020-11-24 20:11:05 DEBUG: [b'@\xb6', b'\x9b\xa7'] 2020-11-24 20:11:05 DEBUG: [b'A\xe0', b'\xe19'] 2020-11-24 20:11:05 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 20:11:05 DEBUG: [b'E7', b'|E'] 2020-11-24 20:11:05 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 20:11:05 DEBUG: Running transaction 3 2020-11-24 20:11:05 DEBUG: SEND: 0x1 0x4 0x1 0x2 0x0 0x8 0x51 0xf0 2020-11-24 20:11:05 DEBUG: Changing state to IDLE - Last Frame End - 1606245065. 775825, Current Time stamp - 1606245065.782329 2020-11-24 20:11:05 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 20:11:05 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:05 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 20:11:06 DEBUG: Changing transaction state from 'WAITING FOR REPLY' t o 'PROCESSING REPLY' 2020-11-24 20:11:06 DEBUG: RECV: 0x1 0x4 0x10 0x3e 0x4e 0x68 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 0xc9 0x3b 2020-11-24 20:11:06 DEBUG: Getting Frame - 0x4 0x10 0x3e 0x4e 0x68 0x0 0x0 0x0 0 x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 2020-11-24 20:11:06 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:06 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:06 DEBUG: Adding transaction 1 2020-11-24 20:11:06 DEBUG: Getting transaction 1 2020-11-24 20:11:06 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:06 DEBUG: [15950, 26624, 0, 0, 0, 0, 16707, 5819] 2020-11-24 20:11:06 DEBUG: [b'>N', b'h\x00'] 2020-11-24 20:11:06 DEBUG: [b'AC', b'\x16\xbb'] 2020-11-24 20:11:06 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 20:11:06 DEBUG: Running transaction 4 2020-11-24 20:11:06 DEBUG: SEND: 0x1 0x4 0x1 0x56 0x0 0x4 0x10 0x25 2020-11-24 20:11:06 DEBUG: Changing state to IDLE - Last Frame End - 1606245066. 019163, Current Time stamp - 1606245066.024257 2020-11-24 20:11:06 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 20:11:06 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:06 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 20:11:06 DEBUG: Changing transaction state from 'WAITING FOR REPLY' t o 'PROCESSING REPLY' 2020-11-24 20:11:06 DEBUG: RECV: 0x1 0x4 0x8 0x45 0xef 0x79 0x8d 0x44 0x62 0x91 0x17 0x41 0xca 2020-11-24 20:11:06 DEBUG: Getting Frame - 0x4 0x8 0x45 0xef 0x79 0x8d 0x44 0x62 0x91 0x17 2020-11-24 20:11:06 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:06 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:06 DEBUG: Adding transaction 1 2020-11-24 20:11:06 DEBUG: Getting transaction 1 2020-11-24 20:11:06 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:06 DEBUG: [17903, 31117, 17506, 37143] 2020-11-24 20:11:06 DEBUG: [b'E\xef', b'y\x8d'] 2020-11-24 20:11:06 DEBUG: [b'Db', b'\x91\x17'] 2020-11-24 20:11:06 DEBUG: [31117, 17903, 53215, 17002, 31117, 17903, 53215, 170 02, 13107, 16563, 13107, 16563, 0, 0, 0, 0, 0, 17258, 0, 17258, 0, 0, 0, 0, 0, 0 , 0, 0, 0, 0, 0, 0, 0, 16968] 2020-11-24 20:11:06 DEBUG: setValues[3] 1001:34 2020-11-24 20:11:06 DEBUG: [31117, 17903, 0, 0, 0, 0, 53215, 17002, 0, 0, 0, 0, 41966, 17901, 41966, 17901, 41966, 17901, 0, 0, 0, 0, 37143, 17506, 37143, 17506 , 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 63862, 15854, 63862, 15854, 0, 0, 0, 0, 0, 49730, 0, 49730, 0, 0, 0, 0, 23721, 16963, 23721, 16963, 0, 0, 0, 0, 57147, 159 51, 0, 0, 0, 0, 39847, 16566, 0, 0, 31813, 17719, 0, 0, 39847, 16566, 0, 0, 0, 0 ] 2020-11-24 20:11:06 DEBUG: setValues[3] 1101:82 2020-11-24 20:11:06 DEBUG: Getting Frame - 0x3 0x6 0x72 0x0 0x6 2020-11-24 20:11:06 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:06 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:06 DEBUG: validate: fc-[3] address-1651: count-6 2020-11-24 20:11:06 DEBUG: getValues fc-[3] address-1651: count-6 2020-11-24 20:11:06 DEBUG: send: [ReadRegisterResponse (6)]- b'02030c00000002000 40000000000054cd2' 2020-11-24 20:11:07 DEBUG: Getting Frame - 0x3 0x3 0xf2 0x0 0x6 2020-11-24 20:11:07 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:07 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:07 DEBUG: validate: fc-[3] address-1011: count-6 2020-11-24 20:11:07 DEBUG: getValues fc-[3] address-1011: count-6 2020-11-24 20:11:07 DEBUG: send: [ReadRegisterResponse (6)]- b'02030c333340b3000 00000000000004792' 2020-11-24 20:11:08 DEBUG: Getting Frame - 0x3 0x6 0xa4 0x0 0x17 2020-11-24 20:11:08 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:08 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:08 DEBUG: validate: fc-[3] address-1701: count-23 2020-11-24 20:11:08 DEBUG: getValues fc-[3] address-1701: count-23 2020-11-24 20:11:08 DEBUG: send: [ReadRegisterResponse (23)]- b'02032e1206000f0000000000000000000000190000000000000000000000000000000000000000000000000000000000004ae0' 2020-11-24 20:11:09 DEBUG: Getting Frame - 0x3 0x6 0xc8 0x0 0x1 2020-11-24 20:11:09 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:09 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:09 DEBUG: validate: fc-[3] address-1737: count-1 2020-11-24 20:11:09 DEBUG: getValues fc-[3] address-1737: count-1 2020-11-24 20:11:09 DEBUG: send: [ReadRegisterResponse (1)]- b'0203020000fc44' 2020-11-24 20:11:10 DEBUG: Getting Frame - 0x3 0x3 0xe8 0x0 0x22 2020-11-24 20:11:10 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:10 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:10 DEBUG: validate: fc-[3] address-1001: count-34 2020-11-24 20:11:10 DEBUG: getValues fc-[3] address-1001: count-34 2020-11-24 20:11:10 DEBUG: send: [ReadRegisterResponse (34)]- b'020344798d45efcfdf426a798d45efcfdf426a333340b3333340b300000000000000000000436a0000436a00000000000000000000000000000000000000000000000000004248ea17' 2020-11-24 20:11:11 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 20:11:11 DEBUG: Running transaction 5 2020-11-24 20:11:11 DEBUG: SEND: 0x1 0x4 0x0 0x0 0x0 0x50 0xf0 0x36 2020-11-24 20:11:11 DEBUG: Changing state to IDLE - Last Frame End - 1606245066.227322, Current Time stamp - 1606245071.241342 2020-11-24 20:11:11 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:11 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 20:11:11 DEBUG: Getting Frame - 0x3 0x4 0x4c 0x0 0x52 2020-11-24 20:11:11 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:11 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:11 DEBUG: validate: fc-[3] address-1101: count-82 2020-11-24 20:11:11 DEBUG: getValues fc-[3] address-1101: count-82 2020-11-24 20:11:11 DEBUG: send: [ReadRegisterResponse (82)]- b'0203a4798d45ef0000000000000000cfdf426a0000000000000000a3ee45eda3ee45eda3ee45ed00000000000000009117446291174462000000000000000000000000000000000000000000000000f9763deef9763dee00000000000000000000c2420000c24200000000000000005ca942435ca942430000000000000000df3b3e4f00000000000000009ba740b6000000007c454537000000009ba740b600000000000000009406' 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 20:11:12 DEBUG: RECV: 0x1 0x4 0xa0 0x43 0x69 0xb3 0x33 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3e 0x53 0xf7 0xcf 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0xb9 0x99 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x43 0x3f 0xc 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xc2 0x41 0x99 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xf4 0xe2 0x5a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x48 0x0 0x0 0x42 0x6a 0xcf 0xdf 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x53 0xf8 0xa1 0xf2 2020-11-24 20:11:12 DEBUG: Getting Frame - 0x4 0xa0 0x43 0x69 0xb3 0x33 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3e 0x53 0xf7 0xcf 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x40 0xb9 0x99 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x43 0x3f 0xc 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xc2 0x41 0x99 0x9a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3d 0xf4 0xe2 0x5a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x42 0x48 0x0 0x0 0x42 0x6a 0xcf 0xdf 0x45 0xed 0xa3 0xee 0x42 0xc9 0xe8 0xf6 0x44 0x49 0x53 0xf8 2020-11-24 20:11:12 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:12 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:12 DEBUG: Adding transaction 1 2020-11-24 20:11:12 DEBUG: Getting transaction 1 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:12 DEBUG: [17257, 45875, 0, 0, 0, 0, 15955, 63439, 0, 0, 0, 0, 16569, 39322, 0, 0, 0, 0, 16963, 16140, 0, 0, 0, 0, 49729, 39322, 0, 0, 0, 0, 15860, 57946, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 16968, 0, 17002, 53215, 17901, 41966, 17097, 59638, 17481, 21496] 2020-11-24 20:11:12 DEBUG: [b'Ci', b'\xb33'] 2020-11-24 20:11:12 DEBUG: [b'>S', b'\xf7\xcf'] 2020-11-24 20:11:12 DEBUG: [b'@\xb9', b'\x99\x9a'] 2020-11-24 20:11:12 DEBUG: [b'BC', b'?\x0c'] 2020-11-24 20:11:12 DEBUG: [b'\xc2A', b'\x99\x9a'] 2020-11-24 20:11:12 DEBUG: [b'=\xf4', b'\xe2Z'] 2020-11-24 20:11:12 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 20:11:12 DEBUG: [b'BH', b'\x00\x00'] 2020-11-24 20:11:12 DEBUG: [b'Bj', b'\xcf\xdf'] 2020-11-24 20:11:12 DEBUG: [b'E\xed', b'\xa3\xee'] 2020-11-24 20:11:12 DEBUG: [b'B\xc9', b'\xe8\xf6'] 2020-11-24 20:11:12 DEBUG: [b'DI', b'S\xf8'] 2020-11-24 20:11:12 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 20:11:12 DEBUG: Running transaction 6 2020-11-24 20:11:12 DEBUG: SEND: 0x1 0x4 0x0 0x54 0x0 0xc 0xb1 0xdf 2020-11-24 20:11:12 DEBUG: Changing state to IDLE - Last Frame End - 1606245072.197467, Current Time stamp - 1606245072.201264 2020-11-24 20:11:12 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 20:11:12 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 20:11:12 DEBUG: RECV: 0x1 0x4 0x18 0x40 0xb6 0x9b 0xa7 0x45 0x37 0x7c 0x45 0x40 0xb6 0x9b 0xa7 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x7c 0x45 0xd9 0xbe 2020-11-24 20:11:12 DEBUG: Getting Frame - 0x4 0x18 0x40 0xb6 0x9b 0xa7 0x45 0x37 0x7c 0x45 0x40 0xb6 0x9b 0xa7 0x41 0xe0 0xe1 0x39 0x0 0x0 0x0 0x0 0x45 0x37 0x7c 0x45 2020-11-24 20:11:12 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:12 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:12 DEBUG: Adding transaction 1 2020-11-24 20:11:12 DEBUG: Getting transaction 1 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:12 DEBUG: [16566, 39847, 17719, 31813, 16566, 39847, 16864, 57657, 0, 0, 17719, 31813] 2020-11-24 20:11:12 DEBUG: [b'@\xb6', b'\x9b\xa7'] 2020-11-24 20:11:12 DEBUG: [b'E7', b'|E'] 2020-11-24 20:11:12 DEBUG: [b'@\xb6', b'\x9b\xa7'] 2020-11-24 20:11:12 DEBUG: [b'A\xe0', b'\xe19'] 2020-11-24 20:11:12 DEBUG: [b'\x00\x00', b'\x00\x00'] 2020-11-24 20:11:12 DEBUG: [b'E7', b'|E'] 2020-11-24 20:11:12 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 20:11:12 DEBUG: Running transaction 7 2020-11-24 20:11:12 DEBUG: SEND: 0x1 0x4 0x1 0x2 0x0 0x8 0x51 0xf0 2020-11-24 20:11:12 DEBUG: Changing state to IDLE - Last Frame End - 1606245072.473211, Current Time stamp - 1606245072.476784 2020-11-24 20:11:12 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 20:11:12 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' 2020-11-24 20:11:12 DEBUG: Getting Frame - 0x3 0x3 0xf2 0x0 0x6 2020-11-24 20:11:12 DEBUG: Factory Request[ReadHoldingRegistersRequest: 3] 2020-11-24 20:11:12 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:12 DEBUG: validate: fc-[3] address-1011: count-6 2020-11-24 20:11:12 DEBUG: getValues fc-[3] address-1011: count-6 2020-11-24 20:11:12 DEBUG: send: [ReadRegisterResponse (6)]- b'02030c333340b300000000000000004792' 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 20:11:12 DEBUG: RECV: 0x1 0x4 0x10 0x3e 0x4e 0x68 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 0xc9 0x3b 2020-11-24 20:11:12 DEBUG: Getting Frame - 0x4 0x10 0x3e 0x4e 0x68 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x41 0x43 0x16 0xbb 2020-11-24 20:11:12 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:12 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:12 DEBUG: Adding transaction 1 2020-11-24 20:11:12 DEBUG: Getting transaction 1 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:12 DEBUG: [15950, 26624, 0, 0, 0, 0, 16707, 5819] 2020-11-24 20:11:12 DEBUG: [b'>N', b'h\x00'] 2020-11-24 20:11:12 DEBUG: [b'AC', b'\x16\xbb'] 2020-11-24 20:11:12 DEBUG: Current transaction state - TRANSACTION_COMPLETE 2020-11-24 20:11:12 DEBUG: Running transaction 8 2020-11-24 20:11:12 DEBUG: SEND: 0x1 0x4 0x1 0x56 0x0 0x4 0x10 0x25 2020-11-24 20:11:12 DEBUG: Changing state to IDLE - Last Frame End - 1606245072.71483, Current Time stamp - 1606245072.71753 2020-11-24 20:11:12 DEBUG: Waiting for 3.5 char before next send - 16.042 ms 2020-11-24 20:11:12 DEBUG: New Transaction state 'SENDING' 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'SENDING' to 'WAITING FOR REPLY' ^C2020-11-24 20:11:12 DEBUG: Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY' 2020-11-24 20:11:12 DEBUG: RECV: 0x1 0x4 0x8 0x45 0xef 0x79 0x8d 0x44 0x62 0x91 0x17 0x41 0xca 2020-11-24 20:11:12 DEBUG: Getting Frame - 0x4 0x8 0x45 0xef 0x79 0x8d 0x44 0x62 0x91 0x17 2020-11-24 20:11:12 DEBUG: Factory Response[ReadInputRegistersResponse: 4] 2020-11-24 20:11:12 DEBUG: Frame advanced, resetting header!! 2020-11-24 20:11:12 DEBUG: Adding transaction 1 2020-11-24 20:11:12 DEBUG: Getting transaction 1 2020-11-24 20:11:12 DEBUG: Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE' 2020-11-24 20:11:12 DEBUG: [17903, 31117, 17506, 37143] 2020-11-24 20:11:12 DEBUG: [b'E\xef', b'y\x8d'] 2020-11-24 20:11:12 DEBUG: [b'Db', b'\x91\x17'] 2020-11-24 20:11:12 DEBUG: [31117, 17903, 53215, 17002, 31117, 17903, 53215, 17002, 39322, 16569, 39322, 16569, 0, 0, 0, 0, 45875, 17257, 45875, 17257, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 16968] 2020-11-24 20:11:12 DEBUG: setValues[3] 1001:34 2020-11-24 20:11:12 DEBUG: [31117, 17903, 0, 0, 0, 0, 53215, 17002, 0, 0, 0, 0, 41966, 17901, 41966, 17901, 41966, 17901, 0, 0, 0, 0, 37143, 17506, 37143, 17506, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 57946, 15860, 57946, 15860, 0, 0, 0, 0, 39322, 49729, 39322, 49729, 0, 0, 0, 0, 16140, 16963, 16140, 16963, 0, 0, 0, 0, 63439, 15955, 0, 0, 0, 0, 39847, 16566, 0, 0, 31813, 17719, 0, 0, 39847, 16566, 0, 0, 0, 0] 2020-11-24 20:11:12 DEBUG: setValues[3] 1101:82

nmakel commented 3 years ago

So it looks like semp-rtu.py is communicating with your SDM120 fine. It also looks like your inverter is talking to semp-rtu.py, requesting values, and receiving those values. Are you still receiving the meter communication error? Are you seeing meter values in your SolarEdge phone application?

Maikel-K commented 3 years ago

Well I just noticed this changed in the appimage

So I guess something happened.

nmakel commented 3 years ago

That's a result of you adding a meter device in your inverter. Almost there.

The device page on your inverter display shows this, right?

R S 4 8 5 - 1 < M T R > < S E > < 2 >

If not, what does it display?

To double check, you went to the RS485-1 Conf page, then Device Type and selected Multi Devices. There you chose Revenue Meter and configured it like this:

D e v i c e T y p e < M T R > 
P r o t o c o l < S E > 
D e v i c e I D < 2 > 
C T   R a t i n g < 2 00 > 
M e t e r F u n c . < E + I > 
T o p o l o g y < W y e > 
P T S c a l i n g < 1 >
Maikel-K commented 3 years ago

image imageimage image imageimage image

nmakel commented 3 years ago

I think the issue is the configuration of your inverter. Would you happen to know whether your inverter came with a built in meter or not? SolarEdge calls this a RGM (revenue grade meter). If so, the configuration process is a little bit different.

Other than that, it looks like on this particular model of inverter the external meter needs to be defined as Meter 2. Can you try setting Meter 1 to device ID 1, and then adding a Meter 2 with the settings I posted above?

Maikel-K commented 3 years ago

I think it is setup correctly

If I have read it correctly .................Dev prot ## RS485-1 mlt 01 01

Where DEV is multi Where prot is ??? Where ## is how many meters connected

I have to check what PROT 01 means.

Oh and I tried to check it but it don't think I have the RGM, I have to double check again tomorrow, but I'm in Europe if that matters anything.

Edit: from the manual:

Dev: The type of device configured to this port. MLT indicates multiple meters. Prot: The number of configured meters. For dual meters it should display 2.

: The number of communicating meters. For dual meters it should display 2.

nmakel commented 3 years ago

I have no idea what options you have to choose from, so it is difficult for me to suggest what to try. All I can recommend is that you read through the document I linked to, and try the two methods described in there.

One way to sidestep the entire built-in meter issue is to connect your Pi to RS485-2 and then configure a new meter in your inverter on that port.

nmakel commented 3 years ago

: The number of communicating meters. For dual meters it should display 2.

You should have this:

               D e v   P r o t   # # 
R S 4 8 5 - 1 < M T R > < S E > < 1 >

Whereas you have:

               D e v   P r o t   # # 
R S 4 8 5 - 1 < M L T > < 01 > < 01 >
Maikel-K commented 3 years ago

Well, maybe my edit came to late but this came from the manual:

Dev: The type of device configured to this port. MLT indicates multiple meters. Prot: The number of configured meters. For dual meters it should display 2.

: The number of communicating meters. For dual meters it should display 2.

So I think we got an older inverter running with serial connection! Great news I guess for me and also for your script! Another box ticked ✅ You could use my photos as example maybe?

nmakel commented 3 years ago

So... it's working?

Maikel-K commented 3 years ago

I think so, but this SDM120 I have connected as productionmeter to verify the SolarEdge. image image image

I have ordered two RS485 gateways from Aliexpress:

€ 8,03 7％ Off | Serial port RS485 to WiFi device server module Elfin-EW11 support TCP/IP Telnet Modbus TCP Protocol data transfer via WiFi https://a.aliexpress.com/_m0dAIpX

So I will connect that one to the SDM630 in the metercabinet too get the real import/export values. So maybe your work now sounds as useless, your script is working with serial comms now too!

nmakel commented 3 years ago

Aha! I think I was confused by your pictures in that case. If the SDM120 is connected as a production meter you should probably configure it as such, and not as an import+export device. Once you connect the SDM630 as an import+export meter you should be seeing real-time usage values in the SolarEdge app.

Thanks a lot for helping me work out the various bugs in the serial portion of the script. No doubt there will be more bugs when multiple meters are configured, so keep me posted on how things are working once you receive your modbus tcp gateways.

Maikel-K commented 3 years ago

For now i will not run the script till those gateways arrive, but it got me thinking... Ethernet Cable is wired with 8 wires but using only 4. Maybe I could splice the cable and use 2 of the wires to get the Modbus up to the attic where the RPI and inverter are... that's also an option haha. Then I will have a gateway as spare.

Another question: Do you think the inverter and SDM could both be running on a seperate RS485 gateway?

Maikel-K commented 3 years ago

Aha! I think I was confused by your pictures in that case. If the SDM120 is connected as a production meter you should probably configure it as such, and not as an import+export device. Once you connect the SDM630 as an import+export meter you should be seeing real-time usage values in the SolarEdge app.

Thanks a lot for helping me work out the various bugs in the serial portion of the script. No doubt there will be more bugs when multiple meters are configured, so keep me posted on how things are working once you receive your modbus tcp gateways.

By the way, no problem helping you out! I want to thank you too for getting it to work!

nmakel commented 3 years ago

Another question: Do you think the inverter and SDM could both be running on a seperate RS485 gateway?

Not sure what you're intending to do. Which of your SDM, and for what purpose, this script or something else?

Maikel-K commented 3 years ago

I want to move the RPI to another place in the house and use RS485 gateway for the inverter too.

nmakel commented 3 years ago

I want to move the RPI to another place in the house and use RS485 gateway for the inverter too.

The SDM meters can be connected to via Modbus TCP no problem. Using the RS485 to Modbus TCP converter you ordered from aliexpress should work fine. I have not tried connecting the inverter to such a converter, so I cannot say whether there is a mode through which the server part of semp-rtu.py will work. If the converter can transparently pass the messages from the inverter to the device on which semp-rtu is listening, it may work just fine. You will likely need a modbus tcp version of solaredge_meterproxy in that case.

Maikel-K commented 3 years ago

Hi Niels,

So it's not as simple as for reading the SDM via tcp or rtu like changing devicetype to host etc?

If you want, do you want to make your script even more flexible than it already is? Then we can try and make that work on my inverter?

If not I will leave the RPI next to the inverter.

nmakel commented 3 years ago

So it's not as simple as for reading the SDM via tcp or rtu like changing devicetype to host etc?

I just uploaded semp-tcp.py, which creates a TCP server instead of an RTU serial server. You will also need semp-tcp.conf. All other configuration, of your source meter, can remain the same.

Untested, untried, but might just work.

Maikel-K commented 3 years ago

Wow, great! As soon as they arrive I will try and make it work!

How should the TCP modules be setup? I saw we can choose multiple protocols if I understood it correctly atleast.

image image image

nmakel commented 3 years ago

Not sure. Ideally you can tell the gateway to forward all frames to an IP address you specify. If I understand the terminology of the gateway correctly this means the gateway must be configured as a TCP Client configured to connect to the IP/port on which semp-tcp.py is listening.

Maikel-K commented 3 years ago

Okay, so it doesn't need to run as transparent mode.

Great, I just recieved an update from AliExpress that the parcel is in the Netherlands! We wait for it.

Side question: would it be easy to make the script send the data from the SDM to MQTT too?

nmakel commented 3 years ago

Side question: would it be easy to make the script send the data from the SDM to MQTT too?

It is possible to have multiple processes talk to the same Modbus device through those gateways. While you should be able to modify the sdm120.py script in /devices/, you should probably find software which is made for that purpose.

Maikel-K commented 3 years ago

I will try, I can understand you don't feel the need to make this script a octopus capable of serving everybody's wishes!

I will try with my low coding skills to see if I can make something up and see if multiple devices can connect to that gateway as written in the manual.