v3.00 (?): nanopi serial ports doing strange

[mpvader]

Short story: on this system, the serial port now and then returns strange data. Caused a device on a VE.Direct port to not be recognised. And also caused the Multi to not be recognised.

From a numbers point of view its quite likely that this EasySolar GX PCBA is broken; however unlikely from a technical point of view.

---

Long story:

This afternoon, when working on the BYD LV test system to check something else, I noticed that after a reboot of Venus OS I got a Solar Charger missing Error #67. And looks like the solar charger indeed went missing after a reboot from v3.00~40 into v3.00~39. And there after came back when booting into v3.00~41.

And thereafter the Multi went missing from Venus OS; Jos is look into that now

What I did was:

1) walked up to the device, was running v3.00~40 2) booted back in to v3.00~39; apparently that caused the solar charger to be missing. But no visible clue on this. 3) booted into v3.00~41; notification was blinking, from the solar charger: error #67, BMS missing

Looking at the logs show that indeed vedirect-interface didn't see the solar charger, or at least didn't go on to the D-Bus with it.

2023-05-11 13:01:45.965313500 switching to rootfs 1
2023-05-11 13:01:45.971416500 current version: 20230510221152 v3.00~40
2023-05-11 13:01:45.971429500 new version: 20230505191133 v3.00~39
2023-05-11 13:02:07.865940500 *** CCGX booted (0) ***
2023-05-11 13:05:59.821459500 *** Checking for updates ***
2023-05-11 13:05:59.821666500 arguments: -check
2023-05-11 13:05:59.887676500 Retrieving latest version... (from https://updates.victronenergy.com/feeds/venus/testing/images/nanopi/venus-swu-nanopi.swu)
2023-05-11 13:06:00.335860500 installed: 20230505191133 v3.00~39
2023-05-11 13:06:00.336127500 available: 20230511051848 v3.00~41

vedirect-interface log:
2023-05-11 03:03:10.901570500 *** CCGX booted (0) v3.00~40 ***
2023-05-11 03:03:19.125269500 *** starting vedirect-interface ***
2023-05-11 03:03:19.226824500 vedirect-dbus 3.71          <-- here all worked fine.
2023-05-11 13:02:07.877699500 *** CCGX booted (0) v3.00~39 ***
2023-05-11 13:02:16.431296500 *** starting vedirect-interface ***
2023-05-11 13:02:16.572503500 vedirect-dbus 3.71           <-- here it seems to have never found the MPPT
2023-05-11 13:06:36.897284500 *** CCGX booted (0) v3.00~41 ***
2023-05-11 13:06:45.310461500 *** starting vedirect-interface ***
2023-05-11 13:06:45.435477500 vedirect-dbus 3.71           <-- here the error appeared.
2023-05-11 13:16:21.896812500 *** CCGX booted (0) v3.00~39 ***
2023-05-11 13:16:30.505606500 *** starting vedirect-interface ***
2023-05-11 13:16:30.570935500 vedirect-dbus 3.71           <-- here all worked fine.

vrmlogger during the boot with the issue (here you also see the solar charger missing):
023-05-11 13:02:07.919260500 *** CCGX booted (0) ***
2023-05-11 13:02:08.135806500 *** starting vrmlogger ***
2023-05-11 13:02:20.639467500 MainThread-vrmlogger: /opt/victronenergy/vrmlogger/vrmlogger.py v2.275 is starting up
2023-05-11 13:02:20.641394500 MainThread-vrmlogger: Loglevel set to INFO
2023-05-11 13:02:20.677196500 MainThread-vedbus: registered ourselves on D-Bus as com.victronenergy.logger
2023-05-11 13:02:21.193780500 MainThread-dbusmonitor: ===== Search on dbus for services that we will monitor starting... =====
2023-05-11 13:02:21.200602500 MainThread-dbusmonitor: Found: com.victronenergy.settings, scanning and storing items
2023-05-11 13:02:21.203872500 MainThread-dbusmonitor:        com.victronenergy.settings has device instance 0
2023-05-11 13:02:21.292876500 MainThread-dbusmonitor: Found: com.victronenergy.battery.socketcan_can0, scanning and storing items
2023-05-11 13:02:21.304276500 MainThread-dbusmonitor:        com.victronenergy.battery.socketcan_can0 has device instance 512
2023-05-11 13:02:21.812850500 MainThread-dbusmonitor: Found: com.victronenergy.system, scanning and storing items
2023-05-11 13:02:21.819670500 MainThread-dbusmonitor:        com.victronenergy.system has device instance 0
2023-05-11 13:02:21.895628500 MainThread-dbusmonitor: ===== Search on dbus for services that we will monitor finished =====

vrmlogger during any other boot:
2023-05-11 13:06:36.942793500 *** CCGX booted (0) ***
2023-05-11 13:06:37.143793500 *** starting vrmlogger ***
2023-05-11 13:06:50.599147500 MainThread-vrmlogger: /opt/victronenergy/vrmlogger/vrmlogger.py v2.276 is starting up
2023-05-11 13:06:50.601116500 MainThread-vrmlogger: Loglevel set to INFO
2023-05-11 13:06:50.629676500 MainThread-vedbus: registered ourselves on D-Bus as com.victronenergy.logger
2023-05-11 13:06:50.904297500 MainThread-dbusmonitor: ===== Search on dbus for services that we will monitor starting... =====
2023-05-11 13:06:50.908817500 MainThread-dbusmonitor: Found: com.victronenergy.settings, scanning and storing items
2023-05-11 13:06:50.912324500 MainThread-dbusmonitor:        com.victronenergy.settings has device instance 0
2023-05-11 13:06:50.993813500 MainThread-dbusmonitor: Found: com.victronenergy.battery.socketcan_can0, scanning and storing items
2023-05-11 13:06:50.999978500 MainThread-dbusmonitor:        com.victronenergy.battery.socketcan_can0 has device instance 512
2023-05-11 13:06:51.292960500 MainThread-dbusmonitor: Found: com.victronenergy.solarcharger.ttyS1, scanning and storing items
2023-05-11 13:06:51.296733500 MainThread-dbusmonitor:        com.victronenergy.solarcharger.ttyS1 has device instance 273
2023-05-11 13:06:51.420802500 MainThread-dbusmonitor: Found: com.victronenergy.system, scanning and storing items
2023-05-11 13:06:51.425508500 MainThread-dbusmonitor:        com.victronenergy.system has device instance 0
2023-05-11 13:06:51.487418500 MainThread-dbusmonitor: ===== Search on dbus for services that we will monitor finished =====

[mpvader]

I checked VRM logs in further detail, wrt the solar charger, and it has been missing for 4 days a few days ago as well:

2023-04-28 02:47:54 -> solar charger showed ok     after installing and booting into v3.00~37
2023-05-07 02:54:23 -> solar charger went missing  after installing and booting into v3.00~39
2023-05-11 03:03:25 -> solar charger reappaeard    after installing and booting into v3.00~40
2023-05-11 13:02:22 -> solar charger went missing  after booting back into v3.00~39
2023-05-11 13:06:52 -> solar charger reappeared    after installing and booting into v3.00~41
2023-05-11 13:16:37 -> solar charger showed OK    after booting back into the same v3.00~39 again; without reinstalling that.

before that I can't find it missing; I didn't check in detail, but simply on VRM I see some solar kWhs every day, so not missing for long at least:

[vejpasop]

With Venus on V3.00~39 the Multi no longer seen seemed to be caused by the serial port spitting out data not recognized by mk2-dbus. It did not log the data but just complains it receives data it does not understand. Now after restarting mk2-dbus which re-opens the tty port mk2-dbus worked ok again. I rebooted 5 times. Every time the Multi and the solar charger where correctly discovered.

Now after I rebooted V3.00~41 (Through stored backup firmware) The solar charger is gone. Multi is there.

[mpvader]

See slack thread initiated yesterday for details