ebusd read error

[modenet]

hi, I have this problem: sometimes (weekly) an ebusd on raspberry stops reading values.
every query ends with error "ERR: element not found".

if I stop ebusd and I start it manualy the log is:
2018-02-12 14:53:45.408 [main notice] ebusd 3.1.p20180131 started with auto scan
2018-02-12 14:53:45.422 [bus notice] bus started with own address 31/36
2018-02-12 14:53:45.425 [bus notice] signal acquired
2018-02-12 14:53:45.586 [bus notice] new master 70, master count 2
2018-02-12 14:53:45.604 [update notice] received unknown MS cmd: 7050b505042d1e0000 / 00
2018-02-12 14:53:45.942 [bus notice] new master 10, master count 3
2018-02-12 14:53:45.998 [update notice] received unknown MS cmd: 1026b5040101 / 09140300000580000100
2018-02-12 14:53:46.168 [update notice] received unknown MS cmd: 1026b505082b0f0f0000000080 / 00
2018-02-12 14:53:52.239 [bus notice] new master f0, master count 4
2018-02-12 14:53:52.294 [update notice] received unknown MS cmd: f051b5040101 / 09170300000081000100
2018-02-12 14:53:52.457 [update notice] received unknown MS cmd: f051b504010d / 050000820417
2018-02-12 14:53:53.142 [update notice] received unknown MS cmd: f051b5040132 / 0a002e0603010060070100
2018-02-12 14:53:53.278 [update notice] received unknown MS cmd: 1050b5040101 / 09170300000081000100
2018-02-12 14:53:53.344 [update notice] received unknown MS cmd: f051b505042d220000 / 00
2018-02-12 14:53:53.481 [update notice] received unknown MS cmd: 1051b5040101 / 09170300000081000100
2018-02-12 14:53:53.659 [update notice] received unknown MS cmd: 1052b5040101 / 093e0300000083000100
2018-02-12 14:53:53.751 [update notice] received unknown MS cmd: 7050b5040101 / 09170300000081000100
2018-02-12 14:53:53.887 [update notice] received unknown MS cmd: 1053b5040101 / 09150400000181000000
2018-02-12 14:53:54.001 [bus notice] max. symbols per second: 155
2018-02-12 14:53:54.041 [bus notice] new master 03, master count 5
2018-02-12 14:53:54.041 [update notice] received unknown MS cmd: 1008b513020508 / 00
2018-02-12 14:53:54.548 [update notice] received unknown MS cmd: 1026b509030d0400 / 033e0400
2018-02-12 14:53:54.711 [update notice] received unknown MS cmd: 1052b504010d / 054b0192023e
2018-02-12 14:53:54.872 [update notice] received unknown MS cmd: 1025b504010d / 050000cd0337
2018-02-12 14:53:55.101 [update notice] received unknown MS cmd: 1008b5110101 / 0997910080ffff0200ff
2018-02-12 14:53:55.255 [update notice] received unknown MS cmd: 1050b5050427014301 / 00
2018-02-12 14:53:55.330 [update notice] received unknown MS cmd: 7050b504010d / 0546009b0417
2018-02-12 14:53:55.514 [update notice] received unknown MS cmd: 7050b5040132 / 0a00300603010060070100
2018-02-12 14:53:55.527 [main error] scan config 08: ERR: read timeout
2018-02-12 14:53:55.668 [update notice] received unknown MS cmd: 7050b505042d1e0000 / 00
2018-02-12 14:53:56.099 [update notice] received unknown MS cmd: 1050b505082b0f0f0000000080 / 00
2018-02-12 14:53:57.577 [main error] scan config 15: ERR: read timeout
2018-02-12 14:53:59.598 [main error] scan config 25: ERR: read timeout
ù2018-02-12 14:54:01.621 [main error] scan config 26: ERR: read timeout
ùùùùùùùùùùùù2018-02-12 14:54:02.158 [update notice] received unknown MS cmd: f051b504010d / 050000820417
ù2018-02-12 14:54:02.257 [update notice] received unknown MS cmd: 1008b510090003ffffa064000001 / 0101
ùùùù2018-02-12 14:54:02.396 [update notice] received unknown MS cmd: f051b5040132 / 0a002e0603010060070100
ùùùùù2018-02-12 14:54:02.550 [update notice] received unknown MS cmd: f051b505042d220000 / 00
ùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùù2018-02-12 14:54:03.634 [update notice] received unknown MS cmd: 1026b509030d0400 / 03400400
2018-02-12 14:54:03.649 [main error] scan config 50: ERR: read timeout
ùùùù2018-02-12 14:54:03.795 [update notice] received unknown MS cmd: 1053b504010d / 050000bb0305
ùùù2018-02-12 14:54:03.960 [update notice] received unknown MS cmd: 1025b504010d / 050000cd0337
ùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùùù2018-02-12 14:54:05.179 [update notice] received unknown MS cmd: 1026b5040100 / 0a03055414120201186008
ùùùùùùùùùù2018-02-12 14:54:05.533 [update notice] received unknown MS cmd: 7050b504010d / 0546009b0417
ùùù2018-02-12 14:54:05.642 [update notice] received unknown MS cmd: 1051b5050427014401 / 00
ùùù2018-02-12 14:54:05.739 [update notice] received unknown MS cmd: 7050b5040132 / 0a00300603010060070100
ù2018-02-12 14:54:05.752 [main error] scan config 51: ERR: read timeout
ùùù2018-02-12 14:54:05.892 [update notice] received unknown MS cmd: 7050b505042d1e0000 / 00
ù2018-02-12 14:54:06.287 [update notice] received unknown MS cmd: 1026b5040101 / 09140300000580000100
2018-02-12 14:54:06.457 [update notice] received unknown MS cmd: 1051b505082b0f0f0000000080 / 00
2018-02-12 14:54:07.121 [main error] scan config 52: ERR: read timeout
2018-02-12 14:54:09.277 [main error] scan config 53: ERR: read timeout
2018-02-12 14:54:10.230 [update notice] received unknown BC cmd: 10feb516080001541412020118

if I launch "listen" on ebusctl I receive only:
broadcast datetime = 8.375;14:40:02;12.02.2018
broadcast datetime = 8.375;14:41:03;12.02.2018
broadcast datetime = 8.375;14:42:03;12.02.2018
broadcast datetime = 8.375;14:43:04;12.02.2018
broadcast datetime = 8.375;14:44:00;12.02.2018
...

I tried to use last version of ebusd repository and ebusd-configuration, but I not resolved.

[john30]

you mean "ERR: read timeout" instead of "ERR: element not found", right? Because not a single line of "not found" is in your log

[modenet]

I confirm the problem was "ERR: element not found". I have to reboot many times to restore ebusd.
I post the log of a ebusd manually launched.

[john30]

ok if you want me to help you, then please provide the log with the error you want to get rid off. and what do you mean by "restore ebusd"? if you have to reboot so many times, then why? and of course a log from a reboot that doesn't show expected results is needed as well

[modenet]

hi, the error I received is always "Errore ERR: element not found" for any query (even the same that I know that is correct).
after 2-3 reboot of raspabbery, or restart of ebus service, I see that ebusd start to return me valid results.

[john30]

please provide the log I've requested, can't help you otherwise

[modenet]

read -c mc OperatingMode
ERR: element not found

on log I see:
2018-02-19 21:10:02.146 [main error] scan config 08: ERR: read timeout
2018-02-19 21:10:04.164 [main error] scan config 15: ERR: read timeout
2018-02-19 21:10:06.185 [main error] scan config 25: ERR: read timeout
2018-02-19 21:10:08.204 [main error] scan config 26: ERR: read timeout
2018-02-19 21:10:10.322 [main error] scan config 50: ERR: read timeout
2018-02-19 21:10:12.334 [main error] scan config 51: ERR: read timeout
2018-02-19 21:10:14.380 [main error] scan config 52: ERR: read timeout
2018-02-19 21:10:16.411 [main error] scan config 53: ERR: read timeout
2018-02-19 21:10:18.433 [main error] scan config 75: ERR: read timeout
2018-02-19 21:10:21.647 [main error] scan config f5: ERR: read timeout
2018-02-19 21:10:33.655 [main error] unable to load scan config 24: no file from /etc/ebusd/vaillant with prefix 24. found
2018-02-19 21:10:33.655 [main error] scan config 24: ERR: element not found
2018-02-19 21:11:01.969 [main error] scan config 23: ERR: read timeout

log raw:
2018-02-19 21:12:26.304 [main debug] >>> read -c mc OperatingMode
2018-02-19 21:12:26.310 [main debug] <<< ERR: element not found
2018-02-19 21:12:29.630 [update info] received MS cmd: f051b504010d / 054600ae0417
2018-02-19 21:12:29.630 [update notice] received unknown MS cmd: f051b504010d / 054600ae0417
2018-02-19 21:12:29.814 [update info] received MS cmd: f051b5040132 / 0a002e06030100f0080100
2018-02-19 21:12:29.814 [update notice] received unknown MS cmd: f051b5040132 / 0a002e06030100f0080100
2018-02-19 21:12:29.967 [update info] received MS cmd: f051b505042d320000 / 00
2018-02-19 21:12:29.967 [update notice] received unknown MS cmd: f051b505042d320000 / 00
2018-02-19 21:12:31.384 [bus debug] ERR: read timeout during receive response, switching to skip
2018-02-19 21:12:31.700 [bus debug] ERR: read timeout during receive response, switching to skip
2018-02-19 21:12:32.223 [update info] received MS cmd: 7050b504010d / 054600b30417
2018-02-19 21:12:32.223 [update notice] received unknown MS cmd: 7050b504010d / 054600b30417
2018-02-19 21:12:32.402 [update info] received MS cmd: 1051b5040101 / 09170300000081000100
2018-02-19 21:12:32.402 [update notice] received unknown MS cmd: 1051b5040101 / 09170300000081000100
2018-02-19 21:12:32.498 [update info] received MS cmd: 7050b5040132 / 0a003006030100f0080100
2018-02-19 21:12:32.499 [update notice] received unknown MS cmd: 7050b5040132 / 0a003006030100f0080100
2018-02-19 21:12:32.634 [update info] received MS cmd: 1052b5040101 / 093e0300000083000100
2018-02-19 21:12:32.634 [update notice] received unknown MS cmd: 1052b5040101 / 093e0300000083000100
2018-02-19 21:12:32.701 [update info] received MS cmd: 7050b505042d2b0000 / 00
2018-02-19 21:12:32.701 [update notice] received unknown MS cmd: 7050b505042d2b0000 / 00
2018-02-19 21:12:32.836 [update info] received MS cmd: 1053b5040101 / 09150400000181000000
2018-02-19 21:12:32.836 [update notice] received unknown MS cmd: 1053b5040101 / 09150400000181000000
2018-02-19 21:12:33.021 [bus debug] ERR: read timeout during receive response, switching to skip
2018-02-19 21:12:33.361 [update info] received MS cmd: 1026b509030d0400 / 034a0400
2018-02-19 21:12:33.361 [update notice] received unknown MS cmd: 1026b509030d0400 / 034a0400
2018-02-19 21:12:33.523 [update info] received MS cmd: 1051b504010d / 054600ae0417
2018-02-19 21:12:33.523 [update notice] received unknown MS cmd: 1051b504010d / 054600ae0417
2018-02-19 21:12:33.687 [update info] received MS cmd: 1025b504010d / 050000d60337
2018-02-19 21:12:33.687 [update notice] received unknown MS cmd: 1025b504010d / 050000d60337

[modenet]

2018-02-21 18:29:40.360 [main notice] read scan config file /etc/ebusd/vaillant/51.vr630.mc.3.csv for ID "vr630", SW0500, HW6301
2018-02-21 18:29:40.378 [main notice] found messages: 502 (12 conditional on 11 conditions, 1 poll, 9 update)
2018-02-21 18:29:40.708 [update notice] received hc SumFlowSensor QQ=10: 66.75;ok
2018-02-21 18:29:40.866 [update notice] received unknown MS cmd: 1052b504010d / 054b0167023e
2018-02-21 18:29:41.036 [update notice] received hwc Status QQ=10: 0;off;58.56;55
2018-02-21 18:29:41.217 [bus notice] new master 03, master count 5
2018-02-21 18:29:41.217 [update notice] received unknown MS cmd: 1008b5110101 / 09958b0080ffff0200ff
2018-02-21 18:29:41.371 [update notice] received unknown MS cmd: 1050b5050427014201 / 00
2018-02-21 18:29:41.809 [update notice] received unknown MS cmd: 1053b5040101 / 09150400000181000501
2018-02-21 18:29:41.987 [update notice] received unknown MS cmd: 1026b5040101 / 09140300000580000501
2018-02-21 18:29:42.110 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:42.274 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:42.399 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:42.543 [bus notice] scan 52: ;Vaillant;MC2 ;0500;6301
2018-02-21 18:29:42.543 [update notice] store 52 ident: done
2018-02-21 18:29:42.543 [update notice] sent scan.52 QQ=31: Vaillant;MC2 ;0500;6301
2018-02-21 18:29:42.544 [bus notice] scan 52: ;Vaillant;MC2 ;0500;6301
2018-02-21 18:29:42.668 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:42.813 [update notice] sent unknown MS cmd: 3152b5090124 / 09003231313633383330
2018-02-21 18:29:42.937 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:43.082 [update notice] sent scan.52 id QQ=31:
2018-02-21 18:29:43.206 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:43.386 [update notice] sent scan.52 id QQ=31:
2018-02-21 18:29:44.081 [update notice] received unknown MS cmd: 7050b5040132 / 0a00300603010000080100
2018-02-21 18:29:44.285 [update notice] received mc RoomTempOffset QQ=70: 1.69
2018-02-21 18:29:44.492 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:44.639 [update notice] sent scan.52 id QQ=31: 21;16;38;306782<<<<;0907;005019;N1
2018-02-21 18:29:44.639 [bus notice] scan 52: ;21;16;38;306782<<<<;0907;005019;N1
2018-02-21 18:29:44.667 [main notice] read scan config file /etc/ebusd/vaillant/52.mc2.mc.4.csv for ID "mc2", SW0500, HW6301
2018-02-21 18:29:44.690 [main notice] found messages: 624 (12 conditional on 11 conditions, 1 poll, 9 update)
2018-02-21 18:29:44.761 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:44.884 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:45.008 [update notice] sent ui YieldThisYear QQ=31: 0;0;0;0;0;0;0;0;0;0;0;0
2018-02-21 18:29:45.109 [bus error] poll ui YieldThisYear failed: ERR: wrong symbol received
2018-02-21 18:29:45.748 [update notice] received unknown MS cmd: f051b5040132 / 0a002e0603010000080100
2018-02-21 18:29:45.903 [update notice] received mc.3 RoomTempOffset QQ=f0: 1.88
2018-02-21 18:29:46.045 [main error] scan config 53: ERR: wrong symbol received
2018-02-21 18:29:46.559 [bus error] send to 15: ERR: wrong symbol received, retry
2018-02-21 18:29:47.074 [bus error] send to 15: ERR: read timeout, retry
2018-02-21 18:29:47.436 [bus error] send to 15: ERR: wrong symbol received, retry
2018-02-21 18:29:48.164 [update notice] received unknown MS cmd: 1008b510090003ffffa064000001 / 0101
2018-02-21 18:29:48.222 [bus error] send to 15: ERR: read timeout
2018-02-21 18:29:48.222 [bus error] send message part 0: ERR: read timeout
2018-02-21 18:29:49.063 [bus error] poll ui YieldThisYear failed: ERR: read timeout
2018-02-21 18:29:49.114 [main notice] read scan config file /etc/ebusd/vaillant/75.rcc.csv for ID "rcc", SW0508, HW6201
2018-02-21 18:29:49.114 [main notice] found messages: 635 (12 conditional on 11 conditions, 1 poll, 9 update)
2018-02-21 18:29:49.150 [bus error] send to 15: ERR: read timeout, retry
2018-02-21 18:29:49.193 [bus error] send to 15: ERR: read timeout, retry
2018-02-21 18:29:49.302 [update notice] received hc SumFlowSensor QQ=10: 66.75;ok
2018-02-21 18:29:49.461 [update notice] received unknown MS cmd: 1053b504010d / 054600860315
2018-02-21 18:29:49.519 [bus error] send to 15: ERR: read timeout, retry
2018-02-21 18:29:49.630 [update notice] received hwc Status QQ=10: 0;off;58.56;55
2018-02-21 18:29:49.812 [bus error] send to 15: ERR: read timeout
2018-02-21 18:29:49.812 [bus error] send message part 0: ERR: read timeout
2018-02-21 18:29:49.898 [bus error] send to 15: ERR: read timeout, retry
2018-02-21 18:29:49.941 [bus error] send to 15: ERR: read timeout, retry
2018-02-21 18:29:49.983 [bus error] send to 15: ERR: read timeout, retry
2018-02-21 18:29:50.027 [bus error] send to 15: ERR: read timeout
2018-02-21 18:29:50.027 [bus error] send message part 0: ERR: read timeout
2018-02-21 18:29:50.195 [update notice] received mc Mode QQ=10: 23;auto;0;0;disabled;mixer;day
2018-02-21 18:29:50.374 [update notice] received mc.3 Mode QQ=10: 23;auto;0;0;disabled;mixer;day
2018-02-21 18:29:50.384 [bus error] send to 25: ERR: read timeout, retry
2018-02-21 18:29:50.428 [bus error] send to 25: ERR: read timeout, retry
2018-02-21 18:29:50.471 [bus error] send to 25: ERR: read timeout, retry
2018-02-21 18:29:50.515 [bus error] send to 25: ERR: read timeout
2018-02-21 18:29:50.515 [bus error] send message part 0: ERR: read timeout
2018-02-21 18:29:50.644 [bus error] send to 25: ERR: read timeout, retry
2018-02-21 18:29:50.686 [bus error] send to 25: ERR: read timeout, retry
2018-02-21 18:29:50.730 [bus error] send to 25: ERR: read timeout, retry
2018-02-21 18:29:50.773 [bus error] send to 25: ERR: read timeout
2018-02-21 18:29:50.773 [bus error] send message part 0: ERR: read timeout
2018-02-21 18:29:51.057 [bus error] send to 25: ERR: read timeout, retry

[modenet]

launching with --lograwdata=bytes show me a lot of AA
so I think that the problem is not the adapter

[john30]

what kind of adapter do you use? it seems the sending fails for some reason.
In order to find that out, you'd have to reproduce the issue while ebusd is logging raw bytes (as you did already). then I can see what is sent and what is returned from the bus in order to determine where the problem comes from.

[modenet]

hi, I'm using a usb interface taken from Reinhard (1.6 series).

here the comand line output:

root@vaillant:~# ebusd --scanconfig -d /dev/ttyUSB0 --httpport=8889 --lograwdata=bytes
root@vaillant:~# ebusctl
localhost: info
version: ebusd 3.1.p20180131
signal: acquired
symbol rate: 79
max symbol rate: 158
min arbitration micros: 54
max arbitration micros: 345
min symbol latency: 4
max symbol latency: 9
reconnects: 0
masters: 5
messages: 423
conditional: 8
poll: 1
update: 9
address 03: master #11
address 08: slave #11
address 10: master #2
address 15: slave #2, scanned "MF=Vaillant;ID=UI   ;SW=0508;HW=6201", loaded "vaillant/15.ui.csv"
address 23: slave
address 25: slave, scanned "MF=Vaillant;ID=VR630;SW=0500;HW=6301", loaded "vaillant/25.vr630.hwc.csv"
address 26: slave, scanned "MF=Vaillant;ID=VR630;SW=0500;HW=6301", loaded "vaillant/26.vr630.hc.csv"
address 31: master #8, ebusd
address 36: slave #8, ebusd
address 50: slave, scanned "MF=Vaillant;ID=VR630;SW=0500;HW=6301", loaded "vaillant/50.vr630.mc.csv"
address 51: slave
address 52: slave
address 53: slave
address 70: master #4
address f0: master #5

localhost: listen
listen started

hwc Status = 0;off;58.38;55
mc RoomTempOffset = 2.56
mc Status = 70;off;73.25;23
hc DateTime = ok;19:03:30;26.02.2018;5.375
mc Status = 70;off;73.06;23
hc SumFlowSensor = 67.25;ok
hwc Status = 0;off;58.25;55
hc SumFlowSensor = 67.38;ok
hwc Status = 0;off;58.12;55
mc Status = 70;off;72.94;23
broadcast datetime = 5.375;19:04:01;26.02.2018
broadcast vdatetime = 19:04:01;26.02.2018
hc DateTime = ok;19:04:05;26.02.2018;5.375
mc Status = 70;off;72.81;23
hwc Status = 0;off;58.00;55

[modenet]

here log file with -lograwdata=bytes
ebusd.log

[john30]

according to the log, you adapter is not able to send at all.
EDIT: hm, it seems it was able to send und til 19:01:57. After that, sending was no longer possible.
What kind of USB/serial adapter do you use?

[modenet]

this one: https://www.amazon.it/gp/product/B00K67X5QI/ref=oh_aui_detailpage_o04_s00?ie=UTF8&psc=1

do you think that with the new 2.1 RPI adapter with DC converter will be resolved?

[john30]

according to the data sheet, this device is buffering up to 256 bytes, which is totally unsuitable for eBUS.
yes, with the RPi adapter such issues are avoided in conjunction with the ttyebus driver

[modenet]

Can you suggest me a better usb / tty adapter? Il 27 feb 2018 1:57 PM, "John" <[email protected]> ha scritto:

…

according to the data sheet, this device is buffering up to 256 bytes, which is totally unsuitable for eBUS. yes, with the RPi adapter such issues are avoided in conjunction with the ttyebus driver <https://github.com/eBUS/ttyebus> — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#164 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AFCO76xttTmg0ZkKhvasMAgcApC7D5Ixks5tY_uygaJpZM4SCbOs> .

[john30]

We have good experience with one of those listed here