search

jmccrohan / pysolarmanv5

A python module to interact with Solarman Data Logging Sticks
MIT License
126 stars 27 forks source link

V5 frame contains invalid sequence number #19

Closed Xhanti closed 1 year ago

Xhanti commented 2 years ago

Hi,

Thank you for this very promising library, I have a Deye 5 KW and after a few issues my side I got almost everything working.

The Issue I face is that I can read registers fine for a min or 2 and then I get these errors and it never comes right: V5 frame contains invalid sequence number. I've tried to re-initialize the PySolarmanV5 object (my python is pretty rust so I could have done it wrong) but still no luck.

Can you spot anything wrong my implementation?

import time
from datetime import datetime
from pysolarmanv5 import PySolarmanV5

modbus = PySolarmanV5("192.***.***.***", 23********, port=8899, mb_slave_id=1, verbose=False)

def main():
    while True:
        global modbus
        try:
            inverterMetric = modbus.read_holding_registers(register_addr=170, quantity=1)[0]
            print(datetime.today().strftime('%Y-%m-%d %H:%M:%S') +" : ", inverterMetric)
        except Exception as ex:
            print(ex)
            modbus = PySolarmanV5("192.***.***.***", 23********, port=8899, mb_slave_id=1, verbose=False);

        time.sleep(30)

if __name__ == "__main__":
    main()
jmccrohan commented 2 years ago

Hi @Xhanti,

If you are throwing a V5 frame contains invalid sequence number exception, that means you are running the latest git, rather than v2.4.0. I added sequence number validation in https://github.com/jmccrohan/pysolarmanv5/commit/edeee309191cedb4b16437b66a852276740e6594. This generates a random sequence number on initialisation, includes it on outgoing requests, validates that same sequence number on incoming responses (byte 05 in both outgoing and incoming requests). The sequence number is then incremented for each subsequent request.

It sounds like your data logger is encountering an issue, and the sequences are diverging. I have noticed this issue occasionally on my logger, but they reconverge after about 2-3 requests.

Could you enable verbose mode and post up the output please?

What I'm expecting to see is output like the following:

DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 0a 00 11 22 33 44 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 81 21 00 02 09 fd bc 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 17 00 10 15 0a 50 11 22 33 44 02 01 7b 48 bd 01 91 15 00 00 25 2a 59 61 01 04 04 00 00 00 00 fb 84 e6 15

DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 0b 00 11 22 33 44 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 81 21 00 02 09 fd bd 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 17 00 10 15 0b 51 11 22 33 44 02 01 7b 48 bd 01 92 15 00 00 25 2a 59 61 01 04 04 00 00 00 00 fb 84 e9 15

DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 0c 00 11 22 33 44 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 81 21 00 02 09 fd be 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 17 00 10 15 0c 52 11 22 33 44 02 01 7c 48 bd 01 92 15 00 00 25 2a 59 61 01 04 04 00 00 00 00 fb 84 ec 15

DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 0d 00 11 22 33 44 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 81 21 00 02 09 fd bf 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 17 00 10 15 0f 53 11 22 33 44 02 01 7d 48 bd 01 93 15 00 00 25 2a 59 61 01 04 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 fb 84 f0 15
pysolarmanv5.pysolarmanv5.V5FrameError: V5 frame contains invalid sequence number.

In the contrived example above, the error is thrown because byte 05 doesn't match (0f != 0d).

Perhaps your logger version isn't able to recover from this issue, and the less stringent validation would work better for you? Could you please retest your script using v2.4.0 from PyPI and report back? If it works, I'll make the new validation optional for the next release.

Thanks, Jon

Xhanti commented 2 years ago

Hi,

Here is the output with verbose logging enabled:

DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 97 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 32 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 97 6c aa 4c 2c 8e 02 01 b6 a6 0f 00 1b 27 00 00 53 76 07 63 01 03 02 01 0a 39 d3 ed 15
2022-09-06 12:12:28
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 98 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 33 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 01 00 10 47 97 6d aa 4c 2c 8e 00 0c 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 d4 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 6f 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 98 6e aa 4c 2c 8e 02 01 d4 a6 0f 00 3a 27 00 00 53 76 07 63 01 03 02 01 2a 38 0b 84 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 47 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a e2 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 d4 6f aa 4c 2c 8e 02 01 f2 a6 0f 00 58 27 00 00 53 76 07 63 01 03 02 0f 59 7d 8e 02 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 1c 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a b7 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 47 70 aa 4c 2c 8e 02 01 10 a7 0f 00 76 27 00 00 53 76 07 63 01 03 02 01 08 b8 12 13 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 34 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a cf 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 1c 71 aa 4c 2c 8e 02 01 30 a7 0f 00 96 27 00 00 53 76 07 63 01 03 02 01 05 79 d7 ac 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 d1 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 6c 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 34 73 aa 4c 2c 8e 02 01 4c a7 0f 00 b2 27 00 00 51 76 07 63 01 03 02 01 04 b8 17 7a 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 e6 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 81 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 d1 74 aa 4c 2c 8e 02 01 7a a7 0f 00 e0 27 00 00 51 76 07 63 01 03 02 01 03 f9 d5 72 15 a5 01 00 10 47 d1 75 aa 4c 2c 8e 00 4e 15
DEBUG:pysolarmanv5.pysolarmanv5:frame_len does not match payload_len.
V5 frame contains invalid V5 checksum
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 db 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 76 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 e6 76 aa 4c 2c 8e 02 01 8c a7 0f 00 f2 27 00 00 51 76 07 63 01 03 02 01 0a 39 d3 f2 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 75 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 10 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 db 77 aa 4c 2c 8e 02 01 a6 a7 0f 00 0c 28 00 00 51 76 07 63 01 03 02 01 12 39 d9 2b 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 3c 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a d7 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 75 78 aa 4c 2c 8e 02 01 ca a7 0f 00 30 28 00 00 51 76 07 63 01 03 02 01 0f f9 d0 c2 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 1a 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a b5 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 3c 79 aa 4c 2c 8e 02 01 e2 a7 0f 00 48 28 00 00 51 76 07 63 01 03 02 01 0e 38 10 38 15 a5 01 00 10 47 3c 7a aa 4c 2c 8e 00 be 15
DEBUG:pysolarmanv5.pysolarmanv5:frame_len does not match payload_len.
V5 frame contains invalid V5 checksum
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 7a 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 15 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 1a 7b aa 4c 2c 8e 02 01 00 a8 0f 00 66 28 00 00 51 76 07 63 01 03 02 0e b3 fd 91 4d 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 5d 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a f8 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 7a 7c aa 4c 2c 8e 02 01 20 a8 0f 00 86 28 00 00 51 76 07 63 01 03 02 00 f7 f9 c2 51 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 c8 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 63 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 5d 7d aa 4c 2c 8e 02 01 3c a8 0f 00 a2 28 00 00 51 76 07 63 01 03 02 01 04 b8 17 8f 15
V5 frame contains invalid sequence number
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 ad 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 48 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 c8 7e aa 4c 2c 8e 02 01 6a a8 0f 00 d0 28 00 00 51 76 07 63 01 03 02 00 fc b8 05 3c 15 a5 01 00 10 47 c8 7f aa 4c 2c 8e 00 4f 15
DEBUG:pysolarmanv5.pysolarmanv5:frame_len does not match payload_len.
V5 frame contains invalid V5 checksum
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 ec 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 87 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 ad 80 aa 4c 2c 8e 02 01 7c a8 0f 00 e2 28 00 00 51 76 07 63 01 03 02 00 fd 79 c5 c9 15
V5 frame contains invalid sequence number

My logger does not come right looks like.

Xhanti commented 2 years ago

Using 2.40 is alot better but the odd error here and there that comes right soon after

2022-09-06 12:35:59
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 1d aa 4c 2c 8e 02 01 37 ac 0f 00 66 02 00 00 59 76 07 63 01 03 02 02 d4 b9 7b ad 15
2022-09-06 12:36:29
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 1e aa 4c 2c 8e 02 01 4e ac 0f 00 7e 02 00 00 59 76 07 63 01 03 02 01 84 b9 b7 c8 15
2022-09-06 12:36:59
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 1f aa 4c 2c 8e 02 01 6d ac 0f 00 9c 02 00 00 59 76 07 63 01 03 02 01 9c b9 bd 24 15 a5 01 00 10 47 00 20 aa 4c 2c 8e 00 28 15
DEBUG:pysolarmanv5.pysolarmanv5:frame_len does not match payload_len.
V5 frame contains invalid V5 checksum
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 21 aa 4c 2c 8e 02 01 8d ac 0f 00 bc 02 00 00 59 76 07 63 01 03 02 01 6e 38 38 32 15
2022-09-06 12:37:59
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 22 aa 4c 2c 8e 02 01 a8 ac 0f 00 d8 02 00 00 59 76 07 63 01 03 02 01 38 b8 06 82 15
2022-09-06 12:38:29
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 23 aa 4c 2c 8e 02 01 d7 ac 0f 00 06 03 00 00 59 76 07 63 01 03 02 01 14 b9 db 93 15
2022-09-06 12:38:59
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 24 aa 4c 2c 8e 02 01 e9 ac 0f 00 18 03 00 00 59 76 07 63 01 03 02 00 ec b9 c9 7d 15 a5 01 00 10 47 00 25 aa 4c 2c 8e 00 2d 15
DEBUG:pysolarmanv5.pysolarmanv5:frame_len does not match payload_len.
V5 frame contains invalid V5 checksum
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 26 aa 4c 2c 8e 02 01 07 ad 0f 00 36 03 00 00 59 76 07 63 01 03 02 00 bb f8 37 38 15
2022-09-06 12:39:59
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 28 aa 4c 2c 8e 02 01 22 ad 0f 00 52 03 00 00 59 76 07 63 01 03 02 00 c2 39 d5 57 15
2022-09-06 12:40:29
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 29 aa 4c 2c 8e 02 01 4b ad 0f 00 7a 03 00 00 59 76 07 63 01 03 02 00 b4 b8 33 78 15
2022-09-06 12:40:59
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 00 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 9b 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 00 2a aa 4c 2c 8e 02 01 5d ad 0f 00 8c 03 00 00 59 76 07 63 01 03 02 00 b5 79 f3 1f 15 a5 01 00 10 47 00 2b aa 4c 2c 8e 00 33 15
DEBUG:pysolarmanv5.pysolarmanv5:frame_len does not match payload_len.
V5 frame contains invalid V5 checksum
Xhanti commented 2 years ago

Newing one up per loop seems to produce the least errors. My concern there though is the use of too many sockets, i'm going to use this to save entries in a db and visualize some metrics and need it run unattended for months. I think creating a new pysolarmanv5 instance every 30 seconds is fast enough to re-use the previous socket, but will have to test and see what's what

P.S : Is it advisable to query more often then every 30 seconds or is that the limit with the WIFI dongle?

Regards

jmccrohan commented 2 years ago

Newing one up per loop seems to produce the least errors. My concern there though is the use of too many sockets, i'm going to use this to save entries in a db and visualize some metrics and need it run unattended for months. I think creating a new pysolarmanv5 instance every 30 seconds is fast enough to re-use the previous socket, but will have to test and see what's what

Creating a new instance on every exception is the cause of your issues in this case. See analysis of your (latest git) traces below:

DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 97 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 32 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 97 6c aa 4c 2c 8e 02 01 b6 a6 0f 00 1b 27 00 00 53 76 07 63 01 03 02 01 0a 39 d3 ed 15
2022-09-06 12:12:28
DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 98 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 33 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 01 00 10 47 97 6d aa 4c 2c 8e 00 0c 15
V5 frame contains invalid sequence number
                                                     ^^

You've received a spurious response from your logger. You sent sequence number 98 (underlined with ^^ above), but received the previous sequence number of 97. Invalid frame.

DEBUG:pysolarmanv5.pysolarmanv5:SENT: a5 17 00 10 45 d4 00 aa 4c 2c 8e 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 aa 00 01 a4 2a 6f 15
DEBUG:pysolarmanv5.pysolarmanv5:RECD: a5 15 00 10 15 98 6e aa 4c 2c 8e 02 01 d4 a6 0f 00 3a 27 00 00 53 76 07 63 01 03 02 01 2a 38 0b 84 15
V5 frame contains invalid sequence number

You've caught the exception and created a new pysolarmanv5 instance. The new instance generates a new initial sequence number of d4. However, your logger has now sent the response to the previous frame, with seq 98. Can I suggest you amend your script to except V5FrameError only, and retry the request rather than create a new pysolarmanv5 instance. Based on the traces you have supplied it does suggest that your data logger does indeed fix itself and the sequence number reconverges.

P.S : Is it advisable to query more often then every 30 seconds or is that the limit with the WIFI dongle?

It depends on the number of, and the size of the requests, but you should be able to query more frequently than 30 seconds. Increasing the frequency will increase the risk of a malformed response, so I think the sequence number functionality added in git will be helpful in that regard.

Regards, Jon

githubDante commented 1 year ago

The reason for the mismatched sequence numbers is a bit strange. According to my observations the logger is broadcasting the responses on port 8899. You may have many clients connected to the logger and when one of the clients sends a request for data the response is propagated back to all clients currently connected. A quick confirmation of this is possible with a single connection from a pysolarmanv5 client and several telnet clients. Then only the pysolarmanv5 is requesting data but the responses will be seen by all telnet clients as well.

Edit: The data received from other requests is buffered in the pysolarmanv5 socket and on call to sock.recv() the buffered data is seen first which in turn causes the error.

danfoster commented 1 year ago

Hi, I wanted to contribute to this discussion, as I'm having similar problems.

Thanks for implementing the sequence number checking, when running the version on pypi, I was getting V5 frame contains incorrect control code, followed by a number of struct.unpack errors on retries. Eventually I would get a valid response, but the data would be incorrect, I think this is because it was just eventually managing to parse something in valid, even if it was the incorrect frame number.

Now that I've upgraded to the version on git, once I hit the V5 frame contains invalid sequence number error, even on retrying, it never recovers as it's always out-by-one. What's interesting is I seem to get 2 reply's for the same sequence number:

2023-03-17 18:52:37.165 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] SENT: a5 17 00 10 45 19 00 d2 b5 ac f3 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 80 e8 00 64 58 15 eb 15
2023-03-17 18:52:37.544 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] RECD: a5 db 00 10 15 19 c4 d2 b5 ac f3 02 01 ba ef 36 38 75 19 00 00 3b c7 dd 2b 01 04 c8 00 f5 00 25 00 35 00 01 31 36 30 46 35 32 32 31 37 32 33 30 31 35 31 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 17 00 03 00 11 00 12 00 34 00 23 00 00 00 00 18 b0 00 00 00 ee 00 00 00 eb 00 a9 00 69 00 00 02 bd 00 00 15 f3 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 8c 00 00 03 e9 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 00 0e 74 00 00 09 13 00 00 00 00 00 0e 00 00 00 00 00 00 01 54 00 00 00 00 00 00 01 4a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 34 01 3f 13 8d 00 03 f8 2f 00 00 00 08 00 00 8b 81 08 15
2023-03-17 18:52:37.546 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] SENT: a5 17 00 10 45 1a 00 d2 b5 ac f3 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 81 4c 00 64 18 0a 06 15
2023-03-17 18:52:37.954 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] RECD: a5 db 00 10 15 1a c5 d2 b5 ac f3 02 01 ba ef 36 38 75 19 00 00 3b c7 dd 2b 01 04 c8 00 00 00 00 00 00 00 00 27 10 03 e8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00 00 00 00 00 00 00 00 07 01 00 00 00 00 00 00 00 00 00 2f c2 68 09 29 01 39 ff ff ff f6 00 11 02 0f 00 65 00 01 0c 13 09 13 00 0e 00 5f 00 64 14 c8 00 52 03 e8 07 6c 00 00 00 00 01 75 00 00 00 00 02 14 00 00 01 6b 00 00 00 00 00 00 00 00 00 22 00 00 00 00 00 05 00 00 07 ed 00 55 00 23 00 00 0a 80 00 13 00 3b 00 00 05 4c 00 10 00 31 00 00 06 ed 00 03 00 00 00 00 18 52 00 77 00 b0 00 00 00 00 16 9a 00 00 00 5a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 59 75 dc 15
2023-03-17 18:52:37.956 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] SENT: a5 17 00 10 45 1b 00 d2 b5 ac f3 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 81 b0 00 56 59 ef 83 15
2023-03-17 18:52:38.296 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] RECD: a5 bf 00 10 15 1b c6 d2 b5 ac f3 02 01 ba ef 36 38 76 19 00 00 3b c7 dd 2b 01 04 ac 00 01 08 fc 13 88 00 01 00 01 00 68 02 8a 02 8a 01 cc 02 17 02 44 02 53 00 00 00 0f 00 0c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 32 00 01 00 00 00 12 09 2a 01 38 00 00 00 00 00 00 00 00 00 00 00 05 00 00 00 00 00 00 00 00 00 00 00 05 00 00 02 88 00 00 00 00 00 00 00 00 00 00 02 88 00 00 02 88 00 00 00 00 00 00 00 00 00 00 02 88 00 00 13 8b 00 02 11 d4 00 02 8e 72 77 15
[... 60 seconds pass ...]
2023-03-17 18:53:38.068 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] SENT: a5 17 00 10 45 1c 00 d2 b5 ac f3 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 80 e8 00 64 58 15 ee 15
2023-03-17 18:53:38.069 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] RECD: a5 01 00 10 47 1b c7 d2 b5 ac f3 00 60 15
2023-03-17 18:53:38.070 INFO (MainThread) [solis.solis] [1/10] Error Updating: V5 frame contains invalid sequence number
2023-03-17 18:53:38.075 DEBUG (MainThread) [solis.solis] Traceback (most recent call last):
  File "/workspaces/home-assistant-core/config/deps/solis/src/solis/solis.py", line 42, in async_update
    self.regs = self.get_regs()
  File "/workspaces/home-assistant-core/config/deps/solis/src/solis/solis.py", line 29, in get_regs
    regs = self.modbus.read_input_registers(self.reg_start, 100)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 368, in read_input_registers
    modbus_values = self._get_modbus_response(mb_request_frame)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 282, in _get_modbus_response
    mb_response_frame = self._send_receive_modbus_frame(mb_request_frame)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 270, in _send_receive_modbus_frame
    mb_response_frame = self._v5_frame_decoder(v5_response_frame)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 227, in _v5_frame_decoder
    raise V5FrameError("V5 frame contains invalid sequence number")
pysolarmanv5.pysolarmanv5.V5FrameError: V5 frame contains invalid sequence number

2023-03-17 18:53:39.076 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] SENT: a5 17 00 10 45 1d 00 d2 b5 ac f3 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 04 80 e8 00 64 58 15 ef 15
2023-03-17 18:53:39.077 DEBUG (MainThread) [pysolarmanv5.pysolarmanv5] RECD: a5 db 00 10 15 1c c8 d2 b5 ac f3 02 01 f7 ef 36 38 b2 19 00 00 3b c7 dd 2b 01 04 c8 00 f5 00 25 00 35 00 01 31 36 30 46 35 32 32 31 37 32 33 30 31 35 31 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 17 00 03 00 11 00 12 00 35 00 23 00 00 00 00 18 b0 00 00 00 ee 00 00 00 eb 00 a9 00 69 00 00 02 bd 00 00 15 f3 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 0b 00 00 03 78 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 00 0e 82 00 00 09 12 00 00 00 00 00 0d 00 00 00 00 00 00 01 2c 00 00 00 00 00 00 01 2c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 34 01 3e 13 8e 00 03 f8 2f 00 00 00 08 00 00 50 f5 97 15
2023-03-17 18:53:39.077 INFO (MainThread) [solis.solis] [2/10] Error Updating: V5 frame contains invalid sequence number
2023-03-17 18:53:39.078 DEBUG (MainThread) [solis.solis] Traceback (most recent call last):
  File "/workspaces/home-assistant-core/config/deps/solis/src/solis/solis.py", line 42, in async_update
    self.regs = self.get_regs()
  File "/workspaces/home-assistant-core/config/deps/solis/src/solis/solis.py", line 29, in get_regs
    regs = self.modbus.read_input_registers(self.reg_start, 100)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 368, in read_input_registers
    modbus_values = self._get_modbus_response(mb_request_frame)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 282, in _get_modbus_response
    mb_response_frame = self._send_receive_modbus_frame(mb_request_frame)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 270, in _send_receive_modbus_frame
    mb_response_frame = self._v5_frame_decoder(v5_response_frame)
  File "/workspaces/home-assistant-core/config/deps/pysolarmanv5/pysolarmanv5/pysolarmanv5.py", line 227, in _v5_frame_decoder
    raise V5FrameError("V5 frame contains invalid sequence number")
pysolarmanv5.pysolarmanv5.V5FrameError: V5 frame contains invalid sequence number
[ ... seq num is always one out ...]

Any idea what this sort reply of a5 01 00 10 47 1b c7 d2 b5 ac f3 00 60 15 is? I'm always requesting the following, in a 60 loop: 100 registers, 100 registers, 86 registers. So to see such a small reply is confusing.

I don't have any other clients talking to the datalogger modbus interface, but it is still configured to report to the solarmanpv.com endpoints as per it's default config.

Any ideas on where to look next would be appreciated.

githubDante commented 1 year ago

The short packets are kind of a ping. They occur if the connection has been opened for a longer period. It seems that the best solution at the moment is to close the connection and to create a new instance of PySolarmanV5 on the next iteration.

danfoster commented 1 year ago

Are there any other situations where >1 response is generated for a request? Or is it only pings? It looks like pysolarmanv5 doesn't handle >1 response for a single request (i.e. where the first byte of the serial stays the same, but the 2nd byte changes).

What do you think about a change to pysolarmanv5 where when receiving a response payload, if the first byte of serial is n-1, then it discards it and attempts to recv a new response payload? This would effectively throw away any extra responses from a given request, but at least it wouldn't break the sequence ordering and allow subsequent responses to work.

Xhanti commented 1 year ago

This is what I ended up doing and it works well. When the connection fails, I new up pysolarman and carry on. I see here the author of this library has some retry logic on there and this might help. This is fantastic library by the way, saved me tons of effort

githubDante commented 1 year ago

What do you think about a change to pysolarmanv5 where when receiving a response payload, if the first byte of serial is n-1, then it discards it and attempts to recv a new response payload? This would effectively throw away any extra responses from a given request, but at least it wouldn't break the sequence ordering and allow subsequent responses to work.

I'm already doing it in an async version of pysolarman. It seems to work well. Data which is not requested is discarded. Own requests are processed without errors for now

DEBUG:pysolarmanv5.pysolarmanv5_async:Data received but nobody waits for it... Discarded
DEBUG:pysolarmanv5.pysolarmanv5_async:b'\xa5\x15\x00\x10\x15\x00KJ\xbf\xa6\xa1\x02\x01\xa9\xa78\x00s!\x00\x00Z1\xdcc\x01\x03\x02\x00f8n\xd0\x15'
asyncio.run_coroutine_threadsafe(logger.read_holding_registers(62, 2), loop)
<Future at 0x7fda004690c0 state=pending>
<_UnixSelectorEventLoop running=True closed=False debug=False>
DEBUG:pysolarmanv5.pysolarmanv5_async:SENT: a5 17 00 10 45 56 00 4a bf a6 a1 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 3e 00 02 a5 c7 c4 15
DEBUG:pysolarmanv5.pysolarmanv5_async:RECD: a5 17 00 10 15 56 4c 4a bf a6 a1 02 01 bf a7 38 00 8a 21 00 00 5a 31 dc 63 01 03 04 17 03 11 17 43 d9 aa 15
DEBUG:pysolarmanv5.pysolarmanv5_async:Data received but nobody waits for it... Discarded
DEBUG:pysolarmanv5.pysolarmanv5_async:b'\xa5\x01\x00\x10GVMJ\xbf\xa6\xa1\x00K\x15'
DEBUG:pysolarmanv5.pysolarmanv5_async:Looks like ping. Sending back to the logger
asyncio.run_coroutine_threadsafe(logger.read_holding_registers(62, 2), loop)
<Future at 0x7fda00469090 state=pending>
<_UnixSelectorEventLoop running=True closed=False debug=False>
DEBUG:pysolarmanv5.pysolarmanv5_async:SENT: a5 17 00 10 45 57 00 4a bf a6 a1 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 3e 00 02 a5 c7 c5 15
DEBUG:pysolarmanv5.pysolarmanv5_async:RECD: a5 17 00 10 15 57 4f 4a bf a6 a1 02 01 d8 a7 38 00 a2 21 00 00 5a 31 dc 63 01 03 04 17 03 11 17 43 d9 df 15
asyncio.run_coroutine_threadsafe(logger.read_holding_registers(62, 3), loop)
<Future at 0x7fda0046bf40 state=pending>
<_UnixSelectorEventLoop running=True closed=False debug=False>
DEBUG:pysolarmanv5.pysolarmanv5_async:SENT: a5 17 00 10 45 58 00 4a bf a6 a1 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 03 00 3e 00 03 64 07 c6 15
DEBUG:pysolarmanv5.pysolarmanv5_async:RECD: a5 19 00 10 15 58 50 4a bf a6 a1 02 01 eb a7 38 00 b5 21 00 00 5a 31 dc 63 01 03 06 17 03 11 17 13 00 de 5a 3a 15
danfoster commented 1 year ago

Nice! Is your async version available for others to use?

githubDante commented 1 year ago

Just pushed a WIP version

jmccrohan commented 1 year ago

@danfoster @Xhanti @githubDante Thanks for the further research and the suggestion to discard the n-1 responses and retry. I'll do some testing here and hopefully push something this week.

@githubDante Thanks also for publishing your async version. I'll reply separately on PR #28.