adafruit / circuitpython

CircuitPython - a Python implementation for teaching coding with microcontrollers
https://circuitpython.org
Other
4.1k stars 1.22k forks source link

esp32-s3-box: wifi connect causes safe mode with with "Internal watchdog timer expired." #7093

Closed PaulskPt closed 2 years ago

PaulskPt commented 2 years ago

CircuitPython version

Adafruit CircuitPython 8.0.0-beta.2 on 2022-10-14; ESP32-S3-Box-2.5 with ESP32S3

Code/REPL

Contents .env file:

`# To auto-connect to Wi-Fi
CIRCUITPY_WIFI_SSID=YOUR_SSID
CIRCUITPY_WIFI_PASSWORD=YOUR_PASSWORD
# Following are variables used by code.py`

To not publish my router's WiFi login details I show the contents here with 'YOUR SSID' and 'YOUR_PASSWORD' placeholders instead.

Behavior

Immediately after copying the .env file to the CIRCUITPY disk, the MCU starts with a looping reboot cycle.

Description

No response

Additional information

Note that a reboot often also happens when, while using mu-editor, press CTRL+S to save the code.py file I'm working on, at moments that the script is running.

Various times it happened that the device turned CPY into 'Safe Mode'. So, I had to reset is manually to reboot and return to a 'normal' state.

This usually does not happen whenever I first issue a CTRL+C (KeybiardInterrupt) to stop the running script. and next when I have back the command prompt '>>' in mu-editor REPL, and issue then a 'save file' (CTRL+S) command.

PaulskPt commented 2 years ago

I just upgraded CPY to V8.0.0-beta.3. Same result.

debug log ``` ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x8 (TG1WDT_SYS_RST),boot:0xa (SPI_FAST_FLASH_BOOT) Saved PC:0x40374203 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (29) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (29) boot: compile time 11:36:39 I (29) boot: chip revision: 0 I (32) qio_mode: Enabling default flash chip QIO I (37) boot.esp32s3: Boot SPI Speed : 80MHz I (42) boot.esp32s3: SPI Mode : QIO I (47) boot.esp32s3: SPI Flash Size : 16MB W (52) boot.esp32s3: PRO CPU has been reset by WDT. W (57) boot.esp32s3: APP CPU has been reset by WDT. I (63) boot: Enabling RNG early entropy source... I (68) boot: Partition Table: I (72) boot: ## Label Usage Type ST Offset Length I (79) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (87) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (94) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (102) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (109) boot: 4 uf2 factory app 00 00 00410000 00040000 I (117) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (124) boot: End of partition table I (629) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2e108h (188680) map I (658) esp_image: segment 1: paddr=0003e130 vaddr=3fc9ae40 size=01ee8h ( 7912) load I (659) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=10d36ch (110270 0) map I (830) esp_image: segment 3: paddr=0014d394 vaddr=3fc9cd28 size=02fc4h ( 12228) load I (833) esp_image: segment 4: paddr=00150360 vaddr=40374000 size=16e34h ( 93748) load I (854) esp_image: segment 5: paddr=0016719c vaddr=600fe000 size=0002ch ( 44) load I (855) esp_image: segment 6: paddr=001671d0 vaddr=600fe030 size=01010h ( 4112) load I (870) boot: Loaded app from partition at offset 0x10000 I (870) boot: Disabling RNG early entropy source... ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x8 (TG1WDT_SYS_RST),boot:0xa (SPI_FAST_FLASH_BOOT) Saved PC:0x40387576 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (29) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (29) boot: compile time 11:36:39 I (29) boot: chip revision: 0 I (32) qio_mode: Enabling default flash chip QIO I (37) boot.esp32s3: Boot SPI Speed : 80MHz I (42) boot.esp32s3: SPI Mode : QIO I (47) boot.esp32s3: SPI Flash Size : 16MB W (52) boot.esp32s3: PRO CPU has been reset by WDT. W (57) boot.esp32s3: APP CPU has been reset by WDT. I (63) boot: Enabling RNG early entropy source... I (68) boot: Partition Table: I (72) boot: ## Label Usage Type ST Offset Length I (79) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (87) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (94) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (102) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (109) boot: 4 uf2 factory app 00 00 00410000 00040000 I (117) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (124) boot: End of partition table I (629) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2e108h (188680) map I (658) esp_image: segment 1: paddr=0003e130 vaddr=3fc9ae40 size=01ee8h ( 7912) load I (659) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=10d36ch (1102700) map I (830) esp_image: segment 3: paddr=0014d394 vaddr=3fc9cd28 size=02fc4h ( 12228) load I (833) esp_image: segment 4: paddr=00150360 vaddr=40374000 size=16e34h ( 93748) load I (854) esp_image: segment 5: paddr=0016719c vaddr=600fe000 size=0002ch ( 44) load I (855) esp_image: segment 6: paddr=001671d0 vaddr=600fe030 size=01010h ( 4112) load I (870) boot: Loaded app from partition at offset 0x10000 I (870) boot: Disabling RNG early entropy source... ```
dhalbert commented 2 years ago

I just upgraded CPY to V8.0.0-beta.3. Same result.

Yes, there isn't anything in beta.3 that I would have expected to fix this. (Btw, could you paste text instead of screenshots? It makes it easier to copy/paste or quote.)

PaulskPt commented 2 years ago

OK, Dan, I am going to reproduce the boot-loop and then copy in text format.

Here the output of a 'normal' boot running my project script "MSFS2020_GPRMC-GPGGA_rx".

log ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x1 (POWERON),boot:0xa (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (24) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (25) boot: compile time 11:36:39 I (25) boot: chip revision: 0 I (28) qio_mode: Enabling default flash chip QIO I (33) boot.esp32s3: Boot SPI Speed : 80MHz I (38) boot.esp32s3: SPI Mode : QIO I (42) boot.esp32s3: SPI Flash Size : 16MB I (47) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (56) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (71) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (78) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (86) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (93) boot: 4 uf2 factory app 00 00 00410000 00040000 I (101) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (108) boot: End of partition table I (613) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2e108h (188680) map I (647) esp_image: segment 1: paddr=0003e130 vaddr=3fc9ae40 size=01ee8h ( 7912) load I (648) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=10d36ch (1102700) map I (820) esp_image: segment 3: paddr=0014d394 vaddr=3fc9cd28 size=02fc4h ( 12228) load I (822) esp_image: segment 4: paddr=00150360 vaddr=40374000 size=16e34h ( 93748) load I (843) esp_image: segment 5: paddr=0016719c vaddr=600fe000 size=0002ch ( 44) load I (844) esp_image: segment 6: paddr=001671d0 vaddr=600fe030 size=01010h ( 4112) load I (859) boot: Loaded app from partition at offset 0x10000 I (859) boot: Disabling RNG early entropy source... ```
Neradoc commented 2 years ago

I believe this is an issue with wifi connection. Instead of .env, connect to wifi from code.py to remove the "boot" aspect. It makes the board reboot into safe mode. Since safe mode does not disable wifi autoconnect from .env, that would cause a boot loop, but it's really a reboot caused by the wifi connection.

import wifi
from secrets import secrets
print("Connecting")
wifi.radio.connect(ssid=secrets["ssid"], password=secrets["password"])
socket_pool = socketpool.SocketPool(wifi.radio)
code.py output:
Connecting

[16:05:50.333] Disconnected
[16:05:51.338] Warning: Could not open tty device (No such file or directory)
[16:05:51.338] Waiting for tty device..
[16:05:53.348] Connected
Auto-reload is off.
Running in safe mode! Not running saved code.

You are in safe mode because:
Internal watchdog timer expired.

Press any key to enter the REPL. Use CTRL-D to reload.

I wasn't able to reproduce with another S3 board.

PaulskPt commented 2 years ago

@Neradoc I ran your example. Here is it and the REPL output:

import wifi from secrets import secrets print("Connecting") wifi.radio.connect(ssid=secrets["ssid"], password=secrets["password"]) socket_pool = socketpool.SocketPool(wifi.radio)

REPL output:

Auto-reload is off. Running in safe mode! Not running saved code.

You are in safe mode because: Internal watchdog timer expired.

Press any key to enter the REPL. Use CTRL-D to reload.

jepler commented 2 years ago

Is there anything unusual about your wifi setup? For instance, are the ssid or password strings long? Do they contain non-alphanumeric characters? I see your latest test appears to exclude the .env file altogether (assuming you removed or renamed the file), which is good information to have.

PaulskPt commented 2 years ago

Next I copied a part that I recently successfully used with an UM PROS3: But it crashed also into safe mode with the 'internal watchdog' error:

import time
import wifi
import socketpool
import ipaddress
from secrets import secrets

use_ping = True 

print("Connecting")

try:
    wifi.radio.connect(ssid=secrets["ssid"], password=secrets["password"])
except ConnectionError as e:
    print("WiFi connection Error: \'{}\'".format(e))

ip = wifi.radio.ipv4_address

pool = socketpool.SocketPool(wifi.radio)

if ip:
    s_ip = str(ip)
if s_ip is not None and s_ip != '0.0.0.0':
    print("s_ip= \'{}\'".format(s_ip))
    print("connected to %s!"%ssid_to_connect)
    print("IP address is", ip)
    if use_ping:
        open_socket()
        addr_idx = 1
        addr_dict = {0:'LAN gateway', 1:'google.com'}
        info = pool.getaddrinfo(addr_dict[addr_idx], 80)
        addr = info[0][4][0]
        print(f"Resolved google address: \'{addr}\'")
        ipv4 = ipaddress.ip_address(addr)
        for _ in range(10):
            result = wifi.radio.ping(ipv4)
            if result:
                print("Ping google.com [%s]: %.0f ms" % (addr, result*1000))
                break
            else:
                print("Ping no response")
        free_socket()

while True:
    time.sleep(5)
log Result on serial output: ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x1 (POWERON),boot:0xa (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (24) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (25) boot: compile time 11:36:39 I (25) boot: chip revision: 0 I (28) qio_mode: Enabling default flash chip QIO I (33) boot.esp32s3: Boot SPI Speed : 80MHz I (38) boot.esp32s3: SPI Mode : QIO I (42) boot.esp32s3: SPI Flash Size : 16MB I (47) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (56) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (71) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (78) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (86) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (93) boot: 4 uf2 factory app 00 00 00410000 00040000 I (101) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (108) boot: End of partition table I (613) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2e108h (188680) map I (647) esp_image: segment 1: paddr=0003e130 vaddr=3fc9ae40 size=01ee8h ( 7912) load I (648) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=10d36ch (1102700) map I (820) esp_image: segment 3: paddr=0014d394 vaddr=3fc9cd28 size=02fc4h ( 12228) load I (822) esp_image: segment 4: paddr=00150360 vaddr=40374000 size=16e34h ( 93748) load I (843) esp_image: segment 5: paddr=0016719c vaddr=600fe000 size=0002ch ( 44) load I (844) esp_image: segment 6: paddr=001671d0 vaddr=600fe030 size=01010h ( 4112) load I (859) boot: Loaded app from partition at offset 0x10000 I (859) boot: Disabling RNG early entropy source... ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x8 (TG1WDT_SYS_RST),boot:0xa (SPI_FAST_FLASH_BOOT) Saved PC:0x40378f40 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (29) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (29) boot: compile time 11:36:39 I (29) boot: chip revision: 0 I (32) qio_mode: Enabling default flash chip QIO I (37) boot.esp32s3: Boot SPI Speed : 80MHz I (42) boot.esp32s3: SPI Mode : QIO I (47) boot.esp32s3: SPI Flash Size : 16MB W (52) boot.esp32s3: PRO CPU has been reset by WDT. W (57) boot.esp32s3: APP CPU has been reset by WDT. I (63) boot: Enabling RNG early entropy source... I (68) boot: Partition Table: I (72) boot: ## Label Usage Type ST Offset Length I (79) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (87) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (94) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (102) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (109) boot: 4 uf2 factory app 00 00 00410000 00040000 I (117) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (124) boot: End of partition table I (629) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2e108h (188680) map I (658) esp_image: segment 1: paddr=0003e130 vaddr=3fc9ae40 size=01ee8h ( 7912) load I (659) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=10d36ch (1102700) map I (830) esp_image: segment 3: paddr=0014d394 vaddr=3fc9cd28 size=02fc4h ( 12228) load I (833) esp_image: segment 4: paddr=00150360 vaddr=40374000 size=16e34h ( 93748) load I (854) esp_image: segment 5: paddr=0016719c vaddr=600fe000 size=0002ch ( 44) load I (855) esp_image: segment 6: paddr=001671d0 vaddr=600fe030 size=01010h ( 4112) load I (870) boot: Loaded app from partition at offset 0x10000 I (870) boot: Disabling RNG early entropy source...
PaulskPt commented 2 years ago

@jepler No. both SSID as PASSWORD use normal characters, plus one dash '-' and one underscore '_'. Length of the SSID string is 19 characters. Length of the PW string is 10 characters. These I used in many CPY scripts without any problem. Yes, I removed the .env file. And I had to re-flash: combined.bin to be able to copy the CPY .uf2 and copy to the CIRCUITPY disk a backup I created earlier.

PaulskPt commented 2 years ago

A few minutes ago I re-flashed the esp-box with tinyuf2 combined.bin (I discovered that I flashed b4 using SPI mode 'DIO' and this afternoon I discovered that the serial output of the MCU says the SPI mode is 'QIO'. I also took the chance to copy the latest CPY version dated today. Unfortunately a script to test the WiFi connection with the AP here in the room resulted in 'WDT expired'. See images below.

IMG_7061

2022-10-22_18h02_CPY_latest_fm_today_WiFi_test_WDT_expired

PaulskPt commented 2 years ago
Saturday 2022-10-22 18h57 utc+1

Adafruit CircuitPython 8.0.0-beta.3-6-g5a6fffca4 on 2022-10-22; ESP32-S3-Box-2.5 with ESP32S3
Board ID:espressif_esp32s3_box
UID:C7FD1A1E7C45

Serial output:

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x8 (TG1WDT_SYS_RST),boot:0xa (SPI_FAST_FLASH_BOOT)
Saved PC:0x40378f28
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x15e8
load:0x403b6000,len:0xbf8
load:0x403ba000,len:0x31c8
entry 0x403b621c
I (29) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader
I (29) boot: compile time 11:36:39
I (29) boot: chip revision: 0
I (32) qio_mode: Enabling default flash chip QIO
I (37) boot.esp32s3: Boot SPI Speed : 80MHz
I (42) boot.esp32s3: SPI Mode       : QIO
I (47) boot.esp32s3: SPI Flash Size : 16MB
W (52) boot.esp32s3: PRO CPU has been reset by WDT.       <<<================================  Crash / reset
W (57) boot.esp32s3: APP CPU has been reset by WDT.       <<<================================  -- idem --
I (63) boot: Enabling RNG early entropy source...
I (68) boot: Partition Table:
I (72) boot: ## Label            Usage          Type ST Offset   Length
I (79) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (87) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (94) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (102) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (109) boot:  4 uf2              factory app      00 00 00410000 00040000
I (117) boot:  5 ffat             Unknown data     01 81 00450000 00bb0000
I (124) boot: End of partition table
I (629) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2b5c0h (177600) map
I (656) esp_image: segment 1: paddr=0003b5e8 vaddr=3fc9ab70 size=0448ch ( 17548) load
I (659) esp_image: segment 2: paddr=0003fa7c vaddr=40374000 size=0059ch (  1436) load
I (662) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=1037f8h (1062904) map
I (831) esp_image: segment 4: paddr=00143820 vaddr=4037459c size=165d4h ( 91604) load
I (849) esp_image: segment 5: paddr=00159dfc vaddr=600fe000 size=0002ch (    44) load
I (849) esp_image: segment 6: paddr=00159e30 vaddr=600fe030 size=01010h (  4112) load
I (865) boot: Loaded app from partition at offset 0x10000
I (865) boot: Disabling RNG early entropy source...
Neradoc commented 2 years ago

I'm getting that with a DEBUG=1 build, it doesn't look like it gives any useful info to me, it just... stops when connecting.

>>> import wifi
D (28309) esp_netif_lwip: LwIP stack has been initialized
D (28309) esp_netif_lwip: esp-netif has been successfully initialized
D (28309) event: created task for loop 0x3fcebd90
D (28309) event: running task for loop 0x3fcebd90
D (28309) event: created event loop 0x3fcebd90
D (28319) esp_netif_objects: esp_netif_add_to_list 0x3fceccbc
D (28329) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (28339) esp_netif_objects: esp_netif_add_to_list 0x3fced088
D (28339) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
I (28349) pp: pp rom version: e7ae62f
I (28349) net80211: net80211 rom version: e7ae62f
I (28369) wifi:wifi driver task: 3fcafc98, prio:23, stack:3584, core=0
I (28369) system_api: Base MAC address is not set
I (28369) system_api: read default base MAC address from EFUSE
D (28379) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (28379) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (28389) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (28399) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (28409) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (28409) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
I (28419) wifi:wifi firmware version: f1d33cc
I (28419) wifi:wifi certification version: v7.0
I (28429) wifi:config NVS flash: disabled
I (28429) wifi:config nano formating: disabled
I (28439) wifi:Init data frame dynamic rx buffer num: 8
I (28439) wifi:Init management frame dynamic rx buffer num: 8
I (28449) wifi:Init management short buffer num: 32
I (28449) wifi:Init static tx buffer num: 16
I (28459) wifi:Init tx cache buffer num: 16
I (28459) wifi:Init static tx FG buffer num: 2
I (28459) wifi:Init static rx buffer size: 1600
I (28469) wifi:Init static rx buffer num: 4
I (28469) wifi:Init dynamic rx buffer num: 8
I (28479) wifi_init: rx ba win: 6
I (28479) wifi_init: tcpip mbox: 32
I (28479) wifi_init: udp mbox: 6
I (28489) wifi_init: tcp mbox: 6
I (28489) wifi_init: tcp tx win: 2880
I (28499) wifi_init: tcp rx win: 2880
I (28499) wifi_init: tcp mss: 1440
I (28499) wifi_init: WiFi IRAM OP enabled
I (28509) wifi_init: WiFi RX IRAM OP enabled
D (28509) ADC: Wi-Fi takes adc2 lock.
I (28519) phy_init: phy_version 503,13653eb,Jun  1 2022,17:47:08
D (28519) phy_init: loading PHY init data from application binary
D (28529) nvs: nvs_open_from_partition phy 0
E (28539) phy_init: esp_phy_load_cal_data_from_nvs: NVS has not been initialized. Call nvs_flash_init before starting WiFi/BT.
W (28549) phy_init: failed to load RF calibration data (0x1101), falling back to full calibration
D (28559) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (28559) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (28569) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (28579) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (28589) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (28589) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
D (28629) nvs: nvs_open_from_partition phy 1
D (28629) phy_init: esp_phy_store_cal_data_to_nvs: failed to open NVS namespace (0x1101)
D (28629) wifi:filter: set rx policy=0
I (28629) wifi:mode : sta (7c:df:a1:**:**:**)
I (28639) wifi:enable tsf
D (28639) wifi:filter: set rx policy=1
D (28639) wifi:connect status 0 -> 0
D (28649) event: running post WIFI_EVENT:2 with handler 0x4207dc14 and context 0x3fcecf34 on loop 0x3fcebd90
D (28659) wifi_init_default: wifi_start esp-netif:0x3fceccbc event-id2
D (28659) wifi_init_default: WIFI mac address: 7c df a1 ** ** **
D (28669) esp_netif_handlers: esp_netif action has started with netif0x3fceccbc from event_id=2
D (28679) esp_netif_lwip: check: remote, if=0x3fceccbc fn=0x4207a1dc

D (28679) esp_netif_lwip: esp_netif_start_api 0x3fceccbc
D (28689) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fceccbc
D (28699) esp_netif_lwip: check: local, if=0x3fceccbc fn=0x4207ab3c

D (28699) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fceccbc
D (28709) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (28719) event: running post WIFI_EVENT:2 with handler 0x42038c10 and context 0x3fced284 on loop 0x3fcebd90
W (28729) CP wifi: sta start
>>> from secrets import secrets
>>> wifi.radio.connect(secrets["ssid"], secrets["password"])
D (140069) wifi:clear blacklist
D (140069) wifi:Start wifi connect
D (140069) wifi:connect status 0 -> 0
D (140069) wifi:connect chan=0
D (140069) wifi:first chan=1
D (140069) wifi:connect status 0 -> 1
D (140079) wifi:filter: set rx policy=3
D (140079) wifi:clear scan ap list
D (140079) wifi:start scan: type=0x50f, priority=2, cb=0x420cbd20, arg=0, ss_state=0x1, time=140087620, index=0
D (140089) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
D (140219) wifi:scan end: arg=0, status=0, ss_state=0x3
D (140219) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
D (140339) wifi:scan end: arg=0, status=0, ss_state=0x3
D (140339) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
D (140459) wifi:scan end: arg=0, status=0, ss_state=0x3
D (140459) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
D (140469) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (140469) wifi:profile match: ss_state=0x7
D (140579) wifi:scan end: arg=0, status=0, ss_state=0x7
D (140579) wifi:perform scan: ss_state=0xd, chan<5,0>, dur<0,120>
D (140699) wifi:scan end: arg=0, status=0, ss_state=0x7
D (140699) wifi:perform scan: ss_state=0xd, chan<6,0>, dur<0,120>
D (140819) wifi:scan end: arg=0, status=0, ss_state=0x7
D (140819) wifi:perform scan: ss_state=0xd, chan<7,0>, dur<0,120>
D (140939) wifi:scan end: arg=0, status=0, ss_state=0x7
D (140949) wifi:perform scan: ss_state=0xd, chan<8,0>, dur<0,120>
D (140949) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (140949) wifi:profile match: ss_state=0x7
D (140949) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (140959) wifi:profile match: ss_state=0x7
D (140959) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (140969) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0>
D (140969) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
D (140979) wifi:profile match: ss_state=0x7
D (140989) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (140989) wifi:profile match: ss_state=0x7
D (141009) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (141009) wifi:profile match: ss_state=0x7
D (141009) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (141009) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0>
D (141019) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
D (141019) wifi:profile match: ss_state=0x7
D (141069) wifi:scan end: arg=0, status=0, ss_state=0x7
D (141069) wifi:perform scan: ss_state=0xd, chan<9,0>, dur<0,120>
D (141189) wifi:scan end: arg=0, status=0, ss_state=0x7
D (141189) wifi:perform scan: ss_state=0xd, chan<10,0>, dur<0,120>
D (141309) wifi:scan end: arg=0, status=0, ss_state=0x7
D (141309) wifi:perform scan: ss_state=0xd, chan<11,0>, dur<0,120>
D (141429) wifi:scan end: arg=0, status=0, ss_state=0x7
D (141429) wifi:perform scan: ss_state=0xd, chan<12,0>, dur<360,360>
D (141789) wifi:scan end: arg=0, status=0, ss_state=0x7
D (141789) wifi:perform scan: ss_state=0xd, chan<13,0>, dur<360,360>
D (142149) wifi:scan end: arg=0, status=0, ss_state=0x7
D (142149) wifi:perform scan: ss_state=0xd, chan<14,0>, dur<360,360>
D (142509) wifi:scan end: arg=0, status=0, ss_state=0x7
D (142509) wifi:filter: set rx policy=4
D (142509) wifi:first chan=1
D (142509) wifi:handoff_cb: status=0
D (142509) wifi:ap found, mac=**:**:**:**:**:**
D (142519) wifi:new_bss=0x3fcaaab8, cur_bss=0, new_chan=<8,0>, cur_chan=1
D (142529) wifi:filter: set rx policy=5
I (142529) wifi:new:<8,0>, old:<1,0>, ap:<255,255>, sta:<8,0>, prof:1
D (142529) wifi:connect_op: status=0, auth=5, cipher=3 

Board resets.

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x8 (TG1WDT_SYS_RST),boot:0xa (SPI_FAST_FLASH_BOOT)
Saved PC:0x403799cc
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1648
load:0x403b6000,len:0xc80
load:0x403ba000,len:0x2f7c
entry 0x403b621c
I (839) boot: ESP-IDF v4.4-dev-3608-gbbe2a1bf34 2nd stage bootloader
I (839) boot: compile time 21:02:16
I (839) boot: chip revision: 0
I (842) qio_mode: Enabling default flash chip QIO
I (848) boot.esp32s3: Boot SPI Speed : 80MHz
I (853) boot.esp32s3: SPI Mode       : QIO
I (858) boot.esp32s3: SPI Flash Size : 16MB
W (862) boot.esp32s3: PRO CPU has been reset by WDT.
W (868) boot.esp32s3: APP CPU has been reset by WDT.
I (874) boot: Enabling RNG early entropy source...
W (879) bootloader_random: RNG for ESP32-S3 not currently supported
I (886) boot: Partition Table:
I (890) boot: ## Label            Usage          Type ST Offset   Length
I (897) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (905) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (912) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (920) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (927) boot:  4 uf2              factory app      00 00 00410000 00040000
I (935) boot:  5 ffat             Unknown data     01 81 00450000 00bb0000
I (943) boot: End of partition table
I (1447) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4cb68h (314216) map
I (1495) esp_image: segment 1: paddr=0005cb90 vaddr=3fc9c620 size=03488h ( 13448) load
I (1497) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=11483ch (1132604) map
I (1672) esp_image: segment 3: paddr=00174864 vaddr=3fc9faa8 size=0200ch (  8204) load
I (1674) esp_image: segment 4: paddr=00176878 vaddr=40374000 size=1861ch ( 99868) load
I (1697) esp_image: segment 5: paddr=0018ee9c vaddr=600fe000 size=0002ch (    44) load
I (1698) esp_image: segment 6: paddr=0018eed0 vaddr=600fe030 size=01010h (  4112) load
I (1714) boot: Loaded app from partition at offset 0x10000
I (1714) boot: Disabling RNG early entropy source...
W (1715) bootloader_random: RNG for ESP32-S3 not currently supported
I (1734) opi psram: vendor id : 0x0d (AP)
I (1734) opi psram: dev id    : 0x02 (generation 3)
I (1734) opi psram: density   : 0x03 (64 Mbit)
I (1738) opi psram: good-die  : 0x01 (Pass)
I (1743) opi psram: Latency   : 0x01 (Fixed)
I (1748) opi psram: VCC       : 0x01 (3V)
I (1752) opi psram: SRF       : 0x01 (Fast Refresh)
I (1758) opi psram: BurstType : 0x01 (Hybrid Wrap)
I (1763) opi psram: BurstLen  : 0x01 (32 Byte)
I (1768) opi psram: Readlatency  : 0x02 (10 cycles@Fixed)
I (1774) opi psram: DriveStrength: 0x00 (1/1)
W (1779) PSRAM: DO NOT USE FOR MASS PRODUCTION! Timing parameters will be updated in future IDF version.
D (1790) MSPI Timing: tuning success, best point is index 4
I (1795) spiram: Found 64MBit SPI RAM device
I (1800) spiram: SPI RAM mode: sram 80m
I (1805) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (1812) cpu_start: Pro cpu up.
I (1816) cpu_start: Starting app cpu, entry point is 0x4037856c
I (0) cpu_start: App cpu up.
I (2242) spiram: SPI SRAM memory test OK
D (2242) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit
D (2242) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit
D (2249) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (2257) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (2264) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit
D (2271) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (2278) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (2285) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (2292) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (2299) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (2306) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (2313) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (2320) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (2327) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (2334) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (2349) clk: RTC_SLOW_CLK calibration value: 3518566
I (2358) cpu_start: Pro cpu start user code
I (2358) cpu_start: cpu freq: 240000000
I (2358) cpu_start: Application information:
I (2361) cpu_start: Project name:     circuitpython
I (2367) cpu_start: App version:      8.0.0-beta.3-15-g5a6fffca4-dirt
I (2374) cpu_start: Compile time:     Oct 22 2022 20:32:33
I (2380) cpu_start: ELF file SHA256:  675e49c87aace213...
I (2386) cpu_start: ESP-IDF:          716d8531d7
D (2391) memory_layout: Checking 6 reserved memory ranges:
D (2397) memory_layout: Reserved memory range 0x3d000000 - 0x3e000000
D (2404) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9c61c
D (2410) memory_layout: Reserved memory range 0x3fc9c620 - 0x3fcae038
D (2417) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (2423) memory_layout: Reserved memory range 0x40374000 - 0x4038c61c
D (2430) memory_layout: Reserved memory range 0x600fe000 - 0x600ff040
D (2436) memory_layout: Building list of available memory regions:
D (2442) memory_layout: Available memory region 0x3fcae038 - 0x3fcb0000
D (2449) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
D (2456) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
D (2462) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
D (2469) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710
D (2476) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34
D (2482) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
D (2489) memory_layout: Available memory region 0x600ff040 - 0x60100000
I (2496) heap_init: Initializing. RAM available for dynamic allocation:
D (2503) heap_init: New heap initialised at 0x3fcae038
I (2508) heap_init: At 3FCAE038 len 0003B6D8 (237 KiB): D/IRAM
I (2515) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
D (2522) heap_init: New heap initialised at 0x3fcf0000
I (2527) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (2533) heap_init: New heap initialised at 0x600ff040
I (2538) heap_init: At 600FF040 len 00000FC0 (3 KiB): RTCRAM
I (2545) spiram: Adding pool of 8192K of external SPI memory to heap allocator
D (2553) FLASH_HAL: extra_dummy: 0
D (2556) spi_flash: trying chip: issi
D (2560) spi_flash: trying chip: gd
I (2563) spi_flash: detected chip: gd
I (2568) spi_flash: flash io: dio
D (2572) cpu_start: calling init function: 0x4210aa48
D (2577) cpu_start: calling init function: 0x4210a658
D (2582) cpu_start: calling init function: 0x420fa038
D (2587) cpu_start: calling init function: 0x420ee130
D (2592) cpu_start: calling init function: 0x4207d7f4
D (2597) cpu_start: calling init function: 0x4207b834
D (2602) cpu_start: calling init function: 0x4207948c
D (2608) intr_alloc: Connected src 59 to int 2 (cpu 0)
I (2613) sleep: Configure to isolate all GPIO pins in sleep state
I (2620) sleep: Enable automatic switching of GPIO sleep configuration
I (2627) coexist: coexist rom version e7ae62f
D (2632) intr_alloc: Connected src 79 to int 3 (cpu 0)
I (2637) cpu_start: Starting scheduler on PRO CPU.
D (2643) intr_alloc: Connected src 57 to int 9 (cpu 0)
D (2643) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (2653) cpu_start: Starting scheduler on APP CPU.
D (2653) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (2673) heap_init: New heap initialised at 0x3fce9710
I (2673) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
D (2673) spiram: Allocating block of size 32768 bytes
D (2683) partition: Loading the partition table
D (2683) partition: Partition table MD5 verified
I (2693) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2693) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2703) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2713) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2723) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2733) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2743) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2753) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2763) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2773) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2783) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2793) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2803) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2813) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2813) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2823) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2833) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2843) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2853) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2863) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2873) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2883) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2893) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2903) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2913) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
E (2923) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (2923) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
E (2933) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (2943) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (2953) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (2953) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
D (3003) gdma: new group (0) at 0x3d8009a4
D (3003) gdma: new pair (0,0) at 0x3d8009e0
D (3003) gdma: new tx channel (0,0) at 0x3d800974
D (3003) gdma: new rx channel (0,0) at 0x3d800a00
D (3013) spi: SPI3 use gpio matrix.
D (3013) intr_alloc: Connected src 22 to int 4 (cpu 1)
D (3023) spi_hal: eff: 250, limit: 80000k(/0), 0 dummy, -1 delay
D (3023) spi_master: SPI3: New device added to CS5, effective clock: 250kHz
I (3033) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (3043) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (3053) gpio: GPIO[48]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
D (3063) spi_hal: eff: 40000, limit: 80000k(/0), 0 dummy, -1 delay
D (3063) spi_master: SPI3: New device added to CS5, effective clock: 40000kHz
D (4253) ledc: Using clock source 1 (in slow mode), divisor: 0x190

D (4253) ledc: In slow speed mode, using clock 1
D (4253) ledc: LEDC_PWM CHANNEL 0|GPIO 45|Duty 0000|Time 0
I (4263) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4263) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4273) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4283) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4293) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4303) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4313) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4323) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4333) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4343) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4353) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4363) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4373) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4383) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4393) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4403) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4413) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4413) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (4423) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
E (4433) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (4443) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
I (4543) espidf: Reserving 0 bytes of psram
D (4543) intr_alloc: Connected src 38 to int 9 (cpu 1)
dhalbert commented 2 years ago

@PaulskPt We talked about doing a similar test on your UM ESP32-S3 ProS3. Do I understand that a similar script did not fail on that board? So it seems to Box-specific?

Neradoc commented 2 years ago

I can't reproduce it with the Feather ESP32-S3 TFT, it seems to run all fine, wifi.radio.connect or .env.

Adafruit CircuitPython 8.0.0-beta.3-10-g773bb99c9 on 2022-10-22; Adafruit Feather ESP32-S3 TFT with ESP32S3

PaulskPt commented 2 years ago

@Neradoc thank you for your investigation. @danh. I soldered the pin-strips to my new UM ProS3. Initial tests OK. Then I re-flashed it with tthe tinyuf2 bootloader for CPY. Loaded the really latest (from 2022-10-22) CPY V8. Wrote a similar script to connect to the same WiFi AP in the room here. It works great. I copied output of it to the dropbox folder.

I just copied also an .env file to the CIRCUITPY disk of the UM ProS3. I see that it works. After boot the statusbar shows an IP-address:

🐍192.168.1.111 | code.py | 8.0.0-beta.3-7-g17bda551c\

Adafruit CircuitPython 8.0.0-beta.3-7-g17bda551c on 2022-10-22; ProS3 with ESP32S3

Yes, it looks that it is the esp-box (Note it is not an esp-box-lite !) specific.

PaulskPt commented 2 years ago

Here REPL output in mu-editor from the WiFi test with the new UM ProS3. Btw: it's programmed to request date & time string from AIO Time Service every 2 minutes.

soft reboot

Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.
code.py output:
]0;🐍192.168.1.111 | code.py | 8.0.0-beta.3-7-g17bda551c\

WiFi test for UM ProS3
Waiting for mu-editor etc. getting ready
wifi.radio.hostname= 'UMProS3'
wifi.radio.mac_address= f4:12:fa:42:4:ec
pr_scanned_ap(): 
Available WiFi networks (sorted on: 'rssi')
    AP nr 14    SSID: Vodafone-287778_EXT               RSSI: -51   Channel:  9
    AP nr 15    SSID: Vodafone-287778                   RSSI: -72   Channel:  9
    AP nr 10    SSID: MEO-AFM_EXT                       RSSI: -74   Channel:  3
    AP nr  1    SSID: devolo-1a9                        RSSI: -80   Channel:  6
    AP nr  2    SSID: MEO-WiFi                          RSSI: -85   Channel:  6
    AP nr 11    SSID: MEO-WiFi                          RSSI: -85   Channel:  3
    AP nr  5    SSID: MEO-8997C0                        RSSI: -86   Channel: 11
    AP nr 12    SSID: MEO-AFM                           RSSI: -86   Channel:  3
    AP nr  3    SSID: MEO-FIBRA                         RSSI: -86   Channel:  6
    AP nr  6    SSID: MEO-FEEE80                        RSSI: -87   Channel: 11
    AP nr 16    SSID: Vodafone-F19ACA                   RSSI: -87   Channel:  9
    AP nr 17    SSID: Vodafone-DBE967                   RSSI: -87   Channel:  7
    AP nr  7    SSID: MEO-WiFi                          RSSI: -88   Channel: 11
    AP nr  8    SSID: ThomsonDAA08B                     RSSI: -89   Channel: 11
    AP nr  9    SSID: MEO-77FBF0                        RSSI: -90   Channel: 11
    AP nr 18    SSID: Vodafone-FEE539                   RSSI: -91   Channel: 10
    AP nr 13    SSID: TP-Link_4E72                      RSSI: -91   Channel:  3
    AP nr  4    SSID: NOS-90E6                          RSSI: -92   Channel:  6
connected to Vodafone-287778_EXT!
IP address is 192.168.1.111
Resolved google address: '216.58.215.174'
Ping no response
Ping no response
Ping google.com [216.58.215.174]: 21 ms
Entering loop
elapsed_t= 10. WiFi status: connected
elapsed_t= 20. WiFi status: connected
elapsed_t= 30. WiFi status: connected
elapsed_t= 40. WiFi status: connected
elapsed_t= 50. WiFi status: connected
elapsed_t= 60. WiFi status: connected
elapsed_t= 70. WiFi status: connected
elapsed_t= 80. WiFi status: connected
elapsed_t= 90. WiFi status: connected
elapsed_t=100. WiFi status: connected
elapsed_t=110. WiFi status: connected
elapsed_t=120. WiFi status: connected
get_time_fm_AIO(): ip= 192.168.1.111
----------------------------------------
Time=  2022-10-23 02:58:09.719 296 7 +0100 WEST
----------------------------------------
elapsed_t= 10. WiFi status: connected
elapsed_t= 20. WiFi status: connected
elapsed_t= 30. WiFi status: connected
elapsed_t= 40. WiFi status: connected
elapsed_t= 50. WiFi status: connected
elapsed_t= 60. WiFi status: connected
elapsed_t= 70. WiFi status: connected
elapsed_t= 80. WiFi status: connected
elapsed_t= 90. WiFi status: connected
elapsed_t=100. WiFi status: connected
elapsed_t=110. WiFi status: connected
elapsed_t=120. WiFi status: connected
get_time_fm_AIO(): ip= 192.168.1.111
----------------------------------------
Time=  2022-10-23 03:00:10.160 296 7 +0100 WEST
----------------------------------------
elapsed_t= 10. WiFi status: connected
elapsed_t= 20. WiFi status: connected
elapsed_t= 30. WiFi status: connected
elapsed_t= 40. WiFi status: connected
elapsed_t= 50. WiFi status: connected
elapsed_t= 60. WiFi status: connected
KeyboardInterrupt. Exiting...
]0;�192.168.1.111 | Done | 8.0.0-beta.3-7-g17bda551c\
Code done running.

Press any key to enter the REPL. Use CTRL-D to reload.
]0;�192.168.1.111 | REPL | 8.0.0-beta.3-7-g17bda551c\
Adafruit CircuitPython 8.0.0-beta.3-7-g17bda551c on 2022-10-22; ProS3 with ESP32S3
PaulskPt commented 2 years ago

I, from my end, restarted my investigation. For what it is worth: Regarding the CPY port definitions for the board 'esp32s3_box', the file: mpconfigboard.mk is the file most recently modified: 18 days ago. In this file the flash mode is defined as dio however a serial output at boot of the esp32-s3-box states flash (SPI) mode qio. See composite screenshot below:

2022-10-24_12h12_Github_Adafruit_CPY_ports_espressif_boards_esp32s3_box_file_mpconfigboard mk_contents_flash_mode_different_from_serial_output_flash_mode_info

PaulskPt commented 2 years ago

As a comparison: the board that is similar (also esp32s3; also 16mb of SPI Flash RAM: Unexpected Maler esp32s3 pros3, which does not go into a boot-loop when trying to connect to a WiFi-Access Point, has in the mpconfigboard.mk the flash mode as qio, the same as in its serial output during boot. See the composite screenshot below:

2022-10-24_12h38_Github_Adafruit_CPY_ports_espressif_boards_unexpected_maker_pros3_file_mpconfigboard mk_

PaulskPt commented 2 years ago

Since Seon Rozenblum (Expected Maker) recently sent me updated replacements for the three models of his esp32s3 series of boards, I am able to compare the serial output at boot time with the flash definitions in the respective mpconfigboard.mk files of the latest edition of CPY V8. Here is the comparison for the board UM tinys3. As you can see: the same difference as with the esp32s3_box: dio in mpconfigboard.mk versus qio in the serial output at boot time.

2022-10-24_13h00_for_comparison_CPY_V8_ports_espressif_boards_unexpectedmaker_tinys3_mpconfigboard mk_

PaulskPt commented 2 years ago

The same situation for the board unexpectedmaker_feathers3: dio in mpconfigboard.mk versus qio in the serial output at boot time:

2022-10-24_13h06_for_comparison_CPY_V8_ports_espressif_boards_unexpectedmaker_feathers3_mpconfigboard mk_

I think that in all three occurrances of differences a 'copy & paste' devil has done it's work, so to speak.

PaulskPt commented 2 years ago

Just flasthed the UM FeatherS3 with CPY V8 latest. Here is the serial output at boot time while running the first WiFi test on this board: Adafruit CircuitPython 8.0.0-beta.3-11-gedce717cf on 2022-10-23; FeatherS3 with ESP32S3

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1644
load:0x403b6000,len:0xf1c
load:0x403ba000,len:0x31c8
entry 0x403b634c
I (25) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader
I (25) boot: compile time 11:37:31
I (25) boot: chip revision: 0
I (28) qio_mode: Enabling QIO for flash chip WinBond
I (33) boot.esp32s3: Boot SPI Speed : 80MHz
I (38) boot.esp32s3: SPI Mode       : QIO
I (43) boot.esp32s3: SPI Flash Size : 16MB
I (48) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (72) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (79) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (86) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (94) boot:  4 uf2              factory app      00 00 00410000 00040000
I (101) boot:  5 ffat             Unknown data     01 81 00450000 00bb0000
I (109) boot: End of partition table
I (613) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2bef0h (179952) map
I (645) esp_image: segment 1: paddr=0003bf18 vaddr=3fc9a520 size=04100h ( 16640) load
I (649) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=103bd4h (1063892) map
I (813) esp_image: segment 3: paddr=00143bfc vaddr=3fc9e620 size=00358h (   856) load
I (813) esp_image: segment 4: paddr=00143f5c vaddr=40374000 size=1651ch ( 91420) load
I (836) esp_image: segment 5: paddr=0015a480 vaddr=600fe000 size=0002ch (    44) load
I (836) esp_image: segment 6: paddr=0015a4b4 vaddr=600fe030 size=01010h (  4112) load
I (851) boot: Loaded app from partition at offset 0x10000
I (852) boot: Disabling RNG early entropy source...

The WiFi test was successful. Received an IP-address. Positive ping on 'google.com'.

PaulskPt commented 2 years ago

To make it complete: just flashed also the new UM TinyS3 with CPY latest: Adafruit CircuitPython 8.0.0-beta.3-11-gedce717cf on 2022-10-23; TinyS3 with ESP32S3 Then I ran the same WiFi test. Result: successfull. Received an IP-address. Also a positive ping on 'google.com'. Below the serial output at boot:



ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1644
load:0x403b6000,len:0xe74
load:0x403ba000,len:0x31c8
entry 0x403b632c
I (25) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader
I (25) boot: compile time 11:37:42
I (25) boot: chip revision: 0
I (28) qio_mode: Enabling default flash chip QIO
I (33) boot.esp32s3: Boot SPI Speed : 80MHz
I (38) boot.esp32s3: SPI Mode       : QIO
I (43) boot.esp32s3: SPI Flash Size : 8MB
I (47) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (71) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (78) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (86) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (93) boot:  4 uf2              factory app      00 00 00410000 00040000
I (101) boot:  5 ffat             Unknown data     01 81 00450000 003b0000
I (108) boot: End of partition table
I (613) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2bf20h (180000) map
I (645) esp_image: segment 1: paddr=0003bf48 vaddr=3fc9a520 size=040d0h ( 16592) load
I (649) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=10420ch (1065484) map
I (813) esp_image: segment 3: paddr=00144234 vaddr=3fc9e5f0 size=00388h (   904) load
I (813) esp_image: segment 4: paddr=001445c4 vaddr=40374000 size=1651ch ( 91420) load
I (836) esp_image: segment 5: paddr=0015aae8 vaddr=600fe000 size=0002ch (    44) load
I (836) esp_image: segment 6: paddr=0015ab1c vaddr=600fe030 size=01010h (  4112) load
I (852) boot: Loaded app from partition at offset 0x10000
I (852) boot: Disabling RNG early entropy source...```
dhalbert commented 2 years ago

Regarding the CPY port definitions for the board 'esp32s3_box', the file: mpconfigboard.mk is the file most recently modified: 18 days ago. In this file the flash mode is defined as dio however a serial output at boot of the esp32-s3-box states flash (SPI) mode qio.

Those three CIRCUITPY_ESP_FLASH_* constants are only used to construct the flags to pass to esptool.py in ports/espressif/Makefile. They are not used for any compilation variations. It does sound like it should be changed, but I don't think it's causing this particular problem.

PaulskPt commented 2 years ago

Thank you. I also expected an answer like this however I wanted to mention it because it is not correct.

PaulskPt commented 2 years ago

Any news for me? Some development?

dhalbert commented 2 years ago

Nope, sorry, I am working on ESP32-nn sleep issues at the moment.

PaulskPt commented 2 years ago

Thank you. I just managed to create a build of CPY 8.0.0-beta.3-12-gf67d2794c-dirty\ with DEBUG=1. I think I have some interesting serial output that will help us further. However I don't understand everything from the errors printed in red but you and @Neradoc maybe will. I made three screenshots because they show you the real problem points in red color. Beside that I also copied the text output version to which I added markings at the points of Error or Reset. See all below please.

details ![2022-10-25_20h40_ESP32-S3-Box_serial_output_errors_01](https://user-images.githubusercontent.com/9107950/197869401-83d96294-9747-4486-b30a-2fb34ce9a9b0.png) ![2022-10-25_20h40_ESP32-S3-Box_serial_output_errors_02](https://user-images.githubusercontent.com/9107950/197869425-97dc9c54-0eb5-4071-8644-84498846b293.png) ![2022-10-25_20h40_ESP32-S3-Box_serial_output_errors_03](https://user-images.githubusercontent.com/9107950/197869435-6567ab5e-2026-42d2-a629-70598a46c30b.png) ``` Tuesday 2022-10-25 20h40 utc+1 Platform: ESP32-S3-Box Circuitpython V8.0.0-beta.3-11- ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x1 (POWERON),boot:0xa (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (24) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (25) boot: compile time 11:36:39 I (25) boot: chip revision: 0 I (28) qio_mode: Enabling default flash chip QIO I (33) boot.esp32s3: Boot SPI Speed : 80MHz I (38) boot.esp32s3: SPI Mode : QIO I (42) boot.esp32s3: SPI Flash Size : 16MB I (47) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (56) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (71) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (78) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (86) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (93) boot: 4 uf2 factory app 00 00 00410000 00040000 I (101) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (108) boot: End of partition table I (613) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4c8cch (313548) map I (665) esp_image: segment 1: paddr=0005c8f4 vaddr=3fc9c620 size=03724h ( 14116) load I (668) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=114920h (1132832) map I (843) esp_image: segment 3: paddr=00174948 vaddr=3fc9fd44 size=01d40h ( 7488) load I (845) esp_image: segment 4: paddr=00176690 vaddr=40374000 size=1861ch ( 99868) load I (868) esp_image: segment 5: paddr=0018ecb4 vaddr=600fe000 size=0002ch ( 44) load I (868) esp_image: segment 6: paddr=0018ece8 vaddr=600fe030 size=01010h ( 4112) load I (884) boot: Loaded app from partition at offset 0x10000 I (885) boot: Disabling RNG early entropy source... I (897) opi psram: vendor id : 0x0d (AP) I (897) opi psram: dev id : 0x02 (generation 3) I (897) opi psram: density : 0x03 (64 Mbit) I (901) opi psram: good-die : 0x01 (Pass) I (905) opi psram: Latency : 0x01 (Fixed) I (910) opi psram: VCC : 0x01 (3V) I (915) opi psram: SRF : 0x01 (Fast Refresh) I (920) opi psram: BurstType : 0x01 (Hybrid Wrap) I (926) opi psram: BurstLen : 0x01 (32 Byte) I (931) opi psram: Readlatency : 0x02 (10 cycles@Fixed) I (937) opi psram: DriveStrength: 0x00 (1/1) W (942) PSRAM: DO NOT USE FOR MASS PRODUCTION! Timing parameters will be updated in future IDF version. D (952) MSPI Timing: tuning success, best point is index 5 I (957) spiram: Found 64MBit SPI RAM device I (962) spiram: SPI RAM mode: sram 80m I (967) spiram: PSRAM initialized, cache is in normal (1-core) mode. I (974) cpu_start: Pro cpu up. I (977) cpu_start: Starting app cpu, entry point is 0x4037856c I (0) cpu_start: App cpu up. I (1410) spiram: SPI SRAM memory test OK D (1410) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit D (1411) efuse: In EFUSE_BLK2__DATA4_REG is used 8 bits starting with 13 bit D (1418) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit D (1425) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit D (1432) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1439) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1446) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit D (1453) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1460) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1467) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1474) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1481) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1488) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1495) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1503) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1510) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1517) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1532) clk: RTC_SLOW_CLK calibration value: 4162509 I (1540) cpu_start: Pro cpu start user code I (1540) cpu_start: cpu freq: 240000000 I (1541) cpu_start: Application information: I (1544) cpu_start: Project name: circuitpython I (1549) cpu_start: App version: 8.0.0-beta.3-33-gf67d2794c-dirt I (1556) cpu_start: Compile time: Oct 25 2022 20:06:21 I (1562) cpu_start: ELF file SHA256: 4a0c2ff3c0a5d0da... I (1568) cpu_start: ESP-IDF: 716d8531d7 D (1574) memory_layout: Checking 6 reserved memory ranges: D (1579) memory_layout: Reserved memory range 0x3d000000 - 0x3e000000 D (1586) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9c61c D (1592) memory_layout: Reserved memory range 0x3fc9c620 - 0x3fcae010 D (1599) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000 D (1605) memory_layout: Reserved memory range 0x40374000 - 0x4038c61c D (1612) memory_layout: Reserved memory range 0x600fe000 - 0x600ff040 D (1618) memory_layout: Building list of available memory regions: D (1625) memory_layout: Available memory region 0x3fcae010 - 0x3fcb0000 D (1631) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000 D (1638) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000 D (1645) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000 D (1651) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710 D (1658) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34 D (1665) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000 D (1671) memory_layout: Available memory region 0x600ff040 - 0x60100000 I (1678) heap_init: Initializing. RAM available for dynamic allocation: D (1685) heap_init: New heap initialised at 0x3fcae010 I (1691) heap_init: At 3FCAE010 len 0003B700 (237 KiB): D/IRAM I (1697) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM D (1704) heap_init: New heap initialised at 0x3fcf0000 I (1709) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM D (1715) heap_init: New heap initialised at 0x600ff040 I (1721) heap_init: At 600FF040 len 00000FC0 (3 KiB): RTCRAM I (1727) spiram: Adding pool of 8192K of external SPI memory to heap allocator D (1735) FLASH_HAL: extra_dummy: 0 D (1738) spi_flash: trying chip: issi D (1742) spi_flash: trying chip: gd I (1746) spi_flash: detected chip: gd I (1750) spi_flash: flash io: dio D (1754) cpu_start: calling init function: 0x4210ab48 D (1759) cpu_start: calling init function: 0x4210ab04 D (1764) cpu_start: calling init function: 0x420fa118 D (1769) cpu_start: calling init function: 0x420ee210 D (1774) cpu_start: calling init function: 0x4207d8b0 D (1779) cpu_start: calling init function: 0x4207b8f0 D (1785) cpu_start: calling init function: 0x42079548 D (1790) intr_alloc: Connected src 59 to int 2 (cpu 0) I (1795) sleep: Configure to isolate all GPIO pins in sleep state I (1802) sleep: Enable automatic switching of GPIO sleep configuration I (1809) coexist: coexist rom version e7ae62f D (1814) intr_alloc: Connected src 79 to int 3 (cpu 0) I (1819) cpu_start: Starting scheduler on PRO CPU. D (1825) intr_alloc: Connected src 57 to int 9 (cpu 0) D (1825) intr_alloc: Connected src 80 to int 2 (cpu 1) I (1835) cpu_start: Starting scheduler on APP CPU. D (1835) intr_alloc: Connected src 58 to int 3 (cpu 1) D (1855) heap_init: New heap initialised at 0x3fce9710 I (1855) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations D (1855) spiram: Allocating block of size 32768 bytes I (1865) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 D (2865) partition: Loading the partition table D (2865) partition: Partition table MD5 verified I (2875) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2875) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2885) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2895) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2905) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2915) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2925) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2935) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2945) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2955) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2965) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2965) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2975) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2985) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2995) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3005) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3015) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3025) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3035) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3045) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3055) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3065) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3075) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3085) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3095) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (3105) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed E (3105) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed E (3115) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | <<<========= ERROR E (3125) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | <<<========= ERROR E (3125) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | <<<========= ERROR E (3135) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | <<<========= ERROR D (3185) gdma: new group (0) at 0x3d8009a4 D (3185) gdma: new pair (0,0) at 0x3d8009e0 D (3185) gdma: new tx channel (0,0) at 0x3d800974 D (3185) gdma: new rx channel (0,0) at 0x3d800a00 D (3195) spi: SPI3 use gpio matrix. D (3195) intr_alloc: Connected src 22 to int 4 (cpu 1) D (3205) spi_hal: eff: 250, limit: 80000k(/0), 0 dummy, -1 delay D (3205) spi_master: SPI3: New device added to CS5, effective clock: 250kHz I (3215) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (3225) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (3235) gpio: GPIO[48]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 D (3245) spi_hal: eff: 40000, limit: 80000k(/0), 0 dummy, -1 delay D (3245) spi_master: SPI3: New device added to CS5, effective clock: 40000kHz D (4435) ledc: Using clock source 1 (in slow mode), divisor: 0x190 D (4435) ledc: In slow speed mode, using clock 1 D (4435) ledc: LEDC_PWM CHANNEL 0|GPIO 45|Duty 0000|Time 0 I (4455) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4455) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4455) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4465) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4475) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4485) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4495) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4505) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4515) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4525) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4535) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4545) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4555) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4565) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4575) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4585) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4595) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4595) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4605) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (4615) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed # |<<<========================== ERROR E (4625) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed # | <<<========================== ERROR I (4725) espidf: Reserving 0 bytes of psram D (4725) intr_alloc: Connected src 38 to int 9 (cpu 1) D (4805) esp_netif_lwip: LwIP stack has been initialized D (4805) esp_netif_lwip: esp-netif has been successfully initialized D (4805) event: created task for loop 0x3fcebd90 D (4805) event: running task for loop 0x3fcebd90 D (4815) event: created event loop 0x3fcebd90 D (4815) esp_netif_objects: esp_netif_add_to_list 0x3fceccbc D (4825) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1) D (4835) esp_netif_objects: esp_netif_add_to_list 0x3fced088 D (4835) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2) I (4845) pp: pp rom version: e7ae62f I (4855) net80211: net80211 rom version: e7ae62f I (4865) wifi:wifi driver task: 3fcafc68, prio:23, stack:3584, core=0 I (4865) system_api: Base MAC address is not set I (4865) system_api: read default base MAC address from EFUSE D (4875) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit D (4885) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit D (4885) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit D (4895) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit D (4905) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit D (4915) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit I (4915) wifi:wifi firmware version: f1d33cc I (4925) wifi:wifi certification version: v7.0 I (4925) wifi:config NVS flash: disabled I (4925) wifi:config nano formating: disabled I (4935) wifi:Init data frame dynamic rx buffer num: 8 I (4935) wifi:Init management frame dynamic rx buffer num: 8 I (4945) wifi:Init management short buffer num: 32 I (4945) wifi:Init static tx buffer num: 16 I (4955) wifi:Init tx cache buffer num: 16 I (4955) wifi:Init static tx FG buffer num: 2 I (4965) wifi:Init static rx buffer size: 1600 I (4965) wifi:Init static rx buffer num: 4 I (4965) wifi:Init dynamic rx buffer num: 8 I (4975) wifi_init: rx ba win: 6 I (4975) wifi_init: tcpip mbox: 32 I (4975) wifi_init: udp mbox: 6 I (4985) wifi_init: tcp mbox: 6 I (4985) wifi_init: tcp tx win: 2880 I (4995) wifi_init: tcp rx win: 2880 I (4995) wifi_init: tcp mss: 1440 I (4995) wifi_init: WiFi IRAM OP enabled I (5005) wifi_init: WiFi RX IRAM OP enabled D (5005) ADC: Wi-Fi takes adc2 lock. I (5015) phy_init: phy_version 503,13653eb,Jun 1 2022,17:47:08 I (5015) phy_init: phy_version 503,13653eb,Jun 1 2022,17:47:08 D (5015) phy_init: loading PHY init data from application binary D (5025) nvs: nvs_open_from_partition phy 0 E (5035) phy_init: esp_phy_load_cal_data_from_nvs: NVS has not been initialized. Call nvs_flash_init before starting WiFi/BT. <<<==================== ERROR W (5045) phy_init: failed to load RF calibration data (0x1101), falling back to full calibration # | <<<=== WARNING D (5055) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit D (5055) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit D (5065) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit D (5075) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit D (5075) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit D (5085) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit D (5115) nvs: nvs_open_from_partition phy 1 D (5115) phy_init: esp_phy_store_cal_data_to_nvs: failed to open NVS namespace (0x1101) D (5125) wifi:filter: set rx policy=0 I (5125) wifi:mode : sta (7c:df:a1:e1:c7:54) I (5125) wifi:enable tsf D (5125) wifi:filter: set rx policy=1 D (5135) wifi:connect status 0 -> 0 D (5135) event: running post WIFI_EVENT:2 with handler 0x4207dc14 and context 0x3fcecf34 on loop 0x3fcebd90 D (5145) wifi_init_default: wifi_start esp-netif:0x3fceccbc event-id2 D (5155) wifi_init_default: WIFI mac address: 7c df a1 e1 c7 54 D (5155) esp_netif_handlers: esp_netif action has started with netif0x3fceccbc from event_id=2 D (5165) esp_netif_lwip: check: remote, if=0x3fceccbc fn=0x4207a1dc D (5175) esp_netif_lwip: esp_netif_start_api 0x3fceccbc D (5175) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fceccbc D (5185) esp_netif_lwip: check: local, if=0x3fceccbc fn=0x4207ab3c D (5195) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fceccbc D (5195) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (5205) event: running post WIFI_EVENT:2 with handler 0x42038c10 and context 0x3fced284 on loop 0x3fcebd90 W (5215) CP wifi: sta start D (5435) wifi:clear blacklist D (5435) wifi:Start wifi connect D (5435) wifi:connect status 0 -> 0 D (5435) wifi:connect chan=0 D (5435) wifi:first chan=1 D (5435) wifi:connect status 0 -> 1 D (5445) wifi:filter: set rx policy=3 D (5445) wifi:clear scan ap list D (5445) wifi:start scan: type=0x50f, priority=2, cb=0x420cbe04, arg=0, ss_state=0x1, time=5451860, index=0 D (5455) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120> D (5585) wifi:scan end: arg=0, status=0, ss_state=0x3 D (5585) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120> D (5705) wifi:scan end: arg=0, status=0, ss_state=0x3 D (5705) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120> D (5825) wifi:scan end: arg=0, status=0, ss_state=0x3 D (5825) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120> D (5945) wifi:scan end: arg=0, status=0, ss_state=0x3 D (5945) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120> D (6065) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6065) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120> D (6185) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6185) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120> D (6315) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6315) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120> D (6435) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6435) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120> D (6435) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (6445) wifi:profile match: ss_state=0x7 D (6455) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (6455) wifi:set max rate: from to D (6455) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144 D (6465) wifi:profile match: ss_state=0x7 D (6555) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (6555) wifi:profile match: ss_state=0x7 D (6555) wifi:scan end: arg=0, status=0, ss_state=0x7 D (6555) wifi:perform scan: ss_state=0xd, chan<10,0>, dur<0,120> D (6685) wifi:scan end: arg=0, status=0, ss_state=0x7 D (6685) wifi:perform scan: ss_state=0xd, chan<11,0>, dur<0,120> D (6805) wifi:scan end: arg=0, status=0, ss_state=0x7 D (6805) wifi:perform scan: ss_state=0xd, chan<12,0>, dur<360,360> D (7165) wifi:scan end: arg=0, status=0, ss_state=0x7 D (7165) wifi:perform scan: ss_state=0xd, chan<13,0>, dur<360,360> D (7525) wifi:scan end: arg=0, status=0, ss_state=0x7 D (7525) wifi:perform scan: ss_state=0xd, chan<14,0>, dur<360,360> D (7885) wifi:scan end: arg=0, status=0, ss_state=0x7 D (7885) wifi:filter: set rx policy=4 D (7885) wifi:first chan=1 D (7885) wifi:handoff_cb: status=0 D (7885) wifi:ap found, mac=e4:c3:2a:e3:14:31 D (7895) wifi:new_bss=0x3fcaa790, cur_bss=0, new_chan=<9,0>, cur_chan=1 D (7895) wifi:filter: set rx policy=5 I (7905) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:1 D (7905) wifi:connect_op: status=0, auth=5, cipher=3 # | <<<===== WiFi Connect command ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x8 (TG1WDT_SYS_RST),boot:0xa (SPI_FAST_FLASH_BOOT) # | <<<===== MOMENT OF RESET BY WATCHDOG TIMER Saved PC:0x40374200 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (29) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (29) boot: compile time 11:36:39 I (29) boot: chip revision: 0 I (32) qio_mode: Enabling default flash chip QIO I (37) boot.esp32s3: Boot SPI Speed : 80MHz I (42) boot.esp32s3: SPI Mode : QIO I (47) boot.esp32s3: SPI Flash Size : 16MB W (52) boot.esp32s3: PRO CPU has been reset by WDT. # | <<<======== WATCHDOG TIMER RESETS BOARD W (57) boot.esp32s3: APP CPU has been reset by WDT. # | <<<======== IDEM I (63) boot: Enabling RNG early entropy source... I (68) boot: Partition Table: I (72) boot: ## Label Usage Type ST Offset Length I (79) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (87) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (94) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (102) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (109) boot: 4 uf2 factory app 00 00 00410000 00040000 I (117) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (124) boot: End of partition table I (629) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4c8cch (313548) map I (676) esp_image: segment 1: paddr=0005c8f4 vaddr=3fc9c620 size=03724h ( 14116) load I (679) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=114920h (1132832) map I (854) esp_image: segment 3: paddr=00174948 vaddr=3fc9fd44 size=01d40h ( 7488) load I (856) esp_image: segment 4: paddr=00176690 vaddr=40374000 size=1861ch ( 99868) load I (879) esp_image: segment 5: paddr=0018ecb4 vaddr=600fe000 size=0002ch ( 44) load I (879) esp_image: segment 6: paddr=0018ece8 vaddr=600fe030 size=01010h ( 4112) load I (895) boot: Loaded app from partition at offset 0x10000 I (896) boot: Disabling RNG early entropy source... I (908) opi psram: vendor id : 0x0d (AP) I (908) opi psram: dev id : 0x02 (generation 3) I (908) opi psram: density : 0x03 (64 Mbit) I (912) opi psram: good-die : 0x01 (Pass) I (916) opi psram: Latency : 0x01 (Fixed) I (921) opi psram: VCC : 0x01 (3V) I (926) opi psram: SRF : 0x01 (Fast Refresh) I (931) opi psram: BurstType : 0x01 (Hybrid Wrap) I (937) opi psram: BurstLen : 0x01 (32 Byte) I (942) opi psram: Readlatency : 0x02 (10 cycles@Fixed) I (948) opi psram: DriveStrength: 0x00 (1/1) W (953) PSRAM: DO NOT USE FOR MASS PRODUCTION! Timing parameters will be updated in future IDF version. D (963) MSPI Timing: tuning success, best point is index 5 I (968) spiram: Found 64MBit SPI RAM device I (973) spiram: SPI RAM mode: sram 80m I (978) spiram: PSRAM initialized, cache is in normal (1-core) mode. I (985) cpu_start: Pro cpu up. I (988) cpu_start: Starting app cpu, entry point is 0x4037856c I (0) cpu_start: App cpu up. I (1421) spiram: SPI SRAM memory test OK D (1421) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit D (1422) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit D (1429) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1436) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1443) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit D (1450) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1457) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1464) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1471) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1478) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1485) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1492) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1499) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1507) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1514) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1529) clk: RTC_SLOW_CLK calibration value: 4164621 I (1537) cpu_start: Pro cpu start user code I (1537) cpu_start: cpu freq: 240000000 I (1537) cpu_start: Application information: I (1540) cpu_start: Project name: circuitpython I (1546) cpu_start: App version: 8.0.0-beta.3-33-gf67d2794c-dirt I (1553) cpu_start: Compile time: Oct 25 2022 20:06:21 I (1559) cpu_start: ELF file SHA256: 4a0c2ff3c0a5d0da... I (1565) cpu_start: ESP-IDF: 716d8531d7 D (1571) memory_layout: Checking 6 reserved memory ranges: D (1576) memory_layout: Reserved memory range 0x3d000000 - 0x3e000000 D (1583) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9c61c D (1589) memory_layout: Reserved memory range 0x3fc9c620 - 0x3fcae010 D (1596) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000 D (1602) memory_layout: Reserved memory range 0x40374000 - 0x4038c61c D (1609) memory_layout: Reserved memory range 0x600fe000 - 0x600ff040 D (1615) memory_layout: Building list of available memory regions: D (1621) memory_layout: Available memory region 0x3fcae010 - 0x3fcb0000 D (1628) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000 D (1635) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000 D (1641) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000 D (1648) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710 D (1655) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34 D (1662) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000 D (1668) memory_layout: Available memory region 0x600ff040 - 0x60100000 I (1675) heap_init: Initializing. RAM available for dynamic allocation: D (1682) heap_init: New heap initialised at 0x3fcae010 I (1687) heap_init: At 3FCAE010 len 0003B700 (237 KiB): D/IRAM I (1694) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM D (1701) heap_init: New heap initialised at 0x3fcf0000 I (1706) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM D (1712) heap_init: New heap initialised at 0x600ff040 I (1717) heap_init: At 600FF040 len 00000FC0 (3 KiB): RTCRAM I (1724) spiram: Adding pool of 8192K of external SPI memory to heap allocator D (1732) FLASH_HAL: extra_dummy: 0 D (1735) spi_flash: trying chip: issi D (1739) spi_flash: trying chip: gd I (1742) spi_flash: detected chip: gd I (1747) spi_flash: flash io: dio D (1751) cpu_start: calling init function: 0x4210ab48 D (1756) cpu_start: calling init function: 0x4210ab04 D (1761) cpu_start: calling init function: 0x420fa118 D (1766) cpu_start: calling init function: 0x420ee210 D (1771) cpu_start: calling init function: 0x4207d8b0 D (1776) cpu_start: calling init function: 0x4207b8f0 D (1781) cpu_start: calling init function: 0x42079548 D (1787) intr_alloc: Connected src 59 to int 2 (cpu 0) I (1792) sleep: Configure to isolate all GPIO pins in sleep state I (1799) sleep: Enable automatic switching of GPIO sleep configuration I (1806) coexist: coexist rom version e7ae62f D (1811) intr_alloc: Connected src 79 to int 3 (cpu 0) I (1816) cpu_start: Starting scheduler on PRO CPU. D (1822) intr_alloc: Connected src 57 to int 9 (cpu 0) D (1822) intr_alloc: Connected src 80 to int 2 (cpu 1) I (1832) cpu_start: Starting scheduler on APP CPU. D (1832) intr_alloc: Connected src 58 to int 3 (cpu 1) D (1852) heap_init: New heap initialised at 0x3fce9710 I (1852) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations D (1852) spiram: Allocating block of size 32768 bytes D (1862) partition: Loading the partition table D (1862) partition: Partition table MD5 verified I (1872) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1872) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1882) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1892) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1902) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1912) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1922) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1932) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1942) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1952) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1962) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1972) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1982) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1992) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1992) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2002) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2012) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2022) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2032) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2042) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2052) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2062) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2072) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2082) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2092) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (2102) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed # | E (2102) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed # | E (2112) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | <<<=================== ERROR E (2122) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | E (2132) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | E (2132) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR # | D (2182) gdma: new group (0) at 0x3d8009a4 D (2182) gdma: new pair (0,0) at 0x3d8009e0 D (2182) gdma: new tx channel (0,0) at 0x3d800974 D (2182) gdma: new rx channel (0,0) at 0x3d800a00 D (2192) spi: SPI3 use gpio matrix. D (2192) intr_alloc: Connected src 22 to int 4 (cpu 1) D (2202) spi_hal: eff: 250, limit: 80000k(/0), 0 dummy, -1 delay D (2202) spi_master: SPI3: New device added to CS5, effective clock: 250kHz I (2212) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (2222) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (2232) gpio: GPIO[48]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 D (2242) spi_hal: eff: 40000, limit: 80000k(/0), 0 dummy, -1 delay D (2242) spi_master: SPI3: New device added to CS5, effective clock: 40000kHz D (3432) ledc: Using clock source 1 (in slow mode), divisor: 0x190 D (3432) ledc: In slow speed mode, using clock 1 D (3432) ledc: LEDC_PWM CHANNEL 0|GPIO 45|Duty 0000|Time 0 I (3442) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3442) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3452) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3462) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3472) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3482) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3492) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3502) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3512) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3522) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3532) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3542) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3552) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3562) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3572) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3582) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3592) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3592) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3602) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (3612) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed # | <<<=============== # | ERROR ? E (3622) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed # | <<<=============== # | ERROR ? I (3722) espidf: Reserving 0 bytes of psram D (3722) intr_alloc: Connected src 38 to int 9 (cpu 1) ```
PaulskPt commented 2 years ago

About the HW TIMER errors: the error is reported four times. The hardware timers are described here: General Purpose Timers. The doc starts to describe that there are 2 Timer groups. Each group having 2 timers. When I google'd for the error I found about four hits. Some had to do with IR-applications.

PaulskPt commented 2 years ago

About the errors I2S port 0/1 has not installed. The doc about I2S says:

ESP32-S3 contains two I2S peripheral(s). These peripherals can be configured to input and output sample data via the I2S driver. [...]

Driver uninstall:

If the established communication is no longer required, the driver can be removed to free allocated resources by calling [i2s_driver_uninstall()](https://docs.espressif.com/projects/esp-idf/en/release-v4.4/esp32s3/api-reference/peripherals/i2s.html#_CPPv420i2s_driver_uninstall10i2s_port_t).

dhalbert commented 2 years ago

I believe we see these errors in the log output from programs running on all similar builds (EDIT for clarity). It would be worth comparing the log output of a board that works with the Box output.

PaulskPt commented 2 years ago

OK. However I don't understand your last sentence. Can you rephrase pse. Btw. The long list that I uploaded is not a BUILD log. It is the serial output from the ESP32-S3-Box while running the script that attempted to make a WiFi connection. I have a CP2102N connected to U0TX and U0RX of the ESP32-S3-Box.

dhalbert commented 2 years ago

I'm saying that you will probably see these same log errors on output from a board that works, such as the UM FeatherS3. It would be worth verifying that is the case, and if you see error reports that differ, to note that. For instance, I am see the HW TIMER NEVER INIT ERROR right now on a test program on a Feather ESP32-S2 that is not using wifi at all.

PaulskPt commented 2 years ago

Thank you for the elaboration. I'll try to build a debug version for the UM FeatherS3.

PaulskPt commented 2 years ago

I managed to build a CPY V8b3-11 for the UM ESP32 FeatherS3 with DEBUG=1. As soon as I try to issue wifi.radio.contact(ssid=ssid, password=password) the CPU halts and disk is lost. I have to reflash the bootloader. The same happens as soon as I copy the file .env to the drive .

See the serial output below:


ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1644
load:0x403b6000,len:0xf1c
load:0x403ba000,len:0x31c8
entry 0x403b634c
I (25) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader
I (25) boot: compile time 11:37:31
I (25) boot: chip revision: 0
I (28) qio_mode: Enabling QIO for flash chip WinBond
I (33) boot.esp32s3: Boot SPI Speed : 80MHz
I (38) boot.esp32s3: SPI Mode       : QIO
I (43) boot.esp32s3: SPI Flash Size : 16MB
I (48) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (72) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (79) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (86) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (94) boot:  4 uf2              factory app      00 00 00410000 00040000
I (101) boot:  5 ffat             Unknown data     01 81 00450000 00bb0000
I (109) boot: End of partition table
I (613) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4d0d4h (315604) map
I (666) esp_image: segment 1: paddr=0005d0fc vaddr=3fc9bd40 size=02f1ch ( 12060) load
I (669) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=114b94h (1133460) map
I (844) esp_image: segment 3: paddr=00174bbc vaddr=3fc9ec5c size=02250h (  8784) load
I (846) esp_image: segment 4: paddr=00176e14 vaddr=40374000 size=17d3ch ( 97596) load
I (868) esp_image: segment 5: paddr=0018eb58 vaddr=600fe000 size=0002ch (    44) load
I (868) esp_image: segment 6: paddr=0018eb8c vaddr=600fe030 size=01010h (  4112) load
I (884) boot: Loaded app from partition at offset 0x10000
I (884) boot: Disabling RNG early entropy source...
I (897) spiram: Found 64MBit SPI RAM device
I (897) spiram: SPI RAM mode: sram 80m
I (897) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (902) cpu_start: Pro cpu up.
I (906) cpu_start: Starting app cpu, entry point is 0x4037847c
I (0) cpu_start: App cpu up.
I (1830) spiram: SPI SRAM memory test OK
D (1830) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit
D (1831) efuse: In EFUSE_BLK2__DATA4_REG is used 8 bits starting with 13 bit
D (1838) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit
D (1845) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit
D (1852) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (1859) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (1866) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit
D (1873) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (1880) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (1887) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (1894) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (1901) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (1908) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (1915) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (1923) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (1930) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (1937) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (1952) clk: RTC_SLOW_CLK calibration value: 3635379
I (1960) cpu_start: Pro cpu start user code
I (1960) cpu_start: cpu freq: 240000000
I (1961) cpu_start: Application information:
I (1963) cpu_start: Project name:     circuitpython
I (1969) cpu_start: App version:      8.0.0-beta.3-33-gf67d2794c-dirt
I (1976) cpu_start: Compile time:     Oct 26 2022 00:33:49
I (1982) cpu_start: ELF file SHA256:  7adcc34a72169957...
I (1988) cpu_start: ESP-IDF:          716d8531d7
D (1994) memory_layout: Checking 6 reserved memory ranges:
D (1999) memory_layout: Reserved memory range 0x3d000000 - 0x3e000000
D (2006) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9bd3c
D (2012) memory_layout: Reserved memory range 0x3fc9bd40 - 0x3fcad4c0
D (2019) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (2025) memory_layout: Reserved memory range 0x40374000 - 0x4038bd3c
D (2032) memory_layout: Reserved memory range 0x600fe000 - 0x600ff040
D (2038) memory_layout: Building list of available memory regions:
D (2045) memory_layout: Available memory region 0x3fcad4c0 - 0x3fcb0000
D (2051) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
D (2058) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
D (2065) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
D (2071) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710
D (2078) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34
D (2085) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
D (2091) memory_layout: Available memory region 0x600ff040 - 0x60100000
I (2098) heap_init: Initializing. RAM available for dynamic allocation:
D (2105) heap_init: New heap initialised at 0x3fcad4c0
I (2111) heap_init: At 3FCAD4C0 len 0003C250 (240 KiB): D/IRAM
I (2117) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
D (2124) heap_init: New heap initialised at 0x3fcf0000
I (2129) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (2135) heap_init: New heap initialised at 0x600ff040
I (2140) heap_init: At 600FF040 len 00000FC0 (3 KiB): RTCRAM
D (2147) FLASH_HAL: extra_dummy: 0
D (2150) spi_flash: trying chip: issi
D (2154) spi_flash: trying chip: gd
D (2158) spi_flash: trying chip: mxic
D (2161) spi_flash: trying chip: winbond
I (2165) spi_flash: detected chip: winbond
I (2170) spi_flash: flash io: dio
D (2174) cpu_start: calling init function: 0x4210ae14
D (2179) cpu_start: calling init function: 0x4210add0
D (2184) cpu_start: calling init function: 0x420fa3e4
D (2189) cpu_start: calling init function: 0x420ee4dc
D (2195) cpu_start: calling init function: 0x4207dc7c
D (2200) cpu_start: calling init function: 0x4207bcf0
D (2205) cpu_start: calling init function: 0x42079948
D (2210) intr_alloc: Connected src 59 to int 2 (cpu 0)
I (2215) sleep: Configure to isolate all GPIO pins in sleep state
I (2222) sleep: Enable automatic switching of GPIO sleep configuration
I (2229) coexist: coexist rom version e7ae62f
D (2235) intr_alloc: Connected src 79 to int 3 (cpu 0)
I (2239) cpu_start: Starting scheduler on PRO CPU.
D (2245) intr_alloc: Connected src 57 to int 9 (cpu 0)
D (2245) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (2255) cpu_start: Starting scheduler on APP CPU.
D (2255) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (2275) heap_init: New heap initialised at 0x3fce9710
I (2275) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (2275) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (2285) rmt: rmt_source_clk_hz: 80000000

D (2285) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2295) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2305) rmt: RMT translator init done
I (2305) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (2315) rmt: rmt_source_clk_hz: 80000000

D (2315) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2325) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2335) rmt: RMT translator init done
D (2435) rmt: rmt_source_clk_hz: 80000000

D (2445) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2445) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2445) rmt: RMT translator init done
D (2565) rmt: rmt_source_clk_hz: 80000000

D (2565) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2565) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2575) rmt: RMT translator init done
D (2685) rmt: rmt_source_clk_hz: 80000000

D (2695) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2695) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2695) rmt: RMT translator init done
D (2815) rmt: rmt_source_clk_hz: 80000000

D (2815) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2815) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2825) rmt: RMT translator init done
D (2935) rmt: rmt_source_clk_hz: 80000000

D (2945) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2945) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2945) rmt: RMT translator init done
D (3065) rmt: rmt_source_clk_hz: 80000000

D (3065) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (3065) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (3075) rmt: RMT translator init done
D (3185) rmt: rmt_source_clk_hz: 80000000

D (3195) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (3195) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (3195) rmt: RMT translator init done
I (3315) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3315) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
D (3325) partition: Loading the partition table
D (3325) partition: Partition table MD5 verified
I (3335) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3345) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3355) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3355) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3365) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3375) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3385) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3395) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3405) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3415) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3425) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3435) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3445) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3455) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3465) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3475) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3485) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3495) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3495) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3505) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3515) gpio: GPIO[33]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3525) gpio: GPIO[34]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3535) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3545) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3555) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3565) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3575) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3585) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3595) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3605) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3615) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3625) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
E (3635) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (3635) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
E (3645) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (3655) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (3655) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (3665) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
D (3715) esp_netif_lwip: LwIP stack has been initialized
D (3715) esp_netif_lwip: esp-netif has been successfully initialized
D (3715) event: created task for loop 0x3fcebaa0
D (3715) event: running task for loop 0x3fcebaa0
D (3725) event: created event loop 0x3fcebaa0
D (3735) esp_netif_objects: esp_netif_add_to_list 0x3fcec9cc
D (3735) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (3745) esp_netif_objects: esp_netif_add_to_list 0x3fcecd98
D (3755) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
I (3765) pp: pp rom version: e7ae62f
I (3765) net80211: net80211 rom version: e7ae62f
I (3785) wifi:wifi driver task: 3fcee9f4, prio:23, stack:3584, core=0
I (3785) system_api: Base MAC address is not set
I (3785) system_api: read default base MAC address from EFUSE
D (3795) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (3795) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (3805) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (3815) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (3825) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (3825) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
I (3835) wifi:wifi firmware version: f1d33cc
I (3835) wifi:wifi certification version: v7.0
I (3845) wifi:config NVS flash: disabled
I (3845) wifi:config nano formating: disabled
I (3855) wifi:Init data frame dynamic rx buffer num: 8
I (3855) wifi:Init management frame dynamic rx buffer num: 8
I (3865) wifi:Init management short buffer num: 32
I (3865) wifi:Init dynamic tx buffer num: 16
I (3865) wifi:Init tx cache buffer num: 16
I (3875) wifi:Init static tx FG buffer num: 2
I (3875) wifi:Init static rx buffer size: 1600
I (3885) wifi:Init static rx buffer num: 4
I (3885) wifi:Init dynamic rx buffer num: 8
I (3885) wifi_init: rx ba win: 6
I (3895) wifi_init: tcpip mbox: 32
I (3895) wifi_init: udp mbox: 6
I (3905) wifi_init: tcp mbox: 6
I (3905) wifi_init: tcp tx win: 2880
I (3905) wifi_init: tcp rx win: 2880
I (3915) wifi_init: tcp mss: 1440
I (3915) wifi_init: WiFi IRAM OP enabled
I (3925) wifi_init: WiFi RX IRAM OP enabled
D (3925) ADC: Wi-Fi takes adc2 lock.
I (3935) phy_init: phy_version 503,13653eb,Jun  1 2022,17:47:08
D (3935) phy_init: loading PHY init data from application binary
D (3945) nvs: nvs_open_from_partition phy 0
E (3945) phy_init: esp_phy_load_cal_data_from_nvs: NVS has not been initialized. Call nvs_flash_init before starting WiFi/BT.
W (3955) phy_init: failed to load RF calibration data (0x1101), falling back to full calibration
D (3965) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (3975) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (3985) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (3985) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (3995) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (4005) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
D (4035) nvs: nvs_open_from_partition phy 1
D (4035) phy_init: esp_phy_store_cal_data_to_nvs: failed to open NVS namespace (0x1101)
D (4035) wifi:filter: set rx policy=0
I (4035) wifi:mode : sta (70:04:1d:ad:c3:fc)
I (4045) wifi:enable tsf
D (4045) wifi:filter: set rx policy=1
D (4045) wifi:connect status 0 -> 0
D (4055) event: running post WIFI_EVENT:2 with handler 0x4207dfe0 and context 0x3fcecc44 on loop 0x3fcebaa0
D (4055) wifi:clear blacklist
D (4065) wifi_init_default: wifi_start esp-netif:0x3fcec9cc event-id2
D (4075) wifi_init_default: WIFI mac address: 70 4 1d ad c3 fc
D (4075) wifi:Start wifi connect
D (4075) wifi:connect status 0 -> 0
D (4085) wifi:connect chan=0
D (4085) wifi:first chan=1
D (4085) wifi:connect status 0 -> 1
D (4095) wifi:filter: set rx policy=3
D (4095) wifi:clear scan ap list
D (4095) wifi:start scan: type=0x50f, priority=2, cb=0x420cc0e0, arg=0, ss_state=0x1, time=4102949, index=0
D (4105) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
D (4115) esp_netif_handlers: esp_netif action has started with netif0x3fcec9cc from event_id=2
D (4125) esp_netif_lwip: check: remote, if=0x3fcec9cc fn=0x4207a5dc

D (4125) esp_netif_lwip: esp_netif_start_api 0x3fcec9cc
D (4135) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fcec9cc
D (4135) esp_netif_lwip: check: local, if=0x3fcec9cc fn=0x4207af3c

D (4145) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcec9cc
D (4155) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (4155) event: running post WIFI_EVENT:2 with handler 0x42038f44 and context 0x3fcecf94 on loop 0x3fcebaa0
W (4165) CP wifi: sta start
D (4235) wifi:scan end: arg=0, status=0, ss_state=0x3
D (4235) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
D (4355) wifi:scan end: arg=0, status=0, ss_state=0x3
D (4355) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
D (4475) wifi:scan end: arg=0, status=0, ss_state=0x3
D (4475) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
D (4595) wifi:scan end: arg=0, status=0, ss_state=0x3
D (4595) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120>
D (4715) wifi:scan end: arg=0, status=0, ss_state=0x3
D (4715) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
D (4835) wifi:scan end: arg=0, status=0, ss_state=0x3
D (4835) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120>
D (4955) wifi:scan end: arg=0, status=0, ss_state=0x3
D (4955) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120>
D (5075) wifi:scan end: arg=0, status=0, ss_state=0x3
D (5075) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120>
D (5125) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (5125) wifi:profile match: ss_state=0x7
D (5195) wifi:scan end: arg=0, status=0, ss_state=0x7
D (5195) wifi:perform scan: ss_state=0xd, chan<10,0>, dur<0,120>
D (5315) wifi:scan end: arg=0, status=0, ss_state=0x7
D (5325) wifi:perform scan: ss_state=0xd, chan<11,0>, dur<0,120>
D (5445) wifi:scan end: arg=0, status=0, ss_state=0x7
D (5445) wifi:perform scan: ss_state=0xd, chan<12,0>, dur<360,360>
D (5805) wifi:scan end: arg=0, status=0, ss_state=0x7
D (5805) wifi:perform scan: ss_state=0xd, chan<13,0>, dur<360,360>
D (6165) wifi:scan end: arg=0, status=0, ss_state=0x7
D (6165) wifi:perform scan: ss_state=0xd, chan<14,0>, dur<360,360>
D (6525) wifi:scan end: arg=0, status=0, ss_state=0x7
D (6525) wifi:filter: set rx policy=4
D (6525) wifi:first chan=1
D (6525) wifi:handoff_cb: status=0
D (6525) wifi:ap found, mac=e4:c3:2a:e3:14:31
D (6525) wifi:new_bss=0x3fca9c40, cur_bss=0, new_chan=<9,0>, cur_chan=1
D (6535) wifi:filter: set rx policy=5
I (6535) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:1
D (6545) wifi:connect_op: status=0, auth=5, cipher=3
D (6555) gdma: new group (0) at 0x3fcb81dc
D (6555) gdma: new pair (0,0) at 0x3fcb8218
D (6555) gdma: new tx channel (0,0) at 0x3fcb8090
D (6565) gdma: new rx channel (0,0) at 0x3fcb8238
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). 
Exception was unhandled.  <<<================  .env present in Drive

Core  0 register dump:
PC      : 0x40056ea0  PS      : 0x00060130  A0      : 0x8002f1fd  A1      : 0x3fcedfe0
A2      : 0x00000001  A3      : 0x00000000  A4      : 0x00000000  A5      : 0x3fcee083
A6      : 0x4002eb04  A7      : 0x00000000  A8      : 0x3fcf0ec5  A9      : 0x3fcf0ec6
A10     : 0x3fceea54  A11     : 0x00000020  A12     : 0x3fcf0c44  A13     : 0x3fcee083
A14     : 0x3fcee059  A15     : 0x00ffffff  SAR     : 0x0000000f  EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000001  LBEG    : 0x400570e8  LEND    : 0x400570f3  LCOUNT  : 0x00000000

Backtrace: 0x40056e9d:0x3fcedfe0 |<-CORRUPTED

ELF file SHA256: 7adcc34a72169957```

Next, when I reflash tthe tinyuf2 bootloader and then copy the 'normal' file (adafruit-circuitpython-unexpectedmaker_feathers3-en_US-20221023-edce717.uf2), downloaded from 'circuitpython.org',
(Adafruit CircuitPython 8.0.0-beta.3-11-gedce717cf on 2022-10-23; FeatherS3 with ESP32S3)
then the script runs OK and automatic connection to WiFi, using the credentials from file '.env' works OK.
The CPY statatusbar showed an IP-address.
PaulskPt commented 2 years ago
Wednesday 2022-10-26 11h48 utc+1

board: Unexpected Maker FeatherS3

Flashed
1) Adafruit tinyuf2 bootloader;
2) Own build: Adafruit CircuitPython 8.0.0-beta.3-12-gf67d2794c-dirty   with DEBUG=1

Serial output using PuTTY on desktop PC MS Windows 11 Pro:

1st boot:
---------

Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1644
load:0x403b6000,len:0xf1c
load:0x403ba000,len:0x31c8
entry 0x403b634c
I (25) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader
I (25) boot: compile time 11:37:31
I (25) boot: chip revision: 0
I (28) qio_mode: Enabling QIO for flash chip WinBond
I (33) boot.esp32s3: Boot SPI Speed : 80MHz
I (38) boot.esp32s3: SPI Mode       : QIO
I (43) boot.esp32s3: SPI Flash Size : 16MB
I (48) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (72) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (79) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (86) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (94) boot:  4 uf2              factory app      00 00 00410000 00040000
I (101) boot:  5 ffat             Unknown data     01 81 00450000 00bb0000
I (109) boot: End of partition table
I (613) esp_image: segment 0: paddr=00010020 vaddr=3c110020 size=2bef0h (179952) map
I (645) esp_image: segment 1: paddr=0003bf18 vaddr=3fc9a520 size=04100h ( 16640) load
I (649) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=103bd4h (1063892) map
I (813) esp_image: segment 3: paddr=00143bfc vaddr=3fc9e620 size=00358h (   856) load
I (813) esp_image: segment 4: paddr=00143f5c vaddr=40374000 size=1651ch ( 91420) load
I (836) esp_image: segment 5: paddr=0015a480 vaddr=600fe000 size=0002ch (    44) load
I (836) esp_image: segment 6: paddr=0015a4b4 vaddr=600fe030 size=01010h (  4112) load
I (851) boot: Loaded app from partition at offset 0x10000
I (852) boot: Disabling RNG early entropy source...
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x0 (DOWNLOAD(USB/UART0))
waiting for download                                         # | <<<=== Put board in DFU mode 

Started the Espressif Flash Download Tool V3.9.3
-------------------------------------------------
Settings: 
SPI SPEED: 40 MHz
SPI MODE: QIO
DoNotChgBin: checked
After pressing 'START' button the following info appeared:

- In 'DetectedInfo':
flash vendor:
EFh: W
flash devID:
4018h
QUAD; 128Mbit
crystal:
40 Mhz

- In 'DownlaoadPanel 1':
AP:  70041DADC3FD  STA:  70041DADC3FC
BT:  70041DADC3FE  ETHERNET:  70041DADC3FF

a) Erase Flash
--------------

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x0 (DOWNLOAD(USB/UART0))
Saved PC:0x40041a7c
waiting for download
▒OHAI▒▒
       ▒▒▒▒
        ▒▒
          ▒▒
            ▒▒
              ▒▒
                ▒▒
                  ▒▒
                    ▒▒
                      ▒í▒▒
                          p▒▒
                             ▒▒
                               ▒▒
                                 ▒(▒▒
                                     $▒▒▒▒▒
                                           ▒▒▒▒▒
                                                I▒▒▒▒
                                                     ▒*▒▒▒
                                                          ▒▒i▒▒
                                                               ▒,▒▒▒
                                                                    ӲV▒▒▒
                                                                         ▒▒▒▒▒▒▒
                                                                                ▒▒M▒▒
                                                                                     ▒▒
                                                                                       ▒▒
                                                                                         ▒▒
                                                                                           ▒▒
                                                                                             ▒▒
                                                                                               ▒▒
                                                                                                 ▒▒
                                                                                                   ▒▒
                                                                                                     ▒▒
                                                                                                       ▒▒
                                                                                                         ▒▒
                                                                                                           ▒▒
                                                                                                             ▒▒
                                                                                                               ▒▒
                                                                                                                 ▒▒
                                                                                                                   ▒▒
                                                                                                                     ▒▒
                                                                                                                       ▒▒
                                                                                                                         ▒▒
                                                                                                                           ▒▒
                                                                                                                             ▒▒
                                                                                                                               ▒▒
                                                                                                                                 ▒▒
                                                                                                                                   ▒▒
                                                                                                                                     ▒▒
                                                                                                                                       ▒▒
                                                                                                                                         ▒▒
                                                                                                                                           ▒▒
                                                                                                                                             ▒▒
                                                                                                                                               ▒▒
                                                                                                                                                 ▒▒
                                                                                                                                                   ▒▒
                                                                                                                                                     ▒▒
                                                                                                                                                       ▒▒
                                                                                                                                                         ▒▒
                                                                                                                                                           ▒▒
                                                                                                                                                             ▒▒
                                                                                                                                                               ▒▒
                                                                                                                                                                 ▒▒
                                                                                                                                                                   ▒▒
                                                                                                                                                                     ▒▒
                                                                                                                                                                       ▒▒
                                                                                                                                                                         ▒▒
                                                                                                                                                                           ▒▒
                                                                                                                                                                             ▒▒
                                                                                                                                                                               ▒▒
 ▒▒
   ▒▒
     ▒▒
       ▒▒
         ▒▒
           ▒▒
             ▒▒
               ▒▒
                 ▒▒
                   ▒▒
                     ▒▒
                       ▒▒
                         ▒▒
                           ▒▒
                             ▒▒
                               ▒▒
                                 ▒▒
                                   ▒▒
                                     ▒▒
                                       ▒▒
                                         ▒▒
                                           ▒▒
                                             ▒▒
                                               ▒▒
                                                 ▒▒
                                                   ▒í▒▒
                                                       p▒▒
                                                          [0▒▒
                                                              ▒▒▒
                                                                 p▒▒    ▒▒      ▒▒      ▒▒      ▒▒      ▒▒
                                                                                                          ▒▒
                                                                                                            ▒@▒▒        ▒▒      ▒▒
                                                                                                                                  ▒▒▒
                                                                                                                                     p▒▒        ▒▒      ▒▒      ▒▒      ▒▒     ▒▒
 ▒▒
   ▒▒   ▒▒      ▒▒
                  ▒▒▒
                     p▒▒        ▒▒      ▒▒      ▒▒      ▒▒      ▒▒
                                                                  ▒▒
                                                                    ▒▒  ▒▒      ▒▒
                                                                                  ▒▒▒
                                                                                     p▒▒        ▒▒      ▒▒      ▒▒      ▒▒      ▒▒
                                                                                                                                  ▒▒
                                                                                                                                    `▒▒ ▒▒      ▒▒▒▒

a.2) flash erase finished

b) flashed Adafruit tinyuf2 to 0x0
(file: C:\Users\pauls2\Downloads\tinyuf2_feathers3\combined.bin)
-----------------------------------

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x0 (DOWNLOAD(USB/UART0))
Saved PC:0x40378b3c
waiting for download
▒OHAI▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒

b.2) flash tinyuf2 finished 

After pressing the board's RST button,
the Boot disk came up.

Serial output:

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1644
load:0x403b6000,len:0xf1c
load:0x403ba000,len:0x31c8
entry 0x403b634c
I (25) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader
I (25) boot: compile time 11:37:31
I (25) boot: chip revision: 0
I (28) qio_mode: Enabling QIO for flash chip WinBond
I (33) boot.esp32s3: Boot SPI Speed : 80MHz
I (38) boot.esp32s3: SPI Mode       : QIO
I (43) boot.esp32s3: SPI Flash Size : 16MB
I (48) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (72) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (79) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (86) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (94) boot:  4 uf2              factory app      00 00 00410000 00040000
I (101) boot:  5 ffat             Unknown data     01 81 00450000 00bb0000
I (109) boot: End of partition table
I (113) boot: Defaulting to factory image
I (118) esp_image: segment 0: paddr=00410020 vaddr=3c020020 size=048cch ( 18636) map
I (129) esp_image: segment 1: paddr=004148f4 vaddr=3fc90390 size=01c84h (  7300) load
I (136) esp_image: segment 2: paddr=00416580 vaddr=40374000 size=09a98h ( 39576) load
I (151) esp_image: segment 3: paddr=00420020 vaddr=42000020 size=148a8h ( 84136) map
I (165) esp_image: segment 4: paddr=004348d0 vaddr=4037da98 size=028f4h ( 10484) load
I (167) esp_image: segment 5: paddr=004371cc vaddr=50000000 size=00010h (    16) load
I (175) boot: Loaded app from partition at offset 0x410000
I (180) boot: Disabling RNG early entropy source...
I (193) cpu_start: Pro cpu up.
I (194) cpu_start: Starting app cpu, entry point is 0x40374d34
I (0) cpu_start: App cpu up.
I (208) cpu_start: Pro cpu start user code
I (208) cpu_start: cpu freq: 160000000
I (208) cpu_start: Application information:
I (210) cpu_start: Project name:     tinyuf2
I (215) cpu_start: App version:      0.11.0
I (220) cpu_start: Compile time:     Oct 17 2022 11:37:26
I (226) cpu_start: ELF file SHA256:  34c7d86ecf947ca0...
I (232) cpu_start: ESP-IDF:          v4.4.2-378-g9269a536ac
I (239) heap_init: Initializing. RAM available for dynamic allocation:
I (246) heap_init: At 3FCA5720 len 00043FF0 (271 KiB): D/IRAM
I (252) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (259) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (265) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (272) spi_flash: detected chip: winbond
                                         I (276) spi_flash: flash io: qio
                                                                         I (280) sleep: Configure to isolate all GPIO pins in sleep state
I (287) sleep: Enable automatic switching of GPIO sleep configuration
I (294) cpu_start: Starting scheduler on PRO CPU.
                                                 I (0) cpu_start: Starting scheduler on APP CPU.
I (314) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
                                                                                              I (36744) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4d0d4h (315604) map
    I (36784) esp_image: segment 1: paddr=0005d0fc vaddr=3fc9bd40 size=02f1ch ( 12060)
                                                                                       I (36784) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=114b94h (1133460) map
                                                                                                                                                                               I (36914) esp_image: segment 3: paddr=00174bbc vaddr=3fc9ec5c size=02250h (  8784)
                                                                                  I (36914) esp_image: segment 4: paddr=00176e14 vaddr=40374000 size=17d3ch ( 97596)
                                                                                                                                                                     I (36924) esp_image: segment 5: paddr=0018eb58 vaddr=600fe000 size=0002ch (    44)
                                                                        I (36924) esp_image: segment 6: paddr=0018eb8c vaddr=600fe030 size=01010h (  4112)

---------------------
Boot after successfull copy of file 'firmware.uf2' (containing the FeatherS3 CPY V8 b.3-11 with DEBUG=1):

Contents file 'boot_out.txt':
Adafruit CircuitPython 8.0.0-beta.3-12-gf67d2794c-dirty on 2022-10-26; FeatherS3 with ESP32S3
Board ID:unexpectedmaker_feathers3
UID:0740D1DA3CCF
----------------

Serial output: 

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40375398
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0108,len:0x1644
load:0x403b6000,len:0xf1c
load:0x403ba000,len:0x31c8
entry 0x403b634c
I (29) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader
I (29) boot: compile time 11:37:31
I (29) boot: chip revision: 0
I (32) qio_mode: Enabling QIO for flash chip WinBond
I (38) boot.esp32s3: Boot SPI Speed : 80MHz
I (43) boot.esp32s3: SPI Mode       : QIO
I (47) boot.esp32s3: SPI Flash Size : 16MB
I (52) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (61) boot: ## Label            Usage          Type ST Offset   Length
I (68) boot:  0 nvs              WiFi data        01 02 00009000 00005000
I (76) boot:  1 otadata          OTA data         01 00 0000e000 00002000
I (83) boot:  2 ota_0            OTA app          00 10 00010000 00200000
I (91) boot:  3 ota_1            OTA app          00 11 00210000 00200000
I (98) boot:  4 uf2              factory app      00 00 00410000 00040000
I (106) boot:  5 ffat             Unknown data     01 81 00450000 00bb0000
I (113) boot: End of partition table
I (618) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4d0d4h (315604) map
I (666) esp_image: segment 1: paddr=0005d0fc vaddr=3fc9bd40 size=02f1ch ( 12060) load
I (668) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=114b94h (1133460) map
I (844) esp_image: segment 3: paddr=00174bbc vaddr=3fc9ec5c size=02250h (  8784) load
I (846) esp_image: segment 4: paddr=00176e14 vaddr=40374000 size=17d3ch ( 97596) load
I (868) esp_image: segment 5: paddr=0018eb58 vaddr=600fe000 size=0002ch (    44) load
I (868) esp_image: segment 6: paddr=0018eb8c vaddr=600fe030 size=01010h (  4112) load
I (884) boot: Loaded app from partition at offset 0x10000
I (884) boot: Disabling RNG early entropy source...
I (897) spiram: Found 64MBit SPI RAM device
I (897) spiram: SPI RAM mode: sram 80m
I (897) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (902) cpu_start: Pro cpu up.
I (906) cpu_start: Starting app cpu, entry point is 0x4037847c
I (890) cpu_start: App cpu up.
I (1830) spiram: SPI SRAM memory test OK
D (1830) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit
D (1831) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit
D (1837) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (1845) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (1852) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit
D (1859) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (1866) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (1873) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (1880) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (1887) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (1894) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (1901) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (1908) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (1916) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (1923) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (1938) clk: RTC_SLOW_CLK calibration value: 3563302
I (1946) cpu_start: Pro cpu start user code
I (1946) cpu_start: cpu freq: 240000000
I (1946) cpu_start: Application information:
I (1949) cpu_start: Project name:     circuitpython
I (1955) cpu_start: App version:      8.0.0-beta.3-33-gf67d2794c-dirt
I (1962) cpu_start: Compile time:     Oct 26 2022 00:33:49
I (1968) cpu_start: ELF file SHA256:  7adcc34a72169957...
I (1974) cpu_start: ESP-IDF:          716d8531d7
D (1980) memory_layout: Checking 6 reserved memory ranges:
D (1985) memory_layout: Reserved memory range 0x3d000000 - 0x3e000000
D (1992) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9bd3c
D (1998) memory_layout: Reserved memory range 0x3fc9bd40 - 0x3fcad4c0
D (2005) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (2011) memory_layout: Reserved memory range 0x40374000 - 0x4038bd3c
D (2018) memory_layout: Reserved memory range 0x600fe000 - 0x600ff040
D (2024) memory_layout: Building list of available memory regions:
D (2030) memory_layout: Available memory region 0x3fcad4c0 - 0x3fcb0000
D (2037) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
D (2044) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
D (2050) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
D (2057) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710
D (2064) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34
D (2070) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
D (2077) memory_layout: Available memory region 0x600ff040 - 0x60100000
I (2084) heap_init: Initializing. RAM available for dynamic allocation:
D (2091) heap_init: New heap initialised at 0x3fcad4c0
I (2096) heap_init: At 3FCAD4C0 len 0003C250 (240 KiB): D/IRAM
I (2103) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
D (2110) heap_init: New heap initialised at 0x3fcf0000
I (2115) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (2121) heap_init: New heap initialised at 0x600ff040
I (2126) heap_init: At 600FF040 len 00000FC0 (3 KiB): RTCRAM
D (2133) FLASH_HAL: extra_dummy: 0
D (2136) spi_flash: trying chip: issi
D (2140) spi_flash: trying chip: gd
D (2144) spi_flash: trying chip: mxic
D (2147) spi_flash: trying chip: winbond
I (2151) spi_flash: detected chip: winbond
I (2156) spi_flash: flash io: dio
D (2160) cpu_start: calling init function: 0x4210ae14
D (2165) cpu_start: calling init function: 0x4210add0
D (2170) cpu_start: calling init function: 0x420fa3e4
D (2175) cpu_start: calling init function: 0x420ee4dc
D (2180) cpu_start: calling init function: 0x4207dc7c
D (2186) cpu_start: calling init function: 0x4207bcf0
D (2191) cpu_start: calling init function: 0x42079948
D (2196) intr_alloc: Connected src 59 to int 2 (cpu 0)
I (2201) sleep: Configure to isolate all GPIO pins in sleep state
I (2208) sleep: Enable automatic switching of GPIO sleep configuration
I (2215) coexist: coexist rom version e7ae62f
D (2220) intr_alloc: Connected src 79 to int 3 (cpu 0)
I (2225) cpu_start: Starting scheduler on PRO CPU.
D (2231) intr_alloc: Connected src 57 to int 9 (cpu 0)
D (2231) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (2241) cpu_start: Starting scheduler on APP CPU.
D (2241) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (2261) heap_init: New heap initialised at 0x3fce9710
I (2261) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (2261) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (2271) rmt: rmt_source_clk_hz: 80000000

D (2271) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2281) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2291) rmt: RMT translator init done
I (2291) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (2301) rmt: rmt_source_clk_hz: 80000000

D (2301) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2311) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2321) rmt: RMT translator init done
D (2431) rmt: rmt_source_clk_hz: 80000000

D (2431) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2431) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2431) rmt: RMT translator init done
D (2551) rmt: rmt_source_clk_hz: 80000000

D (2551) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2551) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2561) rmt: RMT translator init done
D (2681) rmt: rmt_source_clk_hz: 80000000

D (2681) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2681) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2681) rmt: RMT translator init done
D (2801) rmt: rmt_source_clk_hz: 80000000

D (2801) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2801) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2811) rmt: RMT translator init done
D (2931) rmt: rmt_source_clk_hz: 80000000

D (2931) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (2931) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (2931) rmt: RMT translator init done
D (3051) rmt: rmt_source_clk_hz: 80000000

D (3051) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (3051) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (3061) rmt: RMT translator init done
D (3181) rmt: rmt_source_clk_hz: 80000000

D (3181) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (3181) intr_alloc: Connected src 40 to int 4 (cpu 1)
D (3181) rmt: RMT translator init done
I (3301) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (3301) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
D (3311) partition: Loading the partition table
D (3311) partition: Partition table MD5 verified
I (7891) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7891) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7901) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7911) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7921) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7931) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7941) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7951) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7951) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7961) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7971) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7981) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (7991) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8001) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8011) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8021) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8031) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8041) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8051) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8061) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8071) gpio: GPIO[33]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8081) gpio: GPIO[34]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8091) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8101) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8101) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8111) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8121) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8131) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8141) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8151) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8161) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (8171) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
E (8181) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (8191) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
E (8191) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (8201) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (8211) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
E (8211) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR
I (9501) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9501) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9511) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9521) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9531) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9541) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9551) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9561) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9571) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9571) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9581) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9591) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9601) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9611) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9621) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9631) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9641) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9651) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9661) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9671) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9681) gpio: GPIO[33]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9691) gpio: GPIO[34]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9701) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9711) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9711) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9721) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9731) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9741) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9751) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9761) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9771) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9781) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
E (9791) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (9801) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
I (9891) espidf: Reserving 0 bytes of psram
D (9891) intr_alloc: Connected src 38 to int 4 (cpu 1)
I (9961) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9961) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9971) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9971) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9981) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (9991) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10001) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10011) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10021) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10031) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10041) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10051) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10061) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10071) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10081) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10091) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10101) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10111) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10121) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10131) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10131) gpio: GPIO[33]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10141) gpio: GPIO[34]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10151) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10161) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10171) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10181) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10191) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10201) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10211) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10221) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10231) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (10241) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
E (10251) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (10261) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
I (11101) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (11101) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (11111) rmt: rmt_source_clk_hz: 80000000

D (11111) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (11121) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (11121) rmt: RMT translator init done
D (11131) rmt: rmt_source_clk_hz: 80000000

D (11131) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (11141) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (11141) rmt: RMT translator init done
D (11201) rmt: rmt_source_clk_hz: 80000000

D (11201) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (11201) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (11201) rmt: RMT translator init done
I (11211) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (11221) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13901) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13901) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13911) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13921) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13931) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13941) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13951) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13951) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13961) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13971) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13981) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (13991) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14001) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14011) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14021) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14031) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14041) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14051) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14061) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14071) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14081) gpio: GPIO[33]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14091) gpio: GPIO[34]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14101) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14111) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14121) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14121) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14131) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14141) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14151) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14161) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14171) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14181) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
E (14191) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (14201) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
I (14301) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (14301) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (14311) rmt: rmt_source_clk_hz: 80000000

D (14311) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (14321) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (14331) rmt: RMT translator init done
D (14331) rmt: rmt_source_clk_hz: 80000000

D (14331) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (14341) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (14351) rmt: RMT translator init done
D (14401) rmt: rmt_source_clk_hz: 80000000

D (14401) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (14401) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (14411) rmt: RMT translator init done
I (14411) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (14421) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (19701) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (19701) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (19711) rmt: rmt_source_clk_hz: 80000000

D (19711) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (19721) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (19731) rmt: RMT translator init done
D (19731) rmt: rmt_source_clk_hz: 80000000

D (19731) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (19741) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (19751) rmt: RMT translator init done
D (19851) rmt: rmt_source_clk_hz: 80000000

D (19851) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (19851) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (19861) rmt: RMT translator init done
I (19861) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (19871) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0

This cycle keeps repeathing every ca. 10 seconds:
-------------------------------------------------
I (19701) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (19701) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (19711) rmt: rmt_source_clk_hz: 80000000

D (19711) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (19721) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (19731) rmt: RMT translator init done
D (19731) rmt: rmt_source_clk_hz: 80000000

D (19731) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (19741) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (19751) rmt: RMT translator init done
D (19851) rmt: rmt_source_clk_hz: 80000000

D (19851) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (19851) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (19861) rmt: RMT translator init done
I (19861) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (19871) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
---------------------------------------------------
while the contents of file 'code.py' is:
print("Hello World!")
---------------------------------------------------

At moment of copying 3 files to the drive: 'code.py' (a simple WiFi connection (not yet active) script); secrets.py; feathers3.py.
the following serial output appeared:

D (1182751) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1182751) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1182751) rmt: RMT translator init done
I (1182761) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1182771) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1182991) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1182991) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1182991) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183001) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183011) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183021) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183031) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183041) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183051) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183061) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183071) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183081) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183091) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183101) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183111) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183171) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183231) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183241) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183251) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183251) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183261) gpio: GPIO[33]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183271) gpio: GPIO[34]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183281) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183291) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183301) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183311) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183321) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183331) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183341) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183351) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183361) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183371) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
E (1183381) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (1183391) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
I (1183491) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1183491) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (1183491) rmt: rmt_source_clk_hz: 80000000

D (1183501) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1183511) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1183511) rmt: RMT translator init done
D (1183521) rmt: rmt_source_clk_hz: 80000000

D (1183521) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1183531) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1183531) rmt: RMT translator init done
D (1183591) rmt: rmt_source_clk_hz: 80000000

D (1183591) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1183591) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1183591) rmt: RMT translator init done
I (1183601) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183611) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1183891) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1183891) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (1184021) rmt: rmt_source_clk_hz: 80000000

D (1184021) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1184081) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1184081) rmt: RMT translator init done
D (1184081) rmt: rmt_source_clk_hz: 80000000

D (1184081) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1184201) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1184201) rmt: RMT translator init done
D (1184201) rmt: rmt_source_clk_hz: 80000000

D (1184321) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1184321) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1184381) rmt: RMT translator init done
I (1184381) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1184391) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
D (1185211) esp_netif_lwip: LwIP stack has been initialized
D (1185211) esp_netif_lwip: esp-netif has been successfully initialized
D (1185211) event: created task for loop 0x3fcebb7c
D (1185211) event: running task for loop 0x3fcebb7c
D (1185221) event: created event loop 0x3fcebb7c
D (1185231) esp_netif_objects: esp_netif_add_to_list 0x3fcecaa8
D (1185231) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (1185241) esp_netif_objects: esp_netif_add_to_list 0x3fcece74
D (1185251) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
I (1185261) pp: pp rom version: e7ae62f
I (1185261) net80211: net80211 rom version: e7ae62f
I (1185281) wifi:wifi driver task: 3fceead0, prio:23, stack:3584, core=0
I (1185281) system_api: Base MAC address is not set
I (1185281) system_api: read default base MAC address from EFUSE
D (1185341) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (1185341) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (1185401) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (1185401) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (1185411) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (1185411) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
I (1185421) wifi:wifi firmware version: f1d33cc
I (1185431) wifi:wifi certification version: v7.0
I (1185431) wifi:config NVS flash: disabled
I (1185431) wifi:config nano formating: disabled
I (1185441) wifi:Init data frame dynamic rx buffer num: 8
I (1185441) wifi:Init management frame dynamic rx buffer num: 8
I (1185451) wifi:Init management short buffer num: 32
I (1185451) wifi:Init dynamic tx buffer num: 16
I (1185461) wifi:Init tx cache buffer num: 16
I (1185461) wifi:Init static tx FG buffer num: 2
I (1185471) wifi:Init static rx buffer size: 1600
I (1185471) wifi:Init static rx buffer num: 4
I (1185471) wifi:Init dynamic rx buffer num: 8
I (1185481) wifi_init: rx ba win: 6
I (1185481) wifi_init: tcpip mbox: 32
I (1185491) wifi_init: udp mbox: 6
I (1185491) wifi_init: tcp mbox: 6
I (1185501) wifi_init: tcp tx win: 2880
I (1185501) wifi_init: tcp rx win: 2880
I (1185501) wifi_init: tcp mss: 1440
I (1185511) wifi_init: WiFi IRAM OP enabled
I (1185511) wifi_init: WiFi RX IRAM OP enabled
D (1185521) ADC: Wi-Fi takes adc2 lock.
I (1185521) phy_init: phy_version 503,13653eb,Jun  1 2022,17:47:08
D (1185531) phy_init: loading PHY init data from application binary
D (1185541) nvs: nvs_open_from_partition phy 0
E (1185541) phy_init: esp_phy_load_cal_data_from_nvs: NVS has not been initialized. Call nvs_flash_init before starting WiFi/BT.
W (1185551) phy_init: failed to load RF calibration data (0x1101), falling back to full calibration
D (1185561) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (1185571) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (1185581) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (1185581) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (1185591) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (1185601) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
D (1185631) nvs: nvs_open_from_partition phy 1
D (1185631) phy_init: esp_phy_store_cal_data_to_nvs: failed to open NVS namespace (0x1101)
D (1185631) wifi:filter: set rx policy=0
I (1185641) wifi:mode : sta (70:04:1d:ad:c3:fc)
I (1185641) wifi:enable tsf
D (1185641) wifi:filter: set rx policy=1
D (1185651) wifi:connect status 0 -> 0
D (1185651) event: running post WIFI_EVENT:2 with handler 0x4207dfe0 and context 0x3fcecd20 on loop 0x3fcebb7c
D (1185661) wifi_init_default: wifi_start esp-netif:0x3fcecaa8 event-id2
D (1185671) wifi_init_default: WIFI mac address: 70 4 1d ad c3 fc
D (1185671) esp_netif_handlers: esp_netif action has started with netif0x3fcecaa8 from event_id=2
D (1185681) esp_netif_lwip: check: remote, if=0x3fcecaa8 fn=0x4207a5dc

D (1185691) esp_netif_lwip: esp_netif_start_api 0x3fcecaa8
D (1185691) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fcecaa8
D (1185701) esp_netif_lwip: check: local, if=0x3fcecaa8 fn=0x4207af3c

D (1185711) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcecaa8
D (1185721) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (1185721) event: running post WIFI_EVENT:2 with handler 0x42038f44 and context 0x3fced070 on loop 0x3fcebb7c
W (1185731) CP wifi: sta start
D (1185761) wifi:connect status 0 -> 0
D (1185761) wifi:Start wifi disconnect
D (1185761) wifi:connect status 0 -> 0
D (1185761) wifi:filter: set rx policy=8
D (1185771) wifi:filter: set rx policy=2
D (1185771) wifi:clear blacklist
D (1185771) wifi:clear rc list
I (1185781) wifi:flush txq
I (1185781) wifi:stop sw txq
D (1185781) wifi:filter: set rx policy=0
I (1185791) wifi:lmac stop hw txq
D (1185791) ADC: Wi-Fi returns adc2 lock.
D (1185791) event: running post WIFI_EVENT:3 with handler 0x4207deb0 and context 0x3fcecd50 on loop 0x3fcebb7c
D (1185801) esp_netif_handlers: esp_netif action stopped with netif0x3fcecaa8 from event_id=3
D (1185811) esp_netif_lwip: check: remote, if=0x3fcecaa8 fn=0x4207a828

D (1185821) esp_netif_lwip: call api in lwip: ret=0x5002, give sem
D (1185821) event: running post WIFI_EVENT:3 with handler 0x42038f44 and context 0x3fced070 on loop 0x3fcebb7c
W (1185831) CP wifi: sta stop
I (1185841) wifi:Deinit lldesc rx mblock:4
D (1185851) esp_netif_objects: esp_netif_remove_from_list netif successfully removed (total netifs: 1)
D (1185851) esp_netif_objects: esp_netif_remove_from_list netif successfully removed (total netifs: 0)
I (1185861) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1185871) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1185881) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1185891) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1185901) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1185961) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1185961) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186021) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186031) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186151) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186151) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186281) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186341) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186341) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186401) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186401) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186461) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186471) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186481) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186491) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186501) gpio: GPIO[33]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186511) gpio: GPIO[34]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186521) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186531) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186541) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186551) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186561) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186571) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186581) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186591) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186601) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186611) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
E (1186621) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed
E (1186621) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed
I (1186721) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1186721) gpio: GPIO[40]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
D (1186721) rmt: rmt_source_clk_hz: 80000000

D (1186731) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1186741) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1186741) rmt: RMT translator init done
D (1186751) rmt: rmt_source_clk_hz: 80000000

D (1186751) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1186761) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1186761) rmt: RMT translator init done
D (1186821) rmt: rmt_source_clk_hz: 80000000

D (1186821) rmt: Rmt Tx Channel 0|Gpio 40|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (1186821) intr_alloc: Connected src 40 to int 9 (cpu 1)
D (1186821) rmt: RMT translator init done
I (1186831) gpio: GPIO[40]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1186841) gpio: GPIO[39]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
D (1192081) esp_netif_objects: esp_netif_add_to_list 0x3fceec84
D (1192081) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (1192081) esp_netif_objects: esp_netif_add_to_list 0x3fcececc
D (1192091) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
I (1192101) pp: pp rom version: e7ae62f
I (1192101) net80211: net80211 rom version: e7ae62f
I (1192121) wifi:wifi driver task: 3fceead0, prio:23, stack:3584, core=0
I (1192121) wifi:wifi firmware version: f1d33cc
I (1192121) wifi:wifi certification version: v7.0
I (1192121) wifi:config NVS flash: disabled
I (1192131) wifi:config nano formating: disabled
I (1192131) wifi:Init data frame dynamic rx buffer num: 8
I (1192141) wifi:Init management frame dynamic rx buffer num: 8
I (1192141) wifi:Init management short buffer num: 32
I (1192151) wifi:Init dynamic tx buffer num: 16
I (1192151) wifi:Init tx cache buffer num: 16
I (1192161) wifi:Init static tx FG buffer num: 2
I (1192161) wifi:Init static rx buffer size: 1600
I (1192171) wifi:Init static rx buffer num: 4
I (1192171) wifi:Init dynamic rx buffer num: 8
I (1192171) wifi_init: rx ba win: 6
I (1192181) wifi_init: tcpip mbox: 32
I (1192181) wifi_init: udp mbox: 6
I (1192191) wifi_init: tcp mbox: 6
I (1192191) wifi_init: tcp tx win: 2880
I (1192191) wifi_init: tcp rx win: 2880
I (1192201) wifi_init: tcp mss: 1440
I (1192201) wifi_init: WiFi IRAM OP enabled
I (1192211) wifi_init: WiFi RX IRAM OP enabled
D (1192211) ADC: Wi-Fi takes adc2 lock.
D (1192221) wifi:filter: set rx policy=0
I (1192221) wifi:mode : sta (70:04:1d:ad:c3:fc)
I (1192231) wifi:enable tsf
D (1192231) wifi:filter: set rx policy=1
D (1192231) wifi:connect status 0 -> 0
D (1192231) event: running post WIFI_EVENT:2 with handler 0x4207dfe0 and context 0x3fcecd20 on loop 0x3fcebb7c
D (1192251) wifi_init_default: wifi_start esp-netif:0x3fceec84 event-id2
D (1192251) wifi_init_default: WIFI mac address: 70 4 1d ad c3 fc
D (1192261) esp_netif_handlers: esp_netif action has started with netif0x3fceec84 from event_id=2
D (1192271) esp_netif_lwip: check: remote, if=0x3fceec84 fn=0x4207a5dc

D (1192271) esp_netif_lwip: esp_netif_start_api 0x3fceec84
D (1192281) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fceec84
D (1192291) esp_netif_lwip: check: local, if=0x3fceec84 fn=0x4207af3c

D (1192291) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fceec84
D (1192301) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (1192311) event: running post WIFI_EVENT:2 with handler 0x42038f44 and context 0x3fcecc24 on loop 0x3fcebb7c
W (1192321) CP wifi: sta start

---------------------------------
from mu-editor V1.1.1 REPL:
Code done running.
]0;👗i-Fi: off | Done | 8.0.0-beta.3-12-gf67d2794c-dirty\Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.

Press any key to enter the REPL. Use CTRL-D to reload.
]0;👗i-Fi: off | REPL | 8.0.0-beta.3-12-gf67d2794c-dirty\
Adafruit CircuitPython 8.0.0-beta.3-12-gf67d2794c-dirty on 2022-10-26; FeatherS3 with ESP32S3
>>> import wifi
>>> ]0;👗i-Fi: No IP | REPL | 8.0.0-beta.3-12-gf67d2794c-dirty\
>>> from secrets import secrets
>>> ssid = secrets["ssid"]
>>> pw = secrets["password"]
>>> wifi.radio.connect(ssid=ssid, password=pw)

Serial output after this REPL command:

D (2959271) wifi:clear blacklist
D (2959271) wifi:Start wifi connect
D (2959271) wifi:connect status 0 -> 0
D (2959271) wifi:connect chan=0
D (2959271) wifi:first chan=1
D (2959271) wifi:connect status 0 -> 1
D (2959271) wifi:filter: set rx policy=3
D (2959281) wifi:clear scan ap list
D (2959281) wifi:start scan: type=0x50f, priority=2, cb=0x420cc0e0, arg=0, ss_state=0x1, time=-1335679433, index=0
D (2959291) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
D (2959421) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2959421) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
D (2959541) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2959541) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
D (2959661) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2959661) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
D (2959781) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2959781) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120>
D (2959901) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2959901) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
D (2960021) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2960021) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120>
D (2960141) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2960141) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120>
D (2960261) wifi:scan end: arg=0, status=0, ss_state=0x3
D (2960261) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120>
D (2960281) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (2960281) wifi:profile match: ss_state=0x7
D (2960381) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (2960381) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0>
D (2960391) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
D (2960391) wifi:profile match: ss_state=0x7
D (2960401) wifi:scan end: arg=0, status=0, ss_state=0x7
D (2960401) wifi:perform scan: ss_state=0xd, chan<10,0>, dur<0,120>
D (2960531) wifi:scan end: arg=0, status=0, ss_state=0x7
D (2960531) wifi:perform scan: ss_state=0xd, chan<11,0>, dur<0,120>
D (2960651) wifi:scan end: arg=0, status=0, ss_state=0x7
D (2960651) wifi:perform scan: ss_state=0xd, chan<12,0>, dur<360,360>
D (2961011) wifi:scan end: arg=0, status=0, ss_state=0x7
D (2961011) wifi:perform scan: ss_state=0xd, chan<13,0>, dur<360,360>
D (2961371) wifi:scan end: arg=0, status=0, ss_state=0x7
D (2961371) wifi:perform scan: ss_state=0xd, chan<14,0>, dur<360,360>
D (2961731) wifi:scan end: arg=0, status=0, ss_state=0x7
D (2961731) wifi:filter: set rx policy=4
D (2961731) wifi:first chan=1
D (2961731) wifi:handoff_cb: status=0
D (2961731) wifi:ap found, mac=e4:c3:2a:e3:14:31
D (2961741) wifi:new_bss=0x3fca9c40, cur_bss=0, new_chan=<9,0>, cur_chan=1
D (2961751) wifi:filter: set rx policy=5
I (2961751) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:1
D (2961761) wifi:connect_op: status=0, auth=5, cipher=3
D (2961761) gdma: new group (0) at 0x3fcb8374
D (2961771) gdma: new pair (0,0) at 0x3fcb7fd8
D (2961771) gdma: new tx channel (0,0) at 0x3fcb8344
D (2961771) gdma: new rx channel (0,0) at 0x3fcb83b0
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40056ea0  PS      : 0x00060930  A0      : 0x8002f1fd  A1      : 0x3fcee0b0
A2      : 0x00000001  A3      : 0x00000000  A4      : 0x00000000  A5      : 0x3fcee153
A6      : 0x4002eb04  A7      : 0x00000000  A8      : 0x3fcf0ec8  A9      : 0x3fcf0ec9
A10     : 0x3fceeb30  A11     : 0x00000020  A12     : 0x3fcf0c44  A13     : 0x3fcee153
A14     : 0x3fcee129  A15     : 0x00ffffff  SAR     : 0x0000000f  EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000001  LBEG    : 0x400570e8  LEND    : 0x400570f3  LCOUNT  : 0x00000000

Backtrace: 0x40056e9d:0x3fcee0b0 |<-CORRUPTED

ELF file SHA256: 7adcc34a72169957

CPU halted.
-------------------------------------------------------------
PaulskPt commented 2 years ago

So, with the 'own CPY V8 b.3-11.. build' for the FeatherS3, trying to establish a WiFi connection 'by hand', from the REPL, the board's CPU halted. When flashing the 'normal' CPY V8 b.3-11.., downloaded from 'circuitpython.org', WiFi contact establishes without problem on the UM FeatherS3.

OK, all this is 'noise'. The problem is with the Espressif ESP32-S3-Box.

PaulskPt commented 2 years ago

During a Ubuntu-Linux session, I saw that the '/circuitpython/ports/espressif/esp-idf' version is 4.4.2 while the documentation of espressif expresses that for the esp32s3 esp-idf 5.0 is needed. Perhaps this is the source of the problem. Can I clone esp-idf 5.0 into ' /circuitpython/ports/espressif' or is that esp-idf a special version prepared for circuitpython ?

PaulskPt commented 2 years ago

I copied 'esp-idf' (V 5.0) from elsewhere into /circuitpython/ports/espressif. It worked. firmware.uf2 etc built.

PaulskPt commented 2 years ago

@MicroDev1 Here is the serial output from the firmware.uf2 that you creaated / sent to me:

log ``` Thursday 2022-10-27 11h55 utc+1 Board: (Adafruit) Espressif ESP32-S3-BOX Flashed with Circuitpython firmware.uf2 received from @MicroDev Adafruit CircuitPython 8.0.0-beta.3-20-g2bba6a68e on 2022-10-27; ESP32-S3-Box-2.5 with ESP32S3 Serial Output (after Reset) via PuTTY at Com5 (desktop PC with MS Windows 11 Pro) ESP-ROM:esp32s3-2021 rst:0x1 (POWERON),boot:0xa (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (24) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (25) boot: compile time 11:36:39 I (25) boot: chip revision: 0 I (28) qio_mode: Enabling default flash chip QIO I (33) boot.esp32s3: Boot SPI Speed : 80MHz I (38) boot.esp32s3: SPI Mode : QIO I (42) boot.esp32s3: SPI Flash Size : 16MB I (47) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (56) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (71) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (78) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (86) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (93) boot: 4 uf2 factory app 00 00 00410000 00040000 I (101) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (108) boot: End of partition table I (613) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4cd18h (314648) map I (666) esp_image: segment 1: paddr=0005cd40 vaddr=3fc9c620 size=032d8h ( 13016) load I (668) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=114960h (1132896) map I (843) esp_image: segment 3: paddr=00174988 vaddr=3fc9f8f8 size=021dch ( 8668) load I (845) esp_image: segment 4: paddr=00176b6c vaddr=40374000 size=1861ch ( 99868) load I (868) esp_image: segment 5: paddr=0018f190 vaddr=600fe000 size=0002ch ( 44) load I (868) esp_image: segment 6: paddr=0018f1c4 vaddr=600fe030 size=01010h ( 4112) load I (885) boot: Loaded app from partition at offset 0x10000 I (885) boot: Disabling RNG early entropy source... I (897) opi psram: vendor id : 0x0d (AP) I (897) opi psram: dev id : 0x02 (generation 3) I (897) opi psram: density : 0x03 (64 Mbit) I (901) opi psram: good-die : 0x01 (Pass) I (906) opi psram: Latency : 0x01 (Fixed) I (910) opi psram: VCC : 0x01 (3V) I (915) opi psram: SRF : 0x01 (Fast Refresh) I (920) opi psram: BurstType : 0x01 (Hybrid Wrap) I (926) opi psram: BurstLen : 0x01 (32 Byte) I (931) opi psram: Readlatency : 0x02 (10 cycles@Fixed) I (937) opi psram: DriveStrength: 0x00 (1/1) W (942) PSRAM: DO NOT USE FOR MASS PRODUCTION! Timing parameters will be updated in future IDF version. D (953) MSPI Timing: tuning success, best point is index 5 I (957) spiram: Found 64MBit SPI RAM device I (962) spiram: SPI RAM mode: sram 80m I (967) spiram: PSRAM initialized, cache is in normal (1-core) mode. I (974) cpu_start: Pro cpu up. I (978) cpu_start: Starting app cpu, entry point is 0x4037856c I (0) cpu_start: App cpu up. I (1410) spiram: SPI SRAM memory test OK D (1411) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit D (1411) efuse: In EFUSE_BLK2__DATA4_REG is used 8 bits starting with 13 bit D (1418) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit D (1425) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit D (1432) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1439) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1446) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit D (1453) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1460) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1467) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1475) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1482) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1489) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1496) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1503) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1510) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1517) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1533) clk: RTC_SLOW_CLK calibration value: 4155085 I (1541) cpu_start: Pro cpu start user code I (1541) cpu_start: cpu freq: 240000000 I (1541) cpu_start: Application information: I (1544) cpu_start: Project name: circuitpython I (1549) cpu_start: App version: 8.0.0-beta.3-54-g2bba6a68e I (1556) cpu_start: Compile time: Oct 27 2022 16:02:43 I (1562) cpu_start: ELF file SHA256: b99a04578302db9b... I (1568) cpu_start: ESP-IDF: v4.4.2-381-g716d8531d7 D (1575) memory_layout: Checking 6 reserved memory ranges: D (1580) memory_layout: Reserved memory range 0x3d000000 - 0x3e000000 D (1587) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9c61c D (1593) memory_layout: Reserved memory range 0x3fc9c620 - 0x3fcae060 D (1600) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000 D (1606) memory_layout: Reserved memory range 0x40374000 - 0x4038c61c D (1613) memory_layout: Reserved memory range 0x600fe000 - 0x600ff040 D (1619) memory_layout: Building list of available memory regions: D (1625) memory_layout: Available memory region 0x3fcae060 - 0x3fcb0000 D (1632) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000 D (1639) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000 D (1645) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000 D (1652) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710 D (1659) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34 D (1665) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000 D (1672) memory_layout: Available memory region 0x600ff040 - 0x60100000 I (1679) heap_init: Initializing. RAM available for dynamic allocation: D (1686) heap_init: New heap initialised at 0x3fcae060 I (1691) heap_init: At 3FCAE060 len 0003B6B0 (237 KiB): D/IRAM I (1698) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM D (1705) heap_init: New heap initialised at 0x3fcf0000 I (1710) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM D (1716) heap_init: New heap initialised at 0x600ff040 I (1721) heap_init: At 600FF040 len 00000FC0 (3 KiB): RTCRAM I (1728) spiram: Adding pool of 8192K of external SPI memory to heap allocator D (1736) FLASH_HAL: extra_dummy: 0 D (1739) spi_flash: trying chip: issi D (1743) spi_flash: trying chip: gd I (1746) spi_flash: detected chip: gd I (1751) spi_flash: flash io: dio D (1755) cpu_start: calling init function: 0x4210ab88 D (1760) cpu_start: calling init function: 0x4210ab44 D (1765) cpu_start: calling init function: 0x420fa158 D (1770) cpu_start: calling init function: 0x420ee250 D (1775) cpu_start: calling init function: 0x4207d8f0 D (1780) cpu_start: calling init function: 0x4207b930 D (1785) cpu_start: calling init function: 0x42079588 D (1791) intr_alloc: Connected src 59 to int 2 (cpu 0) I (1796) sleep: Configure to isolate all GPIO pins in sleep state I (1803) sleep: Enable automatic switching of GPIO sleep configuration I (1810) coexist: coexist rom version e7ae62f D (1815) intr_alloc: Connected src 79 to int 3 (cpu 0) I (1820) cpu_start: Starting scheduler on PRO CPU. D (1826) intr_alloc: Connected src 57 to int 9 (cpu 0) D (1826) intr_alloc: Connected src 80 to int 2 (cpu 1) I (1836) cpu_start: Starting scheduler on APP CPU. D (1836) intr_alloc: Connected src 58 to int 3 (cpu 1) D (1856) heap_init: New heap initialised at 0x3fce9710 I (1856) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations D (1856) spiram: Allocating block of size 32768 bytes I (1866) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 D (2866) partition: Loading the partition table D (2866) partition: Partition table MD5 verified I (2876) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2876) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2886) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2896) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2906) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2916) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2926) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2936) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2946) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2956) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2966) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2966) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2976) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2986) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2996) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3006) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3016) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3026) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3036) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3046) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3056) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3066) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3076) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3086) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3096) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (3106) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed E (3106) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed E (3116) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR E (3126) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR E (3126) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR E (3136) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR D (3186) gdma: new group (0) at 0x3d8009a4 D (3186) gdma: new pair (0,0) at 0x3d8009e0 D (3186) gdma: new tx channel (0,0) at 0x3d800974 D (3186) gdma: new rx channel (0,0) at 0x3d800a00 D (3196) spi: SPI3 use gpio matrix. D (3196) intr_alloc: Connected src 22 to int 4 (cpu 1) D (3206) spi_hal: eff: 250, limit: 80000k(/0), 0 dummy, -1 delay D (3206) spi_master: SPI3: New device added to CS5, effective clock: 250kHz I (3216) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (3226) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (3236) gpio: GPIO[48]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 D (3246) spi_hal: eff: 40000, limit: 80000k(/0), 0 dummy, -1 delay D (3246) spi_master: SPI3: New device added to CS5, effective clock: 40000kHz D (4436) ledc: Using clock source 1 (in slow mode), divisor: 0x190 D (4436) ledc: In slow speed mode, using clock 1 D (4436) ledc: LEDC_PWM CHANNEL 0|GPIO 45|Duty 0000|Time 0 I (4686) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4686) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4686) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4696) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4706) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4716) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4726) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4736) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4746) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4756) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4766) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4776) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4786) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4796) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4806) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4816) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4826) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4836) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (4836) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (4846) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed E (4856) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed I (4956) espidf: Reserving 0 bytes of psram D (4956) intr_alloc: Connected src 38 to int 9 (cpu 1) D (5036) esp_netif_lwip: LwIP stack has been initialized D (5036) esp_netif_lwip: esp-netif has been successfully initialized D (5036) event: created task for loop 0x3fcebd90 D (5036) event: running task for loop 0x3fcebd90 D (5046) event: created event loop 0x3fcebd90 D (5056) esp_netif_objects: esp_netif_add_to_list 0x3fceccbc D (5056) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1) D (5066) esp_netif_objects: esp_netif_add_to_list 0x3fced088 D (5076) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2) I (5086) pp: pp rom version: e7ae62f I (5086) net80211: net80211 rom version: e7ae62f I (5106) wifi:wifi driver task: 3fcafcb8, prio:23, stack:3584, core=0 I (5106) system_api: Base MAC address is not set I (5106) system_api: read default base MAC address from EFUSE D (5106) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit D (5116) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit D (5126) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit D (5126) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit D (5136) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit D (5146) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit I (5156) wifi:wifi firmware version: f1d33cc I (5156) wifi:wifi certification version: v7.0 I (5156) wifi:config NVS flash: disabled I (5166) wifi:config nano formating: disabled I (5166) wifi:Init data frame dynamic rx buffer num: 8 I (5176) wifi:Init management frame dynamic rx buffer num: 8 I (5176) wifi:Init management short buffer num: 32 I (5186) wifi:Init static tx buffer num: 16 I (5186) wifi:Init tx cache buffer num: 16 I (5186) wifi:Init static tx FG buffer num: 2 I (5196) wifi:Init static rx buffer size: 1600 I (5196) wifi:Init static rx buffer num: 4 I (5206) wifi:Init dynamic rx buffer num: 8 I (5206) wifi_init: rx ba win: 6 I (5206) wifi_init: tcpip mbox: 32 I (5216) wifi_init: udp mbox: 6 I (5216) wifi_init: tcp mbox: 6 I (5226) wifi_init: tcp tx win: 2880 I (5226) wifi_init: tcp rx win: 2880 I (5226) wifi_init: tcp mss: 1440 I (5236) wifi_init: WiFi IRAM OP enabled I (5236) wifi_init: WiFi RX IRAM OP enabled D (5246) ADC: Wi-Fi takes adc2 lock. I (5246) phy_init: phy_version 503,13653eb,Jun 1 2022,17:47:08 D (5256) phy_init: loading PHY init data from application binary D (5256) nvs: nvs_open_from_partition phy 0 E (5266) phy_init: esp_phy_load_cal_data_from_nvs: NVS has not been initialized. Call nvs_flash_init before starting WiFi/BT. W (5276) phy_init: failed to load RF calibration data (0x1101), falling back to full calibration D (5286) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit D (5296) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit D (5296) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit D (5306) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit D (5316) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit D (5316) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit D (5356) nvs: nvs_open_from_partition phy 1 D (5356) phy_init: esp_phy_store_cal_data_to_nvs: failed to open NVS namespace (0x1101) D (5356) wifi:filter: set rx policy=0 I (5356) wifi:mode : sta (7c:df:a1:e1:c7:54) I (5366) wifi:enable tsf D (5366) wifi:filter: set rx policy=1 D (5366) wifi:connect status 0 -> 0 D (5366) event: running post WIFI_EVENT:2 with handler 0x4207dc54 and context 0x3fcecf34 on loop 0x3fcebd90 D (5386) wifi_init_default: wifi_start esp-netif:0x3fceccbc event-id2 D (5386) wifi_init_default: WIFI mac address: 7c df a1 e1 c7 54 D (5396) esp_netif_handlers: esp_netif action has started with netif0x3fceccbc from event_id=2 D (5406) esp_netif_lwip: check: remote, if=0x3fceccbc fn=0x4207a21c D (5406) esp_netif_lwip: esp_netif_start_api 0x3fceccbc D (5416) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fceccbc D (5416) esp_netif_lwip: check: local, if=0x3fceccbc fn=0x4207ab7c D (5426) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fceccbc D (5436) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (5436) event: running post WIFI_EVENT:2 with handler 0x42038c50 and context 0x3fced284 on loop 0x3fcebd90 W (5446) CP wifi: sta start D (5666) wifi:clear blacklist D (5666) wifi:Start wifi connect D (5666) wifi:connect status 0 -> 0 D (5666) wifi:connect chan=0 D (5666) wifi:first chan=1 D (5676) wifi:connect status 0 -> 1 D (5676) wifi:filter: set rx policy=3 D (5676) wifi:clear scan ap list D (5676) wifi:start scan: type=0x50f, priority=2, cb=0x420cbe44, arg=0, ss_state=0x1, time=5685793, index=0 D (5686) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120> D (5816) wifi:scan end: arg=0, status=0, ss_state=0x3 D (5816) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120> D (5936) wifi:scan end: arg=0, status=0, ss_state=0x3 D (5936) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120> D (6056) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6056) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120> D (6176) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6176) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120> D (6296) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6296) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120> D (6426) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6426) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120> D (6546) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6546) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120> D (6666) wifi:scan end: arg=0, status=0, ss_state=0x3 D (6666) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120> D (6666) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (6666) wifi:profile match: ss_state=0x7 D (6716) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (6716) wifi:set max rate: from to D (6716) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144 D (6726) wifi:profile match: ss_state=0x7 D (6786) wifi:scan end: arg=0, status=0, ss_state=0x7 D (6786) wifi:perform scan: ss_state=0xd, chan<10,0>, dur<0,120> D (6906) wifi:scan end: arg=0, status=0, ss_state=0x7 D (6906) wifi:perform scan: ss_state=0xd, chan<11,0>, dur<0,120> D (7026) wifi:scan end: arg=0, status=0, ss_state=0x7 D (7026) wifi:perform scan: ss_state=0xd, chan<12,0>, dur<360,360> D (7386) wifi:scan end: arg=0, status=0, ss_state=0x7 D (7386) wifi:perform scan: ss_state=0xd, chan<13,0>, dur<360,360> D (7746) wifi:scan end: arg=0, status=0, ss_state=0x7 D (7746) wifi:perform scan: ss_state=0xd, chan<14,0>, dur<360,360> D (8106) wifi:scan end: arg=0, status=0, ss_state=0x7 D (8106) wifi:filter: set rx policy=4 D (8106) wifi:first chan=1 D (8106) wifi:handoff_cb: status=0 D (8116) wifi:ap found, mac=e4:c3:2a:e3:14:31 D (8116) wifi:new_bss=0x3fcaa7e0, cur_bss=0, new_chan=<9,0>, cur_chan=1 D (8126) wifi:filter: set rx policy=5 I (8126) wifi:new:<9,0>, old:<1,0>, ap:<255,255>, sta:<9,0>, prof:1 D (8136) wifi:connect_op: status=0, auth=5, cipher=3 ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x8 (TG1WDT_SYS_RST),boot:0xa (SPI_FAST_FLASH_BOOT) Saved PC:0x40374200 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x15e8 load:0x403b6000,len:0xbf8 load:0x403ba000,len:0x31c8 entry 0x403b621c I (29) boot: ESP-IDF v4.4.2-378-g9269a536ac 2nd stage bootloader I (29) boot: compile time 11:36:39 I (29) boot: chip revision: 0 I (32) qio_mode: Enabling default flash chip QIO I (37) boot.esp32s3: Boot SPI Speed : 80MHz I (42) boot.esp32s3: SPI Mode : QIO I (47) boot.esp32s3: SPI Flash Size : 16MB W (52) boot.esp32s3: PRO CPU has been reset by WDT. W (57) boot.esp32s3: APP CPU has been reset by WDT. I (63) boot: Enabling RNG early entropy source... I (68) boot: Partition Table: I (72) boot: ## Label Usage Type ST Offset Length I (79) boot: 0 nvs WiFi data 01 02 00009000 00005000 I (87) boot: 1 otadata OTA data 01 00 0000e000 00002000 I (94) boot: 2 ota_0 OTA app 00 10 00010000 00200000 I (102) boot: 3 ota_1 OTA app 00 11 00210000 00200000 I (109) boot: 4 uf2 factory app 00 00 00410000 00040000 I (117) boot: 5 ffat Unknown data 01 81 00450000 00bb0000 I (124) boot: End of partition table I (629) esp_image: segment 0: paddr=00010020 vaddr=3c120020 size=4cd18h (314648) map I (677) esp_image: segment 1: paddr=0005cd40 vaddr=3fc9c620 size=032d8h ( 13016) load I (679) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=114960h (1132896) map I (854) esp_image: segment 3: paddr=00174988 vaddr=3fc9f8f8 size=021dch ( 8668) load I (856) esp_image: segment 4: paddr=00176b6c vaddr=40374000 size=1861ch ( 99868) load I (879) esp_image: segment 5: paddr=0018f190 vaddr=600fe000 size=0002ch ( 44) load I (879) esp_image: segment 6: paddr=0018f1c4 vaddr=600fe030 size=01010h ( 4112) load I (896) boot: Loaded app from partition at offset 0x10000 I (896) boot: Disabling RNG early entropy source... I (908) opi psram: vendor id : 0x0d (AP) I (908) opi psram: dev id : 0x02 (generation 3) I (908) opi psram: density : 0x03 (64 Mbit) I (912) opi psram: good-die : 0x01 (Pass) I (917) opi psram: Latency : 0x01 (Fixed) I (921) opi psram: VCC : 0x01 (3V) I (926) opi psram: SRF : 0x01 (Fast Refresh) I (931) opi psram: BurstType : 0x01 (Hybrid Wrap) I (937) opi psram: BurstLen : 0x01 (32 Byte) I (942) opi psram: Readlatency : 0x02 (10 cycles@Fixed) I (948) opi psram: DriveStrength: 0x00 (1/1) W (953) PSRAM: DO NOT USE FOR MASS PRODUCTION! Timing parameters will be updated in future IDF version. D (964) MSPI Timing: tuning success, best point is index 5 I (968) spiram: Found 64MBit SPI RAM device I (973) spiram: SPI RAM mode: sram 80m I (978) spiram: PSRAM initialized, cache is in normal (1-core) mode. I (985) cpu_start: Pro cpu up. I (988) cpu_start: Starting app cpu, entry point is 0x4037856c I (0) cpu_start: App cpu up. I (1421) spiram: SPI SRAM memory test OK D (1421) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit D (1422) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit D (1429) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1436) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1443) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit D (1450) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1457) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1464) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1471) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1478) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1485) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit D (1493) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit D (1500) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit D (1507) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit D (1514) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit D (1529) clk: RTC_SLOW_CLK calibration value: 4158016 I (1537) cpu_start: Pro cpu start user code I (1538) cpu_start: cpu freq: 240000000 I (1538) cpu_start: Application information: I (1541) cpu_start: Project name: circuitpython I (1546) cpu_start: App version: 8.0.0-beta.3-54-g2bba6a68e I (1553) cpu_start: Compile time: Oct 27 2022 16:02:43 I (1559) cpu_start: ELF file SHA256: b99a04578302db9b... I (1565) cpu_start: ESP-IDF: v4.4.2-381-g716d8531d7 D (1571) memory_layout: Checking 6 reserved memory ranges: D (1577) memory_layout: Reserved memory range 0x3d000000 - 0x3e000000 D (1583) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc9c61c D (1590) memory_layout: Reserved memory range 0x3fc9c620 - 0x3fcae060 D (1596) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000 D (1603) memory_layout: Reserved memory range 0x40374000 - 0x4038c61c D (1609) memory_layout: Reserved memory range 0x600fe000 - 0x600ff040 D (1616) memory_layout: Building list of available memory regions: D (1622) memory_layout: Available memory region 0x3fcae060 - 0x3fcb0000 D (1629) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000 D (1636) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000 D (1642) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000 D (1649) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710 D (1656) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34 D (1662) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000 D (1669) memory_layout: Available memory region 0x600ff040 - 0x60100000 I (1676) heap_init: Initializing. RAM available for dynamic allocation: D (1683) heap_init: New heap initialised at 0x3fcae060 I (1688) heap_init: At 3FCAE060 len 0003B6B0 (237 KiB): D/IRAM I (1695) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM D (1701) heap_init: New heap initialised at 0x3fcf0000 I (1707) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM D (1713) heap_init: New heap initialised at 0x600ff040 I (1718) heap_init: At 600FF040 len 00000FC0 (3 KiB): RTCRAM I (1725) spiram: Adding pool of 8192K of external SPI memory to heap allocator D (1733) FLASH_HAL: extra_dummy: 0 D (1736) spi_flash: trying chip: issi D (1740) spi_flash: trying chip: gd I (1743) spi_flash: detected chip: gd I (1748) spi_flash: flash io: dio D (1752) cpu_start: calling init function: 0x4210ab88 D (1757) cpu_start: calling init function: 0x4210ab44 D (1762) cpu_start: calling init function: 0x420fa158 D (1767) cpu_start: calling init function: 0x420ee250 D (1772) cpu_start: calling init function: 0x4207d8f0 D (1777) cpu_start: calling init function: 0x4207b930 D (1782) cpu_start: calling init function: 0x42079588 D (1788) intr_alloc: Connected src 59 to int 2 (cpu 0) I (1793) sleep: Configure to isolate all GPIO pins in sleep state I (1799) sleep: Enable automatic switching of GPIO sleep configuration I (1807) coexist: coexist rom version e7ae62f D (1812) intr_alloc: Connected src 79 to int 3 (cpu 0) I (1817) cpu_start: Starting scheduler on PRO CPU. D (1822) intr_alloc: Connected src 57 to int 9 (cpu 0) D (1822) intr_alloc: Connected src 80 to int 2 (cpu 1) I (1832) cpu_start: Starting scheduler on APP CPU. D (1832) intr_alloc: Connected src 58 to int 3 (cpu 1) D (1852) heap_init: New heap initialised at 0x3fce9710 I (1852) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations D (1852) spiram: Allocating block of size 32768 bytes D (1862) partition: Loading the partition table D (1862) partition: Partition table MD5 verified I (1872) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1872) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1882) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1892) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1902) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1912) gpio: GPIO[5]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1922) gpio: GPIO[6]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1932) gpio: GPIO[7]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1942) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1952) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1962) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1972) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1982) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1992) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (1992) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2002) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2012) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2022) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2032) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2042) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2052) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2062) gpio: GPIO[45]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2072) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2082) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (2092) gpio: GPIO[48]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (2102) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed E (2102) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed E (2112) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR E (2122) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR E (2132) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR E (2132) timer_group: timer_deinit(312): HW TIMER NEVER INIT ERROR D (2182) gdma: new group (0) at 0x3d8009a4 D (2182) gdma: new pair (0,0) at 0x3d8009e0 D (2182) gdma: new tx channel (0,0) at 0x3d800974 D (2182) gdma: new rx channel (0,0) at 0x3d800a00 D (2192) spi: SPI3 use gpio matrix. D (2192) intr_alloc: Connected src 22 to int 4 (cpu 1) D (2202) spi_hal: eff: 250, limit: 80000k(/0), 0 dummy, -1 delay D (2202) spi_master: SPI3: New device added to CS5, effective clock: 250kHz I (2212) gpio: GPIO[5]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (2222) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (2232) gpio: GPIO[48]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 D (2242) spi_hal: eff: 40000, limit: 80000k(/0), 0 dummy, -1 delay D (2242) spi_master: SPI3: New device added to CS5, effective clock: 40000kHz D (3432) ledc: Using clock source 1 (in slow mode), divisor: 0x190 D (3432) ledc: In slow speed mode, using clock 1 D (3432) ledc: LEDC_PWM CHANNEL 0|GPIO 45|Duty 0000|Time 0 I (3442) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3442) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3452) gpio: GPIO[2]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3462) gpio: GPIO[3]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3472) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3482) gpio: GPIO[9]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3492) gpio: GPIO[10]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3502) gpio: GPIO[11]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3512) gpio: GPIO[12]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3522) gpio: GPIO[13]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3532) gpio: GPIO[14]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3542) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3552) gpio: GPIO[16]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3562) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3572) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3582) gpio: GPIO[21]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3592) gpio: GPIO[38]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3592) gpio: GPIO[46]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (3602) gpio: GPIO[47]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 E (3612) I2S: i2s_driver_uninstall(2047): I2S port 0 has not installed E (3622) I2S: i2s_driver_uninstall(2047): I2S port 1 has not installed I (3722) espidf: Reserving 0 bytes of psram D (3722) intr_alloc: Connected src 38 to int 9 (cpu 1) ```
PaulskPt commented 2 years ago

Here is the code.py I used:

###
#
# Circuitpython V8b3-20 for ESP32-S3-Box (with DEBUG=1)
# WiFi test
#

import wifi
import sys
import time
#import ssl
import ipaddress
import socketpool
from secrets import secrets
#import adafruit_requests
#from rtc import RTC

my_debug = False

ssid = secrets["ssid"]
password = secrets["password"]
use_ping = True
pool = None
connected = False
ip = None
s_ip = None

print(f"\nTrying to connect to \'{ssid}\'")
wifi.__init__()

wifi.radio.connect(ssid=ssid, password=password)

ip = wifi.radio.ipv4_address

if ip:
    s_ip = str(ip)
    le_s_ip = len(s_ip)

if s_ip is not None and len(s_ip) > 0 and s_ip != '0.0.0.0':
    connected = True
else:
    connected = False

if connected:
    s2 = ''
else:
    s2 = "Not"

print(f"{s2} connected to: \'{ssid}\'")

if my_debug:
    print("s_ip= \'{}\'".format(s_ip))

if use_ping and connected:
    if not pool:
        pool = socketpool.SocketPool(wifi.radio)
    addr_idx = 1
    addr_dict = {0:'LAN gateway', 1:'google.com'}
    info = pool.getaddrinfo(addr_dict[addr_idx], 80)
    addr = info[0][4][0]
    print(f"Resolved google address: \'{addr}\'")
    ipv4 = ipaddress.ip_address(addr)
    for _ in range(10):
        result = wifi.radio.ping(ipv4)
        if result:
            print("Ping google.com [%s]: %.0f ms" % (addr, result*1000))
            break
        else:
            print("Ping no response")

print("Exiting...")
sys.exit()
PaulskPt commented 2 years ago

Hardware: Adafruit ESP32-S3-Box and Adafruit CP2102N.

IMG_7077

IMG_7079

dhalbert commented 2 years ago

During a Ubuntu-Linux session, I saw that the '/circuitpython/ports/espressif/esp-idf' version is 4.4.2 while the documentation of espressif expresses that for the esp32s3 esp-idf 5.0 is needed. Perhaps this is the source of the problem. Can I clone esp-idf 5.0 into ' /circuitpython/ports/espressif' or is that esp-idf a special version prepared for circuitpython ?

There are many incompatible changes between v4.4.2 and v5.0, and v5.0 is still in beta. @MicroDev1 has been working on updating. But there are other issues that v5.0 does not fix. Could you provide a link to some place where v5.0 was listed as "required" for the box?

PaulskPt commented 2 years ago

Thank you Dan. I cannot find back yet the page where I read "needed". I am searching for it.

dhalbert commented 2 years ago

@PaulskPt Re your discord conversations, etc. This unit is not made by Adafruit, so it is not first priority when it comes to fixes. Since this "just another" S3 unit, it should work the same as other S3 boards. Since it is not, there are several possibilities:

  1. Your unit is actually defective. Unlikely, but possible.
  2. There are differences in the board-related files for this unit, and at least one of these differences is a mistake

Rather than spend a lot of time on ESP-IDF upgrades, etc., look for what the differences are between the board files for this board and a more generic S3 board. You might try a more generic build for another Espressif ESP32-S3 board, for instance. You won't get the display but simple wifi testing should be the same.

That is how I would approach debugging this. Also, I will test my own sample of the Box to see if I can reproduce the problem. That is easy for me to do in the near future, and would eliminate or point to 1. above as the issue.

PaulskPt commented 2 years ago

Ok Dan. You aare correct by stating that 'This unit is not made by Adafruit', however I bought it from Adafruit. (May 3, 2022). I doubt the unit is defective. It worked when I received it. The factory demo, using WiFi worked OK; voice command recognition (that sends the voice commands to a server of Espressif): worked. II am going to flash the factory demo again and make a short video to demonstrate. Maybe a defect is there now. We'll find out.

I see that you have a lot 'on your plate' so to speak. I am greatful that you are willing to test your own sample of the Box to see if you can reproduce the problem.

Here an image I took of the prodoct label of Adafruit on the packaging of the ESP-S3-Box on the day I received it. The order was first sent to the address of my son who lives in Goshen (near Louisville), KY. He then sent the ordered items to me.

image ![IMG_5422](https://user-images.githubusercontent.com/9107950/198331111-077ae9db-8f02-4825-ab45-8f39e0443f9e.jpg)
dhalbert commented 2 years ago

I reproduced your problem on my S3 box, so you can hold off on hardawre testing. The settings for PSRAM in sdkconfig are unusual, and I am fiddling with them to see if I can get it to work.

PaulskPt commented 2 years ago

Ah, good! Good luck with the configuration attempt!

Anyway I already had downloaded the latest version of the esp-box repo and was flashing the factory demo. Below two images. The first, from the esp-box app on my mobile phone. Showing that the s3-box had been registered online. The second image of the screen stating "Wi-Fi is connected to Vodafone-287778_EXT' (the SSID of the WiFi extender here in the room.

IMG_7088

IMG_7089

PaulskPt commented 2 years ago

https://user-images.githubusercontent.com/9107950/198345164-c3ef8258-39c4-4fd5-b217-8a0cb5f1f44e.mp4

PaulskPt commented 2 years ago

Just for the record. Serial output after reset with the factory demo flashed. The factory demo has been built with ESP-IDF v4.4.

log ``` ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x1 (POWERON),boot:0x2a (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd0108,len:0x17b4 load:0x403b6000,len:0xe0c load:0x403ba000,len:0x3078 entry 0x403b626c I (25) boot: ESP-IDF v4.4-264-g2bdea81b2a 2nd stage bootloader I (25) boot: compile time 10:06:42 I (25) boot: chip revision: 0 I (28) qio_mode: Enabling default flash chip QIO I (33) boot.esp32s3: Boot SPI Speed : 80MHz I (38) boot.esp32s3: SPI Mode : QIO I (42) boot.esp32s3: SPI Flash Size : 16MB I (47) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (56) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 sec_cert Unknown data 01 06 0000d000 00003000 I (71) boot: 1 nvs WiFi data 01 02 00010000 00006000 I (78) boot: 2 otadata OTA data 01 00 00016000 00002000 I (86) boot: 3 phy_init RF data 01 01 00018000 00001000 I (93) boot: 4 fctry WiFi data 01 02 00019000 00006000 I (101) boot: 5 ota_0 OTA app 00 10 00020000 0039d000 I (108) boot: 6 storage Unknown data 01 82 003bd000 0028a000 I (116) boot: 7 model Unknown data 01 82 00647000 007e9000 I (124) boot: End of partition table I (128) esp_image: segment 0: paddr=00020020 vaddr=3c140020 size=1fc3ach (2081708) map I (452) esp_image: segment 1: paddr=0021c3d4 vaddr=3fca57c0 size=03c44h ( 15428) load I (460) esp_image: segment 2: paddr=00220020 vaddr=42000020 size=13d6a4h (1300132) map I (657) esp_image: segment 3: paddr=0035d6cc vaddr=3fca9404 size=01688h ( 5768) load I (659) esp_image: segment 4: paddr=0035ed5c vaddr=40378000 size=1d7c0h (120768) load I (686) esp_image: segment 5: paddr=0037c524 vaddr=50000000 size=00014h ( 20) load I (698) boot: Loaded app from partition at offset 0x20000 I (698) boot: Disabling RNG early entropy source... I (699) opi psram: vendor id : 0x0d (AP) I (703) opi psram: dev id : 0x02 (generation 3) I (708) opi psram: density : 0x03 (64 Mbit) I (713) opi psram: good-die : 0x01 (Pass) I (718) opi psram: Latency : 0x01 (Fixed) I (723) opi psram: VCC : 0x01 (3V) I (728) opi psram: SRF : 0x01 (Fast Refresh) I (733) opi psram: BurstType : 0x01 (Hybrid Wrap) I (738) opi psram: BurstLen : 0x01 (32 Byte) I (743) opi psram: Readlatency : 0x02 (10 cycles@Fixed) I (749) opi psram: DriveStrength: 0x00 (1/1) W (754) PSRAM: DO NOT USE FOR MASS PRODUCTION! Timing parameters will be updated in future IDF version. I (765) spiram: Found 64MBit SPI RAM device I (769) spiram: SPI RAM mode: sram 80m I (774) spiram: PSRAM initialized, cache is in normal (1-core) mode. I (781) cpu_start: Pro cpu up. I (784) cpu_start: Starting app cpu, entry point is 0x403794f0 ```
dhalbert commented 2 years ago

OK, if I disable PSRAM completely, it works. So there is something about the PSRAM setup that is causing trouble.

I am going to hide a bunch of comments in this issue to expose the ones that are the most relevant.

dhalbert commented 2 years ago

OK, I think this is a dupe of #6206. Closing this in favor of that bug, which gets to the root issue faster. @PaulskPt wait up before trying more things, as I am on the trail of the bug.