Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Host cannot communicate with ESP32-WROOM-32D via spi #533

Open
3 tasks done
luckzhang888 opened this issue Nov 4, 2024 · 41 comments
Open
3 tasks done

Host cannot communicate with ESP32-WROOM-32D via spi #533

luckzhang888 opened this issue Nov 4, 2024 · 41 comments

Comments

@luckzhang888
Copy link

Checklist

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

How often does this bug occurs?

always

Expected behavior

hope spi can work properly

Actual behavior (suspected bug)

Burning ESP-Hosted-NG Release 1.0.2 firmware to ESP32-WROOM32D, a spi communication error occurs when the host loads the driver.

Error logs or terminal output

~# insmod esp32_spi.ko
[ 7679.901290] esp32_spi: spi_dev_init: Using SPI MODE 2
[ 7679.907391] esp32_spi: spi_dev_init: ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [40]
~# [ 7684.880070] esp32_spi: process_rx_buf: offset_rcv[0] != exp[12], drop

Steps to reproduce the behavior

NG host driver with ESP32

Project release version

ESP-Hosted-NG Release 1.0.2

System architecture

ARM 32-bit (Raspberry Pi 32-bit)

Operating system

Linux

Operating system version

ubuntu20.04

Shell

Bash

Additional context

No response

@luckzhang888
Copy link
Author

I (27) boot: ESP-IDF v4.4.1-584-g91dc99a3ce-dirty 2nd stage bootloader
I (27) boot: compile time 17:06:17
I (28) boot: chip revision: 1
I (32) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (39) boot.esp32: SPI Speed : 40MHz
I (43) boot.esp32: SPI Mode : DIO
I (48) boot.esp32: SPI Flash Size : 4MB
I (52) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (61) boot: ## Label Usage Type ST Offset Length
I (69) boot: 0 nvs WiFi data 01 02 00009000 00004000
I (76) boot: 1 otadata OTA data 01 00 0000d000 00002000
I (84) boot: 2 phy_init RF data 01 01 0000f000 00001000
I (91) boot: 3 factory factory app 00 00 00010000 00100000
I (99) boot: 4 ota_0 OTA app 00 10 00110000 00100000
I (106) boot: 5 ota_1 OTA app 00 11 00210000 00100000
I (114) boot: End of partition table
I (118) boot: Defaulting to factory image
I (123) boot_comm: chip revision: 1, min. application chip revision: 0
I (130) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=17a24h ( 96804) map
I (173) esp_image: segment 1: paddr=00027a4c vaddr=3ffbdb60 size=05578h ( 21880) load
I (182) esp_image: segment 2: paddr=0002cfcc vaddr=40080000 size=0304ch ( 12364) load
I (188) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=89534h (562484) map
I (393) esp_image: segment 4: paddr=000b955c vaddr=4008304c size=1a5f0h (108016) load
I (438) esp_image: segment 5: paddr=000d3b54 vaddr=50000000 size=00010h ( 16) load
I (453) boot: Loaded app from partition at offset 0x10000
I (453) boot: Disabling RNG early entropy source...
I (464) cpu_start: Pro cpu up.
I (465) cpu_start: Starting app cpu, entry point is 0x4008125c
I (0) cpu_start: App cpu up.
I (481) cpu_start: Pro cpu start user code
I (481) cpu_start: cpu freq: 240000000

/esp-hosted-master/esp_hosted_ng/host/spi/esp_spi.c
#define SPI_INITIAL_CLK_MHZ 40
#define TX_MAX_PENDING_COUNT 100
#define TX_RESUME_THRESHOLD (TX_MAX_PENDING_COUNT/5)

@mantriyogesh
Copy link
Collaborator

  1. Please check Porting Guide. The jumper lengths and spi frequency to be used.
    As porting guide mentions, Use lower freq and gradually increase in steps (1m), till host saturates (typically in wired setup)

  2. Use exact same git commit at host and slave. If slave binary used from 1.0.2 release , use the git commit of that only.
    We strongly recommend using latest master for multiple bug fixes done recently.

  3. chip id in esp log is confusing.

I (28) boot: chip revision: 1

Which esp chipset do you use? Are you flashing the esp NG firmware correctly?

Reference chip id from esp-idf:
https://github.com/espressif/esp-idf/blob/ce6085349f8d5a95fc857e28e2d73d73dd3629b5/Kconfig#L143-L155

@mantriyogesh
Copy link
Collaborator

ESP32(-WROOM-32D)- can go only 10m max SPI freq. Do not use more than 10, it wouldn't communicate.

@luckzhang888
Copy link
Author

1.It’s not possible to change it to 5M.

insmod esp32_spi.ko

[ 6500.464192] esp32_spi: spi_dev_init: Using SPI MODE 2
[ 6500.470290] esp32_spi: spi_dev_init: ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [5]

[ 6504.576985] esp32_spi: process_rx_buf: offset_rcv[0] != exp[12], drop

2.The binary firmware and host source code here are used.

19138cfd85a94cb346bdf6da4a80803

3.To refresh the firmware, we use flash_download_tool_3.9.7.exe burned by this program.No firmware ID selected

@luckzhang888
Copy link
Author

@mantriyogesh
Copy link
Collaborator

  1. Can you please show your setup by clicking photo?
  2. Would it be possible to test using latest master at both sides (with freq <=10m)?

@luckzhang888
Copy link
Author

Use the latest https://github.com/espressif/esp-hosted.git to compile and burn the firmware and keep restarting

image

@mantriyogesh
Copy link
Collaborator

Can you use esp flashing procedure using https://github.com/espressif/esp-hosted/tree/master/esp_hosted_ng/esp/esp_driver

@luckzhang888
Copy link
Author

Now we can communicate, but we can't scan the AP and connect, and it's always stuck.
iw dev wlan0 scan

# insmod esp32_spi.ko
[ 106.275278] esp32_spi: loading out-of-tree module taints kernel.
[ 106.501437] esp32_spi: spi_dev_init: Using SPI MODE 2
[ 106.507538] esp32_spi: spi_dev_init: ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [4]
root@myd-yt113-i:
# [ 132.608330] esp32_spi: process_esp_bootup_event: Received ESP bootup event
[ 132.616176] esp32_spi: process_event_esp_bootup: Bootup Event tag: 3
[ 132.623431] esp32_spi: esp_validate_chipset: Chipset=ESP32 ID=00 detected over SPI
[ 132.632027] esp32_spi: process_event_esp_bootup: Bootup Event tag: 2
[ 132.639176] esp32_spi: process_event_esp_bootup: Bootup Event tag: 0
[ 132.646353] esp32_spi: process_event_esp_bootup: Bootup Event tag: 1
[ 132.653565] esp32_spi: process_fw_data: ESP chipset's last reset cause:
[ 132.660994] esp32_spi: print_reset_reason: POWERON_RESET
[ 132.666997] esp32_spi: check_esp_version: ESP-Hosted Version: NG-1.0.3.0.0
[ 132.675310] esp32_spi: esp_reg_notifier: Driver init is ongoing
[ 133.121071] esp32_spi: init_bt: ESP Bluetooth init
[ 133.127561] esp32_spi: print_capabilities: Capabilities: 0xf8. Features supported are:
[ 133.136617] esp32_spi: print_capabilities: * WLAN on SPI
[ 133.142928] esp32_spi: print_capabilities: * BT/BLE
[ 133.148632] esp32_spi: print_capabilities: - HCI over SPI
[ 133.155259] esp32_spi: print_capabilities: - BT/BLE dual mode

I (619) main_task: Calling app_main()
I (623) stats: *********************************************************************
I (631) stats: ESP-Hosted Firmware version :: NG-1.0.3.0.0
I (641) stats: Transport used :: SPI only
I (649) stats: *********************************************************************
I (657) FW_MAIN: Supported features are:
I (662) FW_MAIN: - WLAN over SPI
I (666) FW_BT: - BT/BLE
I (669) FW_BT: - HCI Over SPI
I (673) FW_BT: - BT/BLE dual mode
I (677) FW_MAIN: Capabilities: 0xf8
I (693) wifi:wifi driver task: 3ffbd5f0, prio:23, stack:6656, core=1
I (695) wifi:wifi firmware version: d23b633
I (696) wifi:wifi certification version: v7.0
I (698) wifi:config NVS flash: disabled
I (701) wifi:config nano formating: disabled
I (706) wifi:Init data frame dynamic rx buffer num: 40
I (710) wifi:Init static rx mgmt buffer num: 5
I (714) wifi:Init management short buffer num: 32
I (719) wifi:Init dynamic tx buffer num: 64
I (723) wifi:Init static rx buffer size: 1600
I (727) wifi:Init static rx buffer num: 16
I (731) wifi:Init dynamic rx buffer num: 40
I (736) wifi_init: rx ba win: 32
I (738) wifi_init: tcpip mbox: 32
I (742) wifi_init: udp mbox: 6
I (746) wifi_init: tcp mbox: 6
I (750) wifi_init: tcp tx win: 5760
I (754) wifi_init: tcp rx win: 5760
I (758) wifi_init: tcp mss: 1440
I (762) wifi_init: WiFi IRAM OP enabled
I (767) wifi_init: WiFi RX IRAM OP enabled
I (772) BTDM_INIT: BT controller compile version [a38dc5c]
I (779) BTDM_INIT: Bluetooth MAC: 40:f5:20:99:11:46
I (786) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
I (1170) FW_MAIN: ESP Bluetooth MAC addr: 40-f5-20-99-11-46

I (1171) FW_SPI: Using SPI interface
I (1171) FW_SPI: Using SPI MODE 2
I (1174) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1183) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (2195) FW_MAIN: Initial set up done
I (2195) main_task: Returned from app_main()
I (2356) FW_MAIN: INIT Interface command

I (2360) wifi:mode : sta (40:f5:20:99:11:44)
I (2361) wifi:enable tsf
I (2361) FW_CMD: station started and disabled softap mode
I (2416) FW_MAIN: Get MAC command

I (2488) FW_MAIN: Get Tx power command

I (159278) FW_MAIN: Scan request

@luckzhang888
Copy link
Author

~# ifconfig
eth0 Link encap:Ethernet HWaddr 2E:8F:67:11:C5:13
inet addr:192.168.1.201 Bcast:192.168.1.255 Mask:255.255.255.0
inet6 addr: fe80::2c8f:67ff:fe11:c513/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:7875 errors:0 dropped:0 overruns:0 frame:0
TX packets:655 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:2869102 (2.7 MiB) TX bytes:64318 (62.8 KiB)
Interrupt:39

lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
inet6 addr: ::1/128 Scope:Host
UP LOOPBACK RUNNING MTU:65536 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

wlan0 Link encap:Ethernet HWaddr 40:F5:20:99:11:44
inet6 addr: fe80::42f5:20ff:fe99:1144/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:18 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

~# iw dev wlan0 scan | grep SSID
[ 928.621072] esp32_spi: wait_and_decode_cmd_resp: Command[0x4] timed out
[ 928.628522] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
command failed: Invalid argument (-22)

@mantriyogesh
Copy link
Collaborator

@kapilkedawat ++

@luckzhang888
Copy link
Author

Using mode 2, the 3M frequency will also appear.

image

I (29) boot: ESP-IDF e7771c75-dirty 2nd stage bootloader
I (29) boot: compile time Nov 5 2024 15:23:44
I (29) boot: Multicore bootloader
I (34) boot: chip revision: v1.0
I (38) boot.esp32: SPI Speed : 40MHz
I (42) boot.esp32: SPI Mode : DIO
I (47) boot.esp32: SPI Flash Size : 4MB
I (51) boot: Enabling RNG early entropy source...
I (57) boot: Partition Table:
I (60) boot: ## Label Usage Type ST Offset Length
I (68) boot: 0 nvs WiFi data 01 02 00009000 00004000
I (75) boot: 1 otadata OTA data 01 00 0000d000 00002000
I (83) boot: 2 phy_init RF data 01 01 0000f000 00001000
I (90) boot: 3 factory factory app 00 00 00010000 00100000
I (98) boot: 4 ota_0 OTA app 00 10 00110000 00100000
I (105) boot: 5 ota_1 OTA app 00 11 00210000 00100000
I (113) boot: End of partition table
I (117) boot: Defaulting to factory image
I (122) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=204b4h (132276) map
I (178) esp_image: segment 1: paddr=000304dc vaddr=3ffbdb60 size=05894h ( 22676) load
I (187) esp_image: segment 2: paddr=00035d78 vaddr=40080000 size=0a2a0h ( 41632) load
I (205) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=8aabch (567996) map
I (410) esp_image: segment 4: paddr=000caae4 vaddr=4008a2a0 size=15794h ( 87956) load
I (463) boot: Loaded app from partition at offset 0x10000
I (463) boot: Disabling RNG early entropy source...
I (474) cpu_start: Multicore app
I (475) cpu_start: Pro cpu up.
I (475) cpu_start: Starting app cpu, entry point is 0x40081444
I (0) cpu_start: App cpu up.
I (492) cpu_start: Pro cpu start user code
I (493) cpu_start: cpu freq: 240000000 Hz
I (493) cpu_start: Application information:
I (497) cpu_start: Project name: network_adapter
I (503) cpu_start: App version: NG-1.0.3.0.0
I (508) cpu_start: Compile time: Nov 5 2024 16:23:24
I (514) cpu_start: ELF file SHA256: 12630737cc66c48a...
I (520) cpu_start: ESP-IDF: e7771c75-dirty
I (526) cpu_start: Min chip rev: v0.0
I (531) cpu_start: Max chip rev: v3.99
I (535) cpu_start: Chip rev: v1.0
I (540) heap_init: Initializing. RAM available for dynamic allocation:
I (548) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (553) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (560) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (566) heap_init: At 3FFC7D28 len 000182D8 (96 KiB): DRAM
I (572) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (578) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (585) heap_init: At 4009FA34 len 000005CC (1 KiB): IRAM
I (592) spi_flash: detected chip: generic
I (595) spi_flash: flash io: dio
I (600) coexist: coex firmware version: 77cd7f8
I (605) app_start: Starting scheduler on CPU0
I (610) app_start: Starting scheduler on CPU1
mI (610) main_task: Started on CPU0
I (619) main_task: Calling app_main()
I (623) stats: *********************************************************************
I (631) stats: ESP-Hosted Firmware version :: NG-1.0.3.0.0
I (641) stats: Transport used :: SPI only
I (649) stats: *********************************************************************
I (657) FW_MAIN: Supported features are:
I (662) FW_MAIN: - WLAN over SPI
I (666) FW_BT: - BT/BLE
I (669) FW_BT: - HCI Over SPI
I (673) FW_BT: - BT/BLE dual mode
I (677) FW_MAIN: Capabilities: 0xf8
I (693) wifi:wifi driver task: 3ffbd5f0, prio:23, stack:6656, core=1
I (695) wifi:wifi firmware version: d23b633
I (696) wifi:wifi certification version: v7.0
I (698) wifi:config NVS flash: disabled
I (701) wifi:config nano formating: disabled
I (706) wifi:Init data frame dynamic rx buffer num: 40
I (710) wifi:Init static rx mgmt buffer num: 5
I (714) wifi:Init management short buffer num: 32
I (719) wifi:Init dynamic tx buffer num: 64
I (723) wifi:Init static rx buffer size: 1600
I (727) wifi:Init static rx buffer num: 16
I (731) wifi:Init dynamic rx buffer num: 40
I (736) wifi_init: rx ba win: 32
I (738) wifi_init: tcpip mbox: 32
I (742) wifi_init: udp mbox: 6
I (746) wifi_init: tcp mbox: 6
I (750) wifi_init: tcp tx win: 5760
I (754) wifi_init: tcp rx win: 5760
I (758) wifi_init: tcp mss: 1440
I (762) wifi_init: WiFi IRAM OP enabled
I (767) wifi_init: WiFi RX IRAM OP enabled
I (772) BTDM_INIT: BT controller compile version [a38dc5c]
I (778) BTDM_INIT: Bluetooth MAC: 40:f5:20:99:11:46
I (786) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
I (1183) FW_MAIN: ESP Bluetooth MAC addr: 40-f5-20-99-11-46

I (1183) FW_SPI: Using SPI interface
I (1184) FW_SPI: Using SPI MODE 2
I (1187) FW_SPI: Using SPI CLK_MHZ 3
I (1191) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1200) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (2212) FW_MAIN: Initial set up done
I (2212) main_task: Returned from app_main()
I (2342) FW_MAIN: INIT Interface command

I (2346) wifi:mode : sta (40:f5:20:99:11:44)
I (2347) wifi:enable tsf
I (2347) FW_CMD: station started and disabled softap mode

@mantriyogesh
Copy link
Collaborator

can you please check your transport correctness first in both rx and tx directions?

@luckzhang888
Copy link
Author

This is using spi instead of uart

@luckzhang888
Copy link
Author

# insmod esp32_spi.ko
[12092.959365] esp32_spi: spi_dev_init: Using SPI MODE 0
[12092.965371] esp32_spi: spi_dev_init: ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [3]
root@myd-yt113-i:
# [12101.323767] esp32_spi: process_esp_bootup_event: Received ESP bootup event
[12101.331578] esp32_spi: process_event_esp_bootup: Bootup Event tag: 3
[12101.338717] esp32_spi: esp_validate_chipset: Chipset=ESP32 ID=00 detected over SPI
[12101.347266] esp32_spi: process_event_esp_bootup: Bootup Event tag: 2
[12101.354483] esp32_spi: process_event_esp_bootup: Bootup Event tag: 0
[12101.361676] esp32_spi: process_event_esp_bootup: Bootup Event tag: 1
[12101.368813] esp32_spi: process_fw_data: ESP chipset's last reset cause:
[12101.376273] esp32_spi: print_reset_reason: POWERON_RESET
[12101.382281] esp32_spi: check_esp_version: ESP-Hosted Version: NG-1.0.3.0.0
[12101.390538] esp32_spi: esp_reg_notifier: Driver init is ongoing
[12101.779027] esp32_spi: init_bt: ESP Bluetooth init
[12101.785537] esp32_spi: print_capabilities: Capabilities: 0xf8. Features supported are:
[12101.794644] esp32_spi: print_capabilities: * WLAN on SPI
[12101.801576] esp32_spi: print_capabilities: * BT/BLE
[12101.807287] esp32_spi: print_capabilities: - HCI over SPI
[12101.813970] esp32_spi: print_capabilities: - BT/BLE dual mode
[12104.239033] Bluetooth: hci0: command 0x0c46 tx timeout
[12104.249560] Bluetooth: hci0: unexpected event for opcode 0x0c46

@luckzhang888
Copy link
Author

root@myd-yt113-i:~# hciconfig
hci0: Type: Primary Bus: SPI
BD Address: 40:F5:20:99:11:46 ACL MTU: 1021:9 SCO MTU: 255:4
DOWN
RX bytes:660 acl:0 sco:0 events:78 errors:0
TX bytes:408 acl:0 sco:0 commands:0 errors:0

root@myd-yt113-i:#
root@myd-yt113-i:
# hciconfig hci up
[12161.689038] Bluetooth: hci0: command 0x080f tx timeout

@mantriyogesh
Copy link
Collaborator

Bluetooth: hci0: command 0x080f tx timeout

clearly says the spi transport is not correctly transferring the messages and set properly.
Check porting guide and perform transport correctness test.

(link in prior comments)

Unless correctly ported, you would fall in unexpected errors @luckzhang888

@luckzhang888
Copy link
Author

I followed the transplant guide. If the configuration is not correct, there will be no success. Now the handshake is successful and the wifi and Bluetooth functions cannot be realized.

@mantriyogesh
Copy link
Collaborator

Check the spi timing issues that you faced. porting guide suggest to use some ways to correct the spi timing issues.

The guide suggest to use spi mode 1 etc, to avoid spi timing issues. the transport test is mandatory before using it for wifi or bluetooth.

if spi has issues, how can any applications running over it work properly?

@mantriyogesh
Copy link
Collaborator

there are 3 GPIOs, data ready, handshake and slave reset.
verify these are correctly working.
for example reset pin would reset the esp on reload of kernel module.
handshake and data ready interrupts to be checked if hit correctly.

once this is done, lower spi freq and try transport test.

if rx and tx has different speeds or checksum errors, your test is failed. focus on spi timing tuning mentioned in porting guide then.

@Shreyas0-7
Copy link
Contributor

Hey @luckzhang888 can you please try this patch for hci error?
hci.zip

cd ~/PATH/esp_hosted/
Unzip patch
git apply hci.patch

@luckzhang888
Copy link
Author

I should see which document should check the SPI communication question

@luckzhang888
Copy link
Author

The problem after patch is still the same

~# insmod esp32_spi.ko
[ 610.512434] esp32_spi: spi_dev_init: Using SPI MODE 1
[ 610.518527] esp32_spi: spi_dev_init: ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [1]
~#
~# [ 619.519075] esp32_spi: process_esp_bootup_event: Received ESP bootup event
[ 619.526874] esp32_spi: process_event_esp_bootup: Bootup Event tag: 3
[ 619.534056] esp32_spi: esp_validate_chipset: Chipset=ESP32 ID=00 detected over SPI
[ 619.542603] esp32_spi: process_event_esp_bootup: Bootup Event tag: 2
[ 619.549741] esp32_spi: process_event_esp_bootup: Bootup Event tag: 0
[ 619.556947] esp32_spi: process_event_esp_bootup: Bootup Event tag: 1
[ 619.564131] esp32_spi: process_fw_data: ESP chipset's last reset cause:
[ 619.571561] esp32_spi: print_reset_reason: POWERON_RESET
[ 619.577576] esp32_spi: check_esp_version: ESP-Hosted Version: NG-1.0.3.0.0
[ 619.585984] esp32_spi: esp_reg_notifier: Driver init is ongoing
[ 620.092078] esp32_spi: init_bt: ESP Bluetooth init
[ 620.098560] esp32_spi: print_capabilities: Capabilities: 0xf8. Features supported are:
[ 620.107619] esp32_spi: print_capabilities: * WLAN on SPI
[ 620.114149] esp32_spi: print_capabilities: * BT/BLE
[ 620.119858] esp32_spi: print_capabilities: - HCI over SPI
[ 620.126428] esp32_spi: print_capabilities: - BT/BLE dual mode
[ 622.382083] Bluetooth: hci0: command 0x1005 tx timeout
[ 624.542082] Bluetooth: hci0: command 0x0c38 tx timeout
[ 627.182085] Bluetooth: hci0: command 0x0c1b tx timeout
[ 627.201027] Bluetooth: hci0: unexpected event for opcode 0x0c1b
[ 629.582087] Bluetooth: hci0: command 0x1004 tx timeout
[ 635.502105] __hci_init(888), err = -110, EINVAL.

          I (28) boot: ESP-IDF e7771c75-dirty 2nd stage bootloader

I (28) boot: compile time Nov 5 2024 15:23:44
I (29) boot: Multicore bootloader
I (33) boot: chip revision: v1.0
I (37) boot.esp32: SPI Speed : 40MHz
I (42) boot.esp32: SPI Mode : DIO
I (46) boot.esp32: SPI Flash Size : 4MB
I (51) boot: Enabling RNG early entropy source...
I (56) boot: Partition Table:
I (60) boot: ## Label Usage Type ST Offset Length
I (67) boot: 0 nvs WiFi data 01 02 00009000 00004000
I (75) boot: 1 otadata OTA data 01 00 0000d000 00002000
I (82) boot: 2 phy_init RF data 01 01 0000f000 00001000
I (90) boot: 3 factory factory app 00 00 00010000 00100000
I (97) boot: 4 ota_0 OTA app 00 10 00110000 00100000
I (104) boot: 5 ota_1 OTA app 00 11 00210000 00100000
I (112) boot: End of partition table
I (116) boot: Defaulting to factory image
I (121) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=204b4h (132276) map
I (177) esp_image: segment 1: paddr=000304dc vaddr=3ffbdb60 size=05894h ( 22676) load
I (187) esp_image: segment 2: paddr=00035d78 vaddr=40080000 size=0a2a0h ( 41632) load
I (204) esp_image: segment 3: paddr=00040020 vaddr=400d0020 size=8aabch (567996) map
I (409) esp_image: segment 4: paddr=000caae4 vaddr=4008a2a0 size=15794h ( 87956) load
I (462) boot: Loaded app from partition at offset 0x10000
I (462) boot: Disabling RNG early entropy source...
I (474) cpu_start: Multicore app
I (474) cpu_start: Pro cpu up.
I (474) cpu_start: Starting app cpu, entry point is 0x40081444
I (0) cpu_start: App cpu up.
I (492) cpu_start: Pro cpu start user code
I (492) cpu_start: cpu freq: 240000000 Hz
I (492) cpu_start: Application information:
I (497) cpu_start: Project name: network_adapter
I (502) cpu_start: App version: NG-1.0.3.0.0
I (508) cpu_start: Compile time: Nov 5 2024 16:23:24
I (514) cpu_start: ELF file SHA256: 8580863d434136aa...
I (520) cpu_start: ESP-IDF: e7771c75-dirty
I (525) cpu_start: Min chip rev: v0.0
I (530) cpu_start: Max chip rev: v3.99
I (535) cpu_start: Chip rev: v1.0
I (540) heap_init: Initializing. RAM available for dynamic allocation:
I (547) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (553) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (559) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (565) heap_init: At 3FFC7D28 len 000182D8 (96 KiB): DRAM
I (571) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (578) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (584) heap_init: At 4009FA34 len 000005CC (1 KiB): IRAM
I (592) spi_flash: detected chip: generic
I (595) spi_flash: flash io: dio
I (600) coexist: coex firmware version: 77cd7f8
I (605) app_start: Starting scheduler on CPU0
I (609) app_start: Starting scheduler on CPU1
mI (609) main_task: Started on CPU0
I (618) main_task: Calling app_main()
I (622) stats: *********************************************************************
I (630) stats: ESP-Hosted Firmware version :: NG-1.0.3.0.0
I (640) stats: Transport used :: SPI only
I (648) stats: *********************************************************************
I (656) FW_MAIN: Supported features are:
I (661) FW_MAIN: - WLAN over SPI
I (665) FW_BT: - BT/BLE
I (668) FW_BT: - HCI Over SPI
I (672) FW_BT: - BT/BLE dual mode
I (676) FW_MAIN: Capabilities: 0xf8
I (692) wifi:wifi driver task: 3ffbd5f0, prio:23, stack:6656, core=1
I (694) wifi:wifi firmware version: d23b633
I (695) wifi:wifi certification version: v7.0
I (697) wifi:config NVS flash: disabled
I (700) wifi:config nano formating: disabled
I (705) wifi:Init data frame dynamic rx buffer num: 40
I (709) wifi:Init static rx mgmt buffer num: 5
I (713) wifi:Init management short buffer num: 32
I (718) wifi:Init dynamic tx buffer num: 64
I (722) wifi:Init static rx buffer size: 1600
I (726) wifi:Init static rx buffer num: 16
I (730) wifi:Init dynamic rx buffer num: 40
I (735) wifi_init: rx ba win: 32
I (737) wifi_init: tcpip mbox: 32
I (741) wifi_init: udp mbox: 6
I (745) wifi_init: tcp mbox: 6
I (749) wifi_init: tcp tx win: 5760
I (753) wifi_init: tcp rx win: 5760
I (757) wifi_init: tcp mss: 1440
I (761) wifi_init: WiFi IRAM OP enabled
I (766) wifi_init: WiFi RX IRAM OP enabled
I (771) BTDM_INIT: BT controller compile version [a38dc5c]
I (777) BTDM_INIT: Bluetooth MAC: 98:cd:ac:4c:43:72
I (785) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
I (1170) FW_MAIN: ESP Bluetooth MAC addr: 98-cd-ac-4c-43-72

I (1171) FW_SPI: Using SPI interface
I (1171) FW_SPI: Using SPI MODE 1
I (1174) FW_SPI: Using SPI CLK_MHZ 1
I (1179) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1188) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (2199) FW_MAIN: Initial set up done
I (2199) main_task: Returned from app_main()
I (2349) FW_MAIN: INIT Interface command

I (2353) wifi:mode : sta (98:cd:ac:4c:43:70)
I (2354) wifi:enable tsf
I (2355) FW_CMD: station started and disabled softap mode
I (2449) FW_MAIN: Get MAC command

I (2542) FW_MAIN: Get Tx power command

@luckzhang888
Copy link
Author

image

~# [ 3191.520325] esp32_spi: process_rx_buf: SPI RX buf: IF type = 3
[ 3191.526962] esp32_spi: process_esp_bootup_event: Received ESP bootup event
[ 3191.534732] esp32_spi: process_event_esp_bootup: Bootup Event tag: 3
[ 3191.541875] esp32_spi: esp_validate_chipset: Chipset=ESP32 ID=00 detected over SPI
[ 3191.550454] esp32_spi: process_event_esp_bootup: Bootup Event tag: 2
[ 3191.557664] esp32_spi: process_event_esp_bootup: Bootup Event tag: 0
[ 3191.564857] esp32_spi: process_event_esp_bootup: Bootup Event tag: 1
[ 3191.571995] esp32_spi: process_fw_data: ESP chipset's last reset cause:
[ 3191.579482] esp32_spi: print_reset_reason: POWERON_RESET
[ 3191.585485] esp32_spi: check_esp_version: ESP-Hosted Version: NG-1.0.3.0.0
[ 3191.594070] esp32_spi: esp_reg_notifier: Driver init is ongoing
[ 3191.645304] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3191.666019] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3191.685746] esp32_spi: process_rx_buf: SPI RX buf: IF type = 0
[ 3191.755103] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3191.774753] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3191.794416] esp32_spi: process_rx_buf: SPI RX buf: IF type = 0
[ 3191.845152] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3191.864828] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3191.884504] esp32_spi: process_rx_buf: SPI RX buf: IF type = 0
[ 3192.102068] esp32_spi: init_bt: ESP Bluetooth init
[ 3192.108615] esp32_spi: print_capabilities: Capabilities: 0xf8. Features supported are:
[ 3192.117678] esp32_spi: print_capabilities: * WLAN on SPI
[ 3192.123922] esp32_spi: print_capabilities: * BT/BLE
[ 3192.129600] esp32_spi: print_capabilities: - HCI over SPI
[ 3192.136191] esp32_spi: print_capabilities: - BT/BLE dual mode
[ 3192.136558] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.162795] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.182472] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.202136] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.221857] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.241599] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.261300] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.280991] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.300669] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.320368] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.340121] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.359860] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.380055] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.399769] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.419450] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.439142] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.458874] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.478643] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.498344] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.518035] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.537716] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.557406] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.577169] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.596890] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.616586] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.636275] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.655950] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.675630] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.695357] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.715082] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.734736] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.754388] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.774038] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.793702] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.813411] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.833181] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.852841] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.872499] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.892165] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.911821] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.931586] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.951306] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3192.970991] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3192.990679] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3193.010351] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3193.030052] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3193.049792] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3193.069538] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3193.089239] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3193.108929] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3193.128616] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3193.148309] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3193.168055] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.182067] Bluetooth: hci0: command 0x0c45 tx timeout
[ 3195.200971] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.220693] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.240391] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.260097] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.279899] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.299619] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.324106] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.343855] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.363557] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.383249] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.402943] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.422632] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.442315] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.461975] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.481662] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.501351] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.521113] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.540850] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.560548] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.580245] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.599927] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.619643] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.639371] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.659087] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.678806] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.698493] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.718178] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.737870] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.757627] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.777386] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.797067] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.816753] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.836432] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.856130] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.875903] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.895643] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.915349] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.935055] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.954701] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3195.974367] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3195.994063] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3196.013759] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3196.033421] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3196.053083] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3196.072735] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3196.092410] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3196.112202] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3198.142070] Bluetooth: hci0: command 0x1004 tx timeout
[ 3205.742071] __hci_init(888), err = -110, EINVAL.
[ 3205.760433] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.780154] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.799870] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3205.819595] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.839363] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.859095] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3205.878813] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.898507] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.918197] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2
[ 3205.937889] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.957633] esp32_spi: process_rx_buf: SPI RX buf: IF type = 15
[ 3205.977388] esp32_spi: process_rx_buf: SPI RX buf: IF type = 2

@luckzhang888
Copy link
Author

I printed out the spi data on both sides. The sending and receiving are the same, but the host will time out.
image

@Shreyas0-7
Copy link
Contributor

Shreyas0-7 commented Nov 7, 2024

Hey @luckzhang888
can you please enable BT logs for fw
idf.py menuconfig -> example configuration
image
Also set log_level of host to verbose
change line number 39 in ~/PATH/esp_hosted/esp_hosted_ng/host.main.c
from
int log_level = ESP_INFO;
to
int log_level = ESP_VERBOSE;

Also please share complete log files for

  1. wpa_supplicant
  2. dmesg
  3. esp firmware

@luckzhang888
Copy link
Author

dmesg.log

esp.log
These two files are the logs of host and esp.

@luckzhang888
Copy link
Author

can you take a look

@Shreyas0-7
Copy link
Contributor

Hey @luckzhang888
Thank you for trying out and providing the logs, we are checking this and will get back shortly.

@Shreyas0-7
Copy link
Contributor

Hey @luckzhang888
Sharing a patch which will help us to debug more can you please apply this patch on lastest commit and share the logs.
bt_debug.zip

@luckzhang888
Copy link
Author

dmesg.log
esp.log
host.log
This is about the log after adding the patch.

@dnguyen24498
Copy link

dnguyen24498 commented Nov 11, 2024

@luckzhang888 ,
I'm facing the same issue as you when loading the esp32_spi.ko, and I'm also using the ESP32-WROOM-32D dev kit.
image

How you can fix that?

@luckzhang888
Copy link
Author

Try changing the spi clock of host and esp to 1M
image

@luckzhang888
Copy link
Author

@Shreyas0-7
Can you see the problem?

@dnguyen24498
Copy link

Try changing the spi clock of host and esp to 1M image

I tried, but it still failed. Which ESP32 dev kit are you using?
Do you need to add resistors to the SPI pins?
I'm using this kit:
image

@Shreyas0-7
Copy link
Contributor

Shreyas0-7 commented Nov 12, 2024

Hey @luckzhang888
Here is request response between host and spi
Host bt_tx request
[ 981.310913] bt_tx: 6e81cf78: 16 0c 02 00 7d

ESP bt_rx request received
I (4816) H -> S: 0x3ffdb43f 16 0c 02 00 7d 00 00 00 |....}...|
I (4824) bt_rx: 0x3ffdb43f 16 0c 02 00 7d |....}|

ESP bt_tx reponse
I (4835) bt_tx: 0x3ffd24ae 04 0e 04 05 16 0c 00

But we can no SPI RX hence we get
[ 983.394795] Bluetooth: hci0: command 0x0c16 tx timeout

As per the above mentioned request and replies, it seems like packets are dropped in SPI level. Could you please check porting guide and make sure your transport is okay, this is prerequisite before trying out WiFi or BT connections.

@luckzhang888
Copy link
Author

I transplanted it according to this
https://github.com/espressif/esp-hosted/blob/master/esp_hosted_ng/docs/porting_guide.md
This is the host and esp source code

main.zip
host.zip

@luckzhang888
Copy link
Author

@Shreyas0-7

@Shreyas0-7
Copy link
Contributor

Hey @luckzhang888
Hey can you please your transport is working fine by running raw throughput https://github.com/espressif/esp-hosted/blob/master/esp_hosted_ng/docs/Raw_TP_Testing.md
Also can you please us with sharing setup pics and checking wire lenghts

@luckzhang888
Copy link
Author

@Shreyas0-7
How do I perform throughput testing?
image

@Shreyas0-7
Copy link
Contributor

Hey @luckzhang888
You can follow this guide for throughput testing https://github.com/espressif/esp-hosted/blob/master/esp_hosted_ng/docs/Raw_TP_Testing.md

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants