Closed palonsorodriguez closed 8 months ago
Note: ebusd fw Build: 20230917
the wifi latency seems way too high e.g. on 2023-09-27 22:55:48.480 it suggests that it took 44ms to transfer a single byte to the adapter. this way it can't work as the SYN generator on the bus jumps in ("SYN received"). do you have a lot of other wifi nets around that disturb yours?
Hi John, Thanks very much for pointing me in a good direction. When you mention that it took 44ms to transfer a single byte to the adapter, which are the relevant lines in the logs so I can find them while testing? My adapter addres is ff while the heating is 15 at the starting timestamp I can read
2023-09-27 22:55:48.480 [bus notice] >ff15
2023-09-27 22:55:48.480 [bus debug] notify request: ERR: SYN received
2023-09-27 22:55:48.480 [bus error] send to 15: ERR: SYN received, retry
2023-09-27 22:55:48.480 [bus debug] ERR: SYN received during send command, switching to ready
2023-09-27 22:55:48.480 [bus debug] start request ff
2023-09-27 22:55:48.480 [bus debug] arbitration start with ff
Which is the line you pointed that happens 44ms later? What I can see about that timeframe is
2023-09-27 22:55:48.611 [bus debug] arbitration lost (timed out)
2023-09-27 22:55:48.611 [bus debug] ERR: arbitration lost during ready, retry
2023-09-27 22:55:48.611 [bus debug] start request ff
2023-09-27 22:55:48.611 [bus debug] arbitration start with ff
2023-09-27 22:55:48.674 [bus notice] <15
2023-09-27 22:55:48.675 [bus debug] ERR: SYN received during receive command, switching to ready
Yes, there are quite a few wifi networks. Some of them are IoT devices (eg, Shelly https://www.shelly.com/en-es). I've shut down as many net as I could & tried to lower my AP signal. After that did a ping test, and looks like the latency average is about 15 ms.
--- 192.168.0.7 ping statistics ---
500 packets transmitted, 499 received, 0.2% packet loss, time 499713ms
rtt min/avg/max/mdev = 2.630/15.159/134.885/15.806 ms
Is that still too much? What is the maximum recommended?
Thanks a lot! Best regards
this is the difference to the previous log entry 2023-09-27 22:55:48.436 [bus debug] arbitration won
.
the critical delay is the AUTO-SYN that is allowed to appear anywhere between 30ms and 45ms after the last byte seen on the bus. consequently, sending a byte the interface and receiving it back in total may not take longer than 30ms.
with 15ms average ping delay, you're right at the edge of it and the maximum is awfully high, too. whenever you hit such a high delay in the middle of writing something to the interface, you'll see exactly those messages in the log
Had similar issues here. I use multiple access points with identical SSID. Unfortunately there is no easy way to choose to which of those APs the ebus adapter connects and for some reason it always connected to a "distant" AP, resulting in huge latency spikes. Reconfigured it to connect to a different SSID which is only broadcasted by the "closest" AP and the problems went away.
So if you are using multiple APs or (even worse) some kind of WLAN repeaters be aware that the ebus adapter seems not always to connect to the AP with the strongest signal.
Is there a way to force a specific AP to be used ? (By using a mac address or alike ?)
you can check with the newest firmware 20231015 that now does a full scan to find the strongest AP
I just wanted to comment that I also had the above problem: random timeouts and syn errors. As expected, the device connected to a very distant AP.
The latest firmware looks like it has resolved the issue. Regardless, I ordered the Ethernet addon (since it's sitting next to the switch).
Thanks again, @john30 !
you can check with the newest firmware 20231015 that now does a full scan to find the strongest AP
Unfortunately the errors remain. So far: Wifi: unusable Raspberry PI via GPIO: Stable Laptop via USB: Stable
I did some testing. I remove every other device from my wifi and moved the adapter ontop of my AP(Router). The adapter show 100% (-20db). Even then I get an average ping of about 60ms to 100ms. If I do the same with other devices on my wifi network I get much lower ping around 3-4ms.
That smells a bit fishy..
Now the fun bit:
When i simultaniously open my browser on http://
Is suspect the ebus-adapter's wifi adapter goes into some kind of sleep state ? @john30 Can you confirm this ?
how does that fit to your other post where you wrote that pings are below 1ms?
anyway, what exactly do you mean with "Wifi: unstable"? what is the measurement for stability you are using? some logs would be helpful as well probably
Unusable meaning that I can't get a successful scan done. The 1ms were false due to an error in my testing (pinged the wrong host). The adapter is about 3 meters away from my router, short ebus cable to the heater.
I started logging my pings to the device during the test (see timestamps):
Dashboard showing Wifi at 90% (-55dBm) Settings are default on the adapter. Docker compose part of ebusd
ebusd:
image: john30/ebusd
restart: unless-stopped
environment:
EBUSD_SCANCONFIG: ''
EBUSD_DEVICE: "ens:192.168.2.74:9999"
EBUSD_MQTTHOST: "mosquitto"
EBUSD_MQTTPORT: 1883
EBUSD_MQTTJSON: ''
EBUSD_POLLINTERVAL: '10'
EBUSD_MQTTVAR: "filter-direction=r|u|^w,filter-name=^Flame$|^HcPumpMode$|^ReturnTemp$|^StorageTemp$|^FlowTemp$|^FlowTempDesired$|^Statenumber$|^Hc1ActualFlowTempDesired$|^Hc1HeatCurve$|^Hc1ManualOPRoomTempDesired$|^ActualRoomTempDesiredHc1$|^Hc1MinimalFlowTempDesired$|^Hc1NightTemp$|^Hc1OPMode$|^Hc1QuickVetoTemp$|^HolidayRoomTemp$|^HwcActualTempDesired$|^HwcManualOPTempDesired$|^HwcOPMode$|^OutsideTemp$|^RoomTemp$|^DisplayedHwcStorageTemp$|^Hc1Pump$|^IsInHoliday$|^HolidayStartPeriod$|^HolidayEndPeriod$|^WaterPressure$"
EBUSD_MQTTCLIENTID: "ebusd-lx0001"
EBUSD_LOGRAWDATA: ""
networks:
- mqtt
- bridge
Note how the ping goes up after I stopped ebusd. Thats why I suspect some energy saving to apply on the adapter. If there is some, could thos cause spikes during an active connection ?
Guess I have the relevant question, will try to ask here instead of creating a new issue. Sometimes during the write operation I receive ERR: SYN received. Is it possible to make retries for such fails on ebusd side? I though that --sendretries=2 (default value) will make the trick, but don't see any retries in logs at all (--log=all:info --log=bus:info)
this is the difference to the previous log entry
2023-09-27 22:55:48.436 [bus debug] arbitration won
.the critical delay is the AUTO-SYN that is allowed to appear anywhere between 30ms and 45ms after the last byte seen on the bus. consequently, sending a byte the interface and receiving it back in total may not take longer than 30ms.
with 15ms average ping delay, you're right at the edge of it and the maximum is awfully high, too. whenever you hit such a high delay in the middle of writing something to the interface, you'll see exactly those messages in the log
Hi John, thanks very much for your help.
I did a lot of testing and wasn't able to success with WiFi, despite some times the latency was quite low, well below 15ms.
Trying to reduce the distance/latency in the edge, I did another test with a borrowed raspi using usb instead of WiFi, so ebusd runs at the edge, next to the heat pump (yet as a docker) instead of in my home automation server and that works like a charm. No single message seen lost.
I noticed that with hmu is fast lightning while when talking to bass2 it is quite slower and sometimes I don't receive the updates, tried with r1 in the definition file, but no difference so I'm croning reads every min of the most important variables for me.
Thanks a lot! Pablo
Hi John,
like Pablo I have the same error pattern when reading, first it doesn't find the data point and then it sends the value back after all. After I changed the interface to USB it works. Additionally a log with USB and one with Ethernet setup.
With USB: 2023-10-24 21:00:48.252 [update notice] sent read bai StorageTemp QQ=31: 45.19;ok 2023-10-24 21:00:48.404 [update notice] sent read 700 z1RoomTemp QQ=31: 22.125 2023-10-24 21:00:48.528 [update notice] sent read bai WP QQ=31: off 2023-10-24 21:00:48.667 [update notice] sent read 700 Hc1Status QQ=31: 0 2023-10-24 21:00:48.819 [update notice] sent read 700 Hc1HeatCurve QQ=31: 1 2023-10-24 21:00:48.970 [update notice] sent read 700 Hc1FlowTemp QQ=31: 31 2023-10-24 21:00:49.113 [update notice] sent read 700 Hc1PumpStatus QQ=31: 0 2023-10-24 21:00:49.244 [update notice] sent read bai FlowTemp QQ=31: 31.19;ok 2023-10-24 21:00:49.384 [update notice] sent read bai ReturnTemp QQ=31: 32.06;65022;ok 2023-10-24 21:00:49.540 [update notice] sent read 700 Hc1ActualFlowTempDesired QQ=31: 0.0 2023-10-24 21:00:55.801 [update notice] received read bai Status01 QQ=10: 31.0;32.0;13.312;34.0;45.0;off
With Ethernet: 2023-10-24 22:26:52.745 [update notice] sent read bai StorageTemp QQ=31: 42.19;ok 2023-10-24 22:26:52.901 [update notice] received unknown MS cmd: 1008b5110100 / 08c80110001f100000 2023-10-24 22:26:53.165 [update notice] sent read 700 z1RoomTemp QQ=31: 22.1875 2023-10-24 22:26:53.415 [update notice] sent read bai WP QQ=31: off 2023-10-24 22:26:53.525 [update notice] received update-read broadcast outsidetemp QQ=10: 11.562 2023-10-24 22:26:53.765 [update notice] sent read 700 Hc1Status QQ=31: 0 2023-10-24 22:26:54.084 [update notice] sent read 700 Hc1HeatCurve QQ=31: 1 2023-10-24 22:26:54.225 [update notice] received unknown MS cmd: 1008b5100305ff01 / 00 2023-10-24 22:26:54.475 [update notice] sent read 700 Hc1FlowTemp QQ=31: 28 2023-10-24 22:26:54.585 [bus error] send to 15: ERR: wrong symbol received, retry 2023-10-24 22:26:55.215 [bus error] send to 15: ERR: wrong symbol received, retry 2023-10-24 22:26:56.065 [update notice] sent read 700 Hc1PumpStatus QQ=31: 0 2023-10-24 22:26:56.205 [update notice] received update-write bai StatusCirPump QQ=10: off 2023-10-24 22:26:56.402 [update notice] sent read bai FlowTemp QQ=31: 28.81;ok 2023-10-24 22:26:56.502 [bus error] send to 08: ERR: SYN received, retry 2023-10-24 22:26:56.615 [update notice] received unknown MS cmd: 1008b5120204ff / 0101 2023-10-24 22:26:56.715 [bus error] device status: eBUS comm error: overrun 2023-10-24 22:26:56.815 [update notice] sent read bai ReturnTemp QQ=31: 29.56;65062;ok 2023-10-24 22:26:57.130 [update notice] sent read 700 Hc1ActualFlowTempDesired QQ=31: 0.0 2023-10-24 22:26:57.255 [update notice] received unknown MS cmd: 1008b513020508 / 00 2023-10-24 22:26:57.475 [update notice] received unknown BC cmd: 10feb510020601 2023-10-24 22:27:01.516 [update notice] received read bai Status01 QQ=10: 28.0;29.0;13.062;32.0;42.0;off 2023-10-24 22:27:01.802 [update notice] received update-write bai SetMode QQ=10: auto;0.0;50.0;-;1;0;1;0;0;0
Doing a ping from the LXC to ebus adapter:
18 packets transmitted, 18 received, 0% packet loss, time 17366ms rtt min/avg/max/mdev = 0.704/0.860/2.307/0.353 ms
Any idea?
Regards, Lars
@palonsorodriguez for the WIFI you could check with the REPL (available e.g. via the firmware page for flashing) if you have disturbing nets around by using the scan command.
anyway, I'm working on gettings ebusd itself into the adapter which would allow to get rid of the difficultly timed wireless transfer in the first place. but that sill takes time
@Xyaren there is no power save active in the firmware.
the issue is that spikes of 50ms like those seen in your ping list will just make it impossible to get the communication done reliably
there was some default power saving applied by ESP-IDF which is now removed in the new firmware 20231217, maybe that helps. also there were many commits to ESP-IDF that may also improve the situation, so please try
Hi John, Thanks for your help. I updated to the latest firmware, but still not possible to run with wifi Looks like there's losing communication constantly. I tried different latencies for ebusd, the following test is with 100ms
ebusd | 2024-01-08 22:02:48.126 [main notice] starting initial broadcast scan ebusd | 2024-01-08 22:02:48.126 [bus info] send message: fffe070400 ebusd | 2024-01-08 22:02:48.207 [bus notice] <1076b512030f02025200072702003d02ff031d00 ebusd | 2024-01-08 22:02:48.231 [bus notice] <02c1802400 ebusd | 2024-01-08 22:02:49.158 [bus notice] <7108b5110100b300097f020c61180900003fc800 ebusd | 2024-01-08 22:02:49.159 [bus notice] >fffe ebusd | 2024-01-08 22:02:49.159 [bus error] send to fe: ERR: SYN received, retry ebusd | 2024-01-08 22:02:49.159 [bus notice] >fffe ebusd | 2024-01-08 22:02:49.159 [bus error] send to fe: ERR: SYN received, retry ebusd | 2024-01-08 22:02:49.166 [bus notice] <7108b5110101b20009 ebusd | 2024-01-08 22:02:49.212 [bus info] send/receive symbol latency 3 - 46 ms ebusd | 2024-01-08 22:02:49.224 [bus error] send to fe: ERR: wrong symbol received ebusd | 2024-01-08 22:02:49.224 [main error] initial scan failed: ERR: wrong symbol received ebusd | 2024-01-08 22:02:49.724 [bus notice] >fffe07<fe ebusd | 2024-01-08 22:02:49.727 [bus notice] arbitration won in invalid state ready ebusd | 2024-01-08 22:02:49.782 [bus notice] >ff ebusd | 2024-01-08 22:02:49.893 [bus notice] <fe ebusd | 2024-01-08 22:02:49.953 [bus notice] <07
Thanks
Hi, I have had some problems using the adapter v5 with wifi too (see https://github.com/john30/ebusd/issues/1078 ). I found the following workaround which effects a better wifi connection :
Good luck !
PS: In my network sometimes there are problems to connect ebusd to the adapter. Also the adapter can't be reached by ping. In this case I send ping permanently and after a (longer) while ping becomes successful and the ebusd connection started also. I don't know if this is a special problem of my network or of the adapter. @John: Do you have any idea ?
is this on the latest firmware 2024-01-06?
Hi John, I updated the adapter to firmware 2024-01-06 and reactivated WLAN Autokanal/Autochannel. Within 1 day adapter/ebusd lost their connection after the WLAN channel changed automatically and the connection didn´t restart. In difference to firmware 2023-12-17 ping worked furtheron.
Note: I use a MESH-WLAN with FRITZ-router and -repeater. Although the repeater has the stronger signal (~70%) the adapter often connects to the router (~40%).
So I reactivated the fix channel solution and after several reboots the adapter connected to the repeater and the connection with ebusd started again. Since 4 days the connection works stabile.
I hope this information helps you.
Thanks to the ebusd team and your support
closing this one as it does not seem to be an ebusd issue in the first place. go on here ebusd-esp32 if needed
Description
Hi John & ebud team. Thanks very much for your efforts. What you've created is impressive
Issue
My heatpump is managed from Home assistant so I can heat the water during low energy prices or when my solar panels have surplus energy. I'm experiencing long delays reading/writing data from/to ebus (minutes, even hours) via ebusd
Environment
Actual behavior
Symptoms
I noticed that very often the heatpump is having a hard time following the commands written by Home Assistant timely and the heatpump started/stopped when it was not desired, and also the read water temp variable doesn't update for a long time, not being able to see the actual temp.
Among others I'm reading HwcStorageTemp and writting to HwcTempDesired On the other hand, I'm able to read/write the same variables almost instantly using the heatpump remote (MiPro Sense)
Troubleshooting
Wifi looks stable and strong (AP is less than 1m from the adapter), getting signal 100%, -29dBm Doing a ping from the ubuntu (where docker is running) to ebusd adapter
Tried different latency values in ebus env variables ranging from 50 to 200 (ms)
Stopped Home Assistant (so no active client is using the bus) and run manual commands reading/writting to ebusd and noticed that often it takes 3/4 tries until a successful attempt, eg:
when reading from ebus
when writing to ebus
Expected behavior
I used a different adapter before and I didn't experience this issue, but I had other stability issues, so I decided to use the official ebusd adapter
ebusd version
23.2
ebusd arguments
docker-compose.yaml
Operating system
Debian 11 (Bullseye) / Ubuntu 20-21 / Raspbian 11 / Raspberry Pi OS 11 (including lite)
CPU architecture
x64
Dockerized
devel
Hardware interface
adapter 5 via USB
Related integration
TCP (cmdline client like ebusctl or netcat), MQTT Home Assistant via mqtt-hassio.cfg
Logs
Finally I scripted the readings so I can have timestamps to be able to correlate to the logs. Below one reproduction of the issue
Note: the script reads HwcStorageTemp. If it is not a number it will wait 3 seconds and try again until it gets a number, in the case below until it reads 59°C
./getHwcTemp.sh 2023-09-27T22:55:37+00:00Z value: ERR: SYN received isnumber:false retry:0 2023-09-27T22:55:43+00:00Z value: ERR: SYN received isnumber:false retry:1 2023-09-27T22:55:48+00:00Z value: ERR: read timeout isnumber:false retry:2 2023-09-27T22:55:53+00:00Z value: 59 isnumber:true retry:3
The corresponding ebus logs are attached here ebusd_2023_09_27.log
Thanks very much for your help!!! Pablo