Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

VEDirect Error over new emoncms installation #160

Open
maumauns opened this issue Sep 9, 2021 · 39 comments
Open

VEDirect Error over new emoncms installation #160

maumauns opened this issue Sep 9, 2021 · 39 comments

Comments

@maumauns
Copy link

maumauns commented Sep 9, 2021

Hi all, I need help with these error on vedirect.
All was working good until I updated to emonSD-08May21
I’m getting checksum errors, but it doenst happen with older version of emonSD
Any help??

``Traceback (most recent call last):
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 135, in _read_serial
packet = self.input(self._ser.read())
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 61, in input
if self.key.decode() == 'Checksum':
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbe in position 1477: invalid start byte
2021-09-05 05:04:33,570 DEBUG VEDirect Starting Serial read from Serial(port='/dev/ttyUSB0', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-09-05 05:04:33,573 ERROR VEDirect Read error
Traceback (most recent call last):
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 135, in _read_serial
packet = self.input(self._ser.read())
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 61, in input
if self.key.decode() == 'Checksum':
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbe in position 1477: invalid start byte
2021-09-05 05:04:38,597 DEBUG VEDirect Starting Serial read from Serial(port='/dev/ttyUSB0', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-09-05 05:04:38,599 ERROR VEDirect Read error
Traceback (most recent call last):
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 135, in _read_serial
packet = self.input(self._ser.read())
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 61, in input
if self.key.decode() == 'Checksum':
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbe in position 1477: invalid start byte
2021-09-05 05:04:43,687 DEBUG VEDirect Starting Serial read from Serial(port='/dev/ttyUSB0', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-09-05 05:04:43,689 ERROR VEDirect Read error
Traceback (most recent call last):
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 135, in _read_serial
packet = self.input(self._ser.read())
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 61, in input
if self.key.decode() == 'Checksum':
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xbe in position 1477: invalid start byte

LOG LEVEL: DEBUG #(DEFAULT:WARNING) ``

@eroyee
Copy link

eroyee commented Nov 12, 2021

Also reporting a similar error here.

In my case the VEDirect data is collected and processed OK for a minute or two, then it fails per this log extract:

2021-11-13 11:05:47,764 INFO MainThread EmonHub emonHub (emon-pi variant) v2.2.6
2021-11-13 11:05:47,764 INFO MainThread Opening hub...
2021-11-13 11:05:47,764 WARNING MainThread Setting emoncmsorg apikey: obscured
2021-11-13 11:05:57,827 ERROR VEDirect Invalid checksum, discarding data
2021-11-13 11:09:08,467 ERROR VEDirect Invalid checksum, discarding data
2021-11-13 11:09:48,586 ERROR VEDirect Read error
Traceback (most recent call last):
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 135, in _read_serial
packet = self.input(self._ser.read())
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 61, in input
if self.key.decode() == 'Checksum':
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x89 in position 3: invalid start byte
2021-11-13 11:09:58,627 ERROR VEDirect Read error

etc etc...

Presently this is running on an i7/Ubuntu 18.04 (fully up-to-date), and the emonhub installation is as of yesterday.

I've tried three different Victron devices, and two different cables direct to the PC, it may be a little worse if I insert a USB hub but I've not really looked into that in depth. I have zero read issues using direct serial to emonhub from an Arduino.

HTH, happy to supply further details or trial anything as needed. If I happen to run across a solution I'll follow up.

@eroyee
Copy link

eroyee commented Nov 12, 2021

Updated information with debug log. Not sure it helps much but this shows the last correct frame, followed by the failure (which remains at issue thereafter):

2021-11-13 12:09:38,592 DEBUG VEDirect Starting Serial read from Serial<id=0x7ffbd4ecc048, open=True>(port='/dev/ttyUSB2', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-11-13 12:09:38,594 DEBUG VEDirect 61 NEW FRAME : {'PID': '0xA057', 'FW': '154', 'SER#': 'HQ2035I1QX1', 'V': '13540', 'I': '10400', 'VPV': '35490', 'PPV': '144', 'CS': '3', 'MPPT': '2', 'OR': '0x00000000', 'ERR': '0', 'LOAD': 'OFF', 'H19': '15150', 'H20': '47', 'H21': '450', 'H\x0022': '169', 'H23': '593', 'HSDS': '195'}
2021-11-13 12:09:38,594 DEBUG VEDirect 61 Timestamp : 1636758578.594421
2021-11-13 12:09:38,594 DEBUG VEDirect 61 From Node : 9
2021-11-13 12:09:38,594 DEBUG VEDirect 61 Values : [13.540000000000001, 35.49, 144, 10.4]
2021-11-13 12:09:38,594 DEBUG VEDirect 61 Sent to channel(start)' : ToEmonCMS
2021-11-13 12:09:38,594 DEBUG VEDirect 61 Sent to channel(end)' : ToEmonCMS
2021-11-13 12:09:38,727 DEBUG MQTT Publishing: emon/SmartSolarMPPT/V 13.540000000000001
2021-11-13 12:09:38,728 DEBUG MQTT Publishing: emon/SmartSolarMPPT/VPV 35.49
2021-11-13 12:09:38,728 DEBUG MQTT Publishing: emon/SmartSolarMPPT/PPV 144
2021-11-13 12:09:38,729 DEBUG MQTT Publishing: emon/SmartSolarMPPT/I 10.4
2021-11-13 12:09:38,729 INFO MQTT Publishing 'node' formatted msg
2021-11-13 12:09:38,729 DEBUG MQTT Publishing: emonhub/rx/9/values 13.540000000000001,35.49,144,10.4
2021-11-13 12:09:48,395 DEBUG emoncmsorg Buffer size: 3
2021-11-13 12:09:48,614 DEBUG VEDirect Starting Serial read from Serial<id=0x7ffbd4ecc048, open=True>(port='/dev/ttyUSB2', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-11-13 12:09:48,618 ERROR VEDirect Read error
Traceback (most recent call last):
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 135, in _read_serial
packet = self.input(self._ser.read())
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input
self.dict[self.key.decode()] = self.value.decode()
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x8c in position 1: invalid start byte
2021-11-13 12:09:58,638 DEBUG VEDirect Starting Serial read from Serial<id=0x7ffbd4ecc048, open=True>(port='/dev/ttyUSB2', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-11-13 12:09:58,639 ERROR VEDirect Read error
Traceback (most recent call last):
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 135, in _read_serial
packet = self.input(self._ser.read())
File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input
self.dict[self.key.decode()] = self.value.decode()
UnicodeDecodeError: 'utf-8' codec can't decode byte 0x8c in position 1: invalid start byte

@eroyee
Copy link

eroyee commented Nov 13, 2021

Alerted by @maumauns comment re previous version I reverted the 23rd Sept changes to EmonHubVEDirectInterfacer.py from @bwduncan (93a4519#diff-4bcb5856739a061946d2eaaa9e336658ef55b4b0ce8e83b8e4363b95d32c3e6b).

This version still logs the decode error after a period of time, but it appears to (eventually) sort itself and carry on. Here's a log excerpt, note it was working fine for approx 14mins prior to this, and subsequently for a further 20mins (~as of time of writing - it continues ok right now):

2021-11-13 13:34:31,163 ERROR VEDirect 'utf-8' codec can't decode byte 0x86 in position 0: invalid start byte
2021-11-13 13:34:41,206 ERROR VEDirect 'utf-8' codec can't decode byte 0xb3 in position 0: invalid start byte
2021-11-13 13:34:51,254 ERROR VEDirect 'utf-8' codec can't decode byte 0x97 in position 0: invalid start byte
2021-11-13 13:35:01,280 ERROR VEDirect 'utf-8' codec can't decode byte 0x86 in position 0: invalid start byte
2021-11-13 13:35:11,305 ERROR VEDirect 'utf-8' codec can't decode byte 0xb1 in position 0: invalid start byte
2021-11-13 13:35:21,331 ERROR VEDirect 'utf-8' codec can't decode byte 0xbe in position 0: invalid start byte
2021-11-13 13:35:31,357 ERROR VEDirect 'utf-8' codec can't decode byte 0xc8 in position 0: unexpected end of data
2021-11-13 13:35:41,378 ERROR VEDirect 'utf-8' codec can't decode byte 0xca in position 0: unexpected end of data
2021-11-13 13:35:51,413 ERROR VEDirect 'utf-8' codec can't decode byte 0x8f in position 0: invalid start byte
2021-11-13 13:36:01,463 ERROR VEDirect 'utf-8' codec can't decode byte 0x89 in position 0: invalid start byte
2021-11-13 13:36:11,502 ERROR VEDirect 'utf-8' codec can't decode byte 0xc3 in position 0: unexpected end of data
2021-11-13 13:36:21,529 ERROR VEDirect 'utf-8' codec can't decode byte 0x89 in position 0: invalid start byte
2021-11-13 13:36:31,558 ERROR VEDirect 'utf-8' codec can't decode byte 0x8b in position 0: invalid start byte
2021-11-13 13:36:41,583 ERROR VEDirect 'utf-8' codec can't decode byte 0x81 in position 0: invalid start byte
2021-11-13 13:36:51,616 ERROR VEDirect 'utf-8' codec can't decode byte 0x84 in position 0: invalid start byte

UPDATE: Worked ok for about 40mins, then failed again with the same error and has continued to fail for > 10mins. Restarting emonhub often fixes it, but not this time. Here is an example of present serial output from the MPPT:

[14:48:54:340] Checksum⇥ <0xa9>␍␊
[14:48:55:150] PID⇥ 0xA057␍␊
[14:48:55:150] FW⇥ 154␍␊
[14:48:55:150] SER#⇥ HQ2035I1QX1␍␊
[14:48:55:166] V⇥ 13490␍␊
[14:48:55:166] I⇥ 6600␍␊
[14:48:55:166] VPV⇥ 34990␍␊
[14:48:55:182] PPV⇥ 92␍␊
[14:48:55:182] CS⇥ 4␍␊
[14:48:55:182] MPPT⇥ 2␍␊
[14:48:55:198] OR⇥ 0x00000000␍␊
[14:48:55:198] ERR⇥ 0␍␊
[14:48:55:198] LOAD⇥ OFF␍␊
[14:48:55:214] H19⇥ 15195␍␊
[14:48:55:214] H20⇥ 92␍␊
[14:48:55:214] H21⇥ 569␍␊
[14:48:55:214] H22⇥ 169␍␊
[14:48:55:230] H23⇥ 593␍␊
[14:48:55:230] HSDS⇥ 195␍

@eroyee
Copy link

eroyee commented Nov 14, 2021

Today, as part of my fault-finding process, I tried running another python-based vedirect decoder from @karioja (https://github.com/karioja/vedirect).

This code will just print to std out, or send to MQTT, presently it's printing to std out and has done for quite some time - longer at least than the emonhub VEDirect interfacer has on this same machine.

This prompted me to see if I could modify the VEDirect interfacer code to simply print to the console, and from there perhaps help identify the source of the problem. However I'm an old guy so the object style coding and association with EmonHubInterfacer has defeated me for the moment. I'm sure it'd not be difficult to isolate & run it standalone, and if someone was able to assist with that I'd be keen to hear from you.

At this time, bearing in mind my limited understanding of the code (and limited ability!) my feeling is that there is possibly some corruption of incoming data, or failure to properly clear a buffer that eventually presents the issue. Whatever it is doesn't necessarily reset immediately upon restarting emonhub or re-plugging the USB port, although it often will.

Finally, it remains possible there's some other process running on this machine that's causing the problem, and I suppose it may not even have been this particular section of emonhub at issue (although it seems the logical place to start), however:

-karioja's code runs fine with the Victron MPPT
-emonhub direct serial operates flawlessly over a decent number of hours (via same USB port as the MPPT)

So I think it worth concentrating here for the moment...

@bwduncan
Copy link
Contributor

Hi,

Unfortunately I don't have one of these devices so I can't test the code. I'm sorry that it appears my changes to support the transition away from python 2 have broken this interfacer. I will do my best to help clean this up.

However, it is possible that the data was always wrong and we are now seeing errors instead of data just being silently dropped. For example, in the first traceback posted by @maumauns the decoding of the key fails at byte 1477. Do we believe that a >1.44kb message is valid data? A normal message is 78 bytes...

I think one obvious explanation is that the data is not UTF-8. It looks like most of it is: It's simple human-readable text, separated by tabs and newlines. However, the checksum byte is not. It's a computed value so if it's happens to be >127 then that's not valid UTF-8, and the code will fail. That's why the code doesn't trying to decode the "Checksum" value, but if the data is corrupted, it might try to decode a "CHecksum" value, for example... This seems unlikely, though.

We need to get more information about what's happening. If you are comfortable in python, please can you catch the UnicodeDecodeError exception and get the values of the local variables? You could do this by replacing line 135, in _read_serial, so that this line:

                packet = self.input(self._ser.read())

becomes this

                try:
                    packet = self.input(self._ser.read())
                except UnicodeDecodeError:
                    import traceback, sys
                    frame = sys.exc_info()[2]
                    formattedTb = traceback.format_tb(frame)
                    frame = frame.tb_next
                    while frame:
                        self._log.debug("%s\t%s", formattedTb.pop(0), frame.tb_frame.f_locals)
                        frame = frame.tb_next

You'll need to have debug logging turned on, but it looks like you already do. This will generate a lot of output.

FWIW, I have successfully used the code in emonhub as it is now to decode the example dump file in https://github.com/karioja/vedirect/blob/master/test/bluesolar_1.23.dump 8 messages have checksum errors, the rest display data.

Bruce

@bwduncan
Copy link
Contributor

Also, can you confirm whether this is running under python 2 or 3?

@eroyee
Copy link

eroyee commented Nov 14, 2021

Hello Bruce, thanks for responding.

I've altered the code as you request and have turned back on debug logging. It's just come up with an Invalid checksum error, but the Unicode failure has yet to occur.

Prior to this I'd done some further messing around with various parameters, and a little in the code itself. Because of its intermittent nature I can't be completely sure but I have an idea the 'poll interval' may have an effect. When I originally came across the issue I had that set to '10', subsequently I increased it to 15 and while it still gave errors these didn't seem to appear as often, and it didn't crash completely with the Unicode issue.

Interesting you get the checksum errors from that dump file. I ran karioja's code, publishing to MQTT, for several hours yesterday and it didn't have any issue, which led me to trial a couple of things in your code (which I'd describe as force clearing the packet and buffer), but this didn't appear to have any effect.

Re your other question - on my system python defaults to 2.7.17, do you think it worth forcing python 3 (3.6.9 for me)?

@eroyee
Copy link

eroyee commented Nov 14, 2021

@bwduncan it's just crashed, here's a copy of the log with a preceding good frame:

2021-11-15 08:16:21,853 DEBUG VEDirect Starting Serial read from Serial<id=0x7f2689151ba8, open=True>(port='/dev/ttyUSB1', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-11-15 08:16:21,858 DEBUG VEDirect 66 NEW FRAME : {'PID': '0xA057', 'FW': '154', 'SER#': 'HQ2035\x00I1QX1', 'V': '13380', 'I': '7400', 'VPV': '36560', 'PPV': '101', 'CS': '3', 'MPPT': '2', 'OR': '0\x00x00000000', 'ERR': '0', 'LOAD': 'OFF', 'H19': '15326', 'H20': '8', 'H21': '100', 'H22': '97', 'H23': '500', 'HSDS': '197'}
2021-11-15 08:16:21,859 DEBUG VEDirect 66 Timestamp : 1636917381.858685
2021-11-15 08:16:21,859 DEBUG VEDirect 66 From Node : 9
2021-11-15 08:16:21,859 DEBUG VEDirect 66 Values : [13.38, 36.56, 101, 7.4]
2021-11-15 08:16:21,859 DEBUG VEDirect 66 Sent to channel(start)' : ToEmonCMS
2021-11-15 08:16:21,860 DEBUG VEDirect 66 Sent to channel(end)' : ToEmonCMS
2021-11-15 08:16:21,954 DEBUG MQTT Publishing: emon/SmartSolarMPPT/V 13.38
2021-11-15 08:16:21,955 DEBUG MQTT Publishing: emon/SmartSolarMPPT/VPV 36.56
2021-11-15 08:16:21,956 DEBUG MQTT Publishing: emon/SmartSolarMPPT/PPV 101
2021-11-15 08:16:21,956 DEBUG MQTT Publishing: emon/SmartSolarMPPT/I 7.4
2021-11-15 08:16:21,956 INFO MQTT Publishing 'node' formatted msg
2021-11-15 08:16:21,957 DEBUG MQTT Publishing: emonhub/rx/9/values 13.38,36.56,101,7.4
2021-11-15 08:16:21,968 DEBUG emoncmsorg Buffer size: 3
2021-11-15 08:16:31,881 DEBUG VEDirect Starting Serial read from Serial<id=0x7f2689151ba8, open=True>(port='/dev/ttyUSB1', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False)
2021-11-15 08:16:31,884 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,884 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,885 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,885 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,885 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,885 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,886 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,886 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,886 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,886 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,887 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'byte': b'\t', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139803383289600)>}
2021-11-15 08:16:31,887 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial

It carried on with that for several minutes, I had to kill the process to stop it, the usual 'restart' wouldn't cut it. I'll start it again now - btw I set the poll interval back to 10 for this test.

UPDATE: It's just done it again. Pretty much the same data so I won't post it up (although am happy to if you want). As it crashes completely with this I'll stop it for now but am more than happy to carry on with further alterations/tests as you need.

@bwduncan
Copy link
Contributor

I think the code I showed has a bug. Please can you remove the first line which says frame = frame.tb_next and try again?

Yes I would suggest trying it with python3. It's even harder for me to test with python2, which was not supported past January the 1st, 2020. It should just be a simple case of replacing "python" with "python3" in the ExecStart= line in the emonhub.service file.

It looks like the exception handler is getting stuck in one frame, which I don't understand. I tested it in python3, so maybe that will help. If not, you could try putting the same debugging code around the line which was failing before. At least then we'll get the useful stack frame again and again!

The poll interval shouldn't really make any difference. All it does is prevent trying to read from the serial device for that length of time. Once that time is up, it will try to consume all the data. If it polls more frequently than the device delivers data, it will just report a "Read error".

@eroyee
Copy link

eroyee commented Nov 15, 2021 via email

@eroyee
Copy link

eroyee commented Nov 15, 2021

@bwduncan I'd omitted to turn on debug logging again, sigh, here it goes :-)

2021-11-15 13:13:48,567 DEBUG VEDirect Starting Serial read from Serial<id=0x7f487bef7080, open=True>(port='/dev/ttyUSB1', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, ds
rdtr=False)
2021-11-15 13:13:48,572 DEBUG VEDirect 43 NEW FRAME : {'PID': '0xA057', 'FW': '154', 'SER#': 'HQ2035I1QX1', 'V': '13500', 'I': '12400', 'VPV': '38200', 'PPV': '171', 'CS': '5', 'MPPT': '1', 'OR': '0x00000000', 'ERR': '
0', 'LOAD': 'OFF', 'H19': '15409', 'H20': '91', 'H21': '486', 'H22': '97', 'H23': '500', 'HSDS': '197'}
2021-11-15 13:13:48,572 DEBUG VEDirect 43 Timestamp : 1636935228.572169
2021-11-15 13:13:48,572 DEBUG VEDirect 43 From Node : 9
2021-11-15 13:13:48,573 DEBUG VEDirect 43 Values : [13.5, 38.2, 171, 12.4]
2021-11-15 13:13:48,573 DEBUG VEDirect 43 Sent to channel(start)' : ToEmonCMS
2021-11-15 13:13:48,573 DEBUG VEDirect 43 Sent to channel(end)' : ToEmonCMS
2021-11-15 13:13:48,734 DEBUG MQTT Publishing: emon/SmartSolarMPPT/V 13.5
2021-11-15 13:13:48,735 DEBUG MQTT Publishing: emon/SmartSolarMPPT/VPV 38.2
2021-11-15 13:13:48,735 DEBUG MQTT Publishing: emon/SmartSolarMPPT/PPV 171
2021-11-15 13:13:48,736 DEBUG MQTT Publishing: emon/SmartSolarMPPT/I 12.4
2021-11-15 13:13:48,736 INFO MQTT Publishing 'node' formatted msg
2021-11-15 13:13:48,736 DEBUG MQTT Publishing: emonhub/rx/9/values 13.5,38.2,171,12.4
2021-11-15 13:13:58,593 DEBUG VEDirect Starting Serial read from Serial<id=0x7f487bef7080, open=True>(port='/dev/ttyUSB1', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, ds
rdtr=False)
2021-11-15 13:13:58,598 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'formattedTb': [' File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input\n self.dict[self.key.decode()] = self.value.decode()\n'], 'frame': <traceback object at 0x
7f487be71b08>, 'sys': <module 'sys' (built-in)>, 'traceback': <module 'traceback' from '/usr/lib/python3.6/traceback.py'>, 'packet': None, 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139949275346688)>}
2021-11-15 13:13:58,599 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input
self.dict[self.key.decode()] = self.value.decode()
{'byte': b'\r', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139949275346688)>}
2021-11-15 13:13:58,599 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'formattedTb': [' File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input\n self.dict[self.key.decode()] = self.value.decode()\n'], 'frame': <traceback object at 0x
7f487beb5c08>, 'sys': <module 'sys' (built-in)>, 'traceback': <module 'traceback' from '/usr/lib/python3.6/traceback.py'>, 'packet': None, 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139949275346688)>}
2021-11-15 13:13:58,600 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input
self.dict[self.key.decode()] = self.value.decode()
{'byte': b'\r', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139949275346688)>}
2021-11-15 13:13:58,600 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'formattedTb': [' File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input\n self.dict[self.key.decode()] = self.value.decode()\n'], 'frame': <traceback object at 0x
7f487be71bc8>, 'sys': <module 'sys' (built-in)>, 'traceback': <module 'traceback' from '/usr/lib/python3.6/traceback.py'>, 'packet': None, 'self': <EmonHubVEDirectInterfacer(VEDirect, started 139949275346688)>}

@bwduncan
Copy link
Contributor

Depending on how it's started it might not use the shebang. Can you check by looking at the output of ps aux? It should show whether it's using python or python3. You could also start it manually so that we can be sure it's using python3.

Is the legacy code part of emonhub? If it's open source I'd be happy to help port it, although I admit you might be wary of my offer given this bug 🤣

I'm not dismissing it as a possible effect. We could try setting it to extreme values, like 0, or 500, and see if it really is affecting anything. Yes Karioja is just using the pyserial module to wait until there is data to be read. We have other tasks to perform so we can't wait forever. Actually we should be setting a timeout on that read call, but that's for another day...

I have been looking at the two implementations and trying to see where they have diverged, and why it might be important. Will report back!

@bwduncan
Copy link
Contributor

Argh remote debugging is hard!

Can you put a print(self.__dict__) line in there? I need to see what the state of that object is.

@eroyee
Copy link

eroyee commented Nov 15, 2021 via email

@eroyee
Copy link

eroyee commented Nov 15, 2021 via email

@bwduncan
Copy link
Contributor

Oh sorry actually it's more involved than that. Inside that while block, can you add before the frame = frame.tb_next

self._log.debug("%s", self.__dict__)

And yeah I'd be happy to call, if we can exchange numbers in a less public forum, but it's nearly 1am now and it's a school night 😄 I should be free tomorrow evening after work (1900-0000 UTC as it stands hopefully).

@eroyee
Copy link

eroyee commented Nov 15, 2021 via email

@eroyee
Copy link

eroyee commented Nov 15, 2021

@bwduncan When it goes it fair fills up the log file, and then rotates real quick, so I keep losing the start - however here's an idea of what we get:

2021-11-15 16:21:49,742 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())
{'formattedTb': [' File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input\n self.dict[self.key.decode()] = self.value.decode()\n'], 'frame': <traceback object at 0x7fa7f2704188>,
'sys': <module 'sys' (built-in)>, 'traceback': <module 'traceback' from '/usr/lib/python3.6/traceback.py'>, 'packet': None, 'self': <EmonHubVEDirectInterfacer(VEDirect, started 140359312283392)>}
2021-11-15 16:21:49,744 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 70, in input
self.dict[self.key.decode()] = self.value.decode()
{'byte': b'\r', 'self': <EmonHubVEDirectInterfacer(VEDirect, started 140359312283392)>}
2021-11-15 16:21:50,647 DEBUG VEDirect {'_log': <Logger EmonHub (DEBUG)>, '_target': None, '_name': 'VEDirect', '_args': (), '_kwargs': {}, '_daemonic': False, '_ident': 140359312283392, '_tstate_lock': <locked _thread.lock object a
t 0x7fa7f3fc2b20>, '_started': <threading.Event object at 0x7fa7f3f45048>, '_is_stopped': False, '_initialized': True, '_stderr': <_io.TextIOWrapper name='' mode='w' encoding='UTF-8'>, '_defaults': {'pause': 'off', 'interval': 0,
'datacode': '0', 'scale': '1', 'timestamped': False, 'targeted': False, 'nodeoffset': '0', 'pubchannels': [], 'subchannels': [], 'batchsize': '1'}, 'init_settings': {'com_port': '/dev/ttyUSB1', 'com_baud': '19200', 'toextract': ['V', 'V
PV', 'PPV', 'I'], 'poll_interval': '10'}, '_settings': {'pause': 'off', 'interval': 0, 'datacode': '0', 'scale': '1', 'timestamped': False, 'targeted': False, 'nodeoffset': '9', 'pubchannels': ['ToEmonCMS'], 'subchannels': ['ToSmartSolar
MPPT'], 'batchsize': '1'}, '_sub_channels': {}, '_pub_channels': {'ToEmonCMS': []}, '_interval_timestamp': 0, 'buffer': <emonhub_buffer.InMemoryBuffer object at 0x7fa7f3f450b8>, '_item_limit': 1000, 'stop': True, '_ser': Serial<id=0x7fa7
f3f450f0, open=True>(port='/dev/ttyUSB1', baudrate=19200, bytesize=8, parity='N', stopbits=1, timeout=10, xonxoff=False, rtscts=False, dsrdtr=False), 'header1': b'\r', 'header2': b'\n', 'delimiter': b'\t', 'key': bytearray(b'\x00VPVPIDFW
SER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWS
ER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSE
R#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER
#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#
VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#V
IVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VI
VPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIV
PVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksumPIDFWSER#VIVPVPPVCSMPPTORERRLOADH19H20H21H22H23HSDSChecksum'), 'value':
bytearray(b'3258\x940xA057154HQ2035I1QX113360920031210125320x000000000OFF1545313548697500197\x9a0xA057154HQ2035I1QX113360890032980125320x000000000OFF1545313548697500197\x850xA057154HQ2035I1QX113370910032070125320x000000000OFF154531354869
7500197\x950xA057154HQ2035I1QX113370910030320125320x000000000OFF1545313548697500197\x990xA057154HQ2035I1QX113360920031970126320x000000000OFF1545313548697500197\x8c0xA057154HQ2035I1QX113360930031090126320x000000000OFF1545313548697500197\x
920xA057154HQ2035I1QX113370920031060126320x000000000OFF1545313548697500197\x950xA057154HQ2035I1QX113370930031860127320x000000000OFF1545313548697500197\x8b0xA057154HQ2035I1QX113360930031840127320x000000000OFF1545313548697500197\x8e0xA0571
54HQ2035I1QX113370940031030127320x000000000OFF1545313548697500197\x950xA057154HQ2035I1QX113370920032680127320x000000000OFF1545313548697500197\x8b0xA057154HQ2035I1QX113380930031040127320x000000000OFF1545313548697500197\x940xA057154HQ2035I
1QX113370930031770128320x000000000OFF1545313548697500197\x8a0xA057154HQ2035I1QX113370930031810128320x000000000OFF1545313548697500197\x8f0xA057154HQ2035I1QX113360940031010128320x000000000OFF1545313548697500197\x970xA057154HQ2035I1QX113380
920032590128320x000000000OFF1545313548697500197\x890xA057154HQ2035I1QX113380940031030128320x000000000OFF1545313548697500197\x930xA057154HQ2035I1QX113380930030150128320x000000000OFF1545313548697500197\x920xA057154HQ2035I1QX113360940031670
128320x000000000OFF1545313548697500197\x8b0xA057154HQ2035I1QX113370930032530128320x000000000OFF1545313548697500197\x8f0xA057154HQ2035I1QX113370940030870129320x000000000OFF1545313548697500197\x880xA057154HQ2035I1QX113380940031670129320x00
0000000OFF1545313548697500197\x880xA057154HQ2035I1QX113370930030000129320x000000000OFF1545313548697500197\x980xA057154HQ2035I1QX113370940031530129320x000000000OFF1545313548697500197\x8e0xA057154HQ2035I1QX113370940032370129320x000000000OF
F1545313548697500197\x8b0xA057154HQ2035I1QX113380950030760130320x000000000OFF1545313548697500197\x900xA057154HQ2035I1QX113360930030000129320x000000000OFF1545313548697500197\x990xA057154HQ2035I1QX113360930033010129320x000000000OFF15453135
48697500197\x950xA057154HQ2035I1QX113370950032210129320x000000000OFF1545313548697500197\x910xA057154HQ2035I1QX113370940030670130320x000000000OFF1545313548697500197\x920xA057154HQ2035I1QX113370950032160130320x000000000OFF15453135486975001
97\x95:A4F10000100000000005D3C00005D3C0000A31196051EE304FFFFFFFFFFFFFFFFFFFFFFFFFF72\n:A5010000087000000FFFFFFFF8C0520050000000000C20078002301E60100004F012710C50021\n0xA057154HQ2035I1QX113360930033000130320x000000000OFF154531354869750019
7\x9e'), 'bytes_sum': 316214, 'state': 0, 'dict': {'PID': '0xA057', 'FW': '154', 'SER#': 'HQ2035I1QX1', 'V': '13480', 'I': '13000', 'VPV': '\x0032940', 'PPV': '180', 'CS': '5', 'MPPT': '1', 'OR': '0x00000000', 'ERR': '0', 'LOAD': 'OFF',
'\x00H19': '15452', 'H20': '134', 'H21': '486', 'H22': '97', 'H23': '500', 'HSDS': '197', 'Checks\x00um': 'c'}, '_extract': ['V', 'VPV', 'PPV', 'I'], 'poll_interval': 10.0, 'last_read': 1636946478.085835}
2021-11-15 16:21:50,648 DEBUG VEDirect File "/opt/openenergymonitor/emonhub/src/interfacers/EmonHubVEDirectInterfacer.py", line 137, in _read_serial
packet = self.input(self._ser.read())

I've also noted that the checksum errors tend to occur every 3mins or so, reasonably regularly...

@eroyee
Copy link

eroyee commented Nov 15, 2021

@bwduncan Just sent an email to what I think is your personal address. I mentioned 'this evening', by which I mean your evening (the 1900-0000 UTC you mentioned), not my evening ;-)

If you didn't get that then I've managed to confuse someone else, and we'll just have to figure a suitably private way of exchanging contact details...

@bwduncan
Copy link
Contributor

It looks like the data has extra NUL bytes in it. Near the end of the object dump you will see that dict contains a 'Checks\x00um' key, with value 'c'. It looks like the value of 'VPV' and the key '\x00H19' also start with unexpected zero bytes.

Presumably the reason that Karioja's code doesn't fail is that it doesn't try to make sense of the data. It's just taking the data as-is and putting it into a string. If you print strings with nul bytes in them in Python you won't see them, but obviously if you try to get the data, or compare to a known string, it will fail: For example 'Check\x00sum' != 'Checksum' but print('Check\x00sum') prints (what looks like) "Checksum".

This https://stackoverflow.com/a/27477565/567655 gives some reasons why these bytes might be received. Maybe the serial line is noisy, too long, damp, ...

We should also be parsing the : ("HEX") lines. That would help with some checksum errors. I'll prepare a patch.

@eroyee
Copy link

eroyee commented Nov 15, 2021

I'm fairly sure the serial line should be ok - it's direct to the machine and ~3M, so well within limits (and I'd tried several cables just to be sure). Still, not impossible.

Good idea re the hex data though, I had wondered if that might be messing with things a bit.

@acoleman-apc
Copy link
Contributor

I recently upgraded and ran into this issue. While not a great solution, I ended up just stripping out the non UTF-8 chars and letting the parsing fail. It does succeed periodically (90-120 seconds) so I get a data feed.

Example code:
self.dict[self.key.decode()] = self.value.decode('utf-8').strip()

This was this previously:
self.dict[self.key.decode()] = self.value.decode()

@bwduncan
Copy link
Contributor

Hey,

Thanks for your feedback. Unfortunately that's not what the strip method does. strip removes leading and trailing whitespace from a string, it will not remove invalid UTF8 characters. Also, 'utf-8' is the default for decode, so specifying it explicitly doesn't help.

Bruce

@acoleman-apc
Copy link
Contributor

I spoke too soon! My errors have appeared again so please ignore me.

@eroyee
Copy link

eroyee commented Feb 27, 2022

Anthony,

@bwduncan and I spent quite a session on this one night. We, or at least Bruce, was able to come up with a work-around that meant one was able to operate Openenergymonitor with a VEDirect device, but it was probably not completely suitable as a final solution.

In order to make it work you need to use the requisite library from https://github.com/karioja/vedirect with modified interfacer code. If @bwduncan is ok with it I'm happy to pass on the details to you, although I think you'd need to consider it as 'work-in-progress'. An alternative option is just to use karioja's code and publish to MQTT, which I successfully used for a while.

All of this happened a few months ago and I've not really done anything since, however FYI I came to the view that the probable issue was due to the nature of the VEDirect data stream and the start of the parsing algorithm in use here. My recollection is a bit wobbly now but I think that every second or so Victron device sends out HEX data, usually followed by a ln, then the ASCII data that's parsed for sending on via Emonhub.

In terms of the issue here I think that the issue is around using the ln as the start marker - it may be more reliable to look for the end of the HEX data as the effective start of the ASCII data stream. However please bear in mind this is simply my surmise, albeit after quite some time messing with it, and I mention it simply in case you decide to take a look at what's going on...

@acoleman-apc
Copy link
Contributor

acoleman-apc commented Feb 28, 2022

Thanks for the reply. So far, I'm very disappointed with the upgrade. My memory card wouldn't upgrade in place so I had to manually back up and upgrade the emon pi to the latest version and then I had to re-write the Renogy interfacer to get that working and now my VE Direct interface no longer works - meaning that the emon pi no longer serves its purpose. So I'm going to look for a work around or try to code one but I'm inclined to replace the Renogy charge controller with a victron unit and just move away from emon pi in favor of the victron platform as I didn't really see any improvements in emon pi after the upgrade.

@acoleman-apc
Copy link
Contributor

I've changed my code to this (and have started testing - fingers crossed):
self.dict[self.key.decode()] = self.value.decode(encoding="utf-8", errors="replace")

@bwduncan
Copy link
Contributor

self.dict[self.key.decode()] = self.value.decode(encoding="utf-8", errors="replace")

Yes that will avoid the topmost exception, although you probably need errors="replace" for the key, too, and again utf-8 is the default, but I don't think it will give you any more data. The data is still garbage, so it will fail the checksum. You could patch that out as well, but if the data isn't valid UTF-8 (it's 7-bit ASCII, except the checksum byte, so if it's not UTF-8 then it is really garbage) then what is it? From memory (months ago) of what @eroyee and I found was that zero bytes were being randomly dropped into the stream, which didn't make any sense. I think this has always been the problem, but the previous code just silently ignored the error. Was that better? I would argue not. Clearly we're all missing something.

I will be interested to see your results though.

You may have had to re-write your interfacer to get it working, but nobody else had made any effort to port all this to Python 3, and as I think I made fairly clear at the time, I don't have the hardware to test, so I'm relying on the community to provide feedback. I'm not being paid to do this, it is "fun". If you want to move to a different platform, that's up to you.

@acoleman-apc
Copy link
Contributor

Moving to latin encoding with error ignoring:
if self.key.decode(encoding="latin-1", errors="replace") == 'Checksum':
self.dict[self.key.decode(encoding="latin-1", errors="replace")] = self.value.decode(encoding="latin-1", errors="replace")

Seems to do much better. Although it isn't 100% as the serial connection (based on my debugging) doesn't always pop in at the proper part of the frame - thus causing some data to get ignored - it does seem to give me rather consistent data feed so I'll continue to monitor.

@eroyee
Copy link

eroyee commented Mar 1, 2022

Anthony,

Thanks for the update, Bruce thanks for the reminder.

Just to comment on your earlier post. I too could have used another platform, however I liked that OpenEnergyMonitor is... open, whereas my recollection of the Victron ecosystem is that it's proprietary? At least with OEM one has the option to use other equipment, and improve/adapt as needed - and if we can help others along the way that's a plus, in my view, thus thanks for persevering here 👍

So, Bruce is right in that there may be something else going on we've not yet put our finger on completely. It would be good to determine that and correct it if possible, but the meantime the pragmatist says "just it get it working as much as possible", particularly since it appears to effectively not work as it is at present. To that end if your mods work to assist the latter it's good to hear as it's probably simpler than where Bruce & I ended up.

However to begin addressing the real issue a couple of things are of interest; (1) as I understand it you were previously using exactly the same hardware with no apparent issue - the only change being in software? (2) If 1, do you have any log files from the previous iteration of the VEDirectInterfacer? I ask 2, just in case there were a few unidentified hiccups that could have been occurring, but not enough to notice in use. I suppose that could assist in determining if the issue has transferred over from previous code, but is now more apparent, or it previous code didn't exhibit the issue at all (in which case, why not).

FYI in my case I didn't have a previous version running, I simply created a new instance in order to provide some plots from my inverter & MPPT etc, ran across this issue and did as much as I was able to assist in the fix (Bruce is really the guru here, not me!) - hence your prior experience is of interest. At one point I did seriously begin to wonder if it was just my setup but I later installed it to a Pi where it did the same, and with your info now it does seem it's a real 'thing'.

Anyway, in case I can help further I've got the Pi out again and will connect it up to confirm where it's at. If nothing else I can then try your mods to see what they do here. I can test a Victron MPPT, Inverter, and Monitor, although my recollection is that it didn't seem to make any difference to the issue which was connected.

@eroyee
Copy link

eroyee commented Mar 1, 2022

It's been a while since I dealt with this so had to find that Pi, re-learn how it all worked, restore the complete mess of modified conf files with something more like it should be, stop Influx/Grafana (which at one time I'd been playing with as an alternative) but I've now got it back up and running...

As a result I remember some things it would do. With the original code in place, often it'd work ok for several minutes with the occasional 'Invalid checksum' in the log. I don't recall there being a particular pattern to this, but it would eventually crash completely after a series of these errors.

Anthony, I've modified EmonHubVEDirectInterfacer.py with your suggestions. ATM I'm getting the errors at seemingly random intervals, but I doubt it's been going long enough to determine whether it'll fully crash, or not - IIRC it could take 15-20mins for that. Presently it's been running for ~12m with approx 14 errors recorded...

@acoleman-apc
Copy link
Contributor

The communication protocol should be the same but FYI I'm using the BMV 712 shunt, not the MPPT or other devices from Victron.

With the older version, I was able to have an intermittent but stable feed of data - no crashing. I do recall having crashing issues and having to modify it - I even had an issue that is now closed.

With my recent changes (latin encoding w/ error suppression), I'm going on about 20 hours with a decent feed of data. There are periodic errors but no crashing and the data seems to match the victron data (app & display).

I'm not opposed to the open nature of the project - I wrote the Renogy interfacer for my charge controller and shared it. I'm just frustrated with the python 3.x upgrade. This is the first version of python that isn't backwards compatible and I haven't seen many benefits to the upgrade in the Emon system, at least not for me personally. Anyway, thanks for the code contributions and helping to build the community.

@eroyee
Copy link

eroyee commented Mar 3, 2022

Agree re the protocol, albeit it's useful to be able to test a few different inputs just in case that makes a difference.

Good to hear your changes have success of sorts. I've taken mine back to how it was (using the kairoja module) because I felt I was getting too many errors following changes per your code, after which it crashed. However because this is a somewhat modified installation, and it's now some months since I last looked at it, I want to revisit this in case there was some other reason for the failure.

Good on you for sharing the Renogy interfacer. Understand re Python 3, at the risk of bringing the world down upon my head I'd have to say my preference remains 2.7 if there's something I want to do...

@acoleman-apc
Copy link
Contributor

So I've replaced the renogy rover 100 amp unit with a victron smart solar 150v 100 amp unit and having errors using the VEDirect interfacer to read data from the MPPT. Any chance we can get victron to look at this with us?

@acoleman-apc
Copy link
Contributor

from the log:
Invalid checksum for data: {':ADBED001A0D5C\n:A0202000200000045\n\r\nERR': '0', 'LOAD': 'ON', 'Relay': 'OFF', 'H19': '1652', 'H20': '766', 'H21': '2852', 'H22': '886', 'H23': '2864', 'HSDS': '1'}

@acoleman-apc
Copy link
Contributor

From page 2 of the VE.Direct-Protocol-3.32.pdf:
"On power up, a VE.Direct interface will always be in Text-mode, and continuously transmits
all run-time fields. As soon as it receives a valid HEX-message, it will switch to HEX-mode. It
will stay in HEX-mode as long as HEX-messages are frequently received. After a product has
not received any valid HEX-messages for several seconds, it will switch back to Text-mode
and start to auto transmit the run-time fields periodically again. Some products will send
Asynchronous HEX-messages, starting with “:A” and ending with a newline ‘\n’, on their
own. These messages can interrupt a regular Text-mode frame.
"

@eroyee
Copy link

eroyee commented Aug 2, 2022

I doubt Victron would be interested, but you never know, might be worth sending them a message with a reference to this issue?

Unfortunately I've set the Pi aside again and would need to go relive the process in order to remind myself of what I used to get (other than what I showed above) however it may be that my unit doesn't send the Async hex message anyway - is there anything more specific on this than 'some products'?

Otherwise I'm not clear on whether you're just logging the issue yet the system continues, or whether it all grinds to a halt?

@acoleman-apc
Copy link
Contributor

The data feed continues on the wire but the code only randomly publishes to the emon CMS feed as it has the check sum errors and discards the packets - most likely due to the hex messages appearing in the string. Since the victron cerbo gx can run on a pi with the same hardware, I think it is a bug / problem with the interfacer. When I get some free time, I'm going to look into updating the code to detect and remove the hex message from the string before calc of check sum.

However, there is another problem with the code. With the MPPT not all of the data comes across in one frame - it is divided up into multiple frames. And the code in the current interfacer doesn't seem to handle this properly as it publishes to the wrong feeds when this happens. So for instance H20 (solar power generated today) comes across in the 2nd frame but won't ever get pushed to H20 feed as far as I can tell.

TLDR: the victron interfacer has major problems on the blue solar mppt units and minor problems on the BMV712 (I have both). The renogy interfacer was rock solid though so I miss the data feed even though the victron units are better quality and produce more power for me.

@eroyee
Copy link

eroyee commented Aug 4, 2022

Ok, I'm sure people would appreciate it if you could fix this 👍

Unfortunately Bruce doesn't actually have any Victron gear, and I'm fairly sure mine doesn't send the async data (and I've re-utilised the Pi I was using for something else), which makes it difficult to assist. However I can provide serial data from a Smart Solar MPPT, a Phoenix Inverter, and a BMV-702 if/when you need it - although it looks as if I've already presented some data from the MPPT above.

Otherwise I don't recall having any issue with the feeds. I think at one point I was feeding two Victron devices and my own battery monitor (which, immodestly, I think is somewhat better than the Victron unit :) and, aside from the issue described here, the system ran quite reliably for weeks.

I agree the Victron units are quality gear, and I'm very happy with their performance (much less so with the country importer - which, sadly, is why I can't recommend them here). However why manufacturers find it necessary to utilise weird protocols for something simple like this I can never figure out - I've been dealing with such hardware for many years now and still there seems to be no common (and open) format across manufacturers. At least in terms of user control and data interchange this isn't anything secret so really, why!? Grrr.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants