Am I imagining it or have I missed something.
I have an ESPHome camera setup and basically it is all working well.
However I have noticed that when the device starts, it seems to stall (i.e. show up as unavailable) until I connect to the device’s serial port.
I then get the startup details and the ESPHome configuration etc. followed by a successful connection from the Home Assistant server.
(I’m at work right not so I can’t include the log but I’m not sure that it would help at this stage. Happy to show it if asked.)
Have I set some option that tells the ESPHone device to wait until the serial port is open?
Alternatively do I need to remove some ‘default’ item that was included when I first set up the device?
Or, as I said at the start, am I imagining this and all I need to do is to wait a bit longer…?
Susan
Possibly a power supply issue. When the serial to USB adaptor is attached it is powered via the USB cable. How is it powered when the USB cable is not attached?
Do you have any other indication of that “waiting” behaviour?
Because every time you connect to read the logs, you indeed get those “boot” logs, which are cached somewhere, I assume.
FWIW, you can have an “uptime” sensor, which might make things clearer
sensor:
- platform: uptime
name: Uptime
id: sys_uptime
OK - I don’t think it is my imagination.
The device (‘Seeed Xiao ES032S3 Sense’ with a camera) is connected to my iMac via a powered USB hub. The HA runs on a Raspberry Pi 4 in another room. The device connects over WiFi
I unplugged the cable from the hub, waited a few moments and then plugged it in again. I waited over 10 minutes (breakfast!) and there was still nothing - the ESPHome display showed it as ‘Offline’ and the main display showed the card as ‘Unavailable’.
I connected to the serial port (using the ‘screen’ command on the iMac) and I immediately got the log below. My interpretation is that the device had tried several times to reboot in attempts to connect and when I started the serial connection, it proceeded as normal.
On the HA screens, the device was seen as ‘OnLine’ and an image was quickly displayed.
Just as an experiment, I commented out the ‘logger:’ line in the yaml file and the code was recompiled and uploaded to the device. When it rebooted, it became visible to HA within (perhaps) 10 seconds.
To confirm this, I uncommented the ‘logger:’ line and recompiled the code. On uploading (via OTA) the problem reappeared.
My conclusion is that the Logger is somehow blocking until it can send via a serial connection which is preventing a normal startup.
Susan
The log file (edited to remove local details only) is:
ESP-ROM:esp32s3-20210327
[I][logger:262]: Log initialized
[C][ota:469]: There have been 4 suspected unsuccessful boot attempts.
[D][esp32.preferences:114]: Saving 1 preferences to flash...
[D][esp32.preferences:143]: Saving 1 preferences [C][wifi:038]: Setting up WiFi...
[C][wifi:048]: Starting WiFi...
[C][wifi:049]: Local MAC: 48:27:E2:E7:65:68
[D][wifi:425]: Starting scan...
[D][wifi:440]: Found networks:
[I][wifi:484]: - 'xxxx' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:485]: Channel: 6
[D][wifi:486]: RSSI: -71 dB
[D][wifi:489]: - 'xxxxxxxx' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - '' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[I][wifi:274]: WiFi Connecting to 'xxxx'...
[W][wifi:609]: WiFi Unknown connection status 0
[I][wifi:274]: WiFi Connecting to 'xxxx'...
[W][wifi_esp32:504]: Event: Disconnected ssid='xxxx' bssid=xx:xx:xx:xx:xx:xx reason='Association Leave'
[W][wifi:609]: WiFi Unknown connection status 0
[D][esp32_camera:196]: Got Image: len=11252
[D][wifi:425]: Starting scan...
[D][wifi:440]: Found networks:
[D][wifi:440]: Found networks:
[I][wifi:484]: - 'xxxx' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:485]: Channel: 6
[D][wifi:486]: RSSI: -71 dB
[D][wifi:489]: - 'xxxxxxxx' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - '' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[D][wifi:489]: - 'xxxxxxxx'' (xx:xx:xx:xx:xx:xx) ▂▄▆█
[I][wifi:274]: WiFi Connecting to 'xxxx'...
[W][wifi:609]: WiFi Unknown connection status 0
[I][wifi:274]: WiFi Connecting to 'xxxx'...
[W][wifi_esp32:504]: Event: Disconnected ssid='xxxx' bssid=xx:xx:xx:xx:xx:xx reason='Association Leave'
[W][wifi:609]: WiFi Unknown connection status 0
[I][wifi:557]: WiFi Connected!
[C][wifi:379]: Local MAC: xx:xx:xx:xx:xx:xx
[C][wifi:380]: SSID: 'xxxx'
[C][wifi:381]: IP Address: 10.1.1.119
[C][wifi:383]: BSSID: xx:xx:xx:xx:xx:xx
[C][wifi:384]: Hostname: 'patio'
[C][wifi:386]: Signal strength: -72 dB ▂▄▆█
[C][wifi:390]: Channel: 6
[C][wifi:391]: Subnet: 255.255.255.0
[C][wifi:392]: Gateway: 10.1.1.1
[C][wifi:393]: DNS1: 10.1.1.1
[C][wifi:394]: DNS2: 0.0.0.0
[D][wifi:566]: Disabling AP...
[C][ota:093]: Over-The-Air Updates:
[C][ota:094]: Address: patio.local:3232
[C][ota:097]: Using Password.
[W][ota:103]: Last Boot was an unhandled reset, will proceed to safe mode in 6 restarts
[C][api:025]: Setting up Home Assistant API server...
[I][app:062]: setup() finished successfully!
[I][app:102]: ESPHome version 2023.6.5 compiled on Jul 19 2023, 08:15:08
[C][wifi:543]: WiFi:
[C][wifi:379]: Local MAC: xx:xx:xx:xx:xx:xx
[C][wifi:380]: SSID: 'xxxx'
[C][wifi:381]: IP Address: 10.1.1.119
[C][wifi:383]: BSSID: xx:xx:xx:xx:xx:xx
[C][wifi:384]: Hostname: 'patio'
[C][wifi:386]: Signal strength: -72 dB ▂▄▆█
[C][wifi:390]: Channel: 6
[C][wifi:391]: Subnet: 255.255.255.0
[C][wifi:392]: Gateway: 10.1.1.1
[C][wifi:393]: DNS1: 10.1.1.1
[C][wifi:394]: DNS2: 0.0.0.0
[C][logger:301]: Logger:
[C][logger:302]: Level: DEBUG
[C][logger:303]: Log Baud Rate: 115200
[C][logger:305]: Hardware UART: UART0
[C][esp32_camera:048]: ESP32 Camera:
[C][esp32_camera:049]: Name: Patio
[C][esp32_camera:050]: Internal: NO
[C][esp32_camera:052]: Data Pins: D0:15 D1:17 D2:18 D3:16 D4:14 D5:12 D6:11 D7:48
[C][esp32_camera:053]: VSYNC Pin: 38
[C][esp32_camera:054]: HREF Pin: 47
[C][esp32_camera:055]: Pixel Clock Pin: 13
[C][esp32_camera:056]: External Clock: Pin:10 Frequency:20000000
[C][esp32_camera:060]: I2C Pins: SDA:40 SCL:39
[C][esp32_camera:062]: Reset Pin: -1
[C][esp32_camera:080]: Resolution: 640x480 (VGA)
[C][esp32_camera:129]: JPEG Quality: 10
[C][esp32_camera:131]: Contrast: 0
[C][esp32_camera:132]: Brightness: 0
[C][esp32_camera:133]: Saturation: 0
[C][esp32_camera:134]: Vertical Flip: ON
[C][esp32_camera:135]: Horizontal Mirror: ON
[C][esp32_camera:136]: Special Effect: 0
[C][esp32_camera:137]: White Balance Mode: 0
[C][esp32_camera:140]: Auto Exposure Control: 1
[C][esp32_camera:141]: Auto Exposure Control 2: 0
[C][esp32_camera:142]: Auto Exposure Level: 0
[C][esp32_camera:143]: Auto Exposure Value: 300
[C][esp32_camera:144]: AGC: 1
[C][esp32_camera:145]: AGC Gain: 0
[C][esp32_camera:146]: Gain Ceiling: 0
[C][esp32_camera:152]: Test Pattern: NO
[C][psram:020]: PSRAM:
[C][psram:021]: Available: YES
[C][psram:024]: Size: 8191 KB
[C][captive_portal:088]: Captive Portal:
[C][mdns:112]: mDNS:
[C][mdns:113]: Hostname: patio
[C][ota:093]: Over-The-Air Updates:
[C][ota:094]: Address: patio.local:3232
[C][ota:097]: Using Password.
[W][ota:103]: Last Boot was an unhandled reset, will proceed to safe mode in 6 restarts
[C][api:138]: API Server:
[C][api:139]: Address: patio.local:6053
[C][api:141]: Using noise encryption: YES
[D][api:102]: Accepted 10.1.1.2
[D][api.connection:1030]: Home Assistant 2023.7.2 (10.1.1.2): Connected successfully
[D][esp32_camera:196]: Got Image: len=15629
[D][api:102]: Accepted 10.1.1.2
[D][api.connection:1030]: ESPHome Logs 2023.6.5 (10.1.1.2): Connected successfully
[I][app:102]: ESPHome version 2023.6.5 compiled on Jul 19 2023, 08:15:08
[C][wifi:543]: WiFi:
It’s not the logger.
Your device is having trouble connecting to your wifi.
Try powering it from somewhere other than a USB3 port. These generate huge amounts of RFI.
Not doubting your comment but does that mean that it is just coincidence that, after 1-+ minutes of doing nothing, as soon as the serial port connects, the WiFi comes right and stay right on an on-going basis?
Also the device is on the end of a 1m cable that is distanced from all of the other equipment on my work bench.
And I would have thought that -72dB is not all that weak for the signal.
Susan
-72dBm is marginal. Maybe ok for IoT, camera - not so much.
Try it with a power supply rather than USB3. See what happens.
I have done extensive work with ESP32 based cameras - doing a POC for an IOT application. I develop on an MacBook and these cameras are power hogs, leading to all sorts of shenanigans with WiFi connections depending on both how they are powered and what cable is used. It drove me mad until I realised what was happening.
Try a better cable and an independent power supply.
To test out the power source and signal strength suggestions I used a battery pack (5V 2A) and placed the device above the WiFi router. Within about 30 seconds the camera was connected and delivering pic tures.
I then removed the comment form the ‘logger:’ line and rebuilt the code and re-flashed the device (via OTA - see later). The upload was successful and I then waited for over 10 minutes but nothing.
Of course there was no serial connection to the device with this configuration so I unplugged it and connected it back to my iMac, started up the serial connection and it all came to life. That let me again comment out the ‘logger:’ line and rebuild the image.
I re-flashed the camera and then disconnected it from the iMac and reconnected it to the battery placed near the WiFI router. About 30 seconds later it was back in business.
I think that shows that the issue was not with either the power source or the WiFi signal strength.
By the way, the comment above regarding the ‘associated leave’, I think it might have come from the following , which is part of the log as it did the OTA update (connected to the iMac):
[D][esp32_camera:196]: Got Image: len=12057
[D][ota:147]: Starting OTA Update from 10.1.1.2...
[D][ota:316]: OTA in progress: 0.1%
[D][ota:316]: OTA in progress: 14.7%
[D][ota:316]: OTA in progress: 27.1%
[D][ota:316]: OTA in progress: 41.1%
[D][ota:316]: OTA in progress: 53.1%
[D][ota:316]: OTA in progress: 67.7%
[D][ota:316]: OTA in progress: 76.1%
[D][ota:316]: OTA in progress: 91.0%
[I][ota:349]: OTA update finished!
[I][app:134]: Rebooting safely...
[D][esp32.preferences:114]: Saving 1 preferences to flash...
[D][esp32.preferences:143]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[W][wifi_esp32:504]: Event: Disconnected ssid='xxxx' bssid=xx:xx:xx:xx:xx:xx reason='Association Leave'
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0x9 (SPI_FAST_FLASH_BOOT)
Saved PC:0x4209f7c6
SPIWP:0xee
mode:DIO, clock div:1
Susan
Waited where?
Connected to serial or the battery pack?
To the battery pack. As I said in the next (parenthesised) sentence, it was an OTA update.
Also the comment “Of course there was no serial connection to the device…” implies (if the sequence of events is not enough) that it was the battery pack.
Susan
I ran into a similar problem with a Seeed Xiao ESP32C3; disabling logger allowed it to boot when connected only to USB power.
Related: ESP32-C3 with ble_tracker - I'm sharing how it worked - #3 by NewfD90
@blalor - that is very useful.
Looking at USB CDC and DFU Flashing — Arduino-ESP32 2.0.6 documentation it says that the ESP32S2, C3 and S3 devices have the ability to act as a USB CDC device without external components (i.e. a separate FTDI or whatever chip).
Looking at the Seeed Xiao ESP32S3 schematic (https://files.seeedstudio.com/wiki/SeeedStudio-XIAO-ESP32S3/res/XIAO_ESP32S3_SCH_v1.1.pdf) it does show that the USB connector does connect directly to the ESP32S3. (I’m guessing that Seeed do this for your ESP32C3 board as well.)
As I’m using the Arduino platform, and I can see from the logger source file that this refers to the ‘hardware serial’ my guess is that this will be using the Espressif USB CDC driver (USB CDC — Arduino-ESP32 2.0.6 documentation).
If all that is correct and the ‘write()’ function is blocking (either for each call or when an internal buffer is filled) then I can see how any output to the logger might stall the firmware is the internal driver uses some form of flow control (e.g. RTS/CTS) that is stopping values being sent when the CDC client is not connected to some host.
All this is speculation and I’m hoping to do some tests shortly to see if this is correct (outside of ESPHome).
Susan
I’ve done a bit of testing and I’ve also found: USBCDC::flush is blocking · Issue #7554 · espressif/arduino-esp32 · GitHub.
It looks like there is an issue with the ‘Serial.flush()’ function (or however that is implemented in the ESPHome logger).
Just using a Seeed Xiao ESP32S3 and the standard Arduino IDE, I created the sketch:
#include <HardwareSerial.h>
void setup() {
// put your setup code here, to run once:
pinMode(LED_BUILTIN, OUTPUT);
delay(5000);
digitalWrite( LED_BUILTIN, HIGH);
Serial.begin(115200);
Serial.println("Hello UFO");
digitalWrite( LED_BUILTIN, LOW);
}
void loop() {
// put your main code here, to run repeatedly:
digitalWrite( LED_BUILTIN, HIGH);
Serial.println("High");
delay(1000);
digitalWrite( LED_BUILTIN, LOW);
Serial.println("Low");
delay(1000);
}
and it works without any USB serial connection.
I changed it to"
#include <HardwareSerial.h>
void setup() {
// put your setup code here, to run once:
pinMode(LED_BUILTIN, OUTPUT);
delay(5000);
digitalWrite( LED_BUILTIN, HIGH);
Serial.begin(115200);
Serial.println("Hello UFO");
Serial.flush();
digitalWrite( LED_BUILTIN, LOW);
}
void loop() {
// put your main code here, to run repeatedly:
digitalWrite( LED_BUILTIN, HIGH);
Serial.println("High");
delay(1000);
digitalWrite( LED_BUILTIN, LOW);
Serial.println("Low");
delay(1000);
}
(i.e. aded in the flush call) and I can see the LED flash at the start and then no flashes after that. However connect to the USB serial port (using the ‘screen’ command in my case) and I get the first message and the loop executes happily (and the LED flashes).
Perhaps this needs to be looked at in the ‘logger’ module to see if the suggested workarounds are needed for the ESP32S3 (S2 and C3 as well???) modules.
Susan
I ran into this today on ESPHome 2023.9.3 using a Qt Py ESP32-C3. I usually run with esp-idf but I was looking to try the new work on the BME688 PR, which only works for arduino framework. The device seems to be in a boot loop (or at least that’s what I thought) until I open a serial connection to see what the heck is going on. Then, as described above, the device appears to magically be working and reconnects to HASS, etc.
Has a formal github issue been opened?