john30
Bus signal lost and re-acquired but polling does not restart
Description
I have ebusd running on a Raspberry Pi connected to an adapter 3 with WiFi. It has been running mostly smooth for the last couple of month, but lately I am expecting connection aborts that can be fixed with a restart of ebusd. Those drop outs come at random intervals after some days, so it is difficult to reproduce. The behavior might have started after I decreased the poll interval from 60 to 10s, but I am not entirely sure.
When non-operational:
localhost: i
version: ebusd 22.2.p20220227
update check: revision v22.2 available
device: 192.168.178.66:9999, enhanced
signal: acquired
symbol rate: 20
max symbol rate: 95
min arbitration micros: 3
max arbitration micros: 111
min symbol latency: 0
max symbol latency: 67
reconnects: 0
masters: 2
messages: 306
conditional: 0
poll: 5
update: 156
address 31: master #8, ebusd
address 36: slave #8, ebusd
address 71: master #9
address 76: slave #9
eBUS adapter 3
Build: 20220327
ebusd device string: enh:192.168.178.66:9999
WiFi signal: 60% (-70dBm)
Chip ID: 00745a83, d1mini
Hostname: ebus-745a83
Up time: 84362
Free heap: 30664
ebusd connected: yes (inactive)
eBUS signal: acquired
Actual behavior
- No more updates via MQTT, log shows no polling
- Uptime is still counting up (also via MQTT)
- Force read in ebusctl (r -f) takes very long and does not return anything
- sudo service ebusd restart fixes the problem
Before ebusd stops working, errors appear in the log. Some examples below (full log attached):
2022-04-19 21:17:42.397 [bus error] poll SM2 TSolarPuffer failed: ERR: read timeout
2022-04-19 21:19:21.129 [bus error] poll SM2 TSolarPuffer failed: ERR: wrong symbol received
2022-04-19 21:23:34.305 [bus error] poll SM2 hSolarkreispumpe failed: ERR: SYN received
2022-04-19 21:25:46.123 [bus error] poll SM2 TSolarSpeicher failed: ERR: wrong symbol received
2022-04-19 21:30:21.106 [bus error] device status: eBUS comm error: framing
2022-04-19 22:03:15.026 [bus error] signal lost
2022-04-19 22:03:15.459 [bus notice] signal acquired
2022-04-19 22:14:36.029 [bus error] signal lost
2022-04-19 22:14:36.422 [bus error] device status: unexpected available enhanced byte 2
2022-04-19 22:14:36.424 [bus notice] signal acquired
2022-04-19 22:14:49.618 [bus error] poll SM2 THeizungRuecklauf failed: ERR: read timeout
2022-04-19 22:14:49.892 [bus error] device status: unexpected available enhanced byte 2
2022-04-19 22:14:56.353 [bus error] device status: unexpected available enhanced following byte 1
2022-04-19 22:15:50.004 [bus error] poll SM2 TSolarKollektor failed: ERR: no signal
2022-04-19 22:15:50.004 [bus error] signal lost
2022-04-19 22:15:50.250 [bus error] device status: unexpected available enhanced following byte 1
2022-04-19 22:15:50.251 [bus notice] signal acquired
Expected behavior
Connection drop-outs should be understood, polling should resume when signal is re-acquired.
ebusd version
22.2
ebusd arguments
EBUSD_OPTS="-d enh:192.168.178.66:9999 --log=all:notice --configlang=de --configpath=/etc/ebusd/ --mqttport=1883 --mqttuser=mqttUser --mqttpass=*** --pollinterval=10"
Operating system
Debian 10 (Buster) / Raspbian 10 / Ubuntu 18-19
CPU architecture
armv7l
Dockerized
No response
Hardware interface
adapter 3 WiFi
Related integration
No response
Logs
Just did the updates now. Will be difficult to get to a conclusion here for me as the error occurred spontaneous and apparently random. Haven't had an issue for quite a long time until today. I will observe.