ebusd
ebusd copied to clipboard
john30
Arbitration lost
Description
In every try to load configuration it end with arbitration lost error message. It starts on version 22.1. I have Vaillant VR470F + VR61
Actual behavior
[main error] scan config 15: ERR: arbitration lost
Expected behavior
load of configuration.
ebusd version
22.3
ebusd arguments
ebusd: image: john30/ebusd:devel container_name: ebusd depends_on: - mqtt #ports: # - "8888:8888/tcp" restart: unless-stopped privileged: true network_mode: host environment: - TZ=Europe/Bratislava - EBUSD_ARCH=amd64 - EBUSD_SCANCONFIG=full - EBUSD_CONFIGPATH=/etc/ebusd/ebusd-configuration/ebusd-2.1.x/en - EBUSD_LOGAREAS=all - EBUSD_LOGLEVEL=info - EBUSD_ACCESSLEVEL=* - EBUSD_MQTTHOST=192.168.2.7 - EBUSD_MQTTPORT=1883 - EBUSD_MQTTUSER=XXXX - EBUSD_MQTTPASS=YYYY - EBUSD_MQTTTOPIC=ebusd - EBUSD_MQTTJSON= - EBUSD_MQTTINT=/etc/ebusd/mqtt-hassio.cfg - EBUSD_MQTTVERBOSE= - EBUSD_MQTTRETAIN= - EBUSD_MQTTCHANGES= volumes: - "/etc/localtime:/etc/localtime:ro" - "/volume1/docker/ebusd/data:/data" - "/volume1/docker/ebusd:/ebusd" - "/volume1/docker/ebusd/config:/etc/ebusd" - "/volume1/docker/ebusd/log:/var/log" command: -d enh:192.168.1.15:9999 -l /var/log/ebusd.log
Operating system
other
CPU architecture
x64
Dockerized
devel
Hardware interface
adapter 3 WiFi
Related integration
MQTT Home Assistant via mqtt-hassio.cfg
Logs
not much to tell if no log is provided, but anyway: since the device in question (VR470F) seems to be RF based, the timing is a bit different for those and I'd recommend to increase the latency value to ebusd to at least 50ms
2022-08-03 17:54:17.696 [bus info] scan 04 cmd: 3104070400
2022-08-03 17:54:17.696 [bus debug] start request 31
2022-08-03 17:54:17.696 [bus debug] arbitration start with 31
2022-08-03 17:54:17.824 [bus debug] arbitration lost (timed out)
2022-08-03 17:54:17.824 [bus debug] ERR: arbitration lost during ready, retry
2022-08-03 17:54:17.824 [bus debug] start request 31
2022-08-03 17:54:17.825 [bus debug] arbitration start with 31
2022-08-03 17:54:17.955 [bus debug] arbitration lost (timed out)
2022-08-03 17:54:17.955 [bus debug] ERR: arbitration lost during ready, retry
2022-08-03 17:54:17.955 [bus debug] start request 31
2022-08-03 17:54:17.955 [bus debug] arbitration start with 31
2022-08-03 17:54:18.084 [bus debug] arbitration lost (timed out)
2022-08-03 17:54:18.084 [bus debug] ERR: arbitration lost during ready, retry
2022-08-03 17:54:18.085 [bus debug] start request 31
2022-08-03 17:54:18.085 [bus debug] arbitration start with 31
2022-08-03 17:54:18.142 [update info] received MS cmd: 1050b505023001 / 0101
2022-08-03 17:54:18.142 [update notice] received unknown MS cmd: 1050b505023001 / 0101
2022-08-03 17:54:18.236 [bus debug] arbitration lost (timed out)
2022-08-03 17:54:18.236 [bus debug] notify request: ERR: arbitration lost
I have only this info's in log and I use default valus for latency. But even I try with 120ms latency I got same values.
looks as if your adapter can't write to the bus at all. sure you've set up ebusd-esp correctly and also the jumpers on the adapter?
Sometimes it works (after few restarts), but just like for half of day and then same situation happens. Now I am receiving only broadcast messages like uptime and outdoor temperature. I did not change jumpers, but maybe summer heat has something with it. It is in closed room with heater/boiler so it could by too hot for PCB.
Hi,
I do have a similar issue, different hardware. I was using the ebusd docker image on raspberry pi 4 and it worked compeltly fine. I then plugged it into my x86 (Intel) server and used the same CLI line to start the docker image, getting the same issue now with constant arbitration lost:
It looks like this:
2022-08-17 20:29:48.950 [update notice] received unknown MS cmd: 1026b5230f05ffffff000000ffffffffffff0000 / 0101
2022-08-17 20:29:49.156 [main debug] performing regular tasks
2022-08-17 20:29:49.156 [bus info] scan 76 cmd: 3176070400
2022-08-17 20:29:49.194 [update info] received MS cmd: 1026b5230402000000 / 02019c
2022-08-17 20:29:49.194 [update notice] received unknown MS cmd: 1026b5230402000000 / 02019c
2022-08-17 20:29:49.194 [bus debug] start request 31
2022-08-17 20:29:49.194 [bus debug] arbitration start with 31
2022-08-17 20:29:49.374 [bus debug] arbitration lost
2022-08-17 20:29:49.374 [bus debug] ERR: arbitration lost during ready, retry
2022-08-17 20:29:49.439 [update info] received MS cmd: 1026b5230402010000 / 02019c
2022-08-17 20:29:49.439 [update notice] received unknown MS cmd: 1026b5230402010000 / 02019c
2022-08-17 20:29:49.439 [bus debug] start request 31
2022-08-17 20:29:49.439 [bus debug] arbitration start with 31
2022-08-17 20:29:49.619 [bus debug] arbitration lost
2022-08-17 20:29:49.619 [bus debug] ERR: arbitration lost during ready, retry
2022-08-17 20:29:49.684 [update info] received MS cmd: 1026b523040202022c / 02010a
2022-08-17 20:29:49.684 [update notice] received unknown MS cmd: 1026b523040202022c / 02010a
2022-08-17 20:29:49.684 [bus debug] start request 31
2022-08-17 20:29:49.684 [bus debug] arbitration start with 31
2022-08-17 20:29:56.629 [bus debug] arbitration lost
2022-08-17 20:29:56.629 [bus debug] ERR: arbitration lost during ready, retry
2022-08-17 20:29:56.713 [update info] received MS cmd: 1008b5110101 / 092d2fd016ff600000ff
2022-08-17 20:29:56.713 [update notice] received unknown MS cmd: 1008b5110101 / 092d2fd016ff600000ff
2022-08-17 20:29:56.713 [bus debug] start request 31
2022-08-17 20:29:56.713 [bus debug] arbitration start with 31
2022-08-17 20:29:56.893 [bus debug] arbitration lost
2022-08-17 20:29:56.893 [bus debug] notify request: ERR: arbitration lost
2022-08-17 20:29:56.893 [main error] scan config 76: ERR: arbitration lost
2022-08-17 20:29:56.980 [update info] received MS cmd: 1076b5110101 / 09ff2fd016ff600000ff
2022-08-17 20:29:56.980 [update notice] received unknown MS cmd: 1076b5110101 / 09ff2fd016ff600000ff
2022-08-17 20:29:57.246 [update info] received MS cmd: 1076b512030f0101 / 0702030000801205
2022-08-17 20:29:57.246 [update notice] received unknown MS cmd: 1076b512030f0101 / 0702030000801205
2022-08-17 20:29:57.456 [update info] received BC cmd: 10feb505025c01
2022-08-17 20:29:57.456 [update notice] received unknown BC cmd: 10feb505025c01
2022-08-17 20:29:57.753 [update info] received MS cmd: 1026b5230106 / 107801ae01a7017601830100800080003c
2022-08-17 20:29:57.753 [update notice] received unknown MS cmd: 1026b5230106 / 107801ae01a7017601830100800080003c
2022-08-17 20:29:58.046 [update info] received MS cmd: 1026b5230107 / 0f008000800080008000008000805705
2022-08-17 20:29:58.046 [update notice] received unknown MS cmd: 1026b5230107 / 0f008000800080008000008000805705
2022-08-17 20:29:58.312 [update info] received MS cmd: 1008b5100900002cffffff070004 / 0101
2022-08-17 20:29:58.312 [update notice] received unknown MS cmd: 1008b5100900002cffffff070004 / 0101
2022-08-17 20:29:58.554 [update info] received MS cmd: 1008b507020900 / 02b802
2022-08-17 20:29:58.554 [update notice] received unknown MS cmd: 1008b507020900 / 02b802
2022-08-17 20:29:58.821 [update info] received MS cmd: 1076b51009000000ffffff010000 / 0101
2022-08-17 20:29:58.821 [update notice] received unknown MS cmd: 1076b51009000000ffffff010000 / 0101
2022-08-17 20:29:58.893 [main debug] performing regular tasks
2022-08-17 20:29:58.893 [mqtt debug] publish ebusd/global/scan finished
2022-08-17 20:29:59.089 [update info] received MS cmd: 1008b5040100 / 0a0300302217080322d016
2022-08-17 20:29:59.089 [update notice] received unknown MS cmd: 1008b5040100 / 0a0300302217080322d016
2022-08-17 20:29:59.324 [update info] received BC cmd: 10feb516080057292217080322
2022-08-17 20:29:59.324 [update notice] received unknown BC cmd: 10feb516080057292217080322
2022-08-17 20:29:59.591 [update info] received MS cmd: 1008b5110100 / 09680113000008000100
2022-08-17 20:29:59.591 [update notice] received unknown MS cmd: 1008b5110100 / 09680113000008000100
2022-08-17 20:29:59.878 [update info] received MS cmd: 1026b5230f05ffffff000000ffffffffffff0000 / 0101
2022-08-17 20:29:59.878 [update notice] received unknown MS cmd: 1026b5230f05ffffff000000ffffffffffff0000 / 0101
2022-08-17 20:30:00.122 [update info] received MS cmd: 1026b5230402000000 / 02019c
2022-08-17 20:30:00.122 [update notice] received unknown MS cmd: 1026b5230402000000 / 02019c
2022-08-17 20:30:00.367 [update info] received MS cmd: 1026b5230402010000 / 02019c
2022-08-17 20:30:00.367 [update notice] received unknown MS cmd: 1026b5230402010000 / 02019c
I have a Esera EBus-USB module, I haven't changed the USB cable, or the connection, simply removed it from Raspberry Pi, and plugged into into server.
Update:
actually, I have now retried it with a new raspberry pi, and I have the same messages also there. So not sure what changed to the last time I had it working, but it's annoying.
btw, the ebusctl info looks like this:
localhost: info
version: ebusd 22.1.28da22c
device: /dev/ttyUSB0
access: *
signal: acquired
symbol rate: 24
max symbol rate: 110
reconnects: 0
masters: 4
messages: 15
conditional: 0
poll: 0
update: 4
address 03: master #11
address 08: slave #11
address 10: master #2
address 26: slave
address 31: master #8, ebusd
address 36: slave #8, ebusd
address 71: master #9
address 76: slave #9
So it doesn't detect anything anymore, and I already had things working. ...
Update2: So after digging through the wiki I think I understood that a bit better, the arbitration is to figure out who is allowed to send to the bus, and in my case, something else is hogging the bus so ebusd never can write anything on it.
So based on that: https://github.com/john30/ebusd/wiki/eBUS-background
A bus address of 0x00 should give me the arbitration, but it does not:
2022-08-17 22:24:00.365 [bus debug] start request 00
2022-08-17 22:24:00.365 [bus debug] arbitration start with 00
2022-08-17 22:24:00.542 [bus debug] arbitration lost
2022-08-17 22:24:00.542 [bus debug] ERR: arbitration lost during ready, retry
Would it be possible to log which master got the arbitration? Since it anyways sends it's ID on the response, so it could be printed in the error?
@Thoro please don't misuse other ones ticket if it is not 100% related, which is not the case due to completely different setup (interface, OS, hardware)
@Koky05 I don't think temperature will have such an influence. what are we talking about? 50 degrees or higher?
can you post a raw logging with bytes (--lograwdata=bytes) from a successful arbitration and a non successful?
Today I try it recreate with lograwdata but have no luck with arbitration all finish as lost. Only broadcast messages works for me. I try restart ebus adapeter and also use controller on my heater during scanning.
Ebusctl info:
version: ebusd 22.4.v22.4-1-g7d8a871
device: 192.168.2.31:9999, enhanced
access: *
signal: acquired
symbol rate: 55
max symbol rate: 93
reconnects: 0
masters: 3
messages: 127
conditional: 4
poll: 0
update: 8
address 03: master #11
address 08: slave #11, scanning
address 10: master #2
address 15: slave #2, scanned "MF=Vaillant;ID=F4700;SW=0124;HW=6102"
address 31: master #8, ebusd
address 36: slave #8, ebusd, scanning
address 50: slave, scanned "MF=Vaillant;ID=V6100;SW=0306;HW=1902", loaded "vaillant/50.v61.mc.csv"
ebusd_logs.txt
from the logs it looks as if your adapter can't write to the bus at all. please post the jumper settings here as well as the config page of ebusd-esp.
in order to make sure the adapter itslef is able to write, reconfigure it to USB direct mode (i.e. no Wemos sitting on top, J1+J4 set accordingly, connected through USB, jumpered to non-enhanced, ebusd on the host set to use a direct (non-enhanced) USB serial device, and then try again
Sorry but I don't own movable device to direct connection with ebus. I need to work it wirelessly. Or you know how to connect it to cellphone for test purpouse?
I repeat:
please post the jumper settings here as well as the config page of ebusd-esp.
in order to make sure the adapter itslef is able to write, reconfigure it to USB direct mode (i.e. no Wemos sitting on top, J1+J4 set accordingly, connected through USB, jumpered to non-enhanced, ebusd on the host set to use a direct (non-enhanced) USB serial device, and then try again
I check jumpers and it is setted up to RPi (J1 and J4) WiFi (J12 pins 6 and 7) and Enhanced protocol (J12 pins 9 and 10). I do not own mobile device (only cell phone) to dierct connection so I can not test it without WiFi.
I apply setting recommanded by kalledausb in issue #680 and restart heater and my communication for now working. I am curios for how long. So for now I leave this there open and wait if problem was solved by change of configuration:
starting ebusd with high latency/receivetimeout/acquiretimeout values (80000/10000/20000) and set acquireretries to 10.
So after 5 days of running it today stoped with same error arbitration lost on all three masters. (15.f47, 50.V61 and 26.f47.2). Only broadcast still working.
is the WIFI signal strength good enough?
again, not much more to tell if no logs or further details are provided
WiFi signal is strength enough. So only solution will be to catch 5 days detail logs? Because it take that long from normal running to lost arbitration. Maybe som cache problem?
do you have the latest version of ebusd-esp (20221105)? if not, please update it.
then paste the output of the log tab from the www UI here when the arbitration lost message is logged
After upgrade to ebusd-esp (20221105) it looks stabile:
version: ebusd 22.4.v22.4-28-gbc3e611 update check: revision v22.4 available, broadcast.csv: different version available, memory.csv: different version available, vaillant/15.f47.csv: different version available, vaillant/50.v61.mc.csv: different version available, vaillant/bai.0010015600.inc: different version available, vaillant/broadcast.csv: different version available, vaillant/errors.inc: different version available, vaillant/general.csv: different version available, vaillant/hcmode.inc: different version available, vaillant/iotestbmc.inc: different version available, vaillant/scan.csv: different version available, vaillant/tempsetpoints.inc: different version available, vaillant/timercc.inc: different version available, vaillant/timerhc.inc: different version available, vaillant/timerhwc.inc: different version available, vaillant/yield3d43.inc: different version available device: 192.168.2.31:9999, enhanced access: * signal: acquired symbol rate: 23 max symbol rate: 117 min arbitration micros: 1 max arbitration micros: 53 min symbol latency: 8 max symbol latency: 55 reconnects: 0 masters: 4 messages: 985 conditional: 6 poll: 681 update: 10 address 03: master #11 address 08: slave #11, scanned "MF=Vaillant;ID=BAI00;SW=0116;HW=9602", loaded "vaillant/bai.0010015600.inc" ([HW=9602]), "vaillant/08.bai.csv" address 10: master #2 address 15: slave #2, scanned "MF=Vaillant;ID=F4700;SW=0124;HW=6102", loaded "vaillant/15.f47.csv" address 26: slave, scanned "MF=Vaillant;ID=F4700;SW=0124;HW=6102", loaded "vaillant/26.f47.2.csv" address 31: master #8, ebusd address 36: slave #8, ebusd, scanning address 50: slave, scanned "MF=Vaillant;ID=V6100;SW=0306;HW=1902", loaded "vaillant/50.v61.mc.csv" address f1: master #10 address f6: slave #10, scanned "MF=Vaillant;ID=F4700;SW=0124;HW=6102", loaded "vaillant/f6.f47.3.csv"
So it is 10 days up and running and no Arbitration lost. Looks like latest ebusd-esp in combination with older firmware and longer timeouts make it works.
Today it starts again with error. Log from ebus adapter:
10:00:45.8: wifi evt 1
10:00:48.6: wifi evt 8
10:00:50.8: wifi evt 2
10:00:52.9: wifi evt 0
10:00:54.9: check eBUS conn
10:00:55.2: check eBUS conn: 0
10:00:55.2: eBUS >SYN enh
10:00:55.3: skip
10:00:55.3: setup: error=0, wifi=1, ip=1
10:01:00.3: start
10:01:45.1: conn 192.168.2.7:55832
10:02:10.8: disconn
10:02:15.9: conn 192.168.2.7:55866