esp32_spi: esp_cmd_work: Busy in another cmd execution (ESP32C5, nanopi neo air)

### Checklist

- [x] Checked the issue tracker for similar issues to ensure this is not a duplicate
- [x] Read the documentation to confirm the issue is not addressed there and your configuration is set correctly
- [x] Tested with the latest version to ensure the issue hasn't been fixed

### How often does this bug occurs?

always

### Expected behavior

Initialization finished without errors in dmesg on host

>

### Actual behavior (suspected bug)

I am porting to a Nanopi neo air board. I am using the esp32-c5-devkitc-1 and is connecting over SPI only.

From the dmesg logs (and also by checking with a logic analyzer) it appears like the SPI communication at least works initially.

This is the dmesg log on the host:

> [ 1572.782306] spi_data_ready_interrupt_handler
> [ 1572.895147] spi_data_ready_interrupt_handler
> [ 1572.899506] spi_data_ready_interrupt_handler
> [ 1572.903815] spi_interrupt_handler
> [ 1572.942659] spi_interrupt_handler
> [ 1575.817961] spi_data_ready_interrupt_handler
> [ 1575.822341] spi_interrupt_handler
> [ 1575.828328] spi_interrupt_handler
> [ 1575.831749] esp32_spi: process_esp_bootup_event: Received ESP bootup event
> [ 1575.865436] esp32_spi: process_event_esp_bootup: Bootup Event tag: 3
> [ 1575.865509] esp32_spi: esp_validate_chipset: Chipset=ESP32-C5 ID=17 detected over SPI
> [ 1575.865541] esp32_spi: process_event_esp_bootup: Bootup Event tag: 2
> [ 1575.865566] esp32_spi: process_event_esp_bootup: Bootup Event tag: 0
> [ 1575.865588] esp32_spi: process_event_esp_bootup: Bootup Event tag: 1
> [ 1575.865609] esp32_spi: process_fw_data: ESP chipset's last reset cause:
> [ 1575.865629] esp32_spi: print_reset_reason: POWERON_RESET
> [ 1575.865656] esp32_spi: check_esp_version: ESP-Hosted Version: NG-1.0.5.0.1
> [ 1575.868856] esp32_spi: esp_reg_notifier: Driver init is ongoing
> [ 1575.869614] esp32_spi: esp_cfg80211_add_iface: Updated priv[0] to c44bc640
> [ 1575.888520] esp32_spi: esp_cmd_work: Processing Command [0x1]
> [ 1575.888714] tx: 4f28e4dc: 00 00 01 00 08 00 0c 00 16 00 00 00 01 00 00 00  ................
> [ 1575.888761] tx: ad78e5a4: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
> [ 1576.183844] spi_data_ready_interrupt_handler
> [ 1576.190762] spi_interrupt_handler
> [ 1576.196495] esp32_spi: wait_and_decode_cmd_resp: Resp for command [0x1]
> [ 1576.212292] esp32_spi: esp_cmd_work: Processing Command [0x3]
> [ 1576.212352] tx: 276b1061: 00 00 01 00 08 00 0c 00 18 00 00 00 03 00 00 00  ................
> [ 1576.212370] tx: 2298710c: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
> [ 1576.214744] spi_interrupt_handler
> [ 1576.221794] spi_data_ready_interrupt_handler
> [ 1576.236293] **esp32_spi: esp_cmd_work: Busy in another cmd execution**
> [ 1581.304360] **esp32_spi: wait_and_decode_cmd_resp: Command[0x3] timed out**
> [ 1581.311120] esp32_spi: cmd_get_mac: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
> [ 1581.319865] esp32_spi: esp_add_card: esp_add_network_ifaces(adapter) failure, ret: -1
> [ 1581.327854] esp32_spi: process_event_esp_bootup: network interface init failed

The logs from the ESP:

> calling init function: 0x42008dc8 on core: 0
> D (611) cpu_start: calling init function: 0x4200a5c4 on core: 0
> D (617) cpu_start: calling init function: 0x4200baec on core: 0
> D (622) cpu_start: calling init function: 0x4200a8c2 on core: 0
> D (628) cpu_start: calling init function: 0x420071ea on core: 0
> D (634) cpu_start: calling init function: 0x42000922 on core: 0
> V (640) memspi: raw_chip_id: 174020
> 
> V (643) memspi: chip_id: 204017
> 
> V (646) memspi: raw_chip_id: 174020
> 
> V (649) memspi: chip_id: 204017
> 
> D (652) spi_flash: trying chip: generic
> I (656) spi_flash: detected chip: generic
> I (659) spi_flash: flash io: dio
> W (662) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
> D (674) cpu_start: calling init function: 0x4200032e on core: 0
> D (680) cpu_start: calling init function: 0x420ad6c8
> D (685) cpu_start: calling init function: 0x42053b76
> D (690) cpu_start: calling init function: 0x4080d7b8
> D (694) cpu_start: calling init function: 0x4080e2c2
> D (699) cpu_start: calling init function: 0x4204bc98 on core: 0
> V (705) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (711) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC02
> D (718) intr_alloc: Connected src 63 to int 2 (cpu 0)
> D (723) cpu_start: calling init function: 0x420019e0 on core: 0
> D (729) cpu_start: calling init function: 0x42002caa on core: 0
> D (735) cpu_start: calling init function: 0x42003980 on core: 0
> I (740) sleep_gpio: Configure to isolate all GPIO pins in sleep state
> I (746) sleep_gpio: Enable automatic switching of GPIO sleep configuration
> D (753) cpu_start: calling init function: 0x420c6488 on core: 0
> D (759) cpu_start: calling init function: 0x42000974 on core: 0
> I (764) coexist: coex firmware version: 831ec70
> I (769) coexist: coexist rom version 78e5c6e42
> D (773) cpu_start: calling init function: 0x42009dd4 on core: 0
> D (778) cpu_start: calling init function: 0x4200098c on core: 0
> V (784) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (790) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
> D (798) intr_alloc: Connected src 23 to int 3 (cpu 0)
> D (802) app_start: Starting scheduler on CPU0
> V (806) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (806) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x402
> D (806) intr_alloc: Connected src 61 to int 4 (cpu 0)
> I (806) main_task: Started on CPU0
> D (809) heap_init: New heap initialised at 0x4085c5a0
> V (813) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (819) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
> D (827) intr_alloc: Connected src 58 to int 5 (cpu 0)
> I (832) main_task: Calling app_main()
> I (835) stats: *********************************************************************
> I (843) stats:                 ESP-Hosted Firmware version :: NG-1.0.5.0.1                        
> I (852) stats:                 Transport used :: SPI only                      
> I (859) stats: *********************************************************************
> I (866) FW_MAIN: Supported features are:
> I (870) FW_MAIN: - WLAN over SPI
> I (873) FW_BT: - BT/BLE
> I (875) FW_BT:    - HCI Over SPI
> I (878) FW_BT:    - BLE only
> I (880) FW_MAIN: Capabilities: 0xe8
> V (884) partition: Loading the partition table
> V (888) mmap: actual_mapped_len is 0x10000
> V (892) calculated md5: 0x40827528   fd 35 ea be bc e9 5a fd  9d f1 74 0c 7c 12 07 66  |.5....Z...t.|..f|
> V (901) stored md5: 0x421080d0   fd 35 ea be bc e9 5a fd  9d f1 74 0c 7c 12 07 66  |.5....Z...t.|..f|
> V (910) partition: Partition table MD5 verified
> pp rom version: 78a72e9d5
> net80211 rom version: 78a72e9d5
> I (920) wifi:wifi driver task: 4085dd00, prio:23, stack:6656, core=0
> V (925) esp_adapter: thread sem create: sem=0x4085de54
> V (930) esp_adapter: thread sem get: sem=0x4085de54
> D (935) efuse: BLK1 REG1 [8-15], len=8 bits
> D (938) efuse: BLK1 REG1 [0-7], len=8 bits
> D (942) efuse: BLK1 REG0 [24-31], len=8 bits
> D (946) efuse: BLK1 REG0 [16-23], len=8 bits
> D (950) efuse: BLK1 REG0 [8-15], len=8 bits
> D (954) efuse: BLK1 REG0 [0-7], len=8 bits
> I (959) wifi:wifi firmware version: 0f9888e
> I (962) wifi:wifi certification version: v7.0
> I (966) wifi:config NVS flash: disabled
> I (970) wifi:config nano formatting: disabled
> I (974) wifi:mac_version:HAL_MAC_ESP32AX_752MP_ECO2,ut_version:N, band mode:0x3
> I (981) wifi:Init data frame dynamic rx buffer num: 32
> I (986) wifi:Init static rx mgmt buffer num: 5
> I (990) wifi:Init management short buffer num: 32
> I (994) wifi:Init dynamic tx buffer num: 32
> I (998) wifi:Init static tx FG buffer num: 2
> I (1002) wifi:Init static rx buffer size: 1700 (rxctrl:64, csi:512)
> I (1008) wifi:Init static rx buffer num: 10
> I (1012) wifi:Init dynamic rx buffer num: 32
> D (1016) wifi:mms: 3->2
> D (1018) wifi:Reset scan defaults in ms : min,max,passive,chan_dwell :(0,120,360,30)
> V (1026) wifi:hint=255, act_dur=<0,120>, pas_dur=360, nchans=42 history_num=0
> V (1033) esp_adapter: thread sem get: sem=0x4085de54
> I (1037) wifi_init: rx ba win: 6
> I (1040) wifi_init: accept mbox: 6
> I (1043) wifi_init: tcpip mbox: 32
> I (1046) wifi_init: udp mbox: 6
> I (1049) wifi_init: tcp mbox: 6
> I (1052) wifi_init: tcp tx win: 5760
> I (1055) wifi_init: tcp rx win: 5760
> I (1059) wifi_init: tcp mss: 1440
> I (1062) wifi_init: WiFi IRAM OP enabled
> I (1065) wifi_init: WiFi RX IRAM OP enabled
> I (1069) wifi_init: WiFi SLP IRAM OP enabled
> V (1073) esp_adapter: thread sem get: sem=0x4085de54
> V (1078) esp_adapter: thread sem get: sem=0x4085de54
> I (1083) BLE_INIT: Using main XTAL as clock source
> I (1087) BLE_INIT: ble controller commit:[35fe65f]
> I (1095) BLE_INIT: Bluetooth MAC: d0:cf:13:e0:d5:e2
> I (1097) phy_init: phy_version 102,171bf417,Jun 12 2025,15:57:12
> D (1102) phy_init: loading PHY init data from application binary
> D (1108) nvs: nvs_open_from_partition phy 0
> D (1112) nvs: nvs_get cal_version 4
> V (1115) phy_init: phy_get_rf_cal_version: 102
> D (1119) nvs: nvs_get_str_or_blob cal_mac
> D (1123) efuse: BLK1 REG1 [8-15], len=8 bits
> D (1127) efuse: BLK1 REG1 [0-7], len=8 bits
> D (1131) efuse: BLK1 REG0 [24-31], len=8 bits
> D (1135) efuse: BLK1 REG0 [16-23], len=8 bits
> D (1139) efuse: BLK1 REG0 [8-15], len=8 bits
> D (1143) efuse: BLK1 REG0 [0-7], len=8 bits
> D (1147) efuse: BLK1 REG1 [16-31], len=16 bits
> D (1151) nvs: nvs_get_str_or_blob cal_data
> D (1157) nvs: nvs_close 1
> D (1157) efuse: BLK1 REG1 [8-15], len=8 bits
> D (1161) efuse: BLK1 REG1 [0-7], len=8 bits
> D (1165) efuse: BLK1 REG0 [24-31], len=8 bits
> D (1169) efuse: BLK1 REG0 [16-23], len=8 bits
> D (1173) efuse: BLK1 REG0 [8-15], len=8 bits
> D (1177) efuse: BLK1 REG0 [0-7], len=8 bits
> D (1181) efuse: BLK1 REG1 [16-31], len=16 bits
> D (1374) temperature_sensor: range changed, change to index 2
> I (1779) phy: libbtbb version: 09fb4d6, Jun 12 2025, 15:57:24
> V (1779) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (1780) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
> D (1788) intr_alloc: Connected src 7 to int 7 (cpu 0)
> V (1792) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (1798) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
> D (1806) intr_alloc: Connected src 4 to int 8 (cpu 0)
> I (1811) FW_MAIN: ESP Bluetooth MAC addr: d0-cf-13-e0-d5-e2
> 
> I (1816) FW_SPI: Using SPI interface
> I (1820) FW_SPI: Using SPI MODE 2
> D (1823) gpio: GPIO[3]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
> D (1831) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
> I (1840) FW_SPI: SPI Ctrl:1 mode: 2, GPIOs: MOSI: 7, MISO: 2, CS: 10, CLK: 6 HS: 3 DR: 4
> 
> I (1848) FW_SPI: Hosted SPI queue size: Tx:20 Rx:20
> D (1852) gdma: new group (0) at 0x40837c24
> D (1856) gdma: new pair (0,0) at 0x40837ca4
> D (1860) gdma: new tx channel (0,0) at 0x40837bec
> D (1864) gdma: new rx channel (0,0) at 0x40837cc4
> D (1869) spi: SPI2 use iomux pins.
> V (1872) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (1878) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x80E
> D (1886) intr_alloc: Connected src 77 to int 9 (cpu 0)
> I (2892) FW_MAIN: Initial set up done
> I (2892) main_task: Returned from app_main()
> I (2975) FW_MAIN: INIT Interface command
> D (2975) event: created task for loop 0x4085dcd4
> D (2975) event: created event loop 0x4085dcd4
> I (2976) FW_CMD: Setting STA mode
> V (2979) esp_adapter: thread sem create: sem=0x4082771c
> V (2984) esp_adapter: thread sem get: sem=0x4082771c
> V (2988) esp_adapter: thread sem get: sem=0x4082771c
> V (2993) wifi:ht20 freq=2412, chan=1
> W (2998) wifi:WDEV_RXCCK_DELAY:960
> W (2999) wifi:WDEV_RXOFDM_DELAY:262
> W (3003) wifi:WDEV_RX_11G_OFDM_DELAY:263
> W (3006) wifi:WDEV_TXCCK_DELAY:630
> W (3009) wifi:WDEV_TXOFDM_DELAY:94
> W (3013) wifi:ACK_TAB0   :0x   90a0b, QAM16:0x9 (24Mbps), QPSK:0xa (12Mbps), BPSK:0xb (6Mbps)
> W (3021) wifi:CTS_TAB0   :0x   90a0b, QAM16:0x9 (24Mbps), QPSK:0xa (12Mbps), BPSK:0xb (6Mbps)
> W (3029) wifi:WDEVBEAMFORMCONF:0x61d7120, HE_BF_RPT_RA_SET_OPT:1
> W (3035) wifi:WDEVVHTBEAMFORMCONF: 0x61d7120, WDEV_VHT_BEAMFORMEE_ENA: 1, WDEV_VHT_NG_SEL: 0
> W (3043) wifi:(agc)0x600a7128:0xd21f0c20, min.avgNF:0xce->0xd2(dB), RCalCount:0x1f0, min.RRssi:0xc20(-62.00)
> W (3052) wifi:MODEM_SYSCON_WIFI_BB_CFG_REG(0x600a9c18):0x10003802
> W (3059) wifi:(phy)rate:0x0(  LP-1Mbps), pwr:20, txing:20
> W (3063) wifi:(phy)rate:0x1(  LP-2Mbps), pwr:20, txing:20
> W (3068) wifi:(phy)rate:0x2(LP-5.5Mbps), pwr:20, txing:20
> W (3074) wifi:(phy)rate:0x3( LP-11Mbps), pwr:20, txing:20
> W (3079) wifi:(phy)rate:0x5(  SP-2Mbps), pwr:20, txing:20
> W (3084) wifi:(phy)rate:0x6(SP-5.5Mbps), pwr:20, txing:20
> W (3089) wifi:(phy)rate:0x7( SP-11Mbps), pwr:20, txing:20
> W (3094) wifi:(phy)rate:0x8(    48Mbps), pwr:17, txing:17
> W (3099) wifi:(phy)rate:0x9(    24Mbps), pwr:19, txing:19
> W (3104) wifi:(phy)rate:0xa(    12Mbps), pwr:19, txing:19
> W (3109) wifi:(phy)rate:0xb(     6Mbps), pwr:19, txing:19
> W (3115) wifi:(phy)rate:0xc(    54Mbps), pwr:17, txing:17
> W (3120) wifi:(phy)rate:0xd(    36Mbps), pwr:19, txing:19
> W (3125) wifi:(phy)rate:0xe(    18Mbps), pwr:19, txing:19
> W (3130) wifi:(phy)rate:0xf(     9Mbps), pwr:19, txing:19
> W (3135) wifi:(phy)rate:0x10, mcs:0x0, pwr(bw20:19, bw40:18), txing:19, HE pwr(bw20:19), txing:19
> W (3144) wifi:(phy)rate:0x11, mcs:0x1, pwr(bw20:19, bw40:18), txing:19, HE pwr(bw20:19), txing:19
> W (3152) wifi:(phy)rate:0x12, mcs:0x2, pwr(bw20:18, bw40:17), txing:18, HE pwr(bw20:18), txing:18
> W (3161) wifi:(phy)rate:0x13, mcs:0x3, pwr(bw20:18, bw40:17), txing:18, HE pwr(bw20:18), txing:18
> W (3170) wifi:(phy)rate:0x14, mcs:0x4, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3178) wifi:(phy)rate:0x15, mcs:0x5, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3187) wifi:(phy)rate:0x16, mcs:0x6, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3195) wifi:(phy)rate:0x17, mcs:0x7, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3204) wifi:(phy)rate:0x18, mcs:0x8, pwr(bw20:19, bw40:16), txing:19, HE pwr(bw20:16), txing:16
> W (3212) wifi:(phy)rate:0x19, mcs:0x9, pwr(bw20:18, bw40:16), txing:18, HE pwr(bw20:15), txing:15
> W (3221) wifi:(hal)co_hosted_bss:0, max_indicator:0, bitmask:0xff, mBSSIDsEnable:0
> I (3228) wifi:11ax coex: WDEVAX_PTI0(0x55777555), WDEVAX_PTI1(0x00003377).
> 
> D (3235) wifi:filter: set rx policy=0
> V (3239) wifi:(he)attach, station, phymode:11ax
> I (3243) wifi:mode : sta (d0:cf:13:e0:d5:e0)
> I (3247) wifi:enable tsf
> D (3249) wifi:filter: set rx policy=1
> D (3252) wifi:connect status 0 -> 0
> W (3256) wifi:(BB)enable busy check(0x18), disable idle check(0xaa)
> D (3262) FW_CMD: Sending response of cmd=1 status=2
> 
> D (3266) event: running task for loop 0x4085dcd4
> D (3271) event: running post WIFI_EVENT:43 with handler 0x4200ec62 and context 0x4085de84 on loop 0x4085dcd4
> I (3280) FW_CMD: Unregistered event: 43
> 
> D (3284) event: running post WIFI_EVENT:2 with handler 0x4200ec62 and context 0x4085de84 on loop 0x4085dcd4
> I (3293) FW_CMD: station started
> I (3303) FW_MAIN: Get MAC command
> D (3303) FW_CMD: Sending response of cmd=3 status=2
> 
> D (570) cpu_start: calling init function: 0x420071dc on core: 0
> D (576) cpu_start: calling init function: 0x420008f0 on core: 0
> V (581) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (587) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x502
> D (595) intr_alloc: Connected src 15 to int 0 (cpu 0)
> D (600) cpu_start: calling init function: 0x42000912 on core: 0
> D (606) cpu_start: calling init function: 0x42008dc8 on core: 0
> D (611) cpu_start: calling init function: 0x4200a5c4 on core: 0
> D (617) cpu_start: calling init function: 0x4200baec on core: 0
> D (622) cpu_start: calling init function: 0x4200a8c2 on core: 0
> D (628) cpu_start: calling init function: 0x420071ea on core: 0
> D (634) cpu_start: calling init function: 0x42000922 on core: 0
> V (639) memspi: raw_chip_id: 174020
> 
> V (643) memspi: chip_id: 204017
> 
> V (646) memspi: raw_chip_id: 174020
> 
> V (649) memspi: chip_id: 204017
> 
> D (652) spi_flash: trying chip: generic
> I (656) spi_flash: detected chip: generic
> I (659) spi_flash: flash io: dio
> W (662) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
> D (674) cpu_start: calling init function: 0x4200032e on core: 0
> D (680) cpu_start: calling init function: 0x420ad6c8
> D (685) cpu_start: calling init function: 0x42053b76
> D (690) cpu_start: calling init function: 0x4080d7b8
> D (694) cpu_start: calling init function: 0x4080e2c2
> D (699) cpu_start: calling init function: 0x4204bc98 on core: 0
> V (705) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (711) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC02
> D (718) intr_alloc: Connected src 63 to int 2 (cpu 0)
> D (723) cpu_start: calling init function: 0x420019e0 on core: 0
> D (729) cpu_start: calling init function: 0x42002caa on core: 0
> D (734) cpu_start: calling init function: 0x42003980 on core: 0
> I (740) sleep_gpio: Configure to isolate all GPIO pins in sleep state
> I (746) sleep_gpio: Enable automatic switching of GPIO sleep configuration
> D (753) cpu_start: calling init function: 0x420c6488 on core: 0
> D (758) cpu_start: calling init function: 0x42000974 on core: 0
> I (764) coexist: coex firmware version: 831ec70
> I (768) coexist: coexist rom version 78e5c6e42
> D (773) cpu_start: calling init function: 0x42009dd4 on core: 0
> D (778) cpu_start: calling init function: 0x4200098c on core: 0
> V (784) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (790) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
> D (798) intr_alloc: Connected src 23 to int 3 (cpu 0)
> D (802) app_start: Starting scheduler on CPU0
> V (806) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (806) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x402
> D (806) intr_alloc: Connected src 61 to int 4 (cpu 0)
> I (806) main_task: Started on CPU0
> D (809) heap_init: New heap initialised at 0x4085c5a0
> V (813) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (819) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
> D (827) intr_alloc: Connected src 58 to int 5 (cpu 0)
> I (832) main_task: Calling app_main()
> I (835) stats: *********************************************************************
> I (843) stats:                 ESP-Hosted Firmware version :: NG-1.0.5.0.1                        
> I (852) stats:                 Transport used :: SPI only                      
> I (859) stats: *********************************************************************
> I (866) FW_MAIN: Supported features are:
> I (870) FW_MAIN: - WLAN over SPI
> I (873) FW_BT: - BT/BLE
> I (875) FW_BT:    - HCI Over SPI
> I (878) FW_BT:    - BLE only
> I (880) FW_MAIN: Capabilities: 0xe8
> V (884) partition: Loading the partition table
> V (888) mmap: actual_mapped_len is 0x10000
> V (892) calculated md5: 0x40827528   fd 35 ea be bc e9 5a fd  9d f1 74 0c 7c 12 07 66  |.5....Z...t.|..f|
> V (901) stored md5: 0x421080d0   fd 35 ea be bc e9 5a fd  9d f1 74 0c 7c 12 07 66  |.5....Z...t.|..f|
> V (910) partition: Partition table MD5 verified
> pp rom version: 78a72e9d5
> net80211 rom version: 78a72e9d5
> I (920) wifi:wifi driver task: 4085dd00, prio:23, stack:6656, core=0
> V (925) esp_adapter: thread sem create: sem=0x4085de54
> V (930) esp_adapter: thread sem get: sem=0x4085de54
> D (935) efuse: BLK1 REG1 [8-15], len=8 bits
> D (938) efuse: BLK1 REG1 [0-7], len=8 bits
> D (942) efuse: BLK1 REG0 [24-31], len=8 bits
> D (946) efuse: BLK1 REG0 [16-23], len=8 bits
> D (950) efuse: BLK1 REG0 [8-15], len=8 bits
> D (954) efuse: BLK1 REG0 [0-7], len=8 bits
> I (959) wifi:wifi firmware version: 0f9888e
> I (962) wifi:wifi certification version: v7.0
> I (966) wifi:config NVS flash: disabled
> I (970) wifi:config nano formatting: disabled
> I (974) wifi:mac_version:HAL_MAC_ESP32AX_752MP_ECO2,ut_version:N, band mode:0x3
> I (981) wifi:Init data frame dynamic rx buffer num: 32
> I (986) wifi:Init static rx mgmt buffer num: 5
> I (990) wifi:Init management short buffer num: 32
> I (994) wifi:Init dynamic tx buffer num: 32
> I (998) wifi:Init static tx FG buffer num: 2
> I (1002) wifi:Init static rx buffer size: 1700 (rxctrl:64, csi:512)
> I (1008) wifi:Init static rx buffer num: 10
> I (1012) wifi:Init dynamic rx buffer num: 32
> D (1016) wifi:mms: 3->2
> D (1018) wifi:Reset scan defaults in ms : min,max,passive,chan_dwell :(0,120,360,30)
> V (1026) wifi:hint=255, act_dur=<0,120>, pas_dur=360, nchans=42 history_num=0
> V (1033) esp_adapter: thread sem get: sem=0x4085de54
> I (1037) wifi_init: rx ba win: 6
> I (1040) wifi_init: accept mbox: 6
> I (1043) wifi_init: tcpip mbox: 32
> I (1046) wifi_init: udp mbox: 6
> I (1049) wifi_init: tcp mbox: 6
> I (1052) wifi_init: tcp tx win: 5760
> I (1055) wifi_init: tcp rx win: 5760
> I (1059) wifi_init: tcp mss: 1440
> I (1062) wifi_init: WiFi IRAM OP enabled
> I (1065) wifi_init: WiFi RX IRAM OP enabled
> I (1069) wifi_init: WiFi SLP IRAM OP enabled
> V (1073) esp_adapter: thread sem get: sem=0x4085de54
> V (1078) esp_adapter: thread sem get: sem=0x4085de54
> I (1083) BLE_INIT: Using main XTAL as clock source
> I (1087) BLE_INIT: ble controller commit:[35fe65f]
> I (1095) BLE_INIT: Bluetooth MAC: d0:cf:13:e0:d5:e2
> I (1097) phy_init: phy_version 102,171bf417,Jun 12 2025,15:57:12
> D (1102) phy_init: loading PHY init data from application binary
> D (1108) nvs: nvs_open_from_partition phy 0
> D (1112) nvs: nvs_get cal_version 4
> V (1115) phy_init: phy_get_rf_cal_version: 102
> D (1119) nvs: nvs_get_str_or_blob cal_mac
> D (1123) efuse: BLK1 REG1 [8-15], len=8 bits
> D (1127) efuse: BLK1 REG1 [0-7], len=8 bits
> D (1131) efuse: BLK1 REG0 [24-31], len=8 bits
> D (1135) efuse: BLK1 REG0 [16-23], len=8 bits
> D (1139) efuse: BLK1 REG0 [8-15], len=8 bits
> D (1143) efuse: BLK1 REG0 [0-7], len=8 bits
> D (1147) efuse: BLK1 REG1 [16-31], len=16 bits
> D (1151) nvs: nvs_get_str_or_blob cal_data
> D (1157) nvs: nvs_close 1
> D (1157) efuse: BLK1 REG1 [8-15], len=8 bits
> D (1161) efuse: BLK1 REG1 [0-7], len=8 bits
> D (1165) efuse: BLK1 REG0 [24-31], len=8 bits
> D (1169) efuse: BLK1 REG0 [16-23], len=8 bits
> D (1173) efuse: BLK1 REG0 [8-15], len=8 bits
> D (1177) efuse: BLK1 REG0 [0-7], len=8 bits
> D (1181) efuse: BLK1 REG1 [16-31], len=16 bits
> D (1378) temperature_sensor: range changed, change to index 2
> I (1781) phy: libbtbb version: 09fb4d6, Jun 12 2025, 15:57:24
> V (1782) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (1782) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
> D (1790) intr_alloc: Connected src 7 to int 7 (cpu 0)
> V (1795) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (1801) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
> D (1809) intr_alloc: Connected src 4 to int 8 (cpu 0)
> I (1813) FW_MAIN: ESP Bluetooth MAC addr: d0-cf-13-e0-d5-e2
> 
> I (1819) FW_SPI: Using SPI interface
> I (1822) FW_SPI: Using SPI MODE 2
> D (1825) gpio: GPIO[3]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
> D (1834) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
> I (1842) FW_SPI: SPI Ctrl:1 mode: 2, GPIOs: MOSI: 7, MISO: 2, CS: 10, CLK: 6 HS: 3 DR: 4
> 
> I (1850) FW_SPI: Hosted SPI queue size: Tx:20 Rx:20
> D (1855) gdma: new group (0) at 0x40837c24
> D (1858) gdma: new pair (0,0) at 0x40837ca4
> D (1862) gdma: new tx channel (0,0) at 0x40837bec
> D (1867) gdma: new rx channel (0,0) at 0x40837cc4
> D (1871) spi: SPI2 use iomux pins.
> V (1874) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
> V (1880) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x80E
> D (1888) intr_alloc: Connected src 77 to int 9 (cpu 0)
> I (2894) FW_MAIN: Initial set up done
> I (2894) main_task: Returned from app_main()
> I (2963) FW_MAIN: INIT Interface command
> D (2963) event: created task for loop 0x4085dcd4
> D (2963) event: created event loop 0x4085dcd4
> I (2964) FW_CMD: Setting STA mode
> V (2967) esp_adapter: thread sem create: sem=0x4082771c
> V (2972) esp_adapter: thread sem get: sem=0x4082771c
> V (2976) esp_adapter: thread sem get: sem=0x4082771c
> V (2981) wifi:ht20 freq=2412, chan=1
> W (2986) wifi:WDEV_RXCCK_DELAY:960
> W (2987) wifi:WDEV_RXOFDM_DELAY:263
> W (2991) wifi:WDEV_RX_11G_OFDM_DELAY:264
> W (2994) wifi:WDEV_TXCCK_DELAY:630
> W (2997) wifi:WDEV_TXOFDM_DELAY:94
> W (3001) wifi:ACK_TAB0   :0x   90a0b, QAM16:0x9 (24Mbps), QPSK:0xa (12Mbps), BPSK:0xb (6Mbps)
> W (3009) wifi:CTS_TAB0   :0x   90a0b, QAM16:0x9 (24Mbps), QPSK:0xa (12Mbps), BPSK:0xb (6Mbps)
> W (3017) wifi:WDEVBEAMFORMCONF:0x61d7120, HE_BF_RPT_RA_SET_OPT:1
> W (3023) wifi:WDEVVHTBEAMFORMCONF: 0x61d7120, WDEV_VHT_BEAMFORMEE_ENA: 1, WDEV_VHT_NG_SEL: 0
> W (3031) wifi:(agc)0x600a7128:0xd21f0c20, min.avgNF:0xce->0xd2(dB), RCalCount:0x1f0, min.RRssi:0xc20(-62.00)
> W (3041) wifi:MODEM_SYSCON_WIFI_BB_CFG_REG(0x600a9c18):0x10003802
> W (3046) wifi:(phy)rate:0x0(  LP-1Mbps), pwr:20, txing:20
> W (3051) wifi:(phy)rate:0x1(  LP-2Mbps), pwr:20, txing:20
> W (3056) wifi:(phy)rate:0x2(LP-5.5Mbps), pwr:20, txing:20
> W (3062) wifi:(phy)rate:0x3( LP-11Mbps), pwr:20, txing:20
> W (3067) wifi:(phy)rate:0x5(  SP-2Mbps), pwr:20, txing:20
> W (3072) wifi:(phy)rate:0x6(SP-5.5Mbps), pwr:20, txing:20
> W (3077) wifi:(phy)rate:0x7( SP-11Mbps), pwr:20, txing:20
> W (3082) wifi:(phy)rate:0x8(    48Mbps), pwr:17, txing:17
> W (3087) wifi:(phy)rate:0x9(    24Mbps), pwr:19, txing:19
> W (3092) wifi:(phy)rate:0xa(    12Mbps), pwr:19, txing:19
> W (3097) wifi:(phy)rate:0xb(     6Mbps), pwr:19, txing:19
> W (3103) wifi:(phy)rate:0xc(    54Mbps), pwr:17, txing:17
> W (3108) wifi:(phy)rate:0xd(    36Mbps), pwr:19, txing:19
> W (3113) wifi:(phy)rate:0xe(    18Mbps), pwr:19, txing:19
> W (3118) wifi:(phy)rate:0xf(     9Mbps), pwr:19, txing:19
> W (3123) wifi:(phy)rate:0x10, mcs:0x0, pwr(bw20:19, bw40:18), txing:19, HE pwr(bw20:19), txing:19
> W (3132) wifi:(phy)rate:0x11, mcs:0x1, pwr(bw20:19, bw40:18), txing:19, HE pwr(bw20:19), txing:19
> W (3140) wifi:(phy)rate:0x12, mcs:0x2, pwr(bw20:18, bw40:17), txing:18, HE pwr(bw20:18), txing:18
> W (3149) wifi:(phy)rate:0x13, mcs:0x3, pwr(bw20:18, bw40:17), txing:18, HE pwr(bw20:18), txing:18
> W (3158) wifi:(phy)rate:0x14, mcs:0x4, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3166) wifi:(phy)rate:0x15, mcs:0x5, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3175) wifi:(phy)rate:0x16, mcs:0x6, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3183) wifi:(phy)rate:0x17, mcs:0x7, pwr(bw20:17, bw40:16), txing:17, HE pwr(bw20:17), txing:17
> W (3192) wifi:(phy)rate:0x18, mcs:0x8, pwr(bw20:19, bw40:16), txing:19, HE pwr(bw20:16), txing:16
> W (3200) wifi:(phy)rate:0x19, mcs:0x9, pwr(bw20:18, bw40:16), txing:18, HE pwr(bw20:15), txing:15
> W (3209) wifi:(hal)co_hosted_bss:0, max_indicator:0, bitmask:0xff, mBSSIDsEnable:0
> I (3216) wifi:11ax coex: WDEVAX_PTI0(0x55777555), WDEVAX_PTI1(0x00003377).
> 
> D (3223) wifi:filter: set rx policy=0
> V (3227) wifi:(he)attach, station, phymode:11ax
> I (3231) wifi:mode : sta (d0:cf:13:e0:d5:e0)
> I (3235) wifi:enable tsf
> D (3237) wifi:filter: set rx policy=1
> D (3240) wifi:connect status 0 -> 0
> W (3244) wifi:(BB)enable busy check(0x18), disable idle check(0xaa)
> D (3250) FW_CMD: Sending response of cmd=1 status=2
> 
> D (3254) event: running task for loop 0x4085dcd4
> D (3259) event: running post WIFI_EVENT:43 with handler 0x4200ec62 and context 0x4085de84 on loop 0x4085dcd4
> I (3268) FW_CMD: Unregistered event: 43
> 
> D (3272) event: running post WIFI_EVENT:2 with handler 0x4200ec62 and context 0x4085de84 on loop 0x4085dcd4
> I (3281) FW_CMD: station started
> I (3294) FW_MAIN: Get MAC command
> D (3294) FW_CMD: Sending response of cmd=3 status=2


It seems to me it transfers the first data the ESP to the host (firmware version etc.) Then the host sends cmd 0x1 and receives reply. But then there is an error happening after it sent cmd 0x3 and is waiting for the reply. 

I can't see anything strange when checking the SPI communication in the logic analyser...

Anyone understand what is happening? Is it a bug in the host code?

### Error logs or terminal output

```shell

```

### Steps to reproduce the behavior

Connect the ESP with SPI only
Insert the host module
check the dmesg

### Project release version

unreleased master 7c06bbc

### System architecture

ARM 32-bit (Raspberry Pi 32-bit)

### Operating system

Linux

### Operating system version

Armbian

### Shell

ZSH

### Additional context

_No response_

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

esp32_spi: esp_cmd_work: Busy in another cmd execution (ESP32C5, nanopi neo air) #660

Checklist

How often does this bug occurs?

Expected behavior

Actual behavior (suspected bug)

Error logs or terminal output

Steps to reproduce the behavior

Project release version

System architecture

Operating system

Operating system version

Shell

Additional context

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

esp32_spi: esp_cmd_work: Busy in another cmd execution (ESP32C5, nanopi neo air) #660

Description

Checklist

How often does this bug occurs?

Expected behavior

Actual behavior (suspected bug)

Error logs or terminal output

Steps to reproduce the behavior

Project release version

System architecture

Operating system

Operating system version

Shell

Additional context

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions