john30
Truncated eBus messages and ERR: wrong symbol received
Hi,
I've just started with eBus and ebusd and it works quite good out of the box. Some broadcasted values are there, but unfortunately actively reading values does not work reliably.
e.g. issuing
ebusctl read WaterPressure
often returns "ERR: wrong symbol received".
After calling the same command a few times in a row, the value is finally read.
This also appears to lead to problems during the initial detection. Whenever I restart ebusd it detects different devices and loads different files.
Looking at the logs I see several messages like this:
2021-05-21 20:16:57.173 [main error] scan config 50: ERR: wrong symbol received
2021-05-21 20:16:57.759 [bus notice] >3150b5<14
2021-05-21 20:16:57.804 [bus error] send to 08: ERR: wrong symbol received, retry
2021-05-21 20:16:58.386 [bus notice] >3108b5<14
2021-05-21 20:16:58.435 [bus error] send to 08: ERR: wrong symbol received, retry
2021-05-21 20:16:59.025 [bus notice] >3108b5<35fd
2021-05-21 20:16:59.147 [bus notice] >31<1050b55e50102a01850109ff1050b505053c850185010900000000
2021-05-21 20:16:59.238 [bus error] send to 08: ERR: wrong symbol received
2021-05-21 20:16:59.238 [bus error] send message part 0: ERR: wrong symbol received
2021-05-21 20:16:59.828 [bus notice] >3108b5<11ff
I have NOT noticed any "arbitration lost" messages, though.
From my limited understanding of eBus, the messages are not fully sent to the bus and the response from the slave comes while the ebusd master is still sending.
Also I see some good case reads, but these are quite rare
2021-05-21 20:37:43.451 [update notice] sent scan-read scan.15 id QQ=31:
2021-05-21 20:37:43.452 [bus notice] >3115b509012406<0009003231313030323030d2>00
Anyone has a suggestion what the reason for this could be? Maybe the eBus interface? Cables? Or even my heating behaving wrong?
My Setup is as follows:
- Interface eBus Adapter V2.2 (https://ebus.github.io/adapter/)
- Raspberry Pi 3B+
- ebusd v21.2 running as docker container using the official docker image
- I've set --latency=100000
Thanks, Toby
I've now hooked up an old Raspberry Pi 1, installed a fresh Raspberry Pi OS and compiled ebusd from sources. I also replaced the USB cable and the eBus wires.
All that did not change anything.
WIth debugging enabled I get logs like:
2021-05-22 14:51:32.188 [bus notice] <1008b5110101890009303000144a661000ffd700
2021-05-22 14:51:33.928 [update info] received MS cmd: 1008b5040100 / 0a0336511522050621d013
2021-05-22 14:51:33.930 [update notice] received unknown MS cmd: 1008b5040100 / 0a0336511522050621d013
2021-05-22 14:51:33.934 [bus notice] <1008b50401003d000a0336511522050621d0132400
2021-05-22 14:51:34.144 [update info] received BC cmd: 10feb505020400
2021-05-22 14:51:34.146 [update notice] received unknown BC cmd: 10feb505020400
2021-05-22 14:51:34.153 [bus notice] <10feb5050204000b
2021-05-22 14:51:35.884 [update info] received MS cmd: 1050b509040e010001 / 00
2021-05-22 14:51:35.887 [update notice] received unknown MS cmd: 1050b509040e010001 / 00
2021-05-22 14:51:35.893 [main debug] performing regular tasks
2021-05-22 14:51:35.896 [bus info] scan 08 cmd: 3108070400
2021-05-22 14:51:35.897 [bus notice] <1050b509040e0100015500000000
2021-05-22 14:51:35.899 [bus debug] start request 31
2021-05-22 14:51:35.899 [bus debug] arbitration start with 31
2021-05-22 14:51:35.951 [bus debug] arbitration won
2021-05-22 14:51:35.951 [bus debug] arbitration delay 732 micros
2021-05-22 14:51:35.952 [bus info] arbitration delay 544 - 732 micros
2021-05-22 14:51:35.952 [bus debug] switching from ready to send command
2021-05-22 14:51:35.970 [bus debug] send/receive symbol latency 14 ms
2021-05-22 14:51:35.975 [bus notice] >310807
2021-05-22 14:51:35.975 [bus debug] notify request: ERR: SYN received
2021-05-22 14:51:35.976 [main error] scan config 08: ERR: SYN received
2021-05-22 14:51:35.976 [bus debug] ERR: SYN received during send command, switching to ready
2021-05-22 14:51:36.027 [bus notice] <07
2021-05-22 14:51:36.027 [bus debug] ERR: SYN received during receive command, switching to ready
2021-05-22 14:51:36.220 [update info] received MS cmd: 1050b509040e200001 / 00
2021-05-22 14:51:36.222 [update notice] received unknown MS cmd: 1050b509040e200001 / 00
2021-05-22 14:51:36.229 [bus notice] <1050b509040e2000012e00000000
2021-05-22 14:51:36.481 [update info] received MS cmd: 1050b5040118 / 060000007c0116
2021-05-22 14:51:36.483 [update notice] received unknown MS cmd: 1050b5040118 / 060000007c0116
or also
2021-05-22 14:52:42.290 [bus notice] <1008b50401003d000a03445215220506210014b700
2021-05-22 14:52:42.500 [update info] received BC cmd: 10feb505020400
2021-05-22 14:52:42.502 [update notice] received unknown BC cmd: 10feb505020400
2021-05-22 14:52:42.509 [bus notice] <10feb5050204000b
2021-05-22 14:52:43.050 [main debug] performing regular tasks
2021-05-22 14:52:43.054 [bus info] scan 15 cmd: 3115070400
2021-05-22 14:52:43.057 [bus debug] start request 31
2021-05-22 14:52:43.060 [bus debug] arbitration start with 31
2021-05-22 14:52:43.112 [bus debug] arbitration won
2021-05-22 14:52:43.112 [bus debug] arbitration delay 738 micros
2021-05-22 14:52:43.112 [bus debug] switching from ready to send command
2021-05-22 14:52:43.128 [bus debug] send/receive symbol latency 13 ms
2021-05-22 14:52:43.146 [bus debug] notify request: ERR: wrong symbol received
2021-05-22 14:52:43.147 [main error] scan config 15: ERR: wrong symbol received
2021-05-22 14:52:43.148 [bus debug] ERR: wrong symbol received during send command, switching to skip
2021-05-22 14:52:43.733 [bus notice] >311507<8af0
2021-05-22 14:52:44.252 [update info] received MS cmd: 1050b5040118 / 060000007c0116
2021-05-22 14:52:44.255 [update notice] received unknown MS cmd: 1050b5040118 / 060000007c0116
2021-05-22 14:52:44.262 [bus notice] <1050b5040118e700060000007c01168a00
2021-05-22 14:52:45.148 [main debug] performing regular tasks
2021-05-22 14:52:46.259 [update info] received MS cmd: 1050b503020003 / 0affffffffffffffffffff
2021-05-22 14:52:46.261 [update notice] received unknown MS cmd: 1050b503020003 / 0affffffffffffffffffff
2021-05-22 14:52:46.264 [bus notice] <1050b50302000343000affffffffffffffffffff0f00
Interestingly the error "wrong symbol received" comes almost 600ms before the actual bus trace. Is this expected or am i misinterpreting the logs somehow?
are you running through ttyAMA with ttyebus or how is the connection exactly looking like? it seems some other unit is sending on the bus while the protocol is in a state where sending is not allowed yet, as e.g. 311507 is not the complete master part. could be some timeout issue as well, but still non-spec compliant
