nplan/HomeButtons

v2.0.6 Issues

Closed this issue · 23 comments

Hi,

I have 3 Home Button devices and all of them experience the same issues after upgrading to v2.0.6:

  • Button presses take longer than before (as opposed to the release notes)
  • After each button press, the LED lights up, but then the device display shows "restart"
  • The device restart seem also to happen on each update wake-up

@nplan, could you take a look please?

Best regards
Matthias

nplan commented

Hi Matthias,

could you record the log? Would be really helpful.

You can connect an USB-UART adapter to the "debug" connector on the back of device. Home Buttons TX -> UART adapter RX, GND -> GND. The baud is 115200.

Please also try the v2.0.5. I pulled it due to a bootloader compatibility issue, but your devices have the correct bootloader, so it should work.
homebuttons_fw_v2.0.5.bin.zip

How to connect the debug pins? Soldering seems to be hard since there is the display glued to the other side. Looking at the holes supposed for the debug connectors, it looks like there is some metal at the back (backside of the display?) so just plugging some cables loosely will result in a short circuit I guess. Any suggestions? Could also not find anything in the docs.

nplan commented

It's the back side of display, but it's not metal. Just plug some cables in loosely.

It's the back side of display, but it's not metal. Just plug some cables in loosely.

Will try!

Please also try the v2.0.5. I pulled it due to a bootloader compatibility issue, but your devices have the correct bootloader, so it should work.

Flashed back using OTA to 2.0.5, same restart problem. Flashed back using OTA to 2.0.4, which was previously working without the restart problem, now the restart problem is there, too. Then I used esptool to flash 2.0.6 again, hoping it makes a difference... so, it makes, but it doesn't seem to but up anymore :( Still can get into the flash mode, so if you have an idea on how to get it back working...

Some additional info on that: Seems like my mistake was to do erase_flash before writing the new firmware. I guess I lost whatever was flashed to 0x00000-0x0FFFF.

nplan commented

erase_flash erases all partitions, so only flashing update bin will not work. I'll send you the full image, but it's specific to your device, because some configuration data is stored in the NVS partition. Can you tell me the serial number?

Please try to get log on another device, I'm really interested in what could be wrong if even reverting to v2.0.4 didn't fix the issue.

Serial (I guess) is 2301-112. Thanks for your help!

Debug log: Will try later this day.

nplan commented

Here are the full flash images for both v2.0.4 and v2.0.6.
[deleted]

Yo can flash them with: python -m esptool --port PORT --after no_reset write_flash 0x0 BIN_FILE_PATH

Thanks!!! Device is alive again, but still has the restart issue. Below some debug output:

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
[   783][I][main.cpp:959] setup(): [DEVICE] starting...
[   784][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   784][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   788][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   803][I][main.cpp:270] main_task(): [HW] version: 2.3
[   803][I][hardware.cpp:29] init(): configured for hw version: 2.3
[   836][I][display.cpp:50] begin(): [DISP] begin
[   839][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
[   840][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.820952
[   843][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   850][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   859][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[   883][I][main.cpp:384] main_task(): [DEVICE] wakeup cause: RESET
[  7127][I][display.cpp:69] update(): [DISP] ended.
[  7132][I][main.cpp:53] start_esp_sleep(): [DEVICE] deep sleep... z z z
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x5 (DSLEEP),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
[   514][I][main.cpp:959] setup(): [DEVICE] starting...
[   515][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   515][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   519][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   534][I][main.cpp:270] main_task(): [HW] version: 2.3
[   534][I][hardware.cpp:29] init(): configured for hw version: 2.3
[   567][I][display.cpp:50] begin(): [DISP] begin
[   570][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
[   571][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.819682
[   574][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   581][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   590][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[   614][I][main.cpp:370] main_task(): [DEVICE] wakeup cause: PIN 4
[   616][I][leds.cpp:9] begin(): [LEDS] begin
[   627][I][network.cpp:75] update(): [NET] Using DHCP. Static IP not set or not valid.
[  1414][I][network.cpp:134] update(): [NET] connecting Wi-Fi (normal mode): SSID: ********
[  1417][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 202 - AUTH_FAIL
E (1870) wifi:sta is connecting, return error
[  2201][E][WiFiSTA.cpp:278] begin(): connect failed!
[  6199][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 2 - AUTH_EXPIRE
[  8055][I][network.cpp:154] update(): [NET] Wi-Fi connected (normal mode) in 5854 ms. Saving settings for quick mode...
[  8056][I][network.cpp:155] update(): [NET] IP: 192.168.132.167
[  8067][I][network.cpp:162] update(): [NET] SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, CH: 6
[  8073][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 8 - ASSOC_LEAVE
E (7878) wifi:Set status to INIT
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40007e40  PS      : 0x00060d30  A0      : 0x8011ad4c  A1      : 0x3ffe7250  
A2      : 0x00000000  A3      : 0xfffffffc  A4      : 0x000000ff  A5      : 0x0000ff00  
A6      : 0x00ff0000  A7      : 0xff000000  A8      : 0x00000000  A9      : 0x00000000  
A10     : 0x00000000  A11     : 0x3ffe7452  A12     : 0x00000000  A13     : 0x00000000  
A14     : 0x50000000  A15     : 0x00000000  SAR     : 0x00000004  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000000  LBEG    : 0x00000000  LEND    : 0x00000000  LCOUNT  : 0x40027945  


Backtrace: 0x40007e3d:0x3ffe7250 0x4011ad49:0x3ffe7260 0x4011f942:0x3ffe7570 0x4011f97e:0x3ffe7600 0x4009f56d:0x3ffe7640 0x4009f62a:0x3ffe7680 0x400a8a2d:0x3ffe76d0 0x400a8e0d:0x3ffe77c0




ELF file SHA256: fd9bc9c6ad518919

Rebooting...
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x3 (RTC_SW_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40026e21
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
[   832][I][main.cpp:959] setup(): [DEVICE] starting...
[   832][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   832][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   837][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   851][I][main.cpp:270] main_task(): [HW] version: 2.3
[   852][I][hardware.cpp:29] init(): configured for hw version: 2.3
[   885][I][display.cpp:50] begin(): [DISP] begin
[   888][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
[   889][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.798095
[   891][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   899][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   908][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[   932][I][main.cpp:384] main_task(): [DEVICE] wakeup cause: RESET
[  7175][I][display.cpp:69] update(): [DISP] ended.
[  7181][I][main.cpp:53] start_esp_sleep(): [DEVICE] deep sleep... z z z
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x5 (DSLEEP),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
[   514][I][main.cpp:959] setup(): [DEVICE] starting...
[   515][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   515][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   519][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   533][I][main.cpp:270] main_task(): [HW] version: 2.3
[   534][I][hardware.cpp:29] init(): configured for hw version: 2.3
[   567][I][display.cpp:50] begin(): [DISP] begin
[   570][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
[   571][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.818413
[   574][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   581][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   590][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[   614][I][main.cpp:370] main_task(): [DEVICE] wakeup cause: PIN 4
[   616][I][leds.cpp:9] begin(): [LEDS] begin
[   627][I][network.cpp:75] update(): [NET] Using DHCP. Static IP not set or not valid.
[  1366][I][network.cpp:134] update(): [NET] connecting Wi-Fi (normal mode): SSID: ********
[  1370][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 202 - AUTH_FAIL
E (1053) wifi:sta is connecting, return error
[  1383][E][WiFiSTA.cpp:278] begin(): connect failed!
[  3126][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 202 - AUTH_FAIL
[ 21386][W][network.cpp:168] update(): [NET] Wi-Fi connect failed (normal mode). Retrying...
[ 22625][I][network.cpp:134] update(): [NET] connecting Wi-Fi (normal mode): SSID: ********
[ 22628][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 202 - AUTH_FAIL
[ 25062][I][network.cpp:154] update(): [NET] Wi-Fi connected (normal mode) in 2430 ms. Saving settings for quick mode...
[ 25064][I][network.cpp:155] update(): [NET] IP: 192.168.132.167
[ 25077][I][network.cpp:162] update(): [NET] SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, CH: 6
[ 25081][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 8 - ASSOC_LEAVE
E (24792) wifi:Set status to INIT
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40007e40  PS      : 0x00060230  A0      : 0x8011ad4c  A1      : 0x3ffe7250  
A2      : 0x00000000  A3      : 0xfffffffc  A4      : 0x000000ff  A5      : 0x0000ff00  
A6      : 0x00ff0000  A7      : 0xff000000  A8      : 0x00000000  A9      : 0x00000000  
A10     : 0x00000000  A11     : 0x3ffe7452  A12     : 0x00000000  A13     : 0x00000000  
A14     : 0x50000000  A15     : 0x00000000  SAR     : 0x00000004  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000000  LBEG    : 0x00000000  LEND    : 0x00000000  LCOUNT  : 0x40027945  


Backtrace: 0x40007e3d:0x3ffe7250 0x4011ad49:0x3ffe7260 0x4011f942:0x3ffe7570 0x4011f97e:0x3ffe7600 0x4009f56d:0x3ffe7640 0x4009f62a:0x3ffe7680 0x400a8a2d:0x3ffe76d0 0x400a8e0d:0x3ffe77c0




ELF file SHA256: fd9bc9c6ad518919

Rebooting...
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x3 (RTC_SW_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40026e21
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
[   832][I][main.cpp:959] setup(): [DEVICE] starting...
[   832][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   832][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   837][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   851][I][main.cpp:270] main_task(): [HW] version: 2.3
[   852][I][hardware.cpp:29] init(): configured for hw version: 2.3
[   885][I][display.cpp:50] begin(): [DISP] begin
[   888][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
[   889][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.801905
[   891][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   899][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   908][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[   932][I][main.cpp:384] main_task(): [DEVICE] wakeup cause: RESET

I'm a bit confused about the AUTH_FAIL issue, but a couple of line later it returns the IP address which was assigned by the DHCP server. Does that help?

nplan commented

Thanks for the log!

Have you tried the v2.0.4 again? Is it working?

You've said previously:

Flashed back using OTA to 2.0.5, same restart problem. Flashed back using OTA to 2.0.4, which was previously working without the restart problem, now the restart problem is there, too.

So you can get to web setup and update page without crashing?

It's not obvious to me what's the problem. The backtrace decoder is giving me this:

0x4009f56d: log_printfv at /Users/nejc/.platformio/packages/framework-arduinoespressif32/cores/esp32/esp32-hal-uart.c:543
0x4009f62a: log_printf at /Users/nejc/.platformio/packages/framework-arduinoespressif32/cores/esp32/esp32-hal-uart.c:576
0x400a8a2d: WiFiGenericClass::_eventCallback(arduino_event_t*) at /Users/nejc/.platformio/packages/framework-arduinoespressif32/libraries/WiFi/src/WiFiGeneric.cpp:955
0x400a8e0d: _arduino_event_task at /Users/nejc/.platformio/packages/framework-arduinoespressif32/libraries/WiFi/src/WiFiGeneric.cpp:305

Can you please record another log with v2.0.6_debug build? It produces more detailed output. It's on the release page, you can use OTA to install it.

Thanks for the log!

Thanks for investigating and helping me!

Have you tried the v2.0.4 again? Is it working?

Working in the sense of: I flashed it successfully and the device starts up: yes. Without this restart issue? no.

You've said previously:

Flashed back using OTA to 2.0.5, same restart problem. Flashed back using OTA to 2.0.4, which was previously working without the restart problem, now the restart problem is there, too.

So you can get to web setup and update page without crashing?

Yep.

Can you please record another log with v2.0.6_debug build? It produces more detailed output. It's on the release page, you can use OTA to install it.

Quite interesting. The restart problem does not occur with the debug firmware.

debug log
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
I (327) cache: Instruction cache 	: size 8KB, 4Ways, cache line size 32Byte
I (327) cpu_start: Pro cpu up.
I (347) cpu_start: Pro cpu start user code
I (347) cpu_start: cpu freq: 240000000
I (347) cpu_start: Application information:
I (350) cpu_start: Project name:     HomeButtonsArduino
I (356) cpu_start: App version:      v2.0.5-dirty
I (361) cpu_start: Compile time:     Mar 27 2023 19:36:28
I (367) cpu_start: ELF file SHA256:  6d55101a584e7843...
I (373) cpu_start: ESP-IDF:          4.4.2
I (378) heap_init: Initializing. RAM available for dynamic allocation:
I (385) heap_init: At 3FFD59F0 len 00026610 (153 KiB): DRAM
I (392) heap_init: At 3FFFC000 len 00003A10 (14 KiB): DRAM
I (398) heap_init: At 3FF9E030 len 00001FC0 (7 KiB): RTCRAM
I (405) spi_flash: detected chip: generic
I (409) spi_flash: flash io: dio
[   869][D][esp32-hal-tinyusb.c:673] tinyusb_enable_interface(): Interface CDC enabled
I (421) cpu_start: Starting scheduler on PRO CPU.
[   890][I][main.cpp:959] setup(): [DEVICE] starting...
[   891][D][main.cpp:967] setup(): [DEVICE] main task started.
[   891][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   895][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   901][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   907][D][state.cpp:159] load_all(): [PREF] state load all
[   923][I][main.cpp:270] main_task(): [HW] version: 2.3
[   924][I][hardware.cpp:29] init(): configured for hw version: 2.3
I (514) gpio: GPIO[34]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (523) gpio: GPIO[8]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (532) gpio: GPIO[9]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (571) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (572) gpio: GPIO[36]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (579) gpio: GPIO[37]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (588) gpio: GPIO[35]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[  1008][I][display.cpp:50] begin(): [DISP] begin
I (602) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (611) gpio: GPIO[6]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (620) gpio: GPIO[21]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (629) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (639) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (648) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (657) gpio: GPIO[12]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (666) gpio: GPIO[33]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (676) gpio: GPIO[45]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (686) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[  1105][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
I (701) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[  1121][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.814603
[  1127][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[  1134][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[  1143][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
I (757) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (758) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[  1176][I][main.cpp:384] main_task(): [DEVICE] wakeup cause: RESET
[  1181][D][display.cpp:99] update(): [DISP] update: page: 3; disappearing: 0, msg: RESTART...
[  4373][D][state.cpp:153] save_all(): [PREF] state save all
[  4381][D][display.cpp:99] update(): [DISP] update: page: 1; disappearing: 0, msg: 
[  7464][D][display.cpp:56] end(): [DISP] cmd end
[  7465][I][display.cpp:69] update(): [DISP] ended.
[  7465][D][state.cpp:153] save_all(): [PREF] state save all
[  7474][I][main.cpp:53] start_esp_sleep(): [DEVICE] deep sleep... z z z
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x5 (DSLEEP),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
I (41) cache: Instruction cache 	: size 8KB, 4Ways, cache line size 32Byte
I (41) cpu_start: Pro cpu up.
I (53) cpu_start: Pro cpu start user code
I (53) cpu_start: cpu freq: 240000000
I (53) cpu_start: Application information:
I (57) cpu_start: Project name:     HomeButtonsArduino
I (63) cpu_start: App version:      v2.0.5-dirty
I (68) cpu_start: Compile time:     Mar 27 2023 19:36:28
I (74) cpu_start: ELF file SHA256:  6d55101a584e7843...
I (80) cpu_start: ESP-IDF:          4.4.2
I (85) heap_init: Initializing. RAM available for dynamic allocation:
I (92) heap_init: At 3FFD59F0 len 00026610 (153 KiB): DRAM
I (98) heap_init: At 3FFFC000 len 00003A10 (14 KiB): DRAM
I (104) heap_init: At 3FF9E030 len 00001FC0 (7 KiB): RTCRAM
I (111) spi_flash: detected chip: generic
I (115) spi_flash: flash io: dio
[   574][D][esp32-hal-tinyusb.c:673] tinyusb_enable_interface(): Interface CDC enabled
I (128) cpu_start: Starting scheduler on PRO CPU.
[   595][I][main.cpp:959] setup(): [DEVICE] starting...
[   596][D][main.cpp:967] setup(): [DEVICE] main task started.
[   596][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   600][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   606][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   612][D][state.cpp:159] load_all(): [PREF] state load all
[   628][I][main.cpp:270] main_task(): [HW] version: 2.3
[   629][I][hardware.cpp:29] init(): configured for hw version: 2.3
I (221) gpio: GPIO[34]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (230) gpio: GPIO[8]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (239) gpio: GPIO[9]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (278) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (279) gpio: GPIO[36]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (286) gpio: GPIO[37]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (295) gpio: GPIO[35]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   713][I][display.cpp:50] begin(): [DISP] begin
I (309) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (318) gpio: GPIO[6]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (327) gpio: GPIO[21]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (336) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (346) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (355) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (364) gpio: GPIO[12]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (373) gpio: GPIO[33]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (383) gpio: GPIO[45]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (393) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   810][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
I (408) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   826][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.812063
[   832][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   839][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   848][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
I (464) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (465) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   881][I][main.cpp:370] main_task(): [DEVICE] wakeup cause: PIN 4
[   887][D][buttons.cpp:16] begin(): [BTN] id 1 begun
[   891][D][buttons.cpp:16] begin(): [BTN] id 2 begun
[   896][D][buttons.cpp:16] begin(): [BTN] id 3 begun
[   900][D][buttons.cpp:16] begin(): [BTN] id 4 begun
[   905][D][buttons.cpp:16] begin(): [BTN] id 5 begun
[   910][D][buttons.cpp:16] begin(): [BTN] id 6 begun
[   915][D][main.cpp:181] start_button_task(): [DEVICE] button task started.
[   921][I][leds.cpp:9] begin(): [LEDS] begin
[   925][D][main.cpp:238] start_leds_task(): [DEVICE] leds task started.
[   932][D][main.cpp:200] start_display_task(): [DEVICE] display task started.
[   939][D][main.cpp:219] start_network_task(): [DEVICE] network task started.
[   946][D][network.cpp:31] connect(): [NET] cmd connect
[   955][I][network.cpp:75] update(): [NET] Using DHCP. Static IP not set or not valid.
I (554) wifi:wifi driver task: 3ffebcd0, prio:23, stack:6656, core=0
I (557) system_api: Base MAC address is not set
I (561) system_api: read default base MAC address from EFUSE
I (574) wifi:wifi firmware version: 8cb87ff
I (575) wifi:wifi certification version: v7.0
I (576) wifi:config NVS flash: enabled
I (579) wifi:config nano formating: disabled
I (583) wifi:Init data frame dynamic rx buffer num: 12
I (588) wifi:Init management frame dynamic rx buffer num: 12
I (593) wifi:Init management short buffer num: 32
I (598) wifi:Init dynamic tx buffer num: 12
I (602) wifi:Init static rx buffer size: 1600
I (606) wifi:Init static rx buffer num: 8
I (610) wifi:Init dynamic rx buffer num: 12
I (614) wifi_init: rx ba win: 8
I (617) wifi_init: tcpip mbox: 32
I (621) wifi_init: udp mbox: 6
I (625) wifi_init: tcp mbox: 6
I (629) wifi_init: tcp tx win: 5744
I (633) wifi_init: tcp rx win: 5744
I (637) wifi_init: tcp mss: 1440
I (641) wifi_init: WiFi IRAM OP enabled
I (646) wifi_init: WiFi RX IRAM OP enabled
[  1059][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 0 - WIFI_READY
I (659) phy_init: phy_version 2300,d67cf06,Feb 10 2022,10:03:07
I (670) wifi:mode : sta (58:cf:79:b3:a8:72)
I (671) wifi:enable tsf
[  1080][V][WiFiGeneric.cpp:340] _arduino_event_cb(): STA Started
[  1085][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 2 - STA_START
I (683) wifi:Set ps type: 0

[  1105][D][network.cpp:45] update(): [NET] state machine changed to: 2
[  1107][V][WiFiGeneric.cpp:97] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
[  1421][D][buttons.cpp:103] update(): [BTN] id 2 press: SINGLE
[  1425][D][main.cpp:527] main_task(): [DEVICE] BTN_2 pressed - state SINGLE
[  1425][D][leds.cpp:30] blink(): [LEDS] blink - led: 2, blinks: 1, bri: 225, hold: 1
[  1615][I][network.cpp:134] update(): [NET] connecting Wi-Fi (normal mode): SSID: ********
[  1626][V][WiFiGeneric.cpp:97] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
I (1227) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
I (1229) wifi:state: init -> auth (b0)
[  2455][D][network.cpp:45] update(): [NET] state machine changed to: 3
I (3279) wifi:state: auth -> assoc (0)
I (3288) wifi:state: assoc -> run (10)
I (3302) wifi:connected with ********, aid = 1, channel 1, BW20, bssid = xx:yy:zz:aa:bb:cc
I (3303) wifi:security: WPA3-SAE, phy: bgn, rssi: -83
I (3307) wifi:pm start, type: 0

[  3717][V][WiFiGeneric.cpp:355] _arduino_event_cb(): STA Connected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Channel: 1, Auth: WPA2_WPA3_PSK
[  3729][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
W (3363) wifi:<ba-add>idx:0 (ifx:0, xx:yy:zz:aa:bb:cc), tid:6, ssn:1, winSize:64
[  3804][V][WiFiGeneric.cpp:369] _arduino_event_cb(): STA Got New IP:192.168.132.167
I (3396) esp_netif_handlers: sta ip: 192.168.132.167, mask: 255.255.255.0, gw: 192.168.132.1
[  3810][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
[  3817][D][WiFiGeneric.cpp:996] _eventCallback(): STA IP: 192.168.132.167, MASK: 255.255.255.0, GW: 192.168.132.1
[  3828][I][network.cpp:154] update(): [NET] Wi-Fi connected (normal mode) in 2199 ms. Saving settings for quick mode...
[  3838][I][network.cpp:155] update(): [NET] IP: 192.168.132.167
[  3844][D][state.cpp:153] save_all(): [PREF] state save all
[  3855][I][network.cpp:162] update(): [NET] SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, CH: 1
I (3449) wifi:state: run -> init (0)
I (3454) wifi:pm stop, total sleep time: 0 us / 146116 us

W (3457) wifi:<ba-del>idx
I (3460) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
[  3875][V][WiFiGeneric.cpp:362] _arduino_event_cb(): STA Disconnected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Reason: 8
[  3885][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  3892][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 8 - ASSOC_LEAVE
[  3979][V][WiFiGeneric.cpp:97] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
I (3579) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
I (3581) wifi:state: init -> auth (b0)
[  3992][D][network.cpp:45] update(): [NET] state machine changed to: 4
I (3587) wifi:state: auth -> assoc (0)
E (3599) wifi:Set status to INIT
I (3600) wifi:state: assoc -> init (3500)
I (3601) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
[  4012][V][WiFiGeneric.cpp:362] _arduino_event_cb(): STA Disconnected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Reason: 53
[  4022][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  4030][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 53 - ETH_GOT_IP
[  4036][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi Reconnect Running
[  4052][V][WiFiGeneric.cpp:97] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
I (3654) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
I (3655) wifi:state: init -> auth (b0)
I (5689) wifi:state: auth -> assoc (0)
I (5699) wifi:state: assoc -> run (10)
I (5717) wifi:connected with ********, aid = 1, channel 1, BW20, bssid = xx:yy:zz:aa:bb:cc
I (5718) wifi:security: WPA3-SAE, phy: bgn, rssi: -83
I (5721) wifi:pm start, type: 0

[  6132][V][WiFiGeneric.cpp:355] _arduino_event_cb(): STA Connected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Channel: 1, Auth: WPA2_WPA3_PSK
[  6144][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
W (5790) wifi:<ba-add>idx:0 (ifx:0, xx:yy:zz:aa:bb:cc), tid:6, ssn:0, winSize:64
I (5816) wifi:AP's beacon interval = 102400 us, DTIM period = 1
[  6231][V][WiFiGeneric.cpp:369] _arduino_event_cb(): STA Got Same IP:192.168.132.167
I (5823) esp_netif_handlers: sta ip: 192.168.132.167, mask: 255.255.255.0, gw: 192.168.132.1
[  6239][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
[  6246][D][WiFiGeneric.cpp:996] _eventCallback(): STA IP: 192.168.132.167, MASK: 255.255.255.0, GW: 192.168.132.1
[  6257][I][network.cpp:188] update(): [NET] Wi-Fi connected, quick mode settings saved.
[  6264][I][network.cpp:189] update(): [NET] IP: 192.168.132.167
[  6269][I][network.cpp:191] update(): [NET] connecting MQTT....
W (5880) wifi:<ba-add>idx:1 (ifx:0, xx:yy:zz:aa:bb:cc), tid:0, ssn:1, winSize:64
[  6314][D][network.cpp:45] update(): [NET] state machine changed to: 5
[  6315][I][network.cpp:211] update(): [NET] MQTT connected in 40 ms.
[  6316][I][network.cpp:212] update(): [NET] network connected in 5370 ms.
[  6336][D][network.cpp:310] subscribe(): [NET] sub to: homebuttons/Home Buttons B9E8F8/cmd/# SUCCESS.
[  6440][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/awake_mode/available SUCCESS.
[  6443][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/sensor_interval SUCCESS.
[  6451][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_1_label SUCCESS.
[  6460][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_2_label SUCCESS.
[  6470][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_3_label SUCCESS.
[  6479][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_4_label SUCCESS.
[  6491][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_5_label SUCCESS.
[  6500][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_6_label SUCCESS.
[  6509][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/awake_mode SUCCESS.
[  6515][I][WiFiClient.cpp:549] connected(): Unexpected: RES: 0, ERR: 0
[  6528][D][network.cpp:45] update(): [NET] state machine changed to: 6
[  6538][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/button_2 SUCCESS.
[  6539][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[  6545][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
I (6162) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (6164) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[  6593][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/temperature SUCCESS.
[  6607][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/humidity SUCCESS.
[  6623][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/battery SUCCESS.
[  6633][D][buttons.cpp:30] end(): [BTN] id 1 ended
[  6634][D][buttons.cpp:30] end(): [BTN] id 2 ended
[  6636][D][buttons.cpp:30] end(): [BTN] id 3 ended
[  6637][D][buttons.cpp:30] end(): [BTN] id 4 ended
[  6642][D][buttons.cpp:30] end(): [BTN] id 5 ended
[  6647][D][buttons.cpp:30] end(): [BTN] id 6 ended
[  6651][D][leds.cpp:14] end(): [LEDS] cmd end
[  6655][D][network.cpp:37] disconnect(): [NET] cmd disconnect
[  6661][I][network.cpp:242] update(): [NET] disconnecting...
[  6672][I][leds.cpp:80] update(): [LEDS] ended
[  6676][D][network.cpp:45] update(): [NET] state machine changed to: 7
[  7690][D][network.cpp:45] update(): [NET] state machine changed to: 8
I (7283) wifi:state: run -> init (0)
I (7285) wifi:pm stop, total sleep time: 0 us / 1562798 us

W (7286) wifi:<ba-del>idx
W (7288) wifi:<ba-del>idx
I (7291) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
[  7706][V][WiFiGeneric.cpp:362] _arduino_event_cb(): STA Disconnected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Reason: 8
[  7716][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  7724][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 8 - ASSOC_LEAVE
[  7733][V][WiFiGeneric.cpp:343] _arduino_event_cb(): STA Stopped
[  7736][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 3 - STA_STOP
I (7335) wifi:flush txq
I (7337) wifi:stop sw txq
I (7340) wifi:lmac stop hw txq
I (7343) wifi:Deinit lldesc rx mblock:8
[  7855][I][network.cpp:276] update(): [NET] disconnected.
[  7864][D][display.cpp:56] end(): [DISP] cmd end
[  7865][D][network.cpp:45] update(): [NET] state machine changed to: 0
[  7904][I][display.cpp:69] update(): [DISP] ended.
[  7906][D][main.cpp:669] main_task(): [DEVICE] free stack: btns 684, disp 3652, net 7216, leds 736, main 17604, num tasks 11
[  7909][D][main.cpp:674] main_task(): [DEVICE] free heap: esp 93124, esp min 48604, rtos 93124
[  7917][D][state.cpp:153] save_all(): [PREF] state save all
[  7931][I][main.cpp:53] start_esp_sleep(): [DEVICE] deep sleep... z z z
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x5 (DSLEEP),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
I (41) cache: Instruction cache 	: size 8KB, 4Ways, cache line size 32Byte
I (41) cpu_start: Pro cpu up.
I (53) cpu_start: Pro cpu start user code
I (53) cpu_start: cpu freq: 240000000
I (53) cpu_start: Application information:
I (57) cpu_start: Project name:     HomeButtonsArduino
I (63) cpu_start: App version:      v2.0.5-dirty
I (68) cpu_start: Compile time:     Mar 27 2023 19:36:28
I (74) cpu_start: ELF file SHA256:  6d55101a584e7843...
I (80) cpu_start: ESP-IDF:          4.4.2
I (85) heap_init: Initializing. RAM available for dynamic allocation:
I (92) heap_init: At 3FFD59F0 len 00026610 (153 KiB): DRAM
I (98) heap_init: At 3FFFC000 len 00003A10 (14 KiB): DRAM
I (104) heap_init: At 3FF9E030 len 00001FC0 (7 KiB): RTCRAM
I (111) spi_flash: detected chip: generic
I (115) spi_flash: flash io: dio
[   574][D][esp32-hal-tinyusb.c:673] tinyusb_enable_interface(): Interface CDC enabled
I (128) cpu_start: Starting scheduler on PRO CPU.
[   595][I][main.cpp:959] setup(): [DEVICE] starting...
[   596][D][main.cpp:967] setup(): [DEVICE] main task started.
[   596][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   600][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   606][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   612][D][state.cpp:159] load_all(): [PREF] state load all
[   628][I][main.cpp:270] main_task(): [HW] version: 2.3
[   629][I][hardware.cpp:29] init(): configured for hw version: 2.3
I (221) gpio: GPIO[34]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (232) gpio: GPIO[8]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (241) gpio: GPIO[9]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (280) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (281) gpio: GPIO[36]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (288) gpio: GPIO[37]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (297) gpio: GPIO[35]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   715][I][display.cpp:50] begin(): [DISP] begin
I (311) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (320) gpio: GPIO[6]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (329) gpio: GPIO[21]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (338) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (348) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (357) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (366) gpio: GPIO[12]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (375) gpio: GPIO[33]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (385) gpio: GPIO[45]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (395) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   812][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
I (410) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   828][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.822222
[   834][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   841][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   850][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
I (466) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (467) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   883][I][main.cpp:370] main_task(): [DEVICE] wakeup cause: PIN 14
[   889][D][buttons.cpp:16] begin(): [BTN] id 1 begun
[   893][D][buttons.cpp:16] begin(): [BTN] id 2 begun
[   898][D][buttons.cpp:16] begin(): [BTN] id 3 begun
[   902][D][buttons.cpp:16] begin(): [BTN] id 4 begun
[   907][D][buttons.cpp:16] begin(): [BTN] id 5 begun
[   912][D][buttons.cpp:16] begin(): [BTN] id 6 begun
[   917][D][main.cpp:181] start_button_task(): [DEVICE] button task started.
[   924][I][leds.cpp:9] begin(): [LEDS] begin
[   927][D][main.cpp:238] start_leds_task(): [DEVICE] leds task started.
[   934][D][main.cpp:200] start_display_task(): [DEVICE] display task started.
[   941][D][main.cpp:219] start_network_task(): [DEVICE] network task started.
[   948][D][network.cpp:31] connect(): [NET] cmd connect
[   958][I][network.cpp:75] update(): [NET] Using DHCP. Static IP not set or not valid.
I (556) wifi:wifi driver task: 3ffebcd0, prio:23, stack:6656, core=0
I (559) system_api: Base MAC address is not set
I (564) system_api: read default base MAC address from EFUSE
I (576) wifi:wifi firmware version: 8cb87ff
I (577) wifi:wifi certification version: v7.0
I (578) wifi:config NVS flash: enabled
I (581) wifi:config nano formating: disabled
I (586) wifi:Init data frame dynamic rx buffer num: 12
I (590) wifi:Init management frame dynamic rx buffer num: 12
I (596) wifi:Init management short buffer num: 32
I (600) wifi:Init dynamic tx buffer num: 12
I (604) wifi:Init static rx buffer size: 1600
I (608) wifi:Init static rx buffer num: 8
I (612) wifi:Init dynamic rx buffer num: 12
I (616) wifi_init: rx ba win: 8
I (619) wifi_init: tcpip mbox: 32
I (623) wifi_init: udp mbox: 6
I (627) wifi_init: tcp mbox: 6
I (631) wifi_init: tcp tx win: 5744
I (635) wifi_init: tcp rx win: 5744
I (639) wifi_init: tcp mss: 1440
I (643) wifi_init: WiFi IRAM OP enabled
I (648) wifi_init: WiFi RX IRAM OP enabled
[  1061][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 0 - WIFI_READY
I (661) phy_init: phy_version 2300,d67cf06,Feb 10 2022,10:03:07
I (672) wifi:mode : sta (58:cf:79:b3:a8:72)
I (673) wifi:enable tsf
[  1083][V][WiFiGeneric.cpp:340] _arduino_event_cb(): STA Started
[  1087][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 2 - STA_START
I (685) wifi:Set ps type: 0

[  1097][I][network.cpp:82] update(): [NET] connecting Wi-Fi (quick mode)...
[  1104][V][WiFiGeneric.cpp:97] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
I (714) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
I (715) wifi:state: init -> auth (b0)
[  1903][D][buttons.cpp:103] update(): [BTN] id 4 press: TRIPLE
[  1933][D][network.cpp:45] update(): [NET] state machine changed to: 1
[  1935][D][main.cpp:527] main_task(): [DEVICE] BTN_4 pressed - state TRIPLE
[  1936][D][leds.cpp:30] blink(): [LEDS] blink - led: 4, blinks: 3, bri: 225, hold: 1
I (2749) wifi:state: auth -> assoc (0)
I (2756) wifi:state: assoc -> run (10)
I (2775) wifi:connected with ********, aid = 1, channel 1, BW20, bssid = xx:yy:zz:aa:bb:cc
I (2776) wifi:security: WPA3-SAE, phy: bgn, rssi: -85
I (2779) wifi:pm start, type: 0

[  3190][V][WiFiGeneric.cpp:355] _arduino_event_cb(): STA Connected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Channel: 1, Auth: WPA2_WPA3_PSK
[  3202][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
W (2845) wifi:<ba-add>idx:0 (ifx:0, xx:yy:zz:aa:bb:cc), tid:6, ssn:1, winSize:64
I (2867) wifi:AP's beacon interval = 102400 us, DTIM period = 1
[  3282][V][WiFiGeneric.cpp:369] _arduino_event_cb(): STA Got New IP:192.168.132.167
I (2875) esp_netif_handlers: sta ip: 192.168.132.167, mask: 255.255.255.0, gw: 192.168.132.1
[  3290][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
[  3297][D][WiFiGeneric.cpp:996] _eventCallback(): STA IP: 192.168.132.167, MASK: 255.255.255.0, GW: 192.168.132.1
[  3308][I][network.cpp:102] update(): [NET] Wi-Fi connected (quick mode) in 2211 ms.
[  3314][I][network.cpp:103] update(): [NET] IP: 192.168.132.167
[  3320][D][state.cpp:153] save_all(): [PREF] state save all
[  3332][I][network.cpp:109] update(): [NET] SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, CH: 1
[  3334][I][network.cpp:111] update(): [NET] connecting MQTT....
W (2948) wifi:<ba-add>idx:1 (ifx:0, xx:yy:zz:aa:bb:cc), tid:0, ssn:2, winSize:64
[  3379][D][network.cpp:45] update(): [NET] state machine changed to: 5
[  3380][I][network.cpp:211] update(): [NET] MQTT connected in 41 ms.
[  3381][I][network.cpp:212] update(): [NET] network connected in 2433 ms.
[  3401][D][network.cpp:310] subscribe(): [NET] sub to: homebuttons/Home Buttons B9E8F8/cmd/# SUCCESS.
[  3505][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/awake_mode/available SUCCESS.
[  3508][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/sensor_interval SUCCESS.
[  3516][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_1_label SUCCESS.
[  3525][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_2_label SUCCESS.
[  3535][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_3_label SUCCESS.
[  3544][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_4_label SUCCESS.
[  3556][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_5_label SUCCESS.
[  3565][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_6_label SUCCESS.
[  3575][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/awake_mode SUCCESS.
[  3581][I][WiFiClient.cpp:549] connected(): Unexpected: RES: 0, ERR: 0
[  3593][D][network.cpp:45] update(): [NET] state machine changed to: 6
[  3603][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/button_4_triple SUCCESS.
[  3604][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[  3611][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
I (3227) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (3229) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[  3658][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/temperature SUCCESS.
[  3672][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/humidity SUCCESS.
[  3687][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/battery SUCCESS.
[  3697][D][buttons.cpp:30] end(): [BTN] id 1 ended
[  3698][D][buttons.cpp:30] end(): [BTN] id 2 ended
[  3698][D][buttons.cpp:30] end(): [BTN] id 3 ended
[  3701][D][buttons.cpp:30] end(): [BTN] id 4 ended
[  3706][D][buttons.cpp:30] end(): [BTN] id 5 ended
[  3711][D][buttons.cpp:30] end(): [BTN] id 6 ended
[  3715][D][leds.cpp:14] end(): [LEDS] cmd end
[  3719][D][network.cpp:37] disconnect(): [NET] cmd disconnect
[  3726][I][network.cpp:242] update(): [NET] disconnecting...
[  3735][I][leds.cpp:80] update(): [LEDS] ended
[  3740][D][network.cpp:45] update(): [NET] state machine changed to: 7
[  4762][D][network.cpp:45] update(): [NET] state machine changed to: 8
I (4355) wifi:state: run -> init (0)
I (4357) wifi:pm stop, total sleep time: 0 us / 1576963 us

W (4358) wifi:<ba-del>idx
W (4360) wifi:<ba-del>idx
I (4363) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
[  4778][V][WiFiGeneric.cpp:362] _arduino_event_cb(): STA Disconnected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Reason: 8
[  4788][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  4796][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 8 - ASSOC_LEAVE
[  4805][V][WiFiGeneric.cpp:343] _arduino_event_cb(): STA Stopped
[  4808][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 3 - STA_STOP
I (4407) wifi:flush txq
I (4409) wifi:stop sw txq
I (4412) wifi:lmac stop hw txq
I (4415) wifi:Deinit lldesc rx mblock:8
[  4927][I][network.cpp:276] update(): [NET] disconnected.
[  4936][D][display.cpp:56] end(): [DISP] cmd end
[  4937][D][network.cpp:45] update(): [NET] state machine changed to: 0
[  4976][I][display.cpp:69] update(): [DISP] ended.
[  4978][D][main.cpp:669] main_task(): [DEVICE] free stack: btns 684, disp 3652, net 7216, leds 736, main 17604, num tasks 11
[  4981][D][main.cpp:674] main_task(): [DEVICE] free heap: esp 92848, esp min 48768, rtos 92848
[  4990][D][state.cpp:153] save_all(): [PREF] state save all
[  5001][I][main.cpp:53] start_esp_sleep(): [DEVICE] deep sleep... z z z
ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x5 (DSLEEP),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3ffe6100,len:0x11b0
load:0x4004c000,len:0x8b4
load:0x40050000,len:0x2d88
entry 0x4004c198
I (41) cache: Instruction cache 	: size 8KB, 4Ways, cache line size 32Byte
I (41) cpu_start: Pro cpu up.
I (53) cpu_start: Pro cpu start user code
I (53) cpu_start: cpu freq: 240000000
I (53) cpu_start: Application information:
I (57) cpu_start: Project name:     HomeButtonsArduino
I (63) cpu_start: App version:      v2.0.5-dirty
I (68) cpu_start: Compile time:     Mar 27 2023 19:36:28
I (74) cpu_start: ELF file SHA256:  6d55101a584e7843...
I (80) cpu_start: ESP-IDF:          4.4.2
I (85) heap_init: Initializing. RAM available for dynamic allocation:
I (92) heap_init: At 3FFD59F0 len 00026610 (153 KiB): DRAM
I (98) heap_init: At 3FFFC000 len 00003A10 (14 KiB): DRAM
I (104) heap_init: At 3FF9E030 len 00001FC0 (7 KiB): RTCRAM
I (111) spi_flash: detected chip: generic
I (115) spi_flash: flash io: dio
[   574][D][esp32-hal-tinyusb.c:673] tinyusb_enable_interface(): Interface CDC enabled
I (128) cpu_start: Starting scheduler on PRO CPU.
[   595][I][main.cpp:959] setup(): [DEVICE] starting...
[   596][D][main.cpp:967] setup(): [DEVICE] main task started.
[   596][I][main.cpp:249] main_task(): [DEVICE] woke up.
[   600][I][main.cpp:250] main_task(): [DEVICE] cpu freq: 240 MHz
[   606][I][main.cpp:251] main_task(): [DEVICE] SW version: v2.0.6
[   612][D][state.cpp:159] load_all(): [PREF] state load all
[   628][I][main.cpp:270] main_task(): [HW] version: 2.3
[   629][I][hardware.cpp:29] init(): configured for hw version: 2.3
I (221) gpio: GPIO[34]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (232) gpio: GPIO[8]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (241) gpio: GPIO[9]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (280) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (281) gpio: GPIO[36]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (288) gpio: GPIO[37]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (297) gpio: GPIO[35]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   715][I][display.cpp:50] begin(): [DISP] begin
I (311) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (320) gpio: GPIO[6]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (329) gpio: GPIO[21]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (338) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (348) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (357) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (366) gpio: GPIO[12]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (375) gpio: GPIO[33]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (385) gpio: GPIO[45]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (395) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   812][I][main.cpp:296] main_task(): [DEVICE] batt present: 1, DC connected: 0
I (410) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   828][I][main.cpp:300] main_task(): [DEVICE] batt volts: 3.819682
[   834][I][main.cpp:355] main_task(): [DEVICE] usr awake mode: 0, awake mode: 0
[   841][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=10 scl=11 freq=100000
[   850][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
I (466) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (467) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[   883][I][main.cpp:370] main_task(): [DEVICE] wakeup cause: PIN 1
[   889][D][buttons.cpp:16] begin(): [BTN] id 1 begun
[   893][D][buttons.cpp:16] begin(): [BTN] id 2 begun
[   898][D][buttons.cpp:16] begin(): [BTN] id 3 begun
[   902][D][buttons.cpp:16] begin(): [BTN] id 4 begun
[   907][D][buttons.cpp:16] begin(): [BTN] id 5 begun
[   912][D][buttons.cpp:16] begin(): [BTN] id 6 begun
[   917][D][main.cpp:181] start_button_task(): [DEVICE] button task started.
[   923][I][leds.cpp:9] begin(): [LEDS] begin
[   927][D][main.cpp:238] start_leds_task(): [DEVICE] leds task started.
[   934][D][main.cpp:200] start_display_task(): [DEVICE] display task started.
[   941][D][main.cpp:219] start_network_task(): [DEVICE] network task started.
[   948][D][network.cpp:31] connect(): [NET] cmd connect
[   957][I][network.cpp:75] update(): [NET] Using DHCP. Static IP not set or not valid.
I (556) wifi:wifi driver task: 3ffebcd0, prio:23, stack:6656, core=0
I (559) system_api: Base MAC address is not set
I (563) system_api: read default base MAC address from EFUSE
I (576) wifi:wifi firmware version: 8cb87ff
I (577) wifi:wifi certification version: v7.0
I (578) wifi:config NVS flash: enabled
I (581) wifi:config nano formating: disabled
I (585) wifi:Init data frame dynamic rx buffer num: 12
I (590) wifi:Init management frame dynamic rx buffer num: 12
I (595) wifi:Init management short buffer num: 32
I (600) wifi:Init dynamic tx buffer num: 12
I (604) wifi:Init static rx buffer size: 1600
I (608) wifi:Init static rx buffer num: 8
I (612) wifi:Init dynamic rx buffer num: 12
I (616) wifi_init: rx ba win: 8
I (619) wifi_init: tcpip mbox: 32
I (623) wifi_init: udp mbox: 6
I (627) wifi_init: tcp mbox: 6
I (631) wifi_init: tcp tx win: 5744
I (635) wifi_init: tcp rx win: 5744
I (639) wifi_init: tcp mss: 1440
I (643) wifi_init: WiFi IRAM OP enabled
I (648) wifi_init: WiFi RX IRAM OP enabled
[  1061][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 0 - WIFI_READY
I (661) phy_init: phy_version 2300,d67cf06,Feb 10 2022,10:03:07
I (672) wifi:mode : sta (58:cf:79:b3:a8:72)
I (673) wifi:enable tsf
[  1082][V][WiFiGeneric.cpp:340] _arduino_event_cb(): STA Started
[  1087][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 2 - STA_START
I (685) wifi:Set ps type: 0

[  1097][I][network.cpp:82] update(): [NET] connecting Wi-Fi (quick mode)...
[  1104][V][WiFiGeneric.cpp:97] set_esp_interface_ip(): Configuring Station static IP: 0.0.0.0, MASK: 0.0.0.0, GW: 0.0.0.0
I (713) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
I (715) wifi:state: init -> auth (b0)
[  1423][D][buttons.cpp:103] update(): [BTN] id 6 press: SINGLE
[  1931][D][network.cpp:45] update(): [NET] state machine changed to: 1
[  1931][D][main.cpp:527] main_task(): [DEVICE] BTN_6 pressed - state SINGLE
[  1933][D][leds.cpp:30] blink(): [LEDS] blink - led: 6, blinks: 1, bri: 225, hold: 1
I (2744) wifi:state: auth -> assoc (0)
I (2758) wifi:state: assoc -> run (10)
I (2774) wifi:connected with ********, aid = 1, channel 1, BW20, bssid = xx:yy:zz:aa:bb:cc
I (2774) wifi:security: WPA3-SAE, phy: bgn, rssi: -82
I (2777) wifi:pm start, type: 0

[  3188][V][WiFiGeneric.cpp:355] _arduino_event_cb(): STA Connected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Channel: 1, Auth: WPA2_WPA3_PSK
[  3200][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
W (2841) wifi:<ba-add>idx:0 (ifx:0, xx:yy:zz:aa:bb:cc), tid:6, ssn:1, winSize:64
I (2858) wifi:AP's beacon interval = 102400 us, DTIM period = 1
[  3289][V][WiFiGeneric.cpp:369] _arduino_event_cb(): STA Got New IP:192.168.132.167
I (2882) esp_netif_handlers: sta ip: 192.168.132.167, mask: 255.255.255.0, gw: 192.168.132.1
[  3295][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
[  3302][D][WiFiGeneric.cpp:996] _eventCallback(): STA IP: 192.168.132.167, MASK: 255.255.255.0, GW: 192.168.132.1
[  3314][I][network.cpp:102] update(): [NET] Wi-Fi connected (quick mode) in 2217 ms.
[  3320][I][network.cpp:103] update(): [NET] IP: 192.168.132.167
[  3326][D][state.cpp:153] save_all(): [PREF] state save all
[  3338][I][network.cpp:109] update(): [NET] SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, CH: 1
[  3339][I][network.cpp:111] update(): [NET] connecting MQTT....
W (2953) wifi:<ba-add>idx:1 (ifx:0, xx:yy:zz:aa:bb:cc), tid:0, ssn:1, winSize:64
[  3392][D][network.cpp:45] update(): [NET] state machine changed to: 5
[  3393][I][network.cpp:211] update(): [NET] MQTT connected in 48 ms.
[  3394][I][network.cpp:212] update(): [NET] network connected in 2446 ms.
[  3414][D][network.cpp:310] subscribe(): [NET] sub to: homebuttons/Home Buttons B9E8F8/cmd/# SUCCESS.
[  3518][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/awake_mode/available SUCCESS.
[  3521][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/sensor_interval SUCCESS.
[  3529][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_1_label SUCCESS.
[  3538][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_2_label SUCCESS.
[  3548][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_3_label SUCCESS.
[  3557][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_4_label SUCCESS.
[  3567][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_5_label SUCCESS.
[  3581][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/btn_6_label SUCCESS.
[  3587][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/awake_mode SUCCESS.
[  3594][I][WiFiClient.cpp:549] connected(): Unexpected: RES: 0, ERR: 0
[  3604][D][network.cpp:45] update(): [NET] state machine changed to: 6
[  3612][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/button_6 SUCCESS.
[  3615][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[  3621][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
I (3238) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (3240) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
[  3670][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/temperature SUCCESS.
[  3684][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/humidity SUCCESS.
[  3698][D][network.cpp:294] publish(): [NET] pub to: homebuttons/Home Buttons B9E8F8/battery SUCCESS.
[  3708][D][buttons.cpp:30] end(): [BTN] id 1 ended
[  3709][D][buttons.cpp:30] end(): [BTN] id 2 ended
[  3709][D][buttons.cpp:30] end(): [BTN] id 3 ended
[  3712][D][buttons.cpp:30] end(): [BTN] id 4 ended
[  3717][D][buttons.cpp:30] end(): [BTN] id 5 ended
[  3722][D][buttons.cpp:30] end(): [BTN] id 6 ended
[  3726][D][leds.cpp:14] end(): [LEDS] cmd end
[  3730][D][network.cpp:37] di[  3733][I][leds.cpp:80] update(): [LEDS] ended
[  3737][I][network.cpp:242] update(): [NET] disconnecting...
sconnect(): [NET] cmd disconnect
[  3752][D][network.cpp:45] update(): [NET] state machine changed to: 7
[  4774][D][network.cpp:45] update(): [NET] state machine changed to: 8
I (4367) wifi:state: run -> init (0)
I (4369) wifi:pm stop, total sleep time: 0 us / 1590106 us

W (4370) wifi:<ba-del>idx
W (4372) wifi:<ba-del>idx
I (4375) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:6
[  4790][V][WiFiGeneric.cpp:362] _arduino_event_cb(): STA Disconnected: SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, Reason: 8
[  4800][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[  4808][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 8 - ASSOC_LEAVE
[  4817][V][WiFiGeneric.cpp:343] _arduino_event_cb(): STA Stopped
[  4820][D][WiFiGeneric.cpp:931] _eventCallback(): Arduino Event: 3 - STA_STOP
I (4419) wifi:flush txq
I (4421) wifi:stop sw txq
I (4424) wifi:lmac stop hw txq
I (4427) wifi:Deinit lldesc rx mblock:8
[  4939][I][network.cpp:276] update(): [NET] disconnected.
[  4948][D][display.cpp:56] end(): [DISP] cmd end
[  4949][D][network.cpp:45] update(): [NET] state machine changed to: 0
[  4988][I][display.cpp:69] update(): [DISP] ended.
[  4990][D][main.cpp:669] main_task(): [DEVICE] free stack: btns 684, disp 3652, net 7216, leds 736, main 17604, num tasks 11
[  4993][D][main.cpp:674] main_task(): [DEVICE] free heap: esp 92872, esp min 50472, rtos 92872
[  5002][D][state.cpp:153] save_all(): [PREF] state save all
[  5013][I][main.cpp:53] start_esp_sleep(): [DEVICE] deep sleep... z z z

Just to confirm: I just flashed back to the non-debug v2.0.6, the restart problem is back again.

Also I can see a huge difference in speed: With the debug firmware, after a button press it takes a short while until the LED lights up (presumably due to the amount of debug output to be sent prior LED is switched on). Anyway, the event is then sent close in time (1-2 seconds) to MQTT and the LED is off again.

With non-debug firmware, LED light turns on comparatively fast, then it remains on for a quite long while (significantly longer than with the debug firmware...) and then a reboot occurs.

Wild guess: Some race conditions? Is there any action relying on an already active WiFi connection, but it might not be completely set up at that time? And waiting for the logs to be sent with the debug firmware, WiFi has enough time to initialize?

nplan commented

Initially, did you upgrade from v2.0.4 to v2.0.6 or was it from v2.0.3?

The debug is slower because of additional output and because there's no compiler optimisations. That's normal.

Initially, did you upgrade from v2.0.4 to v2.0.6 or was it from v2.0.3?

If I remember correctly, it was v2.0.3 -> v2.0.4 -> v2.0.6.

The debug is slower because of additional output and because there's no compiler optimisations. That's normal.

I know, just mentioned this because suspecting a race condition.

Should I be able to downgrade from 2.0.6 to v2.0.3? Trying any flashing with OTA after full image recovery (regardless if v2.0.4 or v2.0.6): Website looses connection, but after a couple of seconds is back. Same version, nothing changed on the display.

First flashing the full image you provided (regardless if 2.0.4 oder 2.0.6) and then flashing any other image to 0x10000 again bricks the device - no reaction of the display when pressing "reset".

I think, beside the WiFi issue, there is an issue with the full image you sent me. I just tried to downgraded one of the other devices, where I never used a full image. Successfully downgraded to v2.0.3 using OTA, the WiFi issue is gone for this other device.

For the first device, I'm not able to flash anything beside the full images you provided. Using OTA or esptool to flash a normal release does not work anymore.

nplan commented

Downgrading to v2.0.3 from full image v2.0.4 & v2.0.6 will not work because the bootloader is different.

On your other devices that were not flashed with full images v2.0.4 or later it's working, because they have the right bootloader from before. The old v2.0.3 bootloader is working with newer versions, new bootloader is not working with older versions.

The documentation is missing one fact: the flash has two app partitions. One at 0x10000 an the other at 0x150000. OTA writes to the inactive one and changes a switch to boot from it. So if you previously used OTA and later use esptool you might not flash to the active slot - the new image won't boot. To be sure you must flash the same image to both addresses.

Can you please try this update image. It's the same as v2.0.6 just with lower log level set. I think the log output of the arduino Wi-Fi library is causing this issue. The log will be mostly empty since it also disables output from my code.

homebuttons_fw_v2.0.7-beta.bin.zip
(extract the zip first)

First flash the full image v2.0.6 and then this one with OTA or esptool. I confirmed this update steps on my device and I see no reason why it would be any different on yours.

Bootloader issues: Understood, thanks for clarification.

Thanks for the v2.0.7. update. v2.0.6 full (ESP) and then v2.0.7-beta OTA works, button press causes LED to go on... and to go off, without reboot :) Home Assistant is triggered, so... looks very good! Thanks for all the effort!

nplan commented

Great, thanks for testing. I'll need to find another solution since it's still nice to have some log output, but at least we know where the issue is.

Sure, let me know if I should test something else or can be helpful otherwise.

espressif/arduino-esp32#7959 is solved now. If you provide me with an update I can test if the problem is gone with that patch.

nplan commented

This is solved in v2.1.0 by disabling the problematic logs, while still having the useful log output. The fixes from arduino core will be implemented when they are included in a PlatformIO platform release.

@MatthiasLohr please test the v2.1.0.

Seems to be working! Thanks!