Victron Bus System Connection get lost when using dbus-mqtt-devices

[PanicMan]

Version

0.6.5 (current)

What version of VenusOS are you running on your GX device

3.21 (current release)

Does this issue occur during installation or at runtime ?

Runtime

Is there a Discussion thread for this issue? Please paste a link.

No response

What is the issue you are actually experiencing?

Hello, thank you very much for the code and the detailed description! I have the whole thing running on an MP2 5000 GX (Large OS), also have an OpenHab Smarthome and am quite familiar with MQTT. I get the grid data from an LG ESS 10 system and wanted to feed it to my Victron System, which runs in parallel. However, I get errors in the system when I run it on it. I connected an MPPT 450/100 charge controller via VE.direct and a battery system via BMS.CAN (500kbits), which has been running for a few weeks without any problems.
But as soon as I start supplying the MQTT Grid Meter with data, which happens every 10s, I get errors in the system and the charge controller stops charging: Solar Charger - MPPT 450/100: Error code: #67 - No BMS ... VE. Bus system: low battery alarm. Then the CCGX is rebooting...
As soon as I stop sending the MQTT data to the local broker, the whole thing works again. What could be the reason? Is this going to overload the system and prevent the BMS data from reaching the charge controller?
Tried to check the system load with "top", around 50-60%... Seems to be ok...
Thanks a lot!
Greetings Jack

If this is not installation related, what does the status payload look like that you are publishing to the driver to register your device?

{"clientId":"grid01","connected":1,"version":"v0.1","services":{"g1":"grid"}}

Relevant log output

@4000000065db140d27fb34e4 *** starting dbus-mqtt-devices ***
@4000000065db141118a7b6d4 dbus_mqtt_devices v{} 0.6.5
@4000000065db141118a7e1cc INFO:logger:Loglevel set to INFO
@4000000065db141118ce2e7c INFO:dbus_mqtt_devices:-------- dbus_mqtt_devices, v0.6.5 is starting up --------
@4000000065db14111e58baec INFO:device_manager:Using portalId c0619ab41a28
@4000000065db14122a19466c INFO:mqtt_gobject_bridge:[Init] Connecting to local broker
@4000000065db14122e5ab8dc INFO:device_manager:[Connected] Result code 0
@4000000065db14901d2a58c4 INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, 'version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db14901d61147c WARNING:device_manager:tried to remove device grid01 that is not registered
@4000000065db14902c6f8e94 INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 1, 'version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db14902c7e9254 INFO:device:**** Registering device: grid01, services: {'g1': 'grid'} ****
@4000000065db14902c885e24 INFO:device:Registering Service grid for client grid01
@4000000065db14902c91e3a4 INFO:device_service_config:About to open config file
@4000000065db1491114856dc INFO:device_service:Registering service grid for client grid01 at path com.victronenergy.grid.mqtt_grid01_g1
@4000000065db1491137dc0f4 INFO:settingsdevice:Setting /Settings/Devices/mqtt_grid01_g1/ClassAndVrmInstance does not exist yet or must be adjusted
@4000000065db149116e16624 INFO:vedbus:registered ourselves on D-Bus as com.victronenergy.grid.mqtt_grid01_g1
@4000000065db149117c9e1c4 INFO:device_service:Registered Service com.victronenergy.grid.mqtt_grid01_g1 under DeviceInstance 1
@4000000065db14911817b78c INFO:device_manager:publish {'portalId': 'c0619ab41a28', 'deviceInstance': {'g1': 1}} to device/grid01/DBus, status is 0

--- Here I manually send the disconnect Status from Node-Red ---

@4000000065db184202f652dc INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, 'version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db18420609efc4 INFO:device_service:Unregistered mqtt_grid01_g1 from dbus
@4000000065db1842061899ac INFO:device:Removed Service g1 from client grid01
@4000000065db18420634c49c INFO:device_manager:**** Unregistering device grid01 ****

[freakent]

Hi Jack,
There is a good chance that since you are running this on a CCGX you are simply running out of system resources. Take a close look at /var/log/dmesg. Somewhere you might see messages about system being low on resources and the OS forcing a reboot.

I experienced this same problem on my ccgx so I stopped using the driver, but I also experienced this after adding 4 ruuvi tags to my system so I can't blame the driver. I guess it just doesn't take much to cause reboots on a CCGX. This weekend I replaced my own CCGX with an Ekrano.

[PanicMan]

Tried it again, nearly after some seconds the connection breaks an the venusOS reboots...
Can't see anything relevant in the logs, as I thing every time on reboot its clearing:

root@nanopi:~# more /var/log/dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.109-venus-15 (oe-user@oe-host) (arm-ve-linux-gnueabi-gcc (GCC) 9.5.0, GNU ld (GNU B
inutils) 2.34.0.20200910) #1 SMP Fri Feb 16 18:41:20 UTC 2024
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: MultiPlus-II
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 64 MiB at 0x5bc00000
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000040000000-0x000000005fffffff]
[    0.000000]   HighMem  empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000040000000-0x000000005fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x000000005fffffff]
[    0.000000] On node 0 totalpages: 131072
[    0.000000]   Normal zone: 1024 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 131072 pages, LIFO batch:31
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: Using PSCI v0.1 Function IDs from DT
[    0.000000] percpu: Embedded 15 pages/cpu s31564 r8192 d21684 u61440
[    0.000000] pcpu-alloc: s31564 r8192 d21684 u61440 alloc=15*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 130048
[    0.000000] Kernel command line: console=ttyS0,115200 root=/dev/mmcblk1p2 rootwait ro rootfstype=ext4 5 vt.global_
cursor_default=0
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 443668K/524288K available (6144K kernel code, 647K rwdata, 1304K rodata, 1024K init, 221K bss,
 15084K reserved, 65536K cma-reserved, 0K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000]  Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] random: get_random_bytes called from start_kernel+0x314/0x4ac with crng_init=0
[    0.000000] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[    0.000000] arch_timer: cp15 timer(s) running at 24.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 4407952025
92 ns
[    0.000007] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
[    0.000022] Switching to timer-based delay loop, resolution 41ns
[    0.000218] Console: colour dummy device 80x30
[    0.000289] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=240000)
[    0.000310] pid_max: default: 32768 minimum: 301
[    0.000459] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.000476] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.001173] CPU: Testing write buffer coherency: ok
[    0.001514] /cpus/cpu@0 missing clock-frequency property
[    0.001539] /cpus/cpu@1 missing clock-frequency property
[    0.001558] /cpus/cpu@2 missing clock-frequency property
[    0.001578] /cpus/cpu@3 missing clock-frequency property
[    0.001592] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.002170] Setting up static identity map for 0x40100000 - 0x40100060
[    0.002294] rcu: Hierarchical SRCU implementation.
[    0.002921] smp: Bringing up secondary CPUs ...
[    0.013669] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.024486] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.035248] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.035345] smp: Brought up 1 node, 4 CPUs
[    0.035374] SMP: Total of 4 processors activated (192.00 BogoMIPS).
[    0.035383] CPU: All CPU(s) started in HYP mode.
[    0.035389] CPU: Virtualization extensions available.
[    0.036078] devtmpfs: initialized
[    0.041466] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.041650] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.041682] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.043957] pinctrl core: initialized pinctrl subsystem
[    0.045151] NET: Registered protocol family 16
[    0.046620] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.047687] thermal_sys: Registered thermal governor 'step_wise'
[    0.048097] cpuidle: using governor menu
[    0.048309] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.048322] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.066137] cryptd: max_cpu_qlen set to 1000
[    0.067380] vdd-sys-3v3: supplied by vdd-5v
[    0.068111] iommu: Default domain type: Translated
[    0.068366] usbcore: registered new interface driver usbfs
[    0.068415] usbcore: registered new interface driver hub
[    0.068463] usbcore: registered new device driver usb
[    0.069932] clocksource: Switched to clocksource arch_sys_counter
[    0.077223] NET: Registered protocol family 2
[    0.077419] IP idents hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.078160] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.078194] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    0.078241] TCP bind hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    0.078304] TCP: Hash tables configured (established 4096 bind 4096)
[    0.078431] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.078480] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.078631] NET: Registered protocol family 1
[    0.080013] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    0.081754] Initialise system trusted keyrings
[    0.081966] workingset: timestamp_bits=30 max_order=17 bucket_order=0
[    0.086168] Key type asymmetric registered
[    0.086189] Asymmetric key parser 'x509' registered
[    0.086950] sun4i-usb-phy 1c19400.phy: Couldn't request ID GPIO
[    0.090741] sun8i-h3-pinctrl 1c20800.pinctrl: initialized sunXi PIO driver
[    0.092695] sun8i-h3-r-pinctrl 1f02c00.pinctrl: initialized sunXi PIO driver
[    0.097738] Serial: 8250/16550 driver, 8 ports
[    0.118575] 1c28000.serial: ttyS0 at MMIO 0x1c28000 (irq = 43, base_baud = 1500000) is a 16550A
[    0.701256] printk: console [ttyS0] enabled
[    0.726502] 1c28400.serial: ttyS1 at MMIO 0x1c28400 (irq = 44, base_baud = 1500000) is a U6_16550A
[    0.756339] 1c28800.serial: ttyS2 at MMIO 0x1c28800 (irq = 45, base_baud = 1500000) is a U6_16550A
[    0.786170] 1c28c00.serial: ttyS3 at MMIO 0x1c28c00 (irq = 46, base_baud = 1500000) is a U6_16550A
[    0.798626] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    0.805191] ehci-platform: EHCI generic platform driver
[    0.810852] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    0.817049] ohci-platform: OHCI generic platform driver
[    0.823414] i2c /dev entries driver
[    0.827480] i2c i2c-0: using pinctrl states for GPIO recovery
[    0.833332] i2c i2c-0: using generic GPIOs for recovery
[    0.839811] at24 0-0050: 256 byte 24c02 EEPROM, read-only
[    0.848606] rtc-pcf8523 0-0068: registered as rtc0
[    0.854839] rtc-pcf8523 0-0068: setting system clock to 2024-02-29T07:54:38 UTC (1709193278)
[    0.863942] pca953x 0-0020: using no AI
[    0.872221] sunxi-wdt 1c20ca0.watchdog: Watchdog enabled (timeout=16 sec, nowayout=1)
[    0.880639] watchdog: watchdog0 running and kernel based pre-userspace handler disabled
[    0.890728] sunxi-mmc 1c0f000.mmc: Got CD GPIO
[    0.892698] NET: Registered protocol family 10
[    0.900569] Segment Routing with IPv6
[    0.904317] NET: Registered protocol family 17
[    0.908861] Registering SWP/SWPB emulation handler
[    0.915538] registered taskstats version 1
[    0.915976] sunxi-mmc 1c11000.mmc: initialized, max. request size: 16384 KB
[    0.919652] Loading compiled-in X.509 certificates
[    0.919958] sunxi-mmc 1c0f000.mmc: initialized, max. request size: 16384 KB
[    0.948274] vdd-vcc-dram: supplied by vdd-sys-3v3
[    0.997931] random: fast init done
[    1.001496] mmc1: new DDR MMC card at address 0001
[    1.007187] mmcblk1: mmc1:0001 8GTF4R 7.28 GiB
[    1.012382] mmcblk1boot0: mmc1:0001 8GTF4R partition 1 4.00 MiB
[    1.018870] mmcblk1boot1: mmc1:0001 8GTF4R partition 2 4.00 MiB
[    1.026429]  mmcblk1: p1 p2 p3 p4 < p5 >
[    1.160865] ehci-platform 1c1b000.usb: EHCI Host Controller
[    1.166729] ehci-platform 1c1b000.usb: new USB bus registered, assigned bus number 1
[    1.174875] ehci-platform 1c1b000.usb: irq 34, io mem 0x01c1b000
[    1.209945] ehci-platform 1c1b000.usb: USB 2.0 started, EHCI 1.00
[    1.216256] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    1.224546] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.231775] usb usb1: Product: EHCI Host Controller
[    1.236649] usb usb1: Manufacturer: Linux 5.10.109-venus-15 ehci_hcd
[    1.243008] usb usb1: SerialNumber: 1c1b000.usb
[    1.248096] hub 1-0:1.0: USB hub found
[    1.251908] hub 1-0:1.0: 1 port detected
[    1.256705] ehci-platform 1c1d000.usb: EHCI Host Controller
[    1.262514] ehci-platform 1c1d000.usb: new USB bus registered, assigned bus number 2
[    1.270512] ehci-platform 1c1d000.usb: irq 35, io mem 0x01c1d000
[    1.299942] ehci-platform 1c1d000.usb: USB 2.0 started, EHCI 1.00
[    1.306229] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    1.314513] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.321741] usb usb2: Product: EHCI Host Controller
[    1.326615] usb usb2: Manufacturer: Linux 5.10.109-venus-15 ehci_hcd
[    1.332977] usb usb2: SerialNumber: 1c1d000.usb
[    1.337959] hub 2-0:1.0: USB hub found
[    1.341760] hub 2-0:1.0: 1 port detected
[    1.346457] ohci-platform 1c1d400.usb: Generic Platform OHCI controller
[    1.353286] ohci-platform 1c1d400.usb: new USB bus registered, assigned bus number 3
[    1.361248] ohci-platform 1c1d400.usb: irq 36, io mem 0x01c1d400
[    1.434092] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.10
[    1.442378] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.449592] usb usb3: Product: Generic Platform OHCI controller
[    1.455520] usb usb3: Manufacturer: Linux 5.10.109-venus-15 ohci_hcd
[    1.461878] usb usb3: SerialNumber: 1c1d400.usb
[    1.466882] hub 3-0:1.0: USB hub found
[    1.470775] hub 3-0:1.0: 1 port detected
[    1.479463] input: disp_keys as /devices/platform/disp_keys/input/input0
[    1.493575] EXT4-fs (mmcblk1p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.501791] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.509108] devtmpfs: mounted
[    1.513503] Freeing unused kernel memory: 1024K
[    1.539952] usb 1-1: new high-speed USB device number 2 using ehci-platform
[    1.560087] Run /sbin/init as init process
[    1.564184]   with arguments:
[    1.564189]     /sbin/init
[    1.564193]     5
[    1.564197]   with environment:
[    1.564202]     HOME=/
[    1.564206]     TERM=linux
[    1.741106] usb 1-1: New USB device found, idVendor=0bda, idProduct=d723, bcdDevice= 2.00
[    1.749324] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    1.756558] usb 1-1: Product: 802.11n WLAN Adapter
[    1.761414] usb 1-1: Manufacturer: Realtek
[    1.765549] usb 1-1: SerialNumber: 00e04c000001
[    1.816123] EXT4-fs (mmcblk1p5): mounted filesystem with ordered data mode. Opts: (null)
[    1.952864] udevd[134]: starting version 3.2.9
[    1.969246] random: udevd: uninitialized urandom read (16 bytes read)
[    1.976339] random: udevd: uninitialized urandom read (16 bytes read)
[    1.982989] random: udevd: uninitialized urandom read (16 bytes read)
[    2.012862] udevd[135]: starting eudev-3.2.9
[    2.149424] gxdisp_bl 0-0051: supply vcc not found, using dummy regulator
[    2.175514] CAN device driver interface
[    2.187557] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    2.188151] spi_master spi0: will run message pump with realtime priority
[    2.214506] Bluetooth: Core ver 2.22
[    2.218289] NET: Registered protocol family 31
[    2.222867] Bluetooth: HCI device and connection manager initialized
[    2.229270] Bluetooth: HCI socket layer initialized
[    2.234318] Bluetooth: L2CAP socket layer initialized
[    2.258840] lima 1c40000.gpu: gp - mali400 version major 1 minor 1
[    2.265397] lima 1c40000.gpu: pp0 - mali400 version major 1 minor 1
[    2.268709] mcp251xfd spi0.0 can0: MCP2518FD rev0.0 (+RX_INT -MAB_NO_WARN +CRC_REG +CRC_RX +CRC_TX +ECC -HD c:40.0
0MHz m:20.00MHz r:17.00MHz e:16.66MHz) successfully initialized.
[    2.271984] lima 1c40000.gpu: pp1 - mali400 version major 1 minor 1
[    2.294104] dwmac-sun8i 1c30000.ethernet: IRQ eth_wake_irq not found
[    2.294133] dwmac-sun8i 1c30000.ethernet: IRQ eth_lpi not found
[    2.294313] dwmac-sun8i 1c30000.ethernet: No regulator found
[    2.300772] lima 1c40000.gpu: l2 cache 64K, 4-way, 64byte cache line, 64bit external bus
[    2.306787] dwmac-sun8i 1c30000.ethernet: PTP uses main clock
[    2.314452] usbcore: registered new interface driver btusb
[    2.320650] dwmac-sun8i 1c30000.ethernet: Current syscon value is not the default 148000 (expect 58000)
[    2.330388] lima 1c40000.gpu: bus rate = 200000000
[    2.334383] Bluetooth: hci0: RTL: examining hci_ver=08 hci_rev=000d lmp_ver=08 lmp_subver=8723
[    2.334983] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    2.341457] lima 1c40000.gpu: mod rate = 297000000
[    2.341807] lima 1c40000.gpu: dev_pm_opp_set_regulators: no regulator (mali) found: -19
[    2.347322] dwmac-sun8i 1c30000.ethernet: No HW DMA feature register supported
[    2.348209] Bluetooth: hci0: RTL: rom_version status=0 version=2
[    2.348220] Bluetooth: hci0: RTL: loading rtl_bt/rtl8723d_fw.bin
[    2.352414] Bluetooth: hci0: RTL: loading rtl_bt/rtl8723d_config.bin
[    2.356300] Bluetooth: hci0: RTL: cfg_sz 10, total sz 33266
[    2.361977] dwmac-sun8i 1c30000.ethernet: RX Checksum Offload Engine supported
[    2.383709] 8723du: loading out-of-tree module taints kernel.
[    2.388267] dwmac-sun8i 1c30000.ethernet: COE Type 2
[    2.388276] dwmac-sun8i 1c30000.ethernet: TX Checksum insertion supported
[    2.388284] dwmac-sun8i 1c30000.ethernet: Normal descriptors
[    2.388290] dwmac-sun8i 1c30000.ethernet: Chain mode enabled
[    2.390756] dwmac-sun8i 1c30000.ethernet: Found internal PHY node
[    2.393099] lima 1c40000.gpu: Failed to register cooling device
[    2.394085] [drm] Initialized lima 1.1.0 20191231 for 1c40000.gpu on minor 0
[    2.463603] dwmac-sun8i 1c30000.ethernet: Switch mux to internal PHY
[    2.470132] dwmac-sun8i 1c30000.ethernet: Powering internal PHY
[    2.655993] Bluetooth: hci0: RTL: fw version 0x828a96f1
[    2.730017] usbcore: registered new interface driver rtl8723du
[    2.757409] rtl8723du 1-1:1.2 ap0: renamed from wlan1
[    2.824721] rtl8723du 1-1:1.2 wifi0: renamed from wlan0
[    2.975352] EXT4-fs (mmcblk1p2): re-mounted. Opts: (null)

On your logs also nothing special, except the one break, where venusOS rebooted:

root@nanopi:~# more /var/log/dbus-mqtt-devices/current
@4000000065db140d27fb34e4 *** starting dbus-mqtt-devices ***
@4000000065db141118a7b6d4 dbus_mqtt_devices v{} 0.6.5
@4000000065db141118a7e1cc INFO:logger:Loglevel set to INFO
@4000000065db141118ce2e7c INFO:dbus_mqtt_devices:-------- dbus_mqtt_devices, v0.6.5 is starting up --------
@4000000065db14111e58baec INFO:device_manager:Using portalId c0xxx8
@4000000065db14122a19466c INFO:mqtt_gobject_bridge:[Init] Connecting to local broker
@4000000065db14122e5ab8dc INFO:device_manager:[Connected] Result code 0
@4000000065db14901d2a58c4 INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db14901d61147c WARNING:device_manager:tried to remove device grid01 that is not registered
@4000000065db14902c6f8e94 INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 1, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db14902c7e9254 INFO:device:**** Registering device: grid01, services: {'g1': 'grid'} ****
@4000000065db14902c885e24 INFO:device:Registering Service grid for client grid01
@4000000065db14902c91e3a4 INFO:device_service_config:About to open config file
@4000000065db1491114856dc INFO:device_service:Registering service grid for client grid01 at path com.victronenergy.gr
id.mqtt_grid01_g1
@4000000065db1491137dc0f4 INFO:settingsdevice:Setting /Settings/Devices/mqtt_grid01_g1/ClassAndVrmInstance does not e
xist yet or must be adjusted
@4000000065db149116e16624 INFO:vedbus:registered ourselves on D-Bus as com.victronenergy.grid.mqtt_grid01_g1
@4000000065db149117c9e1c4 INFO:device_service:Registered Service com.victronenergy.grid.mqtt_grid01_g1 under DeviceIn
stance 1
@4000000065db14911817b78c INFO:device_manager:publish {'portalId': 'c0xxx8', 'deviceInstance': {'g1': 1}} to de
vice/grid01/DBus, status is 0
@4000000065db184202f652dc INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db18420609efc4 INFO:device_service:Unregistered mqtt_grid01_g1 from dbus
@4000000065db1842061899ac INFO:device:Removed Service g1 from client grid01
@4000000065db18420634c49c INFO:device_manager:**** Unregistering device grid01 ****
@4000000065db51030036dcec INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db5103005e4aac WARNING:device_manager:tried to remove device grid01 that is not registered
@4000000065db511e0861a334 INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 1, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db511e0861ddcc INFO:device:**** Registering device: grid01, services: {'g1': 'grid'} ****
@4000000065db511e0861e984 INFO:device:Registering Service grid for client grid01
@4000000065db511e0861f53c INFO:device_service_config:About to open config file
@4000000065db511e267c515c INFO:device_service:Unregistered mqtt_grid01_g1 from dbus
@4000000065db511e3a0cec7c INFO:device_service:Registering service grid for client grid01 at path com.victronenergy.gr
id.mqtt_grid01_g1
@4000000065db512103d36884 INFO:settingsdevice:Setting /Settings/Devices/mqtt_grid01_g1/ClassAndVrmInstance does not e
xist yet or must be adjusted
@4000000065db51210b668a7c INFO:vedbus:registered ourselves on D-Bus as com.victronenergy.grid.mqtt_grid01_g1
@4000000065db51210df9c434 INFO:device_service:Registered Service com.victronenergy.grid.mqtt_grid01_g1 under DeviceIn
stance 1
@4000000065db512110b64454 INFO:device_manager:publish {'portalId': 'c0xxx8', 'deviceInstance': {'g1': 1}} to de
vice/grid01/DBus, status is 0
@4000000065db531b2960105c INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db531b2e54b1e4 INFO:device_service:Unregistered mqtt_grid01_g1 from dbus
@4000000065db531b2e5dbe4c INFO:device:Removed Service g1 from client grid01
@4000000065db531b2e6ed164 INFO:device_manager:**** Unregistering device grid01 ****
@4000000065db535707752c0c INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 1, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db535707868d44 INFO:device:**** Registering device: grid01, services: {'g1': 'grid'} ****
@4000000065db535707900edc INFO:device:Registering Service grid for client grid01
@4000000065db53570798bd84 INFO:device_service_config:About to open config file
@4000000065db535717950e54 INFO:device_service:Unregistered mqtt_grid01_g1 from dbus
@4000000065db53581f438c34 INFO:device_service:Registering service grid for client grid01 at path com.victronenergy.gr
id.mqtt_grid01_g1
@4000000065db5358244a94ac INFO:settingsdevice:Setting /Settings/Devices/mqtt_grid01_g1/ClassAndVrmInstance does not e
xist yet or must be adjusted
@4000000065db535901ce41e4 INFO:vedbus:registered ourselves on D-Bus as com.victronenergy.grid.mqtt_grid01_g1
@4000000065db53590488ed44 INFO:device_service:Registered Service com.victronenergy.grid.mqtt_grid01_g1 under DeviceIn
stance 1
@4000000065db535908b0c8ec INFO:device_manager:publish {'portalId': 'c0xxx8', 'deviceInstance': {'g1': 1}} to de
vice/grid01/DBus, status is 0
@4000000065db540130008d24 INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db54013988d7fc INFO:device_service:Unregistered mqtt_grid01_g1 from dbus
@4000000065db540139938a44 INFO:device:Removed Service g1 from client grid01
@4000000065db5401399e82dc INFO:device_manager:**** Unregistering device grid01 ****
@4000000065db54822d0371f4 *** CCGX booted (30253) ***
@4000000065db54b8204e4d44 *** starting dbus-mqtt-devices ***
@4000000065db54bb36bcee8c dbus_mqtt_devices v{} 0.6.5
@4000000065db54bb36bd159c INFO:logger:Loglevel set to INFO
@4000000065db54bb36e759ec INFO:dbus_mqtt_devices:-------- dbus_mqtt_devices, v0.6.5 is starting up --------
@4000000065db54bb3acf3e94 INFO:device_manager:Using portalId c0xxx8
@4000000065db54bc2df00c44 INFO:mqtt_gobject_bridge:[Init] Connecting to local broker
@4000000065db54bc30f8bc4c INFO:device_manager:[Connected] Result code 0
@4000000065db54c306e4c34c INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 1, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065db54c3070e0d9c INFO:device:**** Registering device: grid01, services: {'g1': 'grid'} ****
@4000000065db54c307176ff4 INFO:device:Registering Service grid for client grid01
@4000000065db54c3071f8e14 INFO:device_service_config:About to open config file
@4000000065db54c32680fcac INFO:device_service:Registering service grid for client grid01 at path com.victronenergy.gr
id.mqtt_grid01_g1
@4000000065db54c3294b5f7c INFO:settingsdevice:Setting /Settings/Devices/mqtt_grid01_g1/ClassAndVrmInstance does not e
xist yet or must be adjusted
@4000000065db54c32cff91c4 INFO:vedbus:registered ourselves on D-Bus as com.victronenergy.grid.mqtt_grid01_g1
@4000000065db54c32e241c64 INFO:device_service:Registered Service com.victronenergy.grid.mqtt_grid01_g1 under DeviceIn
stance 1
@4000000065db54c32e64bb5c INFO:device_manager:publish {'portalId': 'c0xxx8', 'deviceInstance': {'g1': 1}} to de
vice/grid01/DBus, status is 0
@4000000065e0384f2d23792c *** CCGX booted (0) ***
@4000000065e03880128ef424 *** starting dbus-mqtt-devices ***
@4000000065e038840e5d2984 dbus_mqtt_devices v{} 0.6.5
@4000000065e038840e5d4cac INFO:logger:Loglevel set to INFO
@4000000065e038840e7b63cc INFO:dbus_mqtt_devices:-------- dbus_mqtt_devices, v0.6.5 is starting up --------
@4000000065e03884132d3bac INFO:device_manager:Using portalId c0xxx8
@4000000065e03885115cf81c INFO:mqtt_gobject_bridge:[Init] Connecting to local broker
@4000000065e0388513c8c02c INFO:device_manager:[Connected] Result code 0
@4000000065e0388e1cac4b3c INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 1, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065e0388e1ce6c014 INFO:device:**** Registering device: grid01, services: {'g1': 'grid'} ****
@4000000065e0388e1cf65844 INFO:device:Registering Service grid for client grid01
@4000000065e0388e1d0680fc INFO:device_service_config:About to open config file
@4000000065e0388f00cf3cbc INFO:device_service:Registering service grid for client grid01 at path com.victronenergy.gr
id.mqtt_grid01_g1
@4000000065e0388f0491af74 INFO:settingsdevice:Setting /Settings/Devices/mqtt_grid01_g1/ClassAndVrmInstance does not e
xist yet or must be adjusted
@4000000065e0388f087f50dc INFO:vedbus:registered ourselves on D-Bus as com.victronenergy.grid.mqtt_grid01_g1
@4000000065e0388f091bbbd4 INFO:device_service:Registered Service com.victronenergy.grid.mqtt_grid01_g1 under DeviceIn
stance 1
@4000000065e0388f0958fb84 INFO:device_manager:publish {'portalId': 'c0xxx8', 'deviceInstance': {'g1': 1}} to de
vice/grid01/DBus, status is 0
@4000000065e038e524b11eac INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065e038e5269b721c INFO:device_service:Unregistered mqtt_grid01_g1 from dbus
@4000000065e038e526a9e16c INFO:device:Removed Service g1 from client grid01
@4000000065e038e526b84504 INFO:device_manager:**** Unregistering device grid01 ****
@4000000065e03a9e0bc177d4 INFO:device_manager:Received device status message {'clientId': 'grid01', 'connected': 0, '
version': 'v0.1', 'services': {'g1': 'grid'}}
@4000000065e03a9e0bdaf344 WARNING:device_manager:tried to remove device grid01 that is not registered

But it seems I can't use it, too bad... Thanks anyway...
In your Info is the uninstall section missing, how to uninstall the whole stuff, what are the steps?

[freakent]

Is this on a CCGX? I just saw that your hostname is nanopi?

I'm sure I found a way to look at dmesg log files from previous boot when I had this problem. I'll have look into that again.

To uninstall, there is a ./bin/uninstall.sh script. Also manually adjust (or remove) your /data/rc.local file.

[PanicMan]

It is an Victron Multiplus II 48/5000/70-50 GX, that GX means it has an integrated GX Module and don't need an CerboGX anymore, but it seems it is an really weak NanoPi Module...

[brik2k]

Hi. I'm not sure if this is related, but I had a similar experience with the driver configured for a gps service after I made some changes to the code that prepares the data for MQTT publishing. Same symptoms with my Cerbo GX rebooting, losing connections to other devices, etc. In the end, I believe it was caused by me sending the lat/long values as strings instead of numbers in the MQTT messages. I used the Number() function to convert the strings back to numbers and, so far, everything seems to be back to normal. I'm not using the proxy feature.

I'm curious, if the data type being wrong was my issue, and maybe yours, is that a problem with the dbus-mqtt-devices driver or the Victron MQTT system? As far as I understand it, once the device driver is configured and running, the MQTT messages to the W/portalid/device/etc aren't processed by the dbus-mqtt-devices driver, right?

[freakent]

You are correct, once your device is registered but the driver, the driver's job is done. You are then communicating with Victron's FlashMQ directly. If you have a repeatable test case we should send it to victron.