Logger.log and ESP_LOGD() differences

ESPHome
1

In testing ESP32 deep_sleep I have come across something I can’t explain, and hoping someone can help me. I have a couple of issues:

  1. I have a programming background, but not familiar with C++
  2. For some variables id(variable) contains the value, but other times id(other_variable).state contains the value.
  3. Sometimes ESP_LOGD() and logger.log return different values for the same variable.

Here is my test code:

#####################################################################
#                                                                   #
# The ESP32-S3-DevKitC-1 (v1) board with ESP32-S3-WROOM-1-N16R8     #
#   CURRENT usage for debugging parts of the greenhouse code        #
#                                                                   #
#####################################################################

substitutions:
  devicename:     "esp32s3-test"
  update_interval_sensor:  "2 min"        # How often to measure and report sensor values

deep_sleep: 
  id: deep_sleep_1
  run_duration:   300000ms  # = 5 min - how long to run (be awake)
  sleep_duration: 180000ms  # = 3 min - how long to sleep for

esphome:
  name: $devicename
  platformio_options:
    board_build.flash_mode: dio 
  on_boot: 
    - priority: -100.0
      then:
        - lambda: |-
              ESP_LOGD("on_boot", "");
              ESP_LOGD("on-boot", "#################### ON_BOOT ####################");
              ESP_LOGD("on_boot", ">>>>>> on_boot: initial values   wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d", 
                    id(wakeup_cause), id(wakeup_cause).state, id(num_wake_cycles) );
              // id(wakeup_cause) = esp_sleep_get_wakeup_cause();
              id(num_wake_cycles) += 1;
        #- number.increment: num_wake_cycles
        - logger.log: "##### on_boot finished" 
  on_shutdown:
    - priority: -100
      then:
        - lambda: |-
            ESP_LOGD("on_shutdown", "");
            ESP_LOGD("on_shutdown", " >>>> A >>>>    wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d", 
                    id(wakeup_cause), id(wakeup_cause).state, id(num_wake_cycles) );
        - logger.log: 
            format: "logger  >>>> B >>>>    wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d "
            args: [ 'id(wakeup_cause)', 'id(wakeup_cause).state', 'id(num_wake_cycles)' ]

globals:
  - id: num_wake_cycles
    type: int
    restore_value: yes
    initial_value: '0'

sensor:
  - platform: template
    id: wakeup_cause
    name: $devicename Wakeup cause
    update_interval: $update_interval_sensor
    accuracy_decimals: 0
    lambda:  |-
      ESP_LOGD("wakeup_cause", ">>>> X >>>>   esp_sleep_get_wakeup_cause()=%d, wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d", 
               esp_sleep_get_wakeup_cause(), id(wakeup_cause), id(wakeup_cause).state, id(num_wake_cycles) );
      return esp_sleep_get_wakeup_cause();
    on_raw_value:
      then:
        - logger.log: 
            format: "logger  >>>> C >>>>   wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d, x=%d"
            args: [ 'id(wakeup_cause)', 'id(wakeup_cause).state', 'id(num_wake_cycles)', 'x' ]
        - lambda: |-
            ESP_LOGD("wakeup_cause", ">>>> D >>>>   wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d, x=%d", 
                    id(wakeup_cause), id(wakeup_cause).state, id(num_wake_cycles), x );

  - platform: bh1750
    name: $devicename BH1750 Illuminance
    address: 0x23
    update_interval: $update_interval_sensor
    on_raw_value:
      then:
        - logger.log: 
            format: "logger  >>>> E >>>>   wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d "
            args: [ 'id(wakeup_cause)', 'id(wakeup_cause).state', 'id(num_wake_cycles)' ]
        - lambda: |-
            ESP_LOGD("BH1750", "      >>>> F >>>>   wakeup_cause=%d, wakeup_cause.state=%d, num_wake_cycles=%d ", 
                    id(wakeup_cause), id(wakeup_cause).state, id(num_wake_cycles) );

  - platform: wifi_signal
    name: $devicename Wifi signal
    update_interval: $update_interval_sensor

#
# the other stuff you still want to know...
#

esp32:
  board: esp32-s3-devkitc-1         # devkit from AliExpress
  variant: esp32s3
  flash_size: 16MB
  framework:
    type: esp-idf
    version: recommended

psram:
  mode: octal
  speed: 80MHz

wifi:
  ssid:     !secret upstairs_ssid
  password: !secret upstairs_password 
  manual_ip:
    static_ip: 192.168.1.124
    gateway: 192.168.1.1
    subnet: 255.255.255.0
  fast_connect: True

ota:
  platform: esphome
  password: !secret esphome_ota_password

web_server:
  port: 80

api:
  encryption:
    key: !secret esphome_api_encryption

logger:
  level: DEBUG
  hardware_uart: uart0   

i2c:
  - id: bus_a
    sda: GPIO5
    scl: GPIO4
    scan: true
    frequency: 400kHz

I have setup a template sensor to store the current wakeup cause, and a global variable for the number of times the ESP32 has woken up. I also have a BH1750 Illuminance and wi-fi signal sensors attached to show that normal sensors are still being handled properly.

I have added logger.log and lambda ESP_LOGD() actions to track the variables, but found that sometimes there are differences even though I have copied and pasted the arguments !

The result (from the more comprehensive UART log) is:

[2025-04-24 12:43:09] ESP-ROM:esp32s3-20210327
[2025-04-24 12:43:09] Build:Mar 27 2021
[2025-04-24 12:43:09] rst:0x5 (DSLEEP),boot:0x2b (SPI_FAST_FLASH_BOOT)
[2025-04-24 12:43:09] SPIWP:0xee
[2025-04-24 12:43:09] mode:DIO, clock div:1
[2025-04-24 12:43:09] load:0x3fce3818,len:0x1750
[2025-04-24 12:43:09] load:0x403c9700,len:0x4
[2025-04-24 12:43:09] load:0x403c9704,len:0xbe4
[2025-04-24 12:43:09] load:0x403cc700,len:0x2d34
[2025-04-24 12:43:09] entry 0x403c9908
[2025-04-24 12:43:09] I (27) boot: ESP-IDF 5.1.5 2nd stage bootloader
[2025-04-24 12:43:09] I (27) boot: compile time Feb 22 2025 12:49:26
[2025-04-24 12:43:09] I (27) boot: Multicore bootloader
[2025-04-24 12:43:09] I (30) boot: chip revision: v0.2
[2025-04-24 12:43:09] I (34) boot.esp32s3: Boot SPI Speed : 80MHz
[2025-04-24 12:43:09] I (38) boot.esp32s3: SPI Mode       : DIO
[2025-04-24 12:43:09] I (43) boot.esp32s3: SPI Flash Size : 16MB
[2025-04-24 12:43:09] I (48) boot: Enabling RNG early entropy source...
[2025-04-24 12:43:09] I (53) boot: Partition Table:
[2025-04-24 12:43:09] I (57) boot: ## Label            Usage          Type ST Offset   Length
[2025-04-24 12:43:09] I (64) boot:  0 otadata          OTA data         01 00 00009000 00002000
[2025-04-24 12:43:09] I (72) boot:  1 phy_init         RF data          01 01 0000b000 00001000
[2025-04-24 12:43:09] I (79) boot:  2 app0             OTA app          00 10 00010000 007c0000
[2025-04-24 12:43:09] I (87) boot:  3 app1             OTA app          00 11 007d0000 007c0000
[2025-04-24 12:43:09] I (94) boot:  4 nvs              WiFi data        01 02 00f90000 0006d000
[2025-04-24 12:43:09] I (102) boot: End of partition table
[2025-04-24 12:43:09] I (106) esp_image: segment 0: paddr=007d0020 vaddr=3c0a0020 size=30440h (197696) map
[2025-04-24 12:43:09] I (150) esp_image: segment 1: paddr=00800468 vaddr=3fc9a200 size=04908h ( 18696) load
[2025-04-24 12:43:09] I (154) esp_image: segment 2: paddr=00804d78 vaddr=40374000 size=0b2a0h ( 45728) load
[2025-04-24 12:43:09] I (166) esp_image: segment 3: paddr=00810020 vaddr=42000020 size=99d74h (630132) map
[2025-04-24 12:43:09] I (279) esp_image: segment 4: paddr=008a9d9c vaddr=4037f2a0 size=0aea0h ( 44704) load
[2025-04-24 12:43:09] I (290) esp_image: segment 5: paddr=008b4c44 vaddr=600fe000 size=0005ch (    92) 
[2025-04-24 12:43:09] I (290) esp_image: segment 6: paddr=008b4ca8 vaddr=600fe05c size=00008h (     8) 
[2025-04-24 12:43:09] I (304) boot: Loaded app from partition at offset 0x7d0000
[2025-04-24 12:43:09] I (304) boot: Disabling RNG early entropy source...
[2025-04-24 12:43:09] I (307) cpu_start: Multicore app
[2025-04-24 12:43:09] I (311) octal_psram: vendor id    : 0x0d (AP)
[2025-04-24 12:43:09] I (315) octal_psram: dev id       : 0x02 (generation 3)
[2025-04-24 12:43:09] I (321) octal_psram: density      : 0x03 (64 Mbit)
[2025-04-24 12:43:09] I (327) octal_psram: good-die     : 0x01 (Pass)
[2025-04-24 12:43:09] I (332) octal_psram: Latency      : 0x01 (Fixed)
[2025-04-24 12:43:09] I (337) octal_psram: VCC          : 0x01 (3V)
[2025-04-24 12:43:09] I (342) octal_psram: SRF          : 0x01 (Fast Refresh)
[2025-04-24 12:43:09] I (348) octal_psram: BurstType    : 0x01 (Hybrid Wrap)
[2025-04-24 12:43:09] I (354) octal_psram: BurstLen     : 0x01 (32 Byte)
[2025-04-24 12:43:09] I (359) octal_psram: Readlatency  : 0x02 (10 cycles@Fixed)
[2025-04-24 12:43:09] I (365) octal_psram: DriveStrength: 0x00 (1/1)
[2025-04-24 12:43:09] I (371) MSPI Timing: PSRAM timing tuning index: 5
[2025-04-24 12:43:09] I (376) esp_psram: Found 8MB PSRAM device
[2025-04-24 12:43:09] I (381) esp_psram: Speed: 80MHz
[2025-04-24 12:43:09] I (385) cpu_start: Pro cpu up.
[2025-04-24 12:43:09] I (388) cpu_start: Starting app cpu, entry point is 0x40376f28
[2025-04-24 12:43:09] I (0) cpu_start: App cpu up.
[2025-04-24 12:43:10] I (818) esp_psram: SPI SRAM memory test OK
[2025-04-24 12:43:10] I (826) cpu_start: Pro cpu start user code
[2025-04-24 12:43:10] I (826) cpu_start: cpu freq: 160000000 Hz
[2025-04-24 12:43:10] I (826) cpu_start: Application information:
[2025-04-24 12:43:10] I (829) cpu_start: Project name:     esp32s3-test
[2025-04-24 12:43:10] I (835) cpu_start: App version:      2025.4.0
[2025-04-24 12:43:10] I (840) cpu_start: Compile time:     Apr 20 2025 15:13:57
[2025-04-24 12:43:10] I (846) cpu_start: ELF file SHA256:  a8fd51b9aa6b05a9...
[2025-04-24 12:43:10] I (852) cpu_start: ESP-IDF:          5.1.5
[2025-04-24 12:43:10] I (857) cpu_start: Min chip rev:     v0.0
[2025-04-24 12:43:10] I (861) cpu_start: Max chip rev:     v0.99 
[2025-04-24 12:43:10] I (866) cpu_start: Chip rev:         v0.2
[2025-04-24 12:43:10] I (871) heap_init: Initializing. RAM available for dynamic allocation:
[2025-04-24 12:43:10] I (878) heap_init: At 3FCA2A38 len 00046CD8 (283 KiB): DRAM
[2025-04-24 12:43:10] I (884) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
[2025-04-24 12:43:10] I (891) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
[2025-04-24 12:43:10] I (897) heap_init: At 600FE064 len 00001F84 (7 KiB): RTCRAM
[2025-04-24 12:43:10] I (904) esp_psram: Adding pool of 8192K of PSRAM memory to heap allocator
[2025-04-24 12:43:10] I (912) spi_flash: detected chip: generic
[2025-04-24 12:43:10] I (916) spi_flash: flash io: dio
[2025-04-24 12:43:10] I (920) sleep: Configure to isolate all GPIO pins in sleep state
[2025-04-24 12:43:10] I (926) sleep: Enable automatic switching of GPIO sleep configuration
[2025-04-24 12:43:10] I (934) app_start: Starting scheduler on CPU0
[2025-04-24 12:43:10] I (938) app_start: Starting scheduler on CPU1
[2025-04-24 12:43:10] I (938) main_task: Started on CPU0
[2025-04-24 12:43:10] I (948) main_task: Calling app_main()
[2025-04-24 12:43:10] [I][logger:171]: Log initialized
[2025-04-24 12:43:10] [C][safe_mode:079]: There have been 0 suspected unsuccessful boot attempts
[2025-04-24 12:43:10] [D][esp32.preferences:114]: Saving 1 preferences to flash...
[2025-04-24 12:43:10] [D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[2025-04-24 12:43:10] [I][app:029]: Running through setup()...
[2025-04-24 12:43:10] [C][i2c.idf:021]: Setting up I2C bus...
[2025-04-24 12:43:10] [I][i2c.idf:260]: Performing I2C bus recovery
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1065) gpio: GPIO[4]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1071) gpio: GPIO[5]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [C][bh1750.sensor:041]: Setting up BH1750 'esp32s3-test BH1750 Illuminance'...
[2025-04-24 12:43:10] [C][wifi:048]: Setting up WiFi...
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1099) pp: pp rom version: e7ae62f
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1102) net80211: net80211 rom version: e7ae62f
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1113) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000]: wifi driver task: 3fcb3988, prio:23, stack:6656, core=0
[2025-04-24 12:43:10] [D][esp-idf:000]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1154) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: wifi firmware version: bbd58fc31
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1154) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: wifi certification version: v7.0
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1159) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: config NVS flash: enabled
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1179) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: config nano formating: disabled
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1190) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init data frame dynamic rx buffer num: 32
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1210) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init static rx mgmt buffer num: 5
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1231) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init management short buffer num: 32
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1251) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init dynamic tx buffer num: 32
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1262) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init tx cache buffer num: 32
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1282) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init static tx FG buffer num: 2
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1302) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init static rx buffer size: 1600
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1313) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init static rx buffer num: 10
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1333) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: Init dynamic rx buffer num: 32
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1354) wifi_init: rx ba win: 6
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1354) wifi_init: tcpip mbox: 32
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1364) wifi_init: udp mbox: 6
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1374) wifi_init: tcp mbox: 6
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1374) wifi_init: tcp tx win: 5760
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1384) wifi_init: tcp rx win: 5760
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1384) wifi_init: tcp mss: 1440
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1394) wifi_init: WiFi IRAM OP enabled
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000]: I (1405) wifi_init: WiFi RX IRAM OP enabled
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [C][wifi:061]: Starting WiFi...
[2025-04-24 12:43:10] [C][wifi:062]:   Local MAC: 98:3D:AE:EB:24:F4
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1416) phy_init: phy_version 680,a6008b2,Jun  4 2024,16:41:10
[2025-04-24 12:43:10] 
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: I (1451) wifi:
[2025-04-24 12:43:10] [D][esp-idf:000][wifi]: mode : sta (98:3d:ae:eb:24:f4)
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (1451) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: enable tsf
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (1467) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: Set ps type: 1, coexist: 0
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][wifi:760]: Loaded saved fast_connect wifi settings
[2025-04-24 12:43:11] [I][wifi:313]: WiFi Connecting to 'dagoba'...
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: W (1487) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: Password length matches WPA2 standards, authmode threshold changes from OPEN to WPA2
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (1508) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: Set ps type: 1, coexist: 0
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2058) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2059) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: state: init -> auth (b0)
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2076) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: state: auth -> assoc (0)
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2088) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: state: assoc -> run (10)
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2114) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: connected with dagoba, aid = 5, channel 1, BW20, bssid = 64:66:b3:ed:08:c4
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2115) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: security: WPA2-PSK, phy: bgn, rssi: -62
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2135) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: pm start, type: 1
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2155) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2176) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 25000, mt_pti: 0, mt_time: 10000
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: I (2197) wifi:
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: AP's beacon interval = 102400 us, DTIM period = 1
[2025-04-24 12:43:11] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000][sys_evt]: I (2219) esp_netif_handlers: sta ip: 192.168.1.124, mask: 255.255.255.0, gw: 192.168.1.1
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [D][esp-idf:000]: I (2228) mdns_mem: mDNS task will be created from internal RAM
[2025-04-24 12:43:11] 
[2025-04-24 12:43:11] [C][api:026]: Setting up Home Assistant API server...
[2025-04-24 12:43:11] [D][on_boot:025]: 
[2025-04-24 12:43:11] [D][on-boot:026]: #################### ON_BOOT ####################
[2025-04-24 12:43:11] [D][on_boot:027]: >>>>>> on_boot: initial values   wakeup_cause=1070226904, wakeup_cause.state=-2147483648, num_wake_cycles=0
[2025-04-24 12:43:11] [D][main:033]: ##### on_boot finished
[2025-04-24 12:43:11] [C][deep_sleep:013]: Setting up Deep Sleep...
[2025-04-24 12:43:11] [I][deep_sleep:018]: Scheduling Deep Sleep to start in 300000 ms
[2025-04-24 12:43:11] [I][app:062]: setup() finished successfully!
[2025-04-24 12:43:11] [W][component:172]: Component wifi cleared Warning flag
[2025-04-24 12:43:11] [W][component:157]: Component api set Warning flag: unspecified
[2025-04-24 12:43:11] [I][app:100]: ESPHome version 2025.4.0 compiled on Apr 24 2025, 12:26:48
[2025-04-24 12:43:11] [C][wifi:600]: WiFi:
[2025-04-24 12:43:11] [C][wifi:428]:   Local MAC: 98:3D:AE:EB:24:F4
[2025-04-24 12:43:11] [C][wifi:433]:   SSID: 'dagoba'
[2025-04-24 12:43:11] [C][wifi:436]:   IP Address: 192.168.1.124
[2025-04-24 12:43:11] [C][wifi:439]:   BSSID: 64:66:B3:ED:08:C4
[2025-04-24 12:43:11] [C][wifi:441]:   Hostname: 'esp32s3-test'
[2025-04-24 12:43:11] [C][wifi:443]:   Signal strength: -62 dB ▂▄▆█
[2025-04-24 12:43:11] [C][wifi:447]:   Channel: 1
[2025-04-24 12:43:11] [C][wifi:448]:   Subnet: 255.255.255.0
[2025-04-24 12:43:11] [C][wifi:449]:   Gateway: 192.168.1.1
[2025-04-24 12:43:11] [C][wifi:450]:   DNS1: 0.0.0.0
[2025-04-24 12:43:11] [C][wifi:451]:   DNS2: 0.0.0.0
[2025-04-24 12:43:11] [C][logger:177]: Logger:
[2025-04-24 12:43:11] [C][logger:178]:   Max Level: DEBUG
[2025-04-24 12:43:11] [C][logger:179]:   Initial Level: DEBUG
[2025-04-24 12:43:11] [C][logger:181]:   Log Baud Rate: 115200
[2025-04-24 12:43:11] [C][logger:182]:   Hardware UART: UART0
[2025-04-24 12:43:11] [C][i2c.idf:083]: I2C Bus:
[2025-04-24 12:43:11] [C][i2c.idf:084]:   SDA Pin: GPIO5
[2025-04-24 12:43:11] [C][i2c.idf:085]:   SCL Pin: GPIO4
[2025-04-24 12:43:11] [C][i2c.idf:086]:   Frequency: 400000 Hz
[2025-04-24 12:43:11] [C][i2c.idf:092]:   Recovery: bus successfully recovered
[2025-04-24 12:43:11] [I][i2c.idf:102]: Results from i2c bus scan:
[2025-04-24 12:43:11] [I][i2c.idf:108]: Found i2c device at address 0x23
[2025-04-24 12:43:11] [C][template.sensor:022]: Template Sensor 'esp32s3-test Wakeup cause'
[2025-04-24 12:43:11] [C][template.sensor:022]:   State Class: ''
[2025-04-24 12:43:11] [C][template.sensor:022]:   Unit of Measurement: ''
[2025-04-24 12:43:11] [C][template.sensor:022]:   Accuracy Decimals: 0
[2025-04-24 12:43:11] [C][template.sensor:023]:   Update Interval: 120.0s
[2025-04-24 12:43:12] [C][psram:017]: PSRAM:
[2025-04-24 12:43:12] [C][psram:021]:   Available: YES
[2025-04-24 12:43:12] [C][psram:023]:   Size: 8192 KB
[2025-04-24 12:43:12] [C][bh1750.sensor:118]: BH1750 'esp32s3-test BH1750 Illuminance'
[2025-04-24 12:43:12] [C][bh1750.sensor:118]:   Device Class: 'illuminance'
[2025-04-24 12:43:12] [C][bh1750.sensor:118]:   State Class: 'measurement'
[2025-04-24 12:43:12] [C][bh1750.sensor:118]:   Unit of Measurement: 'lx'
[2025-04-24 12:43:12] [C][bh1750.sensor:118]:   Accuracy Decimals: 1
[2025-04-24 12:43:12] [C][bh1750.sensor:119]:   Address: 0x23
[2025-04-24 12:43:12] [C][bh1750.sensor:124]:   Update Interval: 120.0s
[2025-04-24 12:43:12] [C][web_server:285]: Web Server:
[2025-04-24 12:43:12] [C][web_server:286]:   Address: 192.168.1.124:80
[2025-04-24 12:43:12] [C][mdns:116]: mDNS:
[2025-04-24 12:43:12] [C][mdns:117]:   Hostname: esp32s3-test
[2025-04-24 12:43:12] [C][esphome.ota:073]: Over-The-Air updates:
[2025-04-24 12:43:12] [C][esphome.ota:074]:   Address: 192.168.1.124:3232
[2025-04-24 12:43:12] [C][esphome.ota:075]:   Version: 2
[2025-04-24 12:43:12] [C][safe_mode:018]: Safe Mode:
[2025-04-24 12:43:12] [C][safe_mode:019]:   Boot considered successful after 60 seconds
[2025-04-24 12:43:12] [C][safe_mode:021]:   Invoke after 10 boot attempts
[2025-04-24 12:43:12] [C][safe_mode:022]:   Remain in safe mode for 300 seconds
[2025-04-24 12:43:12] [C][api:140]: API Server:
[2025-04-24 12:43:12] [C][api:141]:   Address: 192.168.1.124:6053
[2025-04-24 12:43:12] [C][api:143]:   Using noise encryption: YES
[2025-04-24 12:43:12] [C][wifi_signal.sensor:010]: WiFi Signal 'esp32s3-test Wifi signal'
[2025-04-24 12:43:12] [C][wifi_signal.sensor:010]:   Device Class: 'signal_strength'
[2025-04-24 12:43:12] [C][wifi_signal.sensor:010]:   State Class: 'measurement'
[2025-04-24 12:43:12] [C][wifi_signal.sensor:010]:   Unit of Measurement: 'dBm'
[2025-04-24 12:43:12] [C][wifi_signal.sensor:010]:   Accuracy Decimals: 0
[2025-04-24 12:43:12] [C][deep_sleep:026]: Setting up Deep Sleep...
[2025-04-24 12:43:12] [C][deep_sleep:029]:   Sleep Duration: 180000 ms
[2025-04-24 12:43:12] [C][deep_sleep:032]:   Run Duration: 300000 ms
[2025-04-24 12:43:12] [D][esp-idf:000][wifi]: I (3440) wifi:
[2025-04-24 12:43:12] [D][esp-idf:000][wifi]: <ba-add>idx:0 (ifx:0, 64:66:b3:ed:08:c4), tid:0, ssn:0, winSize:64
[2025-04-24 12:43:12] [D][esp-idf:000][wifi]: 
[2025-04-24 12:43:12] 
[2025-04-24 12:43:12] [D][api:103]: Accepted 192.168.1.98
[2025-04-24 12:43:12] [D][api:103]: Accepted 192.168.1.98
[2025-04-24 12:43:13] [W][component:172]: Component api cleared Warning flag
[2025-04-24 12:43:13] [W][component:239]: Component api took a long time for an operation (86 ms).
[2025-04-24 12:43:13] [W][component:240]: Components should block for at most 30 ms.
[2025-04-24 12:43:13] [D][api.connection:1801]: Home Assistant 2025.4.2 (192.168.1.98): Connected successfully
[2025-04-24 12:43:13] [D][api.connection:1801]: ESPHome Logs 2025.4.0 (192.168.1.98): Connected successfully
[2025-04-24 12:43:15] [D][wakeup_cause:057]: >>>> X >>>>   esp_sleep_get_wakeup_cause()=4, wakeup_cause=1070226904, wakeup_cause.state=0, num_wake_cycles=2146
959360
[2025-04-24 12:43:15] [D][main:423]: logger  >>>> C >>>>   wakeup_cause=1070226904, wakeup_cause.state=-2147483648, num_wake_cycles=0, x=2146959360
[2025-04-24 12:43:15] [D][wakeup_cause:066]: >>>> D >>>>   wakeup_cause=1070226904, wakeup_cause.state=-2147483648, num_wake_cycles=0, x=2146959360
[2025-04-24 12:43:15] [D][sensor:093]: 'esp32s3-test Wakeup cause': Sending state 4.00000  with 0 decimals of accuracy

The X line shows shows that the esp_sleep_get_wakeup_cause() function returns a 4 to indicate that the ESP32 was woken by the timer after a deep_sleep, and num_wake_cycles has changed. The next line in the yaml returns the esp_sleep_get_wakeup_cause() into the wakeup_cause template sensor.

The C and D lines indicate that the on_raw_value: clause is then executed … and the same values are reported by both. ESPHome docs state that the sensor reading is stored in ‘x’ while we are executing filters and other processing … however ‘x’ is instead now storing what was in my global num_wake_cycles !

to continue …

[2025-04-24 12:43:17] [D][sensor:093]: 'esp32s3-test Wifi signal': Sending state -62.00000 dBm with 0 decimals of accuracy
[2025-04-24 12:43:34] [D][esp32.preferences:114]: Saving 1 preferences to flash...
[2025-04-24 12:43:34] [D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[2025-04-24 12:43:51] [D][bh1750.sensor:159]: 'esp32s3-test BH1750 Illuminance': Got illuminance=7.1lx
[2025-04-24 12:43:51] [D][main:062]: logger  >>>> E >>>>   wakeup_cause=1070226904, wakeup_cause.state=-16777216, num_wake_cycles=0 
[2025-04-24 12:43:51] [D][BH1750:079]:       >>>> F >>>>   wakeup_cause=1070226904, wakeup_cause.state=3, num_wake_cycles=0 
[2025-04-24 12:43:51] [D][sensor:093]: 'esp32s3-test BH1750 Illuminance': Sending state 7.13090 lx with 1 decimals of accuracy

I added a couple of print statements into the unrelated BH1750 sensor’s yaml just to detect the situation after the wakeup_cause sensor completed. My guess is that large number in id(wakeup_cause) is a pointer to either the memory location of the value, or to the esp_sleep_get_wakeup_cause() function, and so id(wakeup_cause).state will be the value of the sensor - but why is the id().state value reported differently by logger.log and ESP_LOGD() ?

[2025-04-24 12:44:10] [I][safe_mode:041]: Boot seems successful; resetting boot loop counter
[2025-04-24 12:44:10] [D][esp32.preferences:114]: Saving 1 preferences to flash...
[2025-04-24 12:44:10] [D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[2025-04-24 12:45:15] [D][wakeup_cause:057]: >>>> X >>>>   esp_sleep_get_wakeup_cause()=4, wakeup_cause=1070226904, wakeup_cause.state=0, num_wake_cycles=1074
790400
[2025-04-24 12:45:15] [D][main:423]: logger  >>>> C >>>>   wakeup_cause=1070226904, wakeup_cause.state=153, num_wake_cycles=0, x=1074790400
[2025-04-24 12:45:15] [D][wakeup_cause:066]: >>>> D >>>>   wakeup_cause=1070226904, wakeup_cause.state=1070179868, num_wake_cycles=0, x=1074790400
[2025-04-24 12:45:15] [D][sensor:093]: 'esp32s3-test Wakeup cause': Sending state 4.00000  with 0 decimals of accuracy
[2025-04-24 12:45:17] [D][sensor:093]: 'esp32s3-test Wifi signal': Sending state -62.00000 dBm with 0 decimals of accuracy
[2025-04-24 12:45:51] [D][bh1750.sensor:159]: 'esp32s3-test BH1750 Illuminance': Got illuminance=7.5lx
[2025-04-24 12:45:51] [D][main:062]: logger  >>>> E >>>>   wakeup_cause=1070226904, wakeup_cause.state=-16777216, num_wake_cycles=0 
[2025-04-24 12:45:51] [D][BH1750:079]:       >>>> F >>>>   wakeup_cause=1070226904, wakeup_cause.state=0, num_wake_cycles=0 
[2025-04-24 12:45:51] [D][sensor:093]: 'esp32s3-test BH1750 Illuminance': Sending state 7.47047 lx with 1 decimals of accuracy
[2025-04-24 12:47:15] [D][wakeup_cause:057]: >>>> X >>>>   esp_sleep_get_wakeup_cause()=4, wakeup_cause=1070226904, wakeup_cause.state=0, num_wake_cycles=1074
790400
[2025-04-24 12:47:15] [D][main:423]: logger  >>>> C >>>>   wakeup_cause=1070226904, wakeup_cause.state=153, num_wake_cycles=0, x=1074790400
[2025-04-24 12:47:15] [D][wakeup_cause:066]: >>>> D >>>>   wakeup_cause=1070226904, wakeup_cause.state=1070179868, num_wake_cycles=0, x=1074790400
[2025-04-24 12:47:15] [D][sensor:093]: 'esp32s3-test Wakeup cause': Sending state 4.00000  with 0 decimals of accuracy
[2025-04-24 12:47:17] [D][sensor:093]: 'esp32s3-test Wifi signal': Sending state -62.00000 dBm with 0 decimals of accuracy
[2025-04-24 12:47:51] [D][bh1750.sensor:159]: 'esp32s3-test BH1750 Illuminance': Got illuminance=8.0lx
[2025-04-24 12:47:51] [D][main:062]: logger  >>>> E >>>>   wakeup_cause=1070226904, wakeup_cause.state=-16777216, num_wake_cycles=0 
[2025-04-24 12:47:51] [D][BH1750:079]:       >>>> F >>>>   wakeup_cause=1070226904, wakeup_cause.state=0, num_wake_cycles=0 
[2025-04-24 12:47:51] [D][sensor:093]: 'esp32s3-test BH1750 Illuminance': Sending state 8.03642 lx with 1 decimals of accuracy
[2025-04-24 12:48:11] [I][deep_sleep:060]: Beginning Deep Sleep
[2025-04-24 12:48:11] [I][deep_sleep:062]: Sleeping for 180000000us
[2025-04-24 12:48:11] [D][esp32.preferences:114]: Saving 1 preferences to flash...
[2025-04-24 12:48:11] [D][esp32.preferences:142]: Saving 1 preferences to flash: 1 cached, 0 written, 0 failed
[2025-04-24 12:48:11] [D][on_shutdown:037]: 
[2025-04-24 12:48:11] [D][on_shutdown:038]:  >>>> A >>>>    wakeup_cause=1070226904, wakeup_cause.state=1070528852, num_wake_cycles=0
[2025-04-24 12:48:11] [D][main:042]: logger  >>>> B >>>>    wakeup_cause=1070226904, wakeup_cause.state=-1287651329, num_wake_cycles=0

and the same repeats for the next awake cycle.

2

My first question is why?? :smiley:

Anyhow, id(wakeup_cause) on its own represents the entire sensor data structure, not the value. The value is accessed as for ALL sensors using .state, i.e. id(wakeup_cause).state.

As to the raw values - why do you need them? I suspect they don’t mean anything at all, as -2147483648 is simply the largest possible 32 bit integer…

Also - your X line doesn’t make sense - you can’t log the value of a sensor until you’ve executed the return statement, which is why the function call evaluates as 4 but the .state is 0. It hasn’t been written yet.

3

Except for template sensors - because they are not evaluated until that return statement is executed…

4

Thanks Daryl for making the effort to reply.

My basic objective is to implement deep_sleep. To store the value returned by esp_sleep_get_wakeup_cause() as the state of wakeup_cause; and for global variable num_wake_cycles to be incremented every time the ESP32 wakes up.

However I noticed that this wasn’t happening as I had expected; and back when I was programming I found it useful to add PRINT statements to help narrow down where the fault in my logic was happening. And doing that, I found that logger.log and ESP_LODG() statements with identical arguments sometimes show different values - which I had thought was not possible.

I know that the problem is that my understanding is wrong. I don’t yet feel confident with yaml, am lost with all but the most basic C++, and am well aware that my programming paradigm is out-of-date … and so I am trying to work out what is happening, to understand and learn.

Consequently I have trimmed the yaml code down to show the behaviour that I do not understand, and added extra logging statements. My test code itself doesn’t achieve anything useful.

OK, I assumed that id(wakeup_cause) is the pointer to the data structure. Maybe I’ve looked at too much code, both lambdas and yaml, and got confused about when the .state is and isn’t needed.

Exactly; it is there to show before and after within the wakeup_cause sensor. It is showing that the return esp_sleep_get_wakeup_cause(); line does change the state of wakeup_cause … but not to the value of 4 returned by esp_sleep_get_wakeup_cause(). And yes, the raw value is simply a convenient place to show that it is happening before filters are applied.

I am confused by this statement…
Within the wakeup_cause template sensor the lambda: clause is executing return esp_sleep_get_wakeup_cause() - is that the ‘return statement’ you are referring to ? Because I assumed that is the value which would be stored in ‘x’ while the filters and on_raw_value: clause are executed.

The Template Sensor examples return only floating point constants … except then they give rather advanced C++ function calls for Bluetooth proxies. Is that maybe the problem, that esp_sleep_get_wakeup_cause() is not returning a float ?

All in all Daryl, it sounds as though you are suggesting that the strange results are caused by my adding the extra logging. Sorry if I sound confrontational, but it feels that I have been fighting this code/problem for a couple of weeks now and only digging the hole deeper.

5

Lol! I am probably not that good at explaining - nor am I an expert.

Firstly - the only time you will see id(variable) used without .state is for global variables. This is because they or not a structure - just a c++ variable you declare in yaml.

Now id(wakeup_cause).state should return the correct value in C and D - but maybe that’s because the sensor value is a float? Have you tried that?

6

I did a quick test - I think a lot of the problem is the print statements.

This sensor:

sensor:
  - platform: template
    id: testlambda
    name: testlambda
    lambda: return 55;
    on_value:
      then:
        logger.log: 
          format: "Final Value is: %f"
          args: x
    on_raw_value: 
      then:
        logger.log: 
          format: "Raw Value is: %f"
          args: x
    filters: 
      lambda: return x * 2;

Shows thus in the logs:

[10:16:38][D][main:170]: Raw Value is: 55.000000
[10:16:38][D][sensor:094]: 'testlambda': Sending state 110.00000  with 1 decimals of accuracy
[10:16:38][D][main:164]: Final Value is: 110.000000

If you change the on_raw: to:

    on_raw_value: 
      then:
        logger.log: 
          format: "Raw Value is: %d"
          args: x

You get:

[10:11:09][D][main:170]: Raw Value is: 0
[10:11:09][D][sensor:094]: 'testlambda': Sending state 110.00000  with 1 decimals of accuracy
[10:11:09][D][main:164]: Final Value is: 110.000000
7

I am definitely finding this swapping between yaml and C++ even more confusing that writing server-side JavaScript to generate client-side JavaScript code !

That is indeed what I was expecting. It doesn’t matter which order the clauses are in the yaml.

  • the lambda: returns 55 (expressed as an integer, but automatically converted to a float shown the subsequent logger.logs), and stored in the C++ local variable ‘x’.
  • on_raw_value is executed before the filters, so the value is 55 (now shown as a float)
  • filters: are executed next, doubling the value of x
  • finally on_value: is processed after the filters, and shows that the final value which gets stored in testlambda.state is 110.0

Ah!! The only change you did in on_raw_value was to change the print formatting from a %f (float) to a %d (integer) ! And I am using %d for all my logger statements without considering which are integers and which are floats !!! :bulb: THANK YOU !

8

Yeah sorry - I could have pointed that out better - oops… :smiley:

9

Don’t be sorry. Always better to figure something out for oneself … no matter how many hints it might take :wink:

FYI, my results and interpretations:

  • I have left num_wake_cycles as %d formatting since it is a global and defined as integer … so should stay an integer. Am now seeing the correct value consistently !
  • I have removed id(wakeup_cause) since it is a pointer to the struct, so will never be meaningful to humankind.
  • I have changed formatting for x to %f, and I am now getting x=0.0 or 4.0 (correct);
  • Which leaves id(wakeup_cause).state which I also changed to %f. The first time id(wakeup_cause).state is ‘nan’ ! This suggests that the struct has been created in bootup, but no value has been assigned to it yet. Makes sense to me.
  • It appears that the value is not actually placed in the .state until ESPHome has finished with the sensor - ie after all of the wakeup_cause sensor yaml code is finished. This also makes sense.
  • subsequent calls to wakeup_cause in the current awake period show the previous value … which in this particular case is irrelevant since it will only change with each wake from deep_sleep.
  • It appears that subsequent awake periods may start with nan or the value from the previous awake period. I assume this depends on whether the sensor’s struct was stored in non-volatile RAM or created new for that boot. That’s Ok … it’s why we have globals :wink:
INFO Successful handshake with esp32s3-test @ 192.168.1.124 in 0.125s
[13:27:09][D][api.connection:1801]: Home Assistant 2025.4.2 (192.168.1.98): Connected successfully
[13:27:12][D][wakeup_cause:057]: >>>> X >>>>   esp_sleep_get_wakeup_cause()=4, wakeup_cause.state=nan, num_wake_cycles=3289
[13:27:12][D][main:390]: logger  >>>> C >>>>   wakeup_cause.state=nan, num_wake_cycles=3289, x=4.000000
[13:27:12][D][sensor:093]: 'esp32s3-test Wakeup cause': Sending state 4.00000  with 0 decimals of accuracy
[13:27:39][D][sensor:093]: 'esp32s3-test Wifi signal': Sending state -58.00000 dBm with 0 decimals of accuracy
[13:27:56][D][bh1750.sensor:159]: 'esp32s3-test BH1750 Illuminance': Got illuminance=5.1lx
[13:27:56][D][main:062]: logger  >>>> E >>>>   wakeup_cause.state=4.000000, num_wake_cycles=3289 
[13:27:56][D][sensor:093]: 'esp32s3-test BH1750 Illuminance': Sending state 5.09350 lx with 1 decimals of accuracy
[13:28:06][I][safe_mode:041]: Boot seems successful; resetting boot loop counter
[13:28:06][D][esp32.preferences:114]: Saving 2 preferences to flash...
[13:28:06][D][esp32.preferences:142]: Saving 2 preferences to flash: 0 cached, 2 written, 0 failed
[13:28:06][W][component:239]: Component safe_mode took a long time for an operation (51 ms).
[13:28:06][W][component:240]: Components should block for at most 30 ms.
[13:29:12][D][wakeup_cause:057]: >>>> X >>>>   esp_sleep_get_wakeup_cause()=4, wakeup_cause.state=4.000000, num_wake_cycles=3289
[13:29:12][D][main:390]: logger  >>>> C >>>>   wakeup_cause.state=4.000000, num_wake_cycles=3289, x=4.000000
[13:29:12][D][sensor:093]: 'esp32s3-test Wakeup cause': Sending state 4.00000  with 0 decimals of accuracy
[13:29:39][D][sensor:093]: 'esp32s3-test Wifi signal': Sending state -58.00000 dBm with 0 decimals of accuracy
[13:29:56][D][bh1750.sensor:159]: 'esp32s3-test BH1750 Illuminance': Got illuminance=4.1lx
[13:29:56][D][main:062]: logger  >>>> E >>>>   wakeup_cause.state=4.000000, num_wake_cycles=3289 
[13:29:56][D][sensor:093]: 'esp32s3-test BH1750 Illuminance': Sending state 4.07480 lx with 1 decimals of accuracy
[13:31:12][D][wakeup_cause:057]: >>>> X >>>>   esp_sleep_get_wakeup_cause()=4, wakeup_cause.state=4.000000, num_wake_cycles=3289
[13:31:12][D][main:390]: logger  >>>> C >>>>   wakeup_cause.state=4.000000, num_wake_cycles=3289, x=4.000000
[13:31:12][D][sensor:093]: 'esp32s3-test Wakeup cause': Sending state 4.00000  with 0 decimals of accuracy
[13:31:39][D][sensor:093]: 'esp32s3-test Wifi signal': Sending state -58.00000 dBm with 0 decimals of accuracy
[13:31:56][D][bh1750.sensor:159]: 'esp32s3-test BH1750 Illuminance': Got illuminance=3.8lx
[13:31:56][D][main:062]: logger  >>>> E >>>>   wakeup_cause.state=4.000000, num_wake_cycles=3289 
[13:31:56][D][sensor:093]: 'esp32s3-test BH1750 Illuminance': Sending state 3.84842 lx with 1 decimals of accuracy
[13:32:07][I][deep_sleep:060]: Beginning Deep Sleep
[13:32:07][I][deep_sleep:062]: Sleeping for 180000000us
[13:32:07][D][esp32.preferences:114]: Saving 1 preferences to flash...
[13:32:07][D][esp32.preferences:142]: Saving 1 preferences to flash: 1 cached, 0 written, 0 failed
INFO Processing expected disconnect from ESPHome API for esp32s3-test @ 192.168.1.124
WARNING Disconnected from API

Such a simple thing to have caused me so much grief ! And so much for me hoping to avoid learning the intricacies of C++ to go with the yaml, Python, and JavaScript (for Node Red). Thank you again Daryl