Open alfwro13 opened 1 year ago
I am seeing the exact same error after updating my Sonoff Basics (8266). Log attached. I attempted to reflash the device with the same version with no change. I have one basic currently in a bootloop.
INFO Successfully connected to extension-cord.local WARNING extension-cord.local: Connection error occurred: Traceback (most recent call last): File "/usr/local/lib/python3.9/dist-packages/aioesphomeapi/connection.py", line 520, in send_message_await_response_complex await fut asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/local/lib/python3.9/dist-packages/aioesphomeapi/connection.py", line 520, in send_message_await_response_complex await fut File "/usr/local/lib/python3.9/dist-packages/async_timeout/init.py", line 129, in aexit self._do_exit(exc_type) File "/usr/local/lib/python3.9/dist-packages/async_timeout/init.py", line 212, in _do_exit raise asyncio.TimeoutError asyncio.exceptions.TimeoutError
The above exception was the direct cause of the following exception:...
I have one basic currently in a bootloop.
How do you know it's a bootloop? That's just the logs disconnecting. Do you have an uptime sensor?
I have one basic currently in a bootloop.
How do you know it's a bootloop? That's just the logs disconnecting. Do you have an uptime sensor?
Well, to be fair, I have no idea exactly what it is doing. It loads (I think because the led starts blinking), and randomly I will see the fallback AP for less than a minute. If I push the button it will toggle the relay, but will reset after a boot cycle within two minutes.
It almost looks like a race condition when connecting to the WiFi, causing it to crash and reboot.
I'm seeing this issue as well. Here are my logs from the ESP32:
I'm also seeing this on an ESP32, for me it's an intermittent issue, my node can run OK for hours, then raise this error and lose connection for a minute or so.
I'm also seeing this on an ESP32, for me it's an intermittent issue, my node can run OK for hours, then raise this error and lose connection for a minute or so.
Digging a little deeper, I'm seeing brief random disconnections on a lot of my nodes at the same times, and they coincide with periods of connectivity errors reported in the HA logs for lots of intergrations, not just ESPHome. So I think maybe what I'm seeing is network or HA issues, rather than specifically ESPHome. Maybe this set of logs in the ESPHome nodes is just what they report when they can't connect to HA.
I'm seeing same set of errors:
Logger: aioesphomeapi.connection
Source: /usr/local/lib/python3.10/site-packages/aioesphomeapi/connection.py:577
First occurred: 12:36:55 (12 occurrences)
Last logged: 16:24:22
nodemcu_a @ 192.168.x.78: Connection error occurred:
sms-gateway @ 192.168.x.50: Connection error occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioesphomeapi/connection.py", line 537, in send_message_await_response_complex
await fut
asyncio.exceptions.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioesphomeapi/connection.py", line 536, in send_message_await_response_complex
async with async_timeout.timeout(timeout):
File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
self._do_exit(exc_type)
File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/aioesphomeapi/connection.py", line 320, in _keep_alive_loop
await self._ping()
File "/usr/local/lib/python3.10/site-packages/aioesphomeapi/connection.py", line 645, in _ping
await self.send_message_await_response(PingRequest(), PingResponse)
File "/usr/local/lib/python3.10/site-packages/aioesphomeapi/connection.py", line 554, in send_message_await_response
res = await self.send_message_await_response_complex(
File "/usr/local/lib/python3.10/site-packages/aioesphomeapi/connection.py", line 539, in send_message_await_response_complex
raise TimeoutAPIError(
aioesphomeapi.core.TimeoutAPIError: Timeout waiting for response for <class 'api_pb2.PingRequest'> after 10.0s
One of thesse nodes operates on -78 dBm sgignal which is not the point of disconnection for other nodes. The other one sits at around -45/-50 which is perfect signal and still I'm experiencing kind-of dropouts and even reboots without any clues in log file...
Home assistant: 2023.3.1 (latest) Supervisor: 2023.01.1 ESPhome: 2023.2.4
I think this is caused by the api connection being dropped. My TAG reader (ESP32) can run for hours and all of a sudden it looses connecting with HA. Also if logging over WiFi, it's all verys slow. In the ESP log i see this when doing nothing
[D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [W][api.connection:083]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connection closed [D][api:102]: Accepted ::FFFF:192.168.24.250 [D][api.connection:918]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connected successfully [D][time:045]: Synchronized time: 2023-03-04 16:40:48 [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][pn532:283]: Mifare ultralight [D][pn532:162]: Found new tag '04-FD-D0-62-12-68-80' [D][pn532:295]: Waiting to read next tag [D][rtttl:038]: Playing song beep [D][ledc.output:051]: Calculating resolution bit-depth for frequency 988.000000 [D][ledc.output:056]: Resolution calculated as 16 [D][rtttl:094]: Playback finished [D][pn532:283]: Mifare ultralight [D][pn532:162]: Found new tag '04-FD-D0-62-12-68-80' [D][pn532:295]: Waiting to read next tag [D][rtttl:038]: Playing song beep [D][ledc.output:051]: Calculating resolution bit-depth for frequency 988.000000 [D][ledc.output:056]: Resolution calculated as 16 [D][rtttl:094]: Playback finished [D][pn532:283]: Mifare ultralight [D][pn532:162]: Found new tag '04-FD-D0-62-12-68-80' [D][pn532:295]: Waiting to read next tag [D][rtttl:038]: Playing song beep [D][ledc.output:051]: Calculating resolution bit-depth for frequency 988.000000 [D][ledc.output:056]: Resolution calculated as 16 [D][rtttl:094]: Playback finished [D][pn532:283]: Mifare ultralight [D][pn532:162]: Found new tag '04-FD-D0-62-12-68-80' [D][pn532:295]: Waiting to read next tag [D][rtttl:038]: Playing song beep [D][ledc.output:051]: Calculating resolution bit-depth for frequency 988.000000 [D][ledc.output:056]: Resolution calculated as 16 [D][rtttl:094]: Playback finished [D][sensor:127]: 'Tag Reader WiFi Sensor': Sending state -41.00000 dBm with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [I][ota:113]: Boot seems successful, resetting boot loop counter. [D][esp32.preferences:113]: Saving 1 preferences to flash... [D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [W][api.connection:083]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connection closed [D][api:102]: Accepted ::FFFF:192.168.24.250 [D][api.connection:918]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connected successfully [D][time:045]: Synchronized time: 2023-03-04 16:47:50 [D][sensor:127]: 'Tag Reader WiFi Sensor': Sending state -43.00000 dBm with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [W][api.connection:083]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connection closed [D][api:102]: Accepted ::FFFF:192.168.24.250 [D][api.connection:918]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connected successfully [D][time:045]: Synchronized time: 2023-03-04 16:50:12 [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sntp:078]: Synchronized time: 2023-03-04 16:51:19 [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Channel': Sending state 13.00000 with 0 decimals of accuracy [D][sensor:127]: 'Tag Reader WiFi Sensor': Sending state -44.00000 dBm with 0 decimals of accuracy
Also when sometimes scanning a TAG, you have to hold the TAG for several seconds on the scanner. In the ESP log, you see the scanning directly, but is HA log (AppDaemon event) it can arrive seonds later
I used to have the RGB config in there, but removed it for the time beeing.
Just my 2cents, Harry
Hmmm, because of a partial power outage last night, a few of my systems needed a reboot. Since the reboot the tag-reader responds much better. I will monitor this for a while to see if i have api timouts again.
Oop, too soon, still have timeout errors
[D][rtttl:094]: Playback finished [D][pn532:280]: Mifare classic [D][pn532:162]: Found new tag 'F3-EC-5F-EF' [D][pn532:166]: NDEF formatted records:
[D][pn532:295]: Waiting to read next tag [W][api.connection:083]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connection closed [D][api:102]: Accepted ::FFFF:192.168.24.250 [D][api.connection:918]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connected successfully [W][api.connection:083]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connection closed [D][api:102]: Accepted ::FFFF:192.168.24.250 [D][api.connection:918]: Home Assistant 2023.3.1 (::FFFF:192.168.24.250): Connected successfully [D][time:045]: Synchronized time: 2023-03-05 08:02:18 [D][pn532:280]: Mifare classic [D][pn532:162]: Found new tag 'F3-EC-5F-EF' [D][pn532:166]: NDEF formatted records:
[D][pn532:295]: Waiting to read next tag [D][rtttl:038]: Playing song two short [D][ledc.output:051]: Calculating resolution bit-depth for frequency 1319.000000 [D][ledc.output:056]: Resolution calculated as 15 [D][ledc.output:051]: Calculating resolution bit-depth for frequency 1319.000000 [D][ledc.output:056]: Resolution calculated as 15 [D][rtttl:094]: Playback finished
I used a wifi signal amplifier and everything worked, apparently it refuses to work with a weak signal, you need a very strong wifi signal. I had the exact same problem before after an update.
I have issues with units almost near to AP
The problem
After updating firmware in my ESPHome rgb lights the are crashing every couple of minutes with this error:
Prior to the upgrade they were working without issues (on December firmware 2022.12)
Which version of ESPHome has the issue?
v2023.2.1
What type of installation are you using?
Home Assistant Add-on
Which version of Home Assistant has the issue?
2023.2.5
What platform are you using?
ESP8266
Board
esp01_1m
Component causing the issue
No response
Example YAML snippet
Anything in the logs that might be useful for us?
No response
Additional information
No response