Recurring "YieldThisYear failed", "wrong symbol received" and "SYN received"

[BlackAlpha700]

Description

Yesterday I've received my ebus-adapter (v5) from John and connected it to my Vaillant heating (ecoTEC exclusiv VC DE 146/4-7, allSTOR VPS800/2, auroMATIC VRS620/3, VPM 20S and VPM 20/25 W). The signal is detected and the ebusd found some devices at scanning the bus.
I use MQTT with retention to send the values to my smarthome server. Some status messages were found directly and if I switch something on the auroMATIC, the values were mostly read/found of ebusd. But I get many errors on the bus like

2023-05-12 09:34:15.390 [bus error] poll ui YieldThisYear failed: ERR: wrong symbol received

Sometimes YieldThisYear could be polled successfully (after some hours) but mostly I get errors.

Topology:
ecoTEC, and VPM 20S are connected directly to auroMATIC and the eBus-adapter is connected to VPM 20S - all with 1,5mm² cables.

The adapter (Firmware Build 20230501) uses wifi to connect to my LAN and the ebusd V23.1.23.1 is installed on a Proxmox LXC, 2CPUs (Intel i5 6400), 256MB RAM, SSD storage) with Debian 11.

Actual behavior

errors

Expected behavior

no errors ;-)

ebusd version

23.1

ebusd arguments

EBUSD_OPTS="--device=ens:mydeviceFQDN:9999 --latency=10 --logfile=/var/log/ebusd.log --log=all:error --log=network:info --log=other:info --mqttjson --mqttretain --mqttchanges --mqttverbose --mqtthost=myhostFQDN --mqttport=1833 --mqttuser=myuser --mqttpass=mypass --mqttclientid=ebusd --scanconfig=full --configpath=/etc/ebusd/configs/ --httpport=8889 --htmlpath=/var/ebusd/html"

Operating system

Debian 11 (Bullseye) / Ubuntu 20-21 / Raspbian 11 / Raspberry Pi OS 11 (including lite)

CPU architecture

x64

Dockerized

None

Hardware interface

other

Related integration

HTTP, MQTT generic

Logs

2023-05-12 09:34:15.040 [bus info] poll cmd: 3115b509030d4400
2023-05-12 09:34:15.280 [bus info] poll cmd: 3115b509030d4408
2023-05-12 09:34:15.390 [bus error] poll ui YieldThisYear failed: ERR: wrong symbol received
2023-05-12 09:34:21.031 [bus info] poll cmd: 3115b509030d4400
2023-05-12 09:34:21.120 [bus error] poll ui YieldThisYear failed: ERR: wrong symbol received
2023-05-12 09:34:22.178 [bus info] scan 23 cmd: 3123b5090124
2023-05-12 09:34:22.300 [main error] scan config 23: ERR: wrong symbol received
2023-05-12 09:34:24.301 [bus info] scan fc cmd: 31fcb5090124
2023-05-12 09:34:24.440 [main error] scan config fc: ERR: SYN received
2023-05-12 09:34:27.010 [bus info] poll cmd: 3115b509030d4400
2023-05-12 09:34:27.130 [bus error] poll ui YieldThisYear failed: ERR: wrong symbol received
2023-05-12 09:34:32.448 [bus info] scan 23 cmd: 3123b5090124
2023-05-12 09:34:32.580 [main error] scan config 23: ERR: wrong symbol received
2023-05-12 09:34:33.025 [bus info] poll cmd: 3115b509030d4400
2023-05-12 09:34:33.366 [bus info] poll cmd: 3115b509030d4408
2023-05-12 09:34:33.468 [bus error] poll ui YieldThisYear failed: ERR: wrong symbol received
2023-05-12 09:34:34.581 [bus info] scan fc cmd: 31fcb5090124
2023-05-12 09:34:34.690 [main error] scan config fc: ERR: wrong symbol received

[john30]

check with "raw" what symbols are received from ui as answer to the query. if that does not produce enough output, use "raw bytes" instead

[john30]

oh and do you have a strong enough wifi?

[BlackAlpha700]

check with "raw" what symbols are received from ui as answer to the query. if that does not produce enough output, use "raw bytes" instead

I've enabled raw logging and called ebusctl r -c ui YieldThisYear.

2023-05-13 08:53:12.245 [bus info] send message: 3115b509030d4400
2023-05-13 08:53:12.506 [bus notice] >3115b509030d44000a<00021400df>00
2023-05-13 08:53:12.506 [bus info] send message: 3115b509030d4408
2023-05-13 08:53:12.615 [bus error] send to 15: ERR: wrong symbol received, retry
2023-05-13 08:53:13.196 [bus notice] >3115b5<14
2023-05-13 08:53:13.246 [bus error] send to 15: ERR: wrong symbol received, retry
2023-05-13 08:53:13.826 [bus notice] >3115b5<14
2023-05-13 08:53:14.074 [bus notice] >3115b509030d440802<0002cb00c0>00
2023-05-13 08:53:14.074 [bus info] send message: 3115b509030d4410
2023-05-13 08:53:14.326 [bus notice] <10edb5080707000020040002e400000000
2023-05-13 08:53:14.472 [bus error] send to 15: ERR: read timeout, retry
2023-05-13 08:53:15.088 [bus notice] >3115b50903<01ecb50401343c0003000001e300
2023-05-13 08:53:15.296 [bus notice] >3115b509030d44101a<0002fe00cc>00
2023-05-13 08:53:15.296 [bus info] send message: 3115b509030d4418
2023-05-13 08:53:15.411 [bus notice] <1026b505082b0f0100000000073000000000
2023-05-13 08:53:15.606 [bus notice] >3115b509030d441812<000223027c>00
2023-05-13 08:53:15.606 [bus info] send message: 3115b509030d4420
2023-05-13 08:53:15.717 [bus error] send to 15: ERR: wrong symbol received, retry
2023-05-13 08:53:16.307 [bus notice] >3115b5<11ff
2023-05-13 08:53:16.349 [bus error] send to 15: ERR: wrong symbol received, retry
2023-05-13 08:53:16.947 [bus notice] >3115b509<f509
2023-05-13 08:53:17.143 [bus notice] >3115b509030d44202a<0002e20026>00
2023-05-13 08:53:17.143 [bus info] send message: 3115b509030d4428
2023-05-13 08:53:17.266 [bus notice] <10ecb5040110d8000a32047b0300800080e703c000
2023-05-13 08:53:17.306 [bus info] poll cmd: 3108b509030d1800
2023-05-13 08:53:17.306 [bus error] send to 15: ERR: wrong symbol received, retry

oh and do you have a strong enough wifi?

The adapter shows 52% (-74dBm). My unifi controller shows -69dBm
Is that enough?

I've seen the adpater didn't use the nearest AP. I've now kicked him to the nearest AP and fixed the configuration.
Now the values are much better: 96% (-52dBm), Controller -43dBm. But the errors stay the same. :-(

[john30]

please check for a potential address conflict by issuing "ebusctl info". if there is no conflict detected, please run that particular read with raw logging bytes enabled and post it here (but don't do that too long, as it yields in massive logging).
70% signal strength should be fine

[BlackAlpha700]

Sorry, I was a litte too busy in the last weeks. :-(

Here is the output of ebusctl info:

localhost: info
version: ebusd 23.1.23.1
device: ebus.xyz.xyz:9999, enhanced, firmware 1.1[3501].1[3501]
signal: acquired
symbol rate: 94
max symbol rate: 231
min arbitration micros: 1
max arbitration micros: 188
min symbol latency: 6
max symbol latency: 70
reconnects: 0
masters: 6
messages: 935
conditional: 24
poll: 58
update: 12
address 00: master #1
address 01: master #6
address 03: master #11
address 06: slave #6, scanned "MF=Vaillant;ID=PMS00;SW=0107;HW=4302", loaded "vaillant/06.pms.csv"
address 08: slave #11, scanned "MF=Vaillant;ID=BAI00;SW=0703;HW=7401", loaded "vaillant/bai.0010006101.inc" ([PROD='']), "vaillant/08.bai.csv"
address 0a: slave, scanned "MF=Vaillant;ID=PMW00;SW=0117;HW=4402", loaded "vaillant/0a.pmw.hwc.csv"
address 10: master #2
address 12: slave, scanned "MF=Vaillant;ID=PMW00;SW=0117;HW=4402"
address 15: slave #2, scanned "MF=Vaillant;ID=UI ;SW=0501;HW=6201", loaded "vaillant/15.ui.csv"
address 23: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0500;HW=6301", loaded "vaillant/23.solsy.cc.csv"
address 25: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0500;HW=6301"
address 26: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0500;HW=6301", loaded "vaillant/26.solsy.hc.csv"
address 31: master #8, ebusd
address 36: slave #8, ebusd, scanning
address 50: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0500;HW=6301", loaded "vaillant/50.solsy.mc.csv"
address ec: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0500;HW=6301", loaded "vaillant/ec.solsy.sc.csv"
address ed: slave, scanned "MF=Vaillant;ID=PMS00;SW=0107;HW=4302", loaded "vaillant/ed.pms.sc.csv"
address f7: master #20
address fc: slave #20, scanned "MF=Vaillant;ID=PMW00;SW=0117;HW=4402"

Next I will do some raw logging...

[BlackAlpha700]

Actually YieldThisYear works everytime, i try to read it via ebusctl, but I found some other recurring errors in the log:

2023-06-01 14:23:39.019 [bus info] poll cmd: 3150b509030d0100
2023-06-01 14:23:39.019 [bus debug] start request 31
2023-06-01 14:23:39.019 [bus debug] arbitration start with 31
2023-06-01 14:23:39.069 [bus debug] arbitration lost
2023-06-01 14:23:39.069 [bus debug] ERR: arbitration lost during ready, retry
2023-06-01 14:23:39.136 [bus debug] start request 31
2023-06-01 14:23:39.136 [bus debug] arbitration start with 31
2023-06-01 14:23:39.136 [bus notice] >31<10ecb504010dc5000500000080004c00
2023-06-01 14:23:39.188 [bus debug] arbitration won
2023-06-01 14:23:39.188 [bus debug] arbitration delay 3 micros
2023-06-01 14:23:39.188 [bus debug] switching from ready to send command
2023-06-01 14:23:39.208 [bus debug] send/receive symbol latency 20 ms
2023-06-01 14:23:39.229 [bus debug] send/receive symbol latency 21 ms
2023-06-01 14:23:39.253 [bus debug] send/receive symbol latency 24 ms
2023-06-01 14:23:39.269 [bus debug] send/receive symbol latency 15 ms
2023-06-01 14:23:39.289 [bus debug] send/receive symbol latency 19 ms
2023-06-01 14:23:39.308 [bus debug] send/receive symbol latency 18 ms
2023-06-01 14:23:39.329 [bus debug] send/receive symbol latency 21 ms
2023-06-01 14:23:39.329 [bus debug] switching from send command to send command CRC
2023-06-01 14:23:39.347 [bus debug] send/receive symbol latency 17 ms
2023-06-01 14:23:39.348 [bus debug] switching from send command CRC to receive command ACK
2023-06-01 14:23:39.349 [bus debug] switching from receive command ACK to receive response
2023-06-01 14:23:39.370 [bus debug] switching from receive response to receive response CRC
2023-06-01 14:23:39.370 [bus debug] switching from receive response CRC to send response ACK
2023-06-01 14:23:39.440 [bus debug] notify request: ERR: read timeout
2023-06-01 14:23:39.440 [bus error] poll mc FlowTemp failed: ERR: read timeout
2023-06-01 14:23:39.440 [bus debug] ERR: read timeout during send response ACK, switching to skip
2023-06-01 14:23:39.904 [bus notice] >3150b509030d01005f<000370020003>00
2023-06-01 14:23:39.982 [bus notice] <100ab504010db50005000000802d6100
2023-06-01 14:23:40.119 [bus notice] <10edb50701077a0001009b00
2023-06-01 14:23:40.519 [bus notice] <10ecb5040110d8000a53048e0300800080a6035200
2023-06-01 14:23:40.708 [bus notice] <1008b51101018900095a640080ffff0000ff1400
2023-06-01 14:23:41.514 [bus notice] <10edb508070700000000c0019300000000
2023-06-01 14:23:42.977 [bus notice] <10ecb5040121e900053f000545647d00

another error:

2023-06-01 14:26:38.875 [bus info] scan 05 cmd: 3105070400
2023-06-01 14:26:38.908 [bus debug] start request 31
2023-06-01 14:26:38.908 [bus debug] arbitration start with 31
2023-06-01 14:26:38.959 [bus debug] arbitration won
2023-06-01 14:26:38.959 [bus debug] arbitration delay 3 micros
2023-06-01 14:26:38.959 [bus debug] switching from ready to send command
2023-06-01 14:26:38.979 [bus debug] send/receive symbol latency 20 ms
2023-06-01 14:26:39.002 [bus debug] send/receive symbol latency 22 ms
2023-06-01 14:26:39.019 [bus debug] send/receive symbol latency 17 ms
2023-06-01 14:26:39.040 [bus debug] send/receive symbol latency 20 ms
2023-06-01 14:26:39.040 [bus debug] switching from send command to send command CRC
2023-06-01 14:26:39.060 [bus debug] send/receive symbol latency 20 ms
2023-06-01 14:26:39.060 [bus debug] switching from send command CRC to receive command ACK
2023-06-01 14:26:39.146 [bus debug] notify request: ERR: read timeout
2023-06-01 14:26:39.146 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-06-01 14:26:39.146 [bus info] poll cmd: 310ab509030d0000
2023-06-01 14:26:39.146 [bus debug] start request 31
2023-06-01 14:26:39.146 [bus debug] arbitration start with 31
2023-06-01 14:26:39.146 [main error] scan config 05: ERR: read timeout
2023-06-01 14:26:39.659 [bus notice] >310507040031<1008b51009000000ffffff01ff005d0001019a00

[BlackAlpha700]

I've set the pollintervall to 1, restarted the ebusd again and the errors are back again:

2023-06-01 15:24:33.116 [bus info] poll cmd: 31ecb509030d0900
2023-06-01 15:24:33.116 [bus debug] start request 31
2023-06-01 15:24:33.116 [bus debug] arbitration start with 31
2023-06-01 15:24:33.195 [bus notice] <01ecb505084de40300006401001700000000
2023-06-01 15:24:33.195 [bus debug] arbitration won
2023-06-01 15:24:33.195 [bus debug] arbitration delay 4 micros
2023-06-01 15:24:33.195 [bus debug] switching from ready to send command
2023-06-01 15:24:33.218 [bus debug] send/receive symbol latency 22 ms
2023-06-01 15:24:33.235 [bus debug] notify request: ERR: wrong symbol received
2023-06-01 15:24:33.236 [bus error] poll sc Coll1Sensor failed: ERR: wrong symbol received
2023-06-01 15:24:33.236 [bus debug] ERR: wrong symbol received during send command, switching to skip
2023-06-01 15:24:33.826 [bus notice] >31ecb5<95fd
2023-06-01 15:24:33.915 [bus notice] <1026b5040101d80009160300000585000100e500
2023-06-01 15:24:34.045 [bus notice] <00
2023-06-01 15:24:34.045 [bus debug] ERR: SYN received during receive command, switching to ready
2023-06-01 15:24:34.135 [bus notice] <1026b505082b0f0100000000073000000000
2023-06-01 15:24:34.184 [bus notice] <01feb505054e77be0080c6
2023-06-01 15:24:34.575 [bus notice] <100e07040048
2023-06-01 15:24:34.575 [bus debug] ERR: SYN received during receive command ACK, switching to ready
2023-06-01 15:24:35.025 [bus info] poll cmd: 310ab509030d0600
2023-06-01 15:24:35.025 [bus debug] start request 31
2023-06-01 15:24:35.025 [bus debug] arbitration start with 31
2023-06-01 15:24:35.075 [bus debug] arbitration won
2023-06-01 15:24:35.075 [bus debug] arbitration delay 3 micros
2023-06-01 15:24:35.075 [bus debug] switching from ready to send command
2023-06-01 15:24:35.095 [bus debug] send/receive symbol latency 19 ms
2023-06-01 15:24:35.115 [bus debug] notify request: ERR: wrong symbol received
2023-06-01 15:24:35.115 [bus error] poll hwc CalculatedMixerPosition failed: ERR: wrong symbol received
2023-06-01 15:24:35.115 [bus debug] ERR: wrong symbol received during send command, switching to skip
2023-06-01 15:24:35.704 [bus notice] >310ab5<35f5
2023-06-01 15:24:36.095 [bus notice] <101b0704004f
2023-06-01 15:24:36.095 [bus debug] ERR: SYN received during receive command ACK, switching to ready
2023-06-01 15:24:36.575 [bus notice] <10ecb5040121e900053e00054664c400
2023-06-01 15:24:37.025 [bus info] poll cmd: 3106b509030d0500
2023-06-01 15:24:37.025 [bus debug] start request 31
2023-06-01 15:24:37.025 [bus debug] arbitration start with 31
2023-06-01 15:24:37.075 [bus debug] arbitration won
2023-06-01 15:24:37.075 [bus debug] arbitration delay 3 micros
2023-06-01 15:24:37.075 [bus debug] switching from ready to send command
2023-06-01 15:24:37.095 [bus debug] send/receive symbol latency 19 ms
2023-06-01 15:24:37.115 [bus debug] notify request: ERR: wrong symbol received
2023-06-01 15:24:37.115 [bus error] poll pms Ntc1Sensor failed: ERR: wrong symbol received
2023-06-01 15:24:37.116 [bus debug] ERR: wrong symbol received during send command, switching to skip
2023-06-01 15:24:37.705 [bus notice] >3106b5<a5ff
2023-06-01 15:24:38.110 [bus notice] <10ed0704008a000ab5504d533030010743024600
2023-06-01 15:24:39.015 [bus info] poll cmd: 3106b509030d0600
2023-06-01 15:24:39.016 [bus debug] start request 31
2023-06-01 15:24:39.016 [bus debug] arbitration start with 31
2023-06-01 15:24:39.125 [bus notice] <1008b51009000000ffffff01ff005d0001019a00
2023-06-01 15:24:39.125 [bus debug] arbitration won
2023-06-01 15:24:39.125 [bus debug] arbitration delay 3 micros
2023-06-01 15:24:39.125 [bus debug] switching from ready to send command
2023-06-01 15:24:39.148 [bus debug] send/receive symbol latency 22 ms
2023-06-01 15:24:39.165 [bus debug] notify request: ERR: wrong symbol received
2023-06-01 15:24:39.165 [bus error] poll pms Ntc2Sensor failed: ERR: wrong symbol received
2023-06-01 15:24:39.165 [bus debug] ERR: wrong symbol received during send command, switching to skip
2023-06-01 15:24:39.756 [bus notice] >3106b5<05fd
2023-06-01 15:24:39.866 [bus notice] <1026b509040e1000000900000000
2023-06-01 15:24:40.161 [bus notice] <1008b513020508c600000000
2023-06-01 15:24:40.655 [bus notice] <1026b509030d04008c000321ffa901e600
2023-06-01 15:24:40.833 [bus notice] <1050b5040101fe00091703000005810001009b00
2023-06-01 15:24:40.997 [bus notice] <1050b504010df200051c00780217c000

[john30]

raw logging in bytes is needed to check the timing

[s0129]

I think I have the same issue. With my old custom ebus adapter it worked ok, but I just received and tested the new v5 adapter and I am seeing lots of intermittent "wrong symbol received" and "SYN received".

WiFi signal 88%.

~ # ebusctl info
version: ebusd 23.1.p20230413
update check: revision 23.1 available, device firmware 1[8419] available, vaillant/08.bai.csv: different version available, vaillant/bai.308523.inc: different version available, vaillant/errors.inc: different version available
device: 192.168.4.81:9999, enhanced, firmware 1.1[3501].1[3501]
access: *
signal: acquired
symbol rate: 22
max symbol rate: 40
min arbitration micros: 0
max arbitration micros: 7
min symbol latency: 6
max symbol latency: 59
reconnects: 0
masters: 2
messages: 225
conditional: 3
poll: 8
update: 10
address 03: master #11
address 08: slave #11, scanned "MF=Vaillant;ID=BAI00;SW=0202;HW=8001", loaded "vaillant/bai.308523.inc", "vaillant/08.bai.csv"
address 31: master #8, ebusd
address 36: slave #8, ebusd, scanning

2023-06-03 20:58:08.117 [bus error] poll bai FlowTemp failed: ERR: wrong symbol received
2023-06-03 20:58:14.282 [update notice] sent poll-read bai ReturnTemp QQ=31: 27.38;65097;ok
2023-06-03 20:58:20.104 [bus error] poll bai Flame failed: ERR: SYN received
2023-06-03 20:59:20.097 [bus error] poll bai FlowTemp failed: ERR: SYN received
2023-06-03 20:59:26.137 [bus error] poll bai ReturnTemp failed: ERR: SYN received
2023-06-03 20:59:32.141 [bus error] poll bai Flame failed: ERR: SYN received
2023-06-03 21:00:08.297 [update notice] sent poll-read bai FlowTemp QQ=31: 26.81;ok

I have attached raw bytes dump while reading flame ebusctl read -f -V flame.
ebus_raw.log

ebusd --scanconfig=full --accesslevel=* --configpath=/root/ebusd-configuration/ebusd-2.1.x/en/ -d enh:192.168.4.81:9
999 -p 8888 --latency 30 --lograwdatafile=raw.log -f

[john30]

thanks for the log. at several times like 21:16:13.230 there is a successful read of flame (0500), so that does not fit to the findings.

on the other side, there are some weird examples in the log as well like at 21:16:09.688 where the receive is interrupted by a SYN symbol after 16ms. now it would be good to know if easi> reports WIFI issues at such occasions.

also your max symbol latency of around 60 suggests there is either a lot of traffic on your WIFI or many lost(broken packets. maybe check with your router?

[s0129]

Yes sometimes the read is successful other times it fails.

I have ruled out WiFi issues by switching to usb mode and connecting it to a raspberry pi running ebusd.

pi@boilerpi:~ $ ebusctl info
version: ebusd 22.4.v22.4
update check: version 23.1 available, broadcast.csv: different version available, memory.csv: different version available
device: /dev/ttyACM0, enhanced
access: *
signal: acquired
symbol rate: 13
max symbol rate: 73
min arbitration micros: 2
max arbitration micros: 35
min symbol latency: 4
max symbol latency: 5
reconnects: 0
masters: 2
messages: 225
conditional: 3
poll: 8
update: 10
address 03: master #11
address 08: slave #11, scanned "MF=Vaillant;ID=BAI00;SW=0202;HW=8001", loaded "vaillant/bai.308523.inc", "vaillant/08.bai.csv"
address 31: master #8, ebusd
address 36: slave #8, ebusd, scanning

2023-06-04 09:45:48.781 [bus error] send message part 0: ERR: read timeout
2023-06-04 09:45:49.587 [bus error] send to 08: ERR: SYN received, retry
2023-06-04 09:45:49.752 [update notice] sent poll-read bai Flame QQ=31: off
2023-06-04 09:45:59.155 [bus error] poll bai Flame failed: ERR: read timeout

[john30]

please provide the corresponding raw log

[s0129]

Unfortunately I can't get it to make a connection anymore. It can't find any other devices on the bus anymore so just getting an empty raw log.

All I get is lots of these messages.

2023-06-12 10:04:34.557 [bus error] poll f37 currenterror failed: ERR: arbitration lost
2023-06-12 10:04:39.574 [bus error] poll sc currenterror failed: ERR: arbitration lost
2023-06-12 10:04:45.579 [bus error] poll sc YieldThisYear failed: ERR: arbitration lost

[john30]

what do you mean by "empty raw log"? if that would be really empty, then your bus is dead, so that's probably not the case

[s0129]

Worked out why was getting an empty log file, it was a permissions problem, log file owned by root and running ebusd as non-root user!
I have attached the raw log file. Very little data in there though.
raw_dump.txt

This is the command I used.

$ ebusd --configpath=/home/pi/ebusd-configuration/latest/en/ -d ens:/dev/ttyACM0 --lograwdatafile ~/raw_dump.txt -f --lograwdata=bytes
2023-06-15 21:55:10.142 [main notice] ebusd 22.4.v22.4 started on enhanced device /dev/ttyACM0
2023-06-15 21:55:10.224 [main error] error reading config files from /home/pi/ebusd-configuration/latest/en/: ERR: duplicate entry, last error: vaillant/15.360.csv:8: ERR: duplicate entry, duplicate ID
2023-06-15 21:55:10.232 [bus notice] device status: resetting
2023-06-15 21:55:10.232 [bus notice] bus started with own address 31/36
2023-06-15 21:55:10.251 [bus notice] signal acquired
2023-06-15 21:55:20.250 [main notice] found messages: 370 (2 conditional on 3 conditions, 3 poll, 4 update)
2023-06-15 21:55:20.827 [bus error] poll f37 currenterror failed: ERR: arbitration lost
2023-06-15 21:55:26.588 [bus error] poll sc currenterror failed: ERR: arbitration lost
2023-06-15 21:55:32.576 [bus error] poll sc YieldThisYear failed: ERR: arbitration lost

Also tried with this command but the raw data file only contained <aa lines.

$ ebusd --scanconfig=full --accesslevel=* --configpath=/home/pi/ebusd-configuration/latest/en/ -d ens:/dev/ttyACM0 -p 8888 --latency 30 --lograwdatafile ~/raw_dump.txt -f --lograwdata=bytes
2023-06-15 22:09:18.580 [main notice] ebusd 22.4.v22.4 started with full scan on enhanced device /dev/ttyACM0
2023-06-15 22:09:18.601 [bus notice] device status: resetting
2023-06-15 22:09:18.601 [bus notice] bus started with own address 31/36
2023-06-15 22:09:18.626 [bus notice] signal acquired
2023-06-15 22:09:28.602 [main notice] starting initial full scan
2023-06-15 22:11:28.780 [main notice] update check: version 23.1 available, broadcast.csv: different version available, memory.csv: different version available

I swapped the hardware back to my old one and it works fine, so the bus is working fine.

[john30]

the raw log does not contain any send, so again not useful at all. I need at least to have it cover one of the issued active reads.

furthermore it is easier to read everything if the raw log is embedded in the normal log (i.e. leave out "--lograwdatafile ...")

why are you using an older ebusd version?

[s0129]

Looks like I haven't upgraded ebusd for a while, will update and try again.

Problem is I can't do any commands like ebusctl read flame as I get error element not found.
This is because the scan isn't picking up the boiler. Is there a command I am missing to force a read or scan?

[s0129]

I have upgraded to the latest version and seeing the same issue.
Is there any commands I can run to force a read or scan as currently it isn't picking up the boiler so not allowing any reads.

[john30]

again, I need some raw logging in order to check in detail. this is also true for the scanning process after starting ebusd. futhermore it would good to know if errors are reported in the easi> log page in the same time period

[s0129]

I have tried to get some raw logging.
ebusd --configpath=/home/user/ebusd-configuration/latest/en/ -d ens:/dev/ttyACM0 -f --lograwdata=bytes --loglevel=debug

ebusdlog.txt
ebusdlog2.txt

I have checked the easi> log page and there are no errors whilst running ebusd, however there are some on startup but I don't think they are relevant to this issue as I am connecting via USB cable.

22:10:47	Error	w5500.mac: W5500 version mismatched, expected 0x04, got 0x00
22:10:47	Error	w5500.mac: emac_w5500_init(715): vefiry chip ID failed
22:10:47	Info	gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Error	esp_eth: esp_eth_driver_install(228): init mac failed
22:10:47	Error	initialise_ethernet: initialise_ethernet(229): install driver
22:10:47	Error	esp_eth: esp_eth_driver_uninstall(256): invalid argument
22:10:47	Info	gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Info	gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Info	gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Info	gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47		Ethernet not available
22:10:47	Warning	executeCommand: command failed: eth -t = 1
22:10:47	Info	executeCommand: executing command: if "eth -wt" "var eth 2"
22:10:47	Info	executeCommand: executing command: eth -wt
22:10:47	Error	w5500.mac: w5500_reset(222): reset timeout
22:10:47	Error	w5500.mac: emac_w5500_init(713): reset w5500 failed
22:10:47	Info	gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Error	esp_eth: esp_eth_driver_install(228): init mac failed
22:10:47	Error	initialise_ethernet: initialise_ethernet(229): install driver
22:10:47	Error	esp_eth: esp_eth_driver_uninstall(256): invalid argument
22:10:47	Info	gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Info	gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Info	gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47	Info	gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
22:10:47		Ethernet not available
22:10:47	Warning	executeCommand: command failed: eth -wt = 1

[s0129]

I can also do a capture of the bus using a logic analyser if that helps.

[john30]

you didn't specify "--scanconfig" as argument to ebusd, so it will pick up all messages from the config folder, which is definitely wrong. consequently it would try to poll those messages for which not even a device exists, so you better fix that first.

furthermore, from the logs it seems that your device can't write anything to the bus. do you have special cabling of some sort? would be interesting to find out the voltage levels on the bus if you have the possibility

[s0129]

I have added --scanconfig and it worked for a bit and then stopped. Haven't been able to get it to work again since, so I assume it must be on the edge. I have included the log file from the time it did work.
ebusdlog3.txt

I have no special cabling, just two wires connected directly to the boiler. Measuring the voltage one wire of ebus is tied to the boiler ground, and the other is at 22v from this ground. There is not continuity between the boiler ground the the ebusd adapter ground but I understand this is ok.

[s0129]

I have attached some scope captures.

[john30]

can you try to grab the levels when writing with the adapter? or does your rigol have decoding capability? then you could make it trigger on 0xaa or on the master source address of ebusd.

one thing that just comes to my mind: in case of a simple broken diode, you could check if inverting the two wires to the bus makes a difference

[s0129]

I think the last photo is from when the adapter was writing. Unfortunately that is the best I can do with my rigol as it is quite basic.

Is there anywhere on the adapter board I can hook into the ebus signal as I have another scope/logic analyser but it only supports up to 10v.

I tried switching the cables but it hasn't made a difference.

[john30]

I've checked your screenshot and if your rigol is correct, then the signal timing of your heating is probably damaged as the baudrate is at 2460 Bd instead of 2400 for the SYN symbol. this is more than the allowed tolerance of +/- 1,2% and most probably the root cause of the issues.
I'll check if a slightly modified bitrate could be used

[s0129]

I think it is right on the edge, measuring today I am getting a baud of 2428 from the boiler on the 0xaa pattern. This might explain why it works sometimes and other times it doesn't.

[john30]

this issue is continued in the appropriate repo:
john30/ebusd-esp32#14