esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
294 stars 37 forks source link

Hourly reboots on minimal configuration #5583

Open l3zha opened 8 months ago

l3zha commented 8 months ago

The problem

Uptime reaches almost an hour and a reboot occurs, sometimes it reboots earlier, but there was no uptime for more than an hour. I am newbie. I tried to reflash from scratch several times, but the result is the same

Which version of ESPHome has the issue?

2024.2.2

What type of installation are you using?

Home Assistant Add-on

Which version of Home Assistant has the issue?

2024.3.0

What platform are you using?

ESP32

Board

petkit solo feeder

Component causing the issue

No response

Example YAML snippet

esphome:
  name: dogfeeder
  friendly_name: dogfeeder

esp32:
  board: esp32dev
  framework:
    type: arduino

# Enable logging
logger:
  level: DEBUG
  baud_rate: 9600
# Enable Home Assistant API
api:
  encryption:
    key: !secret encryption_key

ota:
  password: !secret ota_password

wifi:
  ssid: !secret wifi_ssid
  password: !secret wifi_password

  # Enable fallback hotspot (captive portal) in case wifi connection fails
  ap:
    ssid: "Dogfeeder Fallback Hotspot"
    password: "xrZYexCLi0RF"

captive_portal:

sensor:
  - platform: uptime
    name: Uptime Sensor

button:
  - platform: restart
    name: "Living Room Restart"

debug:
  update_interval: 5s

text_sensor:
  - platform: debug
    device:
      name: "Device Info"
    reset_reason:
      name: "Reset Reason"

Anything in the logs that might be useful for us?

[W][component:214]: Component api took a long time for an operation (0.12 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3536331 (now=3541331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3541331 (now=3546332)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3546331 (now=3551331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3551331 (now=3556331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3556331 (now=3561331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3561331 (now=3566331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3566331 (now=3571331)
[VV][scheduler:226]: Running interval '' with interval=60000 last_execution=3515615 (now=3575615)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3571331 (now=3576331)
[VV][scheduler:226]: Running interval 'update' with interval=60000 last_execution=3518367 (now=3578367)
[V][sensor:043]: 'Uptime Sensor': Received new state 3578.366943
[D][sensor:094]: 'Uptime Sensor': Sending state 3578.36694 s with 0 decimals of accuracy
[VV][api.service:140]: send_sensor_state_response: SensorStateResponse {
  key: 683514054
  state: 3578.37
  missing_state: NO
}
[W][component:214]: Component uptime.sensor took a long time for an operation (0.37 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3576331 (now=3581331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3581331 (now=3586331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3586331 (now=3591331)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=3591331 (now=3596331)
ЌdRСиХ—LEqШТБшpє �р[I][logger:359]: Log initialized
[VV][esp32.preferences:071]: nvs_get_blob: key: 233825507, len: 4
[C][ota:483]: There have been 0 suspected unsuccessful boot attempts.
[VV][esp32.preferences:040]: s_pending_save: key: 233825507, len: 4
[D][esp32.preferences:114]: Saving 1 preferences to flash...
[VV][esp32.preferences:123]: Checking if NVS data 233825507 has changed
[V][esp32.preferences:126]: sync: key: 233825507, len: 4
[D][esp32.preferences:143]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[I][app:029]: Running through setup()...
[V][app:030]: Sorting components by setup priority...
[VV][scheduler:063]: set_interval(name='', interval=60000, offset=11397)
[VV][scheduler:063]: set_interval(name='update', interval=60000, offset=13660)
[C][wifi:038]: Setting up WiFi...
[C][wifi:051]: Starting WiFi...
[C][wifi:052]:   Local MAC: E8:9F:6D:A6:FA:88
[V][esp32.preferences:059]: nvs_get_blob('2740577916'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet
[V][wifi_esp32:039]: Enabling STA.
[  1268][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 0 - WIFI_READY
[V][wifi_esp32:417]: Event: WiFi ready[  1361][V][WiFiGeneric.cpp:338] _arduino_event_cb(): STA Started

[  1392][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 2 - STA_START
[V][wifi_esp32:428]: Event: WiFi STA start
[  7688][V][WiFiGeneric.cpp:381] _arduino_event_cb(): SCAN Done: ID: 128, Status: 0, Results: 13
[  7689][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 1 - SCAN_DONE
[V][wifi_esp32:422]: Event: WiFi Scan Done status=0 number=13 scan_id=128
[D][wifi:474]: Found networks:
[I][wifi:518]: - 'Airport' (50:FF:20:5B:48:87) вЦВвЦДвЦЖвЦИ
[D][wifi:519]:     Channel: 8
[D][wifi:520]:     RSSI: -56 dB
[I][wifi:518]: - 'Airport' (50:FF:20:8F:07:AA) вЦВвЦДвЦЖвЦИ
[D][wifi:519]:     Channel: 4
[D][wifi:520]:     RSSI: -68 dB
[D][wifi:523]: - 'DIR-615-ED10' (0C:B6:D2:8A:ED:11) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - 'Keenetic-1591' (E4:18:6B:6C:2A:78) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - '' (52:FF:20:4B:48:87) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - 'tovaroved' (F0:B4:D2:90:DB:3F) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - '' (52:FF:20:CF:07:AA) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - 'Liga-Telecom' (D8:0D:17:22:34:3C) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - '26s823' (B0:6E:BF:73:7A:28) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - '' (56:EF:44:4A:CB:71) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - 'TP-Link_5FB6' (40:3F:8C:96:5F:B6) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - 'OMKB' (D8:0D:17:1C:FC:12) вЦВвЦДвЦЖвЦИ
[D][wifi:523]: - 'Keenetic-3260' (50:FF:20:87:9B:C3) вЦВвЦДвЦЖвЦИ
[I][wifi:304]: WiFi Connecting to 'Airport'...
[V][wifi:306]: Connection Params:
[V][wifi:307]:   SSID: 'Airport'
[V][wifi:310]:   BSSID: 50:FF:20:5B:48:87
[V][wifi:330]:   Password: 'Svyaznoy123'
[V][wifi:335]:   Channel: 8
[V][wifi:344]:   Using DHCP IP
[V][wifi:346]:   Hidden: NO
[ 10702][V][WiFiGeneric.cpp:353] _arduino_event_cb(): STA Connected: SSID: Airport, BSSID: 50:ff:20:5b:48:87, Channel: 8, Auth: WPA2_PSK
[ 10712][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
[V][wifi_esp32:442]: Event: Connected ssid='Airport' bssid=50:FF:20:5B:48:87 channel=8, authmode=WPA2 PSK
[ 11084][V][WiFiGeneric.cpp:367] _arduino_event_cb(): STA Got New IP:192.168.68.67
[ 11086][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
[ 11123][D][WiFiGeneric.cpp:991] _eventCallback(): STA IP: 192.168.68.67, MASK: 255.255.255.0, GW: 192.168.68.1
[V][wifi_esp32:496]: Event: Got IP static_ip=192.168.68.67 gateway=192.168.68.1
[C][logger:447]: Logger:
[C][logger:448]:   Level: VERY_VERBOSE
[C][logger:449]:   Log Baud Rate: 9600
[C][logger:451]:   Hardware UART: UART0
[C][uptime.sensor:031]: Uptime Sensor 'Uptime Sensor'
[C][uptime.sensor:031]:   Device Class: 'duration'
[C][uptime.sensor:031]:   State Class: 'total_increasing'
[C][uptime.sensor:031]:   Unit of Measurement: 's'
[C][uptime.sensor:031]:   Accuracy Decimals: 0
[C][uptime.sensor:031]:   Icon: 'mdi:timer-outline'
[V][uptime.sensor:031]:   Unique ID: 'e89f6da6fa88-uptime'
[C][restart.button:017]: Restart Button 'Living Room Restart'
[C][captive_portal:088]: Captive Portal:
[C][mdns:115]: mDNS:
[C][mdns:116]:   Hostname: dogfeeder
[V][mdns:117]:   Services:
[V][mdns:119]:   - _esphomelib, _tcp, 6053
[V][mdns:121]:     TXT: friendly_name = dogfeeder
[V][mdns:121]:     TXT: version = 2024.2.2
[V][mdns:121]:     TXT: mac = e89f6da6fa88
[V][mdns:121]:     TXT: platform = ESP32
[V][mdns:121]:     TXT: board = esp32dev
[V][mdns:121]:     TXT: network = wifi
[V][mdns:121]:     TXT: api_encryption = Noise_NNpsk0_25519_ChaChaPoly_SHA256
[C][ota:096]: Over-The-Air Updates:
[C][ota:097]:   Address: dogfeeder.local:3232
[C][ota:100]:   Using Password.
[C][ota:103]:   OTA version: 2.
[D][api:102]: Accepted 192.168.68.132
[VV][api.socket:696]: 192.168.68.132: Handshake complete!
[W][component:214]: Component api took a long time for an operation (0.18 s).
[W][component:215]: Components should block for at most 20-30ms.
[C][api:139]: API Server:
[C][api:140]:   Address: dogfeeder.local:6053
[C][api:142]:   Using noise encryption: YES
[VV][api.service:522]: on_hello_request: HelloRequest {
  client_info: 'Home Assistant 2024.3.0'
  api_version_major: 1
  api_version_minor: 9
}
[V][api.connection:1103]: Hello from client: 'Home Assistant 2024.3.0' | 192.168.68.132 | API Version 1.9
[VV][api.service:013]: send_hello_response: HelloResponse {
  api_version_major: 1
  api_version_minor: 9
  server_info: 'dogfeeder (esphome v2024.2.2)'
  name: 'dogfeeder'
}
[W][component:214]: Component api took a long time for an operation (0.38 s).
[W][component:215]: Components should block for at most 20-30ms.
[C][debug:064]: Debug component:
[C][debug:066]:   Device info 'Device Info'
[C][debug:066]:     Icon: 'mdi:chip'
[D][debug:076]: ESPHome version 2024.2.2
[D][debug:080]: Free Heap Size: 237856 bytes
[D][debug:110]: Flash Chip: Size=8192kB Speed=40MHz Mode=DIO
[D][debug:159]: Chip: Model=ESP32, Features=WIFI_BGN,BLE,BT, Cores=2, Revision=1
[D][debug:167]: ESP-IDF Version: v4.4.2
[D][debug:172]: EFuse MAC: E8:9F:6D:A6:FA:88
[D][debug:272]: Reset Reason: Power On Reset
[D][debug:317]: Wakeup Reason: Unknown
[V][text_sensor:013]: 'Device Info': Received new state 2024.2.2|Flash: 8192kB Speed:40MHz Mode:DIO|Chip: ESP32 Features:WIFI_BGN,BLE,BT, Cores:2 Revision:1|ESP-IDF: v4.4.2|EFuse MAC: E8:9F:6D:A6:FA:88|Reset: Power On Reset|Wakeup: Unknown
[D][text_sensor:064]: 'Device Info': Sending state '2024.2.2|Flash: 8192kB Speed:40MHz Mode:DIO|Chip: ESP32 Features:WIFI_BGN,BLE,BT, Cores:2 Revision:1|ESP-IDF: v4.4.2|EFuse MAC: E8:9F:6D:A6:FA:88|Reset: Power On Reset|Wakeup: Unknown'
[V][text_sensor:013]: 'Reset Reason': Received new state Power On Reset
[D][text_sensor:064]: 'Reset Reason': Sending state 'Power On Reset'
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=9804 (now=15523)
[VV][api.service:531]: on_connect_request: ConnectRequest {
  password: ''
}
[D][api.connection:1121]: Home Assistant 2024.3.0 (192.168.68.132): Connected successfully
[VV][api.service:019]: send_connect_response: ConnectResponse {
  invalid_password: NO
}
[W][component:214]: Component api took a long time for an operation (0.25 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:576]: on_device_info_request: DeviceInfoRequest {}
[VV][api.service:049]: send_device_info_response: DeviceInfoResponse {
  uses_password: NO
  name: 'dogfeeder'
  mac_address: 'E8:9F:6D:A6:FA:88'
  esphome_version: '2024.2.2'
  compilation_time: 'Mar  9 2024, 08:06:06'
  model: 'esp32dev'
  has_deep_sleep: NO
  project_name: ''
  project_version: ''
  webserver_port: 0
  legacy_bluetooth_proxy_version: 0
  bluetooth_proxy_feature_flags: 0
  manufacturer: 'Espressif'
  friendly_name: 'dogfeeder'
  voice_assistant_version: 0
  suggested_area: ''
}
[W][component:214]: Component api took a long time for an operation (0.50 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:585]: on_list_entities_request: ListEntitiesRequest {}
[VV][api.service:132]: send_list_entities_sensor_response: ListEntitiesSensorResponse {
  object_id: 'uptime_sensor'
  key: 683514054
  name: 'Uptime Sensor'
  unique_id: 'e89f6da6fa88-uptime'
  icon: 'mdi:timer-outline'
  unit_of_measurement: 's'
  accuracy_decimals: 0
  force_update: NO
  device_class: 'duration'
  state_class: STATE_CLASS_TOTAL_INCREASING
  legacy_last_reset_type: LAST_RESET_NONE
  disabled_by_default: NO
  entity_category: ENTITY_CATEGORY_DIAGNOSTIC
}
[W][component:214]: Component api took a long time for an operation (0.50 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:306]: send_list_entities_button_response: ListEntitiesButtonResponse {
  object_id: 'living_room_restart'
  key: 547939800
  name: 'Living Room Restart'
  unique_id: 'dogfeederbuttonliving_room_restart'
  icon: ''
  disabled_by_default: NO
  entity_category: ENTITY_CATEGORY_CONFIG
  device_class: 'restart'
}
[W][component:214]: Component api took a long time for an operation (0.25 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:166]: send_list_entities_text_sensor_response: ListEntitiesTextSensorResponse {
  object_id: 'device_info'
  key: 999430890
  name: 'Device Info'
  unique_id: 'dogfeedertext_sensordevice_info'
  icon: 'mdi:chip'
  disabled_by_default: NO
  entity_category: ENTITY_CATEGORY_DIAGNOSTIC
}
[W][component:214]: Component api took a long time for an operation (0.25 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:166]: send_list_entities_text_sensor_response: ListEntitiesTextSensorResponse {
  object_id: 'reset_reason'
  key: 2962208445
  name: 'Reset Reason'
  unique_id: 'dogfeedertext_sensorreset_reason'
  icon: 'mdi:restart'
  disabled_by_default: NO
  entity_category: ENTITY_CATEGORY_DIAGNOSTIC
}
[W][component:214]: Component api took a long time for an operation (0.25 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:055]: send_list_entities_done_response: ListEntitiesDoneResponse {}
[VV][api.service:594]: on_subscribe_states_request: SubscribeStatesRequest {}
[W][component:214]: Component api took a long time for an operation (0.12 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:656]: on_subscribe_homeassistant_services_request: SubscribeHomeassistantServicesRequest {}
[VV][api.service:140]: send_sensor_state_response: SensorStateResponse {
  key: 683514054
  state: 1.373
  missing_state: NO
}
[W][component:214]: Component api took a long time for an operation (0.25 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=14804 (now=20102)
[VV][api.service:683]: on_subscribe_home_assistant_states_request: SubscribeHomeAssistantStatesRequest {}
[W][component:214]: Component api took a long time for an operation (0.12 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:174]: send_text_sensor_state_response: TextSensorStateResponse {
  key: 999430890
  state: '2024.2.2|Flash: 8192kB Speed:40MHz Mode:DIO|Chip: ESP32 Features:WIFI_BGN,BLE,BT, Cores:2 Revision:1|ESP-IDF: v4.4.2|EFuse MAC: E8:9F:6D:A6:FA:88|Reset: Power On Reset|Wakeup: Unknown'
  missing_state: NO
}
[W][component:214]: Component api took a long time for an operation (0.25 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][api.service:174]: send_text_sensor_state_response: TextSensorStateResponse {
  key: 2962208445
  state: 'Power On Reset'
  missing_state: NO
}
[W][component:214]: Component api took a long time for an operation (0.13 s).
[W][component:215]: Components should block for at most 20-30ms.
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=19804 (now=24804)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=24804 (now=29806)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=29804 (now=34804)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=34804 (now=39804)
[VV][scheduler:226]: Running interval 'update' with interval=5000 last_execution=39804 (now=44804)
[VV][scheduler:226]: Running interval 'update' with interval=60000 last_execution=4294954404 (now=47108)
[V][sensor:043]: 'Uptime Sensor': Received new state 47.108002
[D][sensor:094]: 'Uptime Sensor': Sending state 47.10800 s with 0 decimals of accuracy
[VV][api.service:140]: send_sensor_state_response: SensorStateResponse {
  key: 683514054
  state: 47.108
  missing_state: NO
}
[W][component:214]: Component uptime.sensor took a long time for an operation (0.37 s).
[W][component:215]: Components should block for at most 20-30ms.

Additional information

Detecting chip type... ESP32 Chip is ESP32-D0WD (revision 1) Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None Crystal is 40MHz MAC: e8:9f:6d:a6:fa:88 Stub is already running. No upload is necessary. Manufacturer: c8 Device: 4017 Detected flash size: 8MB Hard resetting via RTS pin...

ssieb commented 8 months ago

Those logs do not match your config. Change the log level back to debug and why did you change the logger baud rate? That's going to slow things down. If you leave the logs running, see if you can see the reason for it restarting.

l3zha commented 8 months ago

Those logs do not match your config. Change the log level back to debug and why did you change the logger baud rate? That's going to slow things down. If you leave the logs running, see if you can see the reason for it restarting.

I use terminal on Mac OS - screen -L -U /dev/tty.usbserial-0001. For some reason the log at a speed of 115200 looks like this:

€Тb�R™€≈DшёДEIОdHR€т�¬�QMЎМАс(PN$А€ыхы-x± ”•ЂЋЋ©DЄЛ~sLµнЈj/МьoSµќ•љOмуB÷Є/џ÷5…PkЁ/[≈UЏТ акЁЌjuƒ÷cƒ€zЯ4kOрOнEEЏЁMЉ{QkЯЬЃXH≤ѓю%5лQі€дцЛmgХ•?©Ѓ€ЛђшBjяўЌ †?0ѓЯ®П$е€DьЪqbы&ѓѕґ[µ#—я‘Ё„С≥чЊІw@vп1“€_Е…нuИпµ]ы€>xov©ЯдµOµ€Њ™Я$№&ЏRMz{—¬Z;F√ЯВКЧKЎk" №ЂU÷†≥<Ўl{€єaJтђ¶пх>=mъ#Х€цЧU�vэЭ|6J•€vм+XZэ

Today I installed Tasmota, the device still reboots, the reason for the reboot is "Vbat power on reset"

ssieb commented 8 months ago

You need to tell screen the baud rate. The serial logs should give a better reason. I have no idea what that means.

Masterz69 commented 8 months ago

Which power supply using ? Is it capable for 1A current ? Suggest to use more powerfull supply for some time.

github-actions[bot] commented 4 months ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.