Second VE.Direct device goes offline (Firmware woes?)

Hello community,

First of all - wow, there is a pile of information out there and a pile of really helpful and knowledgeable people who are willing to share that knowledge, thank-you!

I have a small solar setup that acts as an “Internet relay” between two pieces of my property. A BlueSolar MPPT 75/15 charging a couple of retired batteries from a cell-tower back-up system which then run a pair of Ubiquiti antennas which bounce internet from one wired location to another on my farm. Coupled with the above I have a RaspberryPi running Venus OS and the Charge controller is connected to the Pi using a home made cable and things have been happily plugging along for a couple of years now.

My father recently made me a small wind generator and I’ve had no idea if it’s actually done much, it has its own charge controller and there is no interface at all for me to interact with it - so I figured I’d pony up and get myself one of the Smart Shunts I’ve been watching for so long.

I picked up SmartShunt 500A/50mV and plugged it in to the Pi using another home made cable and was very happy to see it was immediately picked up in the Venus remote console! - Only a few minutes later my Charge Controller went offline… I discovered that if I remotely rebooted the system (via the Remote Console) both devices would be online for a few moments (sending realtime data nicely) - but again the Charge Controller would go offline - Annoying.

I disconnected the Smart Shunt cable and the Charge Controller would stay online. If I disconnected the Charge Controller the Shunt would stay online…

Eventually in my troubleshooting I swapped the ports the Charge Controller and Shunt cables were plugged into, now the Charge Controller stays online but the Shunt goes offline after a few moments. This told me it was likely something communication related and possibly within the OS, so I started digging.

When looking at /var/log/ I was able to see that there was two vedirect.ttyUSBx devices showing up as expected. Quickly looking at the logs I was able to determine that vedirect.ttyUSB1 was the device that was going offline (which makes sense I guess as it’s the 2nd initialized device, regardless of how they’re plugged in)

Looking at the logs after a reboot shows the following:

@40000000672e8f5a001c5fac *** CCGX booted (0) ***
@40000000672e8f7301ac71a4 *** starting vedirect-interface ***
@40000000672e8f7315f2d3ec vedirect-dbus 3.83
@40000000672e91d73939a68c
@40000000672e91d73939bdfc -------- dumping backlog -------
@40000000672e91d73939c9b4 607.040 INF.VE.Text: H12=0
@40000000672e91d73939d184 607.040 INF.VE.Text: H15=0
@40000000672e91d73939dd3c 607.040 INF.VE.Text: H16=0
@40000000672e91d73939e50c 607.055 INF.VE.Text: H17=277
@40000000672e91d73939ecdc 607.055 INF.VE.Text: H18=109
@40000000672e91d73939f894 607.055 INF.VE.Direct: TEXT RegId=0308 Value=000045B4
@40000000672e91d7393a044c 607.055 INF.bmv: itemUpdate 0308 000045B4 1
@40000000672e91d7393a1004 607.055 INF.bmv: Found item History/TimeSinceLastFullCharge
@40000000672e91d7393c001c 607.505 INF.VE.Text: PID=0XA389
@40000000672e91d7393c0bd4 607.505 INF.VE.Text: V=12797
@40000000672e91d7393c178c 607.505 INF.VE.Text: I=-1157
@40000000672e91d7393c1f5c 607.505 INF.VE.Text: P=-15
@40000000672e91d7393c272c 607.505 INF.VE.Text: CE=-4935
@40000000672e91d7393c32e4 607.505 INF.VE.Text: SOC=986
@40000000672e91d7393c3ab4 607.536 INF.VE.Text: TTG=8634
@40000000672e91d7393c466c 607.536 INF.VE.Text: ALARM=OFF
@40000000672e91d7393cabfc 607.536 INF.VE.Text: AR=0
@40000000672e91d7393cb7b4 607.536 INF.VE.Text: BMV=SMARTSHUNT 500A/50MV
@40000000672e91d7393cc36c 607.536 INF.VE.Text: FW=0413
@40000000672e91d7393ccb3c 607.546 INF.VE.Text: MON=0
@40000000672e91d7393cd6f4 607.546 INF.VE.Direct: TEXT RegId=ED8F Value=0000FFF4
@40000000672e91d7393ce2ac 607.546 INF.bmv: itemUpdate ED8F 0000FFF4 1
@40000000672e91d7393cee64 607.546 INF.bmv: Found item Dc/0/Current
@40000000672e91d7393cfa1c 607.546 INF.items: Setting item Dc/0/Current to value -1.200000
@40000000672e91d7393e711c 612.591 INF.VE.Direct: Setting status to VdDisConnected
@40000000672e91d7393e80bc 612.592 ERR.service: connection lost
@40000000672e91d7393f440c 612.592 INF.task: done in 612.592
@40000000672e91e80eae8d74 *** starting vedirect-interface ***
@40000000672e91e81011b754 vedirect-dbus 3.83
@40000000672e91eb0fd58914
@40000000672e91eb0fd598b4 -------- dumping backlog -------
@40000000672e91eb0fd5a46c 000.092 INF.task: using ttyUSB1 as unique service part
@40000000672e91eb0fd5b40c 000.093 INF.VE.Direct: Setting status to VdUnknown
@40000000672e91eb0fd5bfc4 000.099 INF.settings: connected to settings on dbus (com.victronenergy.settings)
@40000000672e91eb0fd5e2ec 002.996 ERR.values: timeout connecting device
@40000000672e91eb0fd5fa5c 002.996 INF.task: done in 002.996
@40000000672e91f62ca9b934 *** starting vedirect-interface ***
@40000000672e91f62e0fadec vedirect-dbus 3.83
@40000000672e91f92ded1674
@40000000672e91f92ded29fc -------- dumping backlog -------
@40000000672e91f92ded3d84 000.092 INF.task: using ttyUSB1 as unique service part
@40000000672e91f92ded58dc 000.092 INF.VE.Direct: Setting status to VdUnknown
@40000000672e91f92ded7434 000.099 INF.settings: connected to settings on dbus (com.victronenergy.settings)
@40000000672e91f92ded975c 002.997 ERR.values: timeout connecting device
@40000000672e91f92dedaecc 002.998 INF.task: done in 002.998

--------repeating--------

RECORD SCRATCH

Ok so get this - just to make my life extra fun I’ve hit a snag as been composing this post. I’ve been at this for a couple of hours now: looking at log files, making notes of serial numbers to keep things straight, etc. After I started to capture log files and put things in order to make the post I, for some reason, stumbled across the ability to update the firmware on the devices remotely using the VRM Portal and looking at the device list. I had Venus updated and I had (I thought) applied updates via the Remote Console for each of the two devices connected via VE.Direct (but they must apply sequentially there vs skipping right to the latest?) I was surprised to see I was behind by SEVERAL versions on both devices - so I updated them.

I then set things up to tail a few log files again and started to actually draft this message - only it appears both devices have remained online…

Could I have simply been running bad firmware causing this issue? None of my searching and reading various threads/troubleshooting lead me to think this may have been the case, in fact some of the keywords I expected to find results for yielded virtually no help (let me add them again in the event this thread does nothing but help out someone else in the future - INF.VE.Direct: Setting status to VdUnknown, ERR.values: timeout connecting device, INF.VE.Direct: Setting status to VdDisConnected)

I debated just trashing this message, as it is, but I’m going to post it as I don’t find myself with a lot of time for this kind of stuff lately and my luck something will still go wrong and I’ll have to start from scratch again. I’ll chime in within a few days if this has resolved the issue for good or not - but for now I’ll just awkwardly see myself out…

Footnote:
Special thanks to these posts for providing a direction to go for looking at logs (You’ll need to enable SSH and set a password in order to be able to access them)

https://communityarchive.victronenergy.com/questions/80746/lost-connection-to-multiplus-from-rpi-3b.html

Would you mind sharing a link to the cables you made. Are they usb or do they attach to the serial port on the pi.
Looks like usb by the logs.

I used the following cables from AliExpress:
https://www.aliexpress.com/item/32775876897.html

With these plugs:

https://www.aliexpress.com/item/4001171977947.html

Issue update:

Wishful thinking - the Shunt stayed online for 2 hours though, that’s way better than the typical one-and-done I was getting out of it. I am again short on time for trying to gather a whole lot for logs at the moment but thought I’d throw this out there for anyone who may have some advice where to look.

Some follow-up debugging:

Again, it’s USB1 that seems to be giving me the issue here. When I try to get a list of serial devices (as mentioned here) by ID I only see the one device oddly, the one that’s giving me issues.

root@raspberrypi2:/dev/serial/by-id# ls -ltr
lrwxrwxrwx    1 root     root            13 Jan  1  1970 usb-Prolific_Technology_Inc._USB-Serial_Controller-if00-port0 -> ../../ttyUSB1

I seem to also be having the same issue where, for some reason, the device gets recognized as a GPS and then as a vedirect-interface:

root@raspberrypi2:/var/log/serial-starter# tail -f current
@40000000672f651406f453ac INFO: Start service gps-dbus.ttyUSB1 once
@40000000672f651d195fb07c INFO: Start service vedirect-interface.ttyUSB1 once
@40000000672f65222791ff4c INFO: Start service gps-dbus.ttyUSB1 once
@40000000672f652b3a273ec4 INFO: Start service vedirect-interface.ttyUSB1 once
@40000000672f65310d1c9334 INFO: Start service gps-dbus.ttyUSB1 once
@40000000672f653a2031d434 INFO: Start service vedirect-interface.ttyUSB1 once
@40000000672f653f2ee41104 INFO: Start service gps-dbus.ttyUSB1 once

and the vedirect log for the device just shows it constantly timing out:

root@raspberrypi2:/var/log/vedirect.ttyUSB1# tail -f current
@40000000672f65ec12cc3ba4 002.995 INF.task: done in 002.995
@40000000672f65f732bc9bfc *** starting vedirect-interface ***
@40000000672f65f7342528c4 vedirect-dbus 3.83
@40000000672f65fa37c3eeac
@40000000672f65fa37c3fe4c -------- dumping backlog -------
@40000000672f65fa37c40a04 000.101 INF.task: using ttyUSB1 as unique service part
@40000000672f65fa37c419a4 000.102 INF.VE.Direct: Setting status to VdUnknown
@40000000672f65fa37c4255c 000.110 INF.settings: connected to settings on dbus (com.victronenergy.settings)
@40000000672f65fa37c438e4 003.059 ERR.values: timeout connecting device
@40000000672f65fa37c4449c 003.059 INF.task: done in 003.059
@40000000672f66061860ca94 *** starting vedirect-interface ***
@40000000672f660619c07dbc vedirect-dbus 3.83
@40000000672f66091963f254
@40000000672f6609196405dc -------- dumping backlog -------
@40000000672f660919640dac 000.090 INF.task: using ttyUSB1 as unique service part
@40000000672f660919641d4c 000.090 INF.VE.Direct: Setting status to VdUnknown
@40000000672f6609196434bc 000.097 INF.settings: connected to settings on dbus (com.victronenergy.settings)
@40000000672f6609196453fc 002.994 ERR.values: timeout connecting device
@40000000672f660919646f54 002.994 INF.task: done in 002.994

I find it interesting that both myself and this person both have similar issues with the device flopping back and forth between GPS and the proper thing… His issue looks like the eeprom on his MK3-USB cable lost information - in my case I’m not sure that applies as I don’t have genuine cables, but I just find it odd the second-connected device is the one that loses connectivity regardless of which physical device it is.

I AM able to see that there is two separate Serial Ports here:

root@raspberrypi2:/usr/bin# lsusb
Bus 001 Device 005: ID 067b:2303 Prolific Technology, Inc. PL2303 Serial Port
Bus 001 Device 004: ID 067b:2303 Prolific Technology, Inc. PL2303 Serial Port
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter
Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

The hunt continues…

Well this is kind of odd, after rebooting I see the following:

@400000006730ae0f2360b594 *** starting serial-starter ***
@400000006730ae0f3aabe7b4 serstart starting
@400000006730ae0f3b888c14 INFO: loading config file /etc/venus/serial-starter.conf
@400000006730ae11356b25e4 INFO: Create daemontools service vedirect-interface.ttyUSB0
@400000006730ae21333eacdc INFO: Create daemontools service vedirect-interface.ttyUSB1
@400000006730ae261a19ffcc INFO: Start service vedirect-interface.ttyUSB0 once
@400000006730ae273a5a6c54 INFO: Start service vedirect-interface.ttyUSB1 once
@400000006730ae2b21533a24 INFO: Create daemontools service gps-dbus.ttyUSB1
@400000006730ae31247b8404 INFO: Start service gps-dbus.ttyUSB1 once
@400000006730ae3a37808cac INFO: Start service vedirect-interface.ttyUSB1 once

Why would we be trying to initialize the same device as a vedirect-interface and then again as a GPS interface? I don’t have a GPS, nor do I want one…

I edited the /etc/venus/serial-starter.conf file and commented out the entry for the GPS out of curiosity, the device was connected for 10 minutes or so but I’m seeing a few errors in the/var/log/vedirect.ttyUSB1/current log:

root@raspberrypi2:/dev/serial/by-id# tail -f /var/log/vedirect.ttyUSB1/current
@400000006730af3d0d0eeb1c 000.361 INF.VE.Frame: Ignoring BMV=SMARTSHUNT 500A/50MV due to parsing errors
@400000006730af3d0d0fd57c 000.361 INF.VE.Frame: Ignoring FW=0416 due to parsing errors
=OFF due to parsing errors000.361 INF.VE.Frame: Ignoring MON14400
@400000006730af3d0d0ff4bc 000.361 INF.VE.Frame: Ignoring AR=0 due to parsing errors
@400000006730af3d0d10045c 000.361 INF.VE.Frame: Ignoring BMV=SMARTSHUNT 500A/50MV due to parsing errors
@400000006730af3d0d1013fc 000.361 INF.VE.Frame: Ignoring FW=0416 due to parsing errors
=OFF due to parsing errors000.361 INF.VE.Frame: Ignoring MON14400
@400000006730af3d0d10e304 000.361 INF.VE.Frame: Ignoring AR=0 due to parsing errors
@400000006730af3d0d10f2a4 000.361 INF.VE.Frame: Ignoring BMV=SMARTSHUNT 500A/50MV due to parsing errors
@400000006730af3d0d110244 000.361 INF.VE.Frame: Ignoring FW=0416 due to parsing errors
@400000006730b589044dc8a4
@400000006730b589044de3fc -------- dumping backlog -------
@400000006730b589044defb4 607.335 INF.VE.Text: H7=11701
@400000006730b589044df784 607.335 INF.VE.Text: H8=14712
@400000006730b589044e033c 607.335 INF.VE.Text: H9=67610
@400000006730b589044e0b0c 607.335 INF.VE.Text: H10=1
@400000006730b589044e12dc 607.335 INF.VE.Text: H11=0
@400000006730b589044e1e94 607.335 INF.VE.Text: H12=0
@400000006730b589044e2664 607.335 INF.VE.Text: H15=0
@400000006730b589044e3604 607.335 INF.VE.Text: H16=0
@400000006730b58904507054 607.350 INF.VE.Text: H17=327
@400000006730b58904507c0c 607.350 INF.VE.Text: H18=109
@400000006730b589045083dc 607.350 INF.VE.Direct: TEXT RegId=0308 Value=0001081A
@400000006730b5890450937c 607.350 INF.bmv: itemUpdate 0308 0001081A 1
@400000006730b58904509f34 607.350 INF.bmv: Found item History/TimeSinceLastFullCharge
@400000006730b5890450aed4 607.805 INF.VE.Text: PID=0XA389
@400000006730b5890450b6a4 607.805 INF.VE.Text: V=13169
@400000006730b5890450c25c 607.805 INF.VE.Text: I=-194
@400000006730b589045127ec 607.805 INF.VE.Text: P=-3
@400000006730b5890451b48c 607.805 INF.VE.Text: CE=-19981
@400000006730b5890451c42c 607.805 INF.VE.Text: SOC=943
@400000006730b5890451cbfc 607.838 INF.VE.Text: TTG=14400
@400000006730b5890451d7b4 607.838 INF.VE.Text: ALARM=OFF
@400000006730b5890451df84 607.838 INF.VE.Text: AR=0
@400000006730b5890451e754 607.838 INF.VE.Text: BMV=SMARTSHUNT 500A/50MV
@400000006730b5890451f30c 607.838 INF.VE.Text: FW=0416
@400000006730b5890451fec4 612.410 INF.VE.Direct: Setting status to VdDisConnected
@400000006730b58904526c24 612.411 ERR.service: connection lost
@400000006730b589045277dc 612.411 INF.task: done in 1612.411

Even the error logging is poorly formatted… I’m curious if maybe there is errors being encountered, vedirect takes the device offline, it tries to re-initialize it as a GPS (for some reason) then the services try to compete for the USB port and nothing ever gets initialized or logged?

After the device eventually went offline I noticed the following error about the GPS also:

root@raspberrypi2:~# tail -f /var/log/serial-starter/current
@400000006730ae3a37808cac INFO: Start service vedirect-interface.ttyUSB1 once
@400000006730af2335d0d90c *** CCGX booted (0) ***
@400000006730af24133d1e14 *** starting serial-starter ***
@400000006730af2426bd4a2c serstart starting
@400000006730af242848187c INFO: loading config file /etc/venus/serial-starter.conf
@400000006730af261bf7acf4 INFO: Create daemontools service vedirect-interface.ttyUSB0
@400000006730af273b8abe94 INFO: Create daemontools service vedirect-interface.ttyUSB1
@400000006730af3b044dc4bc INFO: Start service vedirect-interface.ttyUSB0 once
@400000006730af3c232baf5c INFO: Start service vedirect-interface.ttyUSB1 once
@400000006730b58929286e2c ERROR: unknown service gps

After doing a bunch more looking and reading I’m seeing that someone else has encountered a similar issue and it was due to using non-isolated USB to Serial cables:

https://communityarchive.victronenergy.com/questions/118932/rpi-3-venus-os-not-seeing-smart-shunt-vedirect-ove.html

I ended up ordering a couple and will have a go a making new cables to see if that helps. If not I may look at getting one of these: Victron VE.direct Schnittstellenerweiterung 1 x USB auf 4 x VE.direct |

In the meantime I did a bit of digging into Bluetooth connectivity as I also purchased the Victron Energy Blue Smart 5 amp Battery Charger, I’d certainly be nice to do away with the cables entirely and have access to the information from the battery charger.

I found this thread:
https://communityarchive.victronenergy.com/questions/170165/venus-os-and-smart-solar-bluetooth-connection.html

In doing some digging on the Pi I was happy to see I can see both bluetooth enabled devices:

root@raspberrypi2:/# bluetoothctl
Agent registered
[CHG] Controller B8:27:EB:CD:98:F1 Pairable: yes
[bluetooth]# scan on
Discovery started
[CHG] Controller B8:27:EB:CD:98:F1 Discovering: yes
[NEW] Device D8:20:4A:17:19:F0 BSC IP65 12/5 HQ2414GJ3VM
[NEW] Device EE:2C:2A:54:E3:7E Relay Tower Charge
[bluetooth]# devices
Device 24:95:2F:5C:79:4F 24-95-2F-5C-79-4F
Device D8:20:4A:17:19:F0 BSC IP65 12/5 HQ2414GJ3VM
Device EE:2C:2A:54:E3:7E Relay Tower Charge

Buuuuuut in doing more digging it appears that there isn’t a whole lot more I can do with the devices than just that… there is no way to interface with them yet (despite some apparently abandoned efforts)

Did you get to the bottom of this problem?
I believe mine is voltage related as the port that shuts down, top right looking at the RPi, is at 4.83v under load, whereas the others are at 4.89v

I haven’t yet, I am waiting for my isolated cables to show up but they’re held up due to a postal strike here in Canada at the moment…