For months all devices working perfect. Updated ESPhome to 2024.5.0 and update just one device and its over. (this happend also with a version released in November 2023)
What can I do to find out what this can be?
Here log after its wireless flashed:
INFO ESPHome 2024.5.0
INFO Reading configuration /config/esphome/meek-dressoir.yaml...
INFO Detected timezone 'Europe/Amsterdam'
INFO Generating C++ source...
INFO Compiling app...
Processing meek-dressoir (board: esp01_1m; framework: arduino; platform: platformio/[email protected])
--------------------------------------------------------------------------------
HARDWARE: ESP8266 80MHz, 80KB RAM, 1MB Flash
Dependency Graph
|-- ESPAsyncTCP-esphome @ 2.0.0
|-- ESPAsyncWebServer-esphome @ 3.2.0
|-- DNSServer @ 1.1.1
|-- ESP8266WiFi @ 1.0
|-- ESP8266mDNS @ 1.2
|-- ArduinoJson @ 6.18.5
|-- NeoPixelBus @ 2.7.3
|-- noise-c @ 0.1.4
RAM: [===== ] 48.0% (used 39288 bytes from 81920 bytes)
Flash: [====== ] 58.1% (used 594973 bytes from 1023984 bytes)
========================= [SUCCESS] Took 2.07 seconds =========================
INFO Successfully compiled program.
INFO Connecting to 192.168.100.207
INFO Uploading /data/build/meek-dressoir/.pioenvs/meek-dressoir/firmware.bin (599120 bytes)
INFO Compressed to 407668 bytes
Uploading: [============================================================] 100% Done...
INFO Upload took 13.49 seconds, waiting for result...
INFO OTA successful
INFO Successfully uploaded program.
INFO Starting log output from 192.168.100.207 using esphome API
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 11.320s
INFO Successful handshake with meek-dressoir @ 192.168.100.207 in 3.028s
[15:36:11][I][app:100]: ESPHome version 2024.5.0 compiled on May 15 2024, 14:37:21
[15:36:16][W][component:237]: Component api took a long time for an operation (287 ms).
[15:36:21][W][component:237]: Component api took a long time for an operation (286 ms).
[15:36:31][W][component:237]: Component api took a long time for an operation (287 ms).
[15:36:44][W][api.connection:106]: : Reading failed: HANDSHAKESTATE_SPLIT_FAILED errno=11
Then try to check log and its connected and disconnected all the time:
INFO ESPHome 2024.5.0
INFO Reading configuration /config/esphome/meek-dressoir.yaml...
INFO Detected timezone 'Europe/Amsterdam'
INFO Starting log output from 192.168.100.207 using esphome API
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 0.004s
WARNING meek-dressoir @ 192.168.100.207: Connection error occurred: meek-dressoir @ 192.168.100.207: EOF received
WARNING Can't connect to ESPHome API for meek-dressoir @ 192.168.100.207: meek-dressoir @ 192.168.100.207: EOF received (SocketClosedAPIError)
INFO Trying to connect to meek-dressoir @ 192.168.100.207 in the background
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 0.004s
WARNING meek-dressoir @ 192.168.100.207: Connection error occurred: meek-dressoir @ 192.168.100.207: EOF received
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 0.005s
WARNING meek-dressoir @ 192.168.100.207: Connection error occurred: meek-dressoir @ 192.168.100.207: EOF received
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 0.005s
WARNING meek-dressoir @ 192.168.100.207: Connection error occurred: meek-dressoir @ 192.168.100.207: The connection dropped immediately after encrypted hello; Try enabling encryption on the device or turning off encryption on the client (ESPHome Logs 2024.5.0).
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 0.105s
INFO Successful handshake with meek-dressoir @ 192.168.100.207 in 2.931s
[15:42:04][I][app:100]: ESPHome version 2024.5.0 compiled on May 15 2024, 14:37:21
How old is the config? Are you using an encryption key?
I only suggest this because of your error message:
WARNING meek-dressoir @ 192.168.100.207:
Connection error occurred: meek-dressoir @ 192.168.100.207:
The connection dropped immediately after encrypted hello;
Try enabling encryption on the device or turning off encryption on the client (ESPHome Logs 2024.5.0).
I wonder if your on_client_connected sequence is messing things up?
[15:36:11][I][app:100]: ESPHome version 2024.5.0 compiled on May 15 2024, 14:37:21
[15:36:16][W][component:237]: Component api took a long time for an operation (287 ms).
[15:36:21][W][component:237]: Component api took a long time for an operation (286 ms).
[15:36:31][W][component:237]: Component api took a long time for an operation (287 ms).
These timestamps gaps align nicely with the delays you have. Try commenting that out or moving it to a separate automation?
When I check the log with a old ESPhome version (2023.11) next to the latest one this is in the log:
16:10:02 [E] [json:041]
Could not allocate memory for JSON document! Requested 872 bytes, largest free heap block: 872 bytes
16:10:25 [E] [json:041]
Could not allocate memory for JSON document! Requested 736 bytes, largest free heap block: 736 bytes
16:10:25 [E] [json:041]
Could not allocate memory for JSON document! Requested 352 bytes, largest free heap block: 352 bytes
========================= [SUCCESS] Took 74.18 seconds =========================
INFO Successfully compiled program.
INFO Connecting to 192.168.100.207
INFO Uploading /data/build/meek-dressoir/.pioenvs/meek-dressoir/firmware.bin (591936 bytes)
INFO Compressed to 403762 bytes
Uploading: [============================================================] 100% Done...
INFO Upload took 12.09 seconds, waiting for result...
INFO OTA successful
INFO Successfully uploaded program.
INFO Starting log output from 192.168.100.207 using esphome API
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 19.459s
WARNING Can't connect to ESPHome API for meek-dressoir @ 192.168.100.207: Handshake timed out after 30.0s (TimeoutAPIError)
INFO Trying to connect to meek-dressoir @ 192.168.100.207 in the background
WARNING meek-dressoir @ 192.168.100.207: Connection error occurred: meek-dressoir @ 192.168.100.207: Connection lost
INFO Successfully connected to meek-dressoir @ 192.168.100.207 in 0.004s
INFO Successful handshake with meek-dressoir @ 192.168.100.207 in 2.629s
[16:21:45][I][app:100]: ESPHome version 2024.5.0 compiled on May 15 2024, 16:20:01
[16:21:50][W][component:237]: Component api took a long time for an operation (286 ms).
[16:21:50][W][component:238]: Components should block for at most 30 ms.
[16:21:53][W][component:237]: Component api took a long time for an operation (287 ms).
Log part of ESPhome 2023.11
|16:21:41|[W]|[component:170]|Component api cleared Warning flag|
| --- | --- | --- | --- |
|16:21:41|[W]|[component:237]|Component api took a long time for an operation (292 ms).|
|16:21:41|[W]|[component:238]|Components should block for at most 30 ms.|
|16:21:43|[I]|[app:100]|ESPHome version 2024.5.0 compiled on May 15 2024, 16:20:01|
|16:21:47|[W]|[component:237]|Component api took a long time for an operation (286 ms).|
|16:21:47|[W]|[component:238]|Components should block for at most 30 ms.|
|16:21:51|[W]|[component:237]|Component api took a long time for an operation (287 ms).|
|16:21:51|[W]|[component:238]|Components should block for at most 30 ms.|
Why don’t you share your entire yaml, so we can try to duplicate the issue.
Please make sure you hide any sensitive info (wifi credentials, etc) before sharing.
Same happened to me. The strange thing is that out of 5 devices, 3 worked fine. Out of the 5, 3 have the same firmware, and only worked on one. I even tried to flash the same rom on all and same errors, I thought the mini d1 was gone, but I revert back to 2024.4.2 and all devices just work with no issue, after flashing all devices again.
I think I’ve had similar with an IRBlaster I’ve got (here).
I dont still have the logs of it failing though, so can’t be 100% sure.
After updating esphome, it was refusing to connect back to tthe wifi.
After a lot of messing about, I found that if I removed some IR remote buttons from my yaml and got the resulting binary onto the device, it started behaving again.
It took quite a few retrys, restarts, and generally messing with it to get the smaller code uploaded.
I’d hit a similar thing previously, where adding more IR buttons to it made it do the same. Whatever limit I’ve been hitting seems to happen earlier (with fewer buttons) after updating. I’m not sure what the limit is or where it’s coming from though.
To try to narrow down what’s going on, it might be useful to cut chunks out of your yaml and retry updating?
This update’s causing trouble with a smart speaker/assistant I’ve got thats using esphome too (here), but doing the same with that hasn’t get it going again so I’ve rolled back the update.
I had a similar thing happen here. I have a lot of ESP devices around the home and I always faithfully upgraded everything. Then with ESPHome 2024.4, some of those devices (especially the Sonoff Basic modules) would not connect to WiFi.
I tried raising the issue with the ESPHome devs, but it was dismissed with a weak excuse that I am using old hardware. As I said, recompiling with ESPHome 2023.9 fixed the issue.
I’m experiencing the same issue, I used to be on 2024.4, ESPhome docker is always updated.
I noticed by removing the “encryption” and the “key” from API it’s working fine.
I am experiencing the same on a D1 Mini, i upgraded, the device resets twice and then is active on wifi and stable, there is no output on logging when connected to usb and also wont repsond to API requests. all my ESP32 devices are fine, just the two D1 Mini’s i have arent working
I have a 2024.4.2 version of the firmware. I flashed it back and the device boots. But not all entities are there anymore in home assistant. I am using for monitoring my inverter and solar. On the old firmware the entities there are working but the main sensors for electricity monitoring are not and the entities no longer exist in home assistant