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

espsta0 interface does not appear #191

Open
in-text opened this issue Jan 8, 2023 · 188 comments
Open

espsta0 interface does not appear #191

in-text opened this issue Jan 8, 2023 · 188 comments

Comments

@in-text
Copy link

in-text commented Jan 8, 2023

Hello! I've try to porting to the Allwinner F1C200s SoC device.
I've successfully compile kernel module and load it on target system, but i can't see espsta0 interface in ifconfig -a output.

Kernel logs:

[   65.951657] esp32_spi: loading out-of-tree module taints kernel.
[   65.961218] esp_reset, ESP32: Triggering ESP reset.
[   66.178300] ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [10]

In output of ps -e I've see this process: 160 root [ESP_SPI_WORK_QU]

full ps -e output ``` PID USER COMMAND 1 root init 2 root [kthreadd] 4 root [kworker/0:0H-kb] 6 root [mm_percpu_wq] 7 root [ksoftirqd/0] 8 root [kdevtmpfs] 9 root [netns] 10 root [kworker/0:1-pm] 11 root [oom_reaper] 12 root [writeback] 13 root [kcompactd0] 38 root [kblockd] 39 root [watchdogd] 40 root [cfg80211] 41 root [kswapd0] 43 root [spi0] 44 root [kworker/u2:1] 46 root [spi1] 47 root [irq/21-sunxi-mm] 53 root [kworker/0:1H-kb] 58 root [jffs2_gcd_mtd3] 78 root /sbin/syslogd -n 82 root /sbin/klogd -n 93 root /sbin/udevd -d 112 root [kworker/u2:2-ev] 124 root /usr/sbin/haveged -w 1024 -r 0 145 root /usr/sbin/umtprd 150 root -sh 160 root [ESP_SPI_WORK_QU] 173 root [kworker/0:2-eve] 179 root [kworker/0:0-eve] 181 root ps -e ```

I found line of code with same name of task:

adapter.if_rx_workqueue = alloc_workqueue("ESP_IF_RX_WORK_QUEUE", 0, 0);

Where I may wrong?

@in-text
Copy link
Author

in-text commented Jan 8, 2023

I have moved on, the device is detected, but another error occurs:

# insmod esp32_spi.ko resetpin=128
[   16.418130] esp32_spi: loading out-of-tree module taints kernel.
[   16.658232] ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [10]
# [   18.840864]
[   18.840864] Received ESP bootup event
[   18.846026] EVENT: 3
[   18.848332] EVENT: 2
[   18.850525] EVENT: 0
[   18.852706] EVENT: 4
[   18.854888] EVENT: 1
[   18.857076] esp32: process_fw_data ESP chipset's last reset cause:
[   18.857083] POWERON_RESET
[   18.865999] esp32: ESP Firmware version: 1.0.2
[   18.870475] ESP chipset detected [esp32]
[   23.927470] esp32: Command[1] timed out
[   23.931339] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
[   23.938598] esp32: add_network_iface() failure, ret: -1
[   23.943819] network iterface init failed
[   23.947796] ESP peripheral capabilities: 0xf8
[   24.167410] ESP Bluetooth init
[   24.171302] Capabilities: 0xf8. Features supported are:
[   24.176532]   * WLAN on SPI
[   24.179443]   * BT/BLE
[   24.181808]     - HCI over SPI
[   24.184853]     - BT/BLE dual mode

@in-text
Copy link
Author

in-text commented Jan 8, 2023

I've capture data exchange between Host-side and ESP32:
DSLogic-la-230108-221959.dsl.zip

May view in DSView util

@in-text
Copy link
Author

in-text commented Jan 8, 2023

image

There is a first data since `insmod esp32_spi.ko resetpin=128` command

@in-text
Copy link
Author

in-text commented Jan 8, 2023

Some text errors from Host side
image
image
image
image
image

@in-text
Copy link
Author

in-text commented Jan 8, 2023

ESP32 logs:

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:6680
load:0x40078000,len:14848
load:0x40080400,len:3792
entry 0x40080694
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 (44) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) 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 (174) 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 (394) 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 (465) 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
I (481) cpu_start: Application information:
I (486) cpu_start: Project name:     network_adapter
I (491) cpu_start: App version:      2027593
I (496) cpu_start: Compile time:     Dec 16 2022 17:12:03
I (502) cpu_start: ELF file SHA256:  e7d000f940d62741...
I (508) cpu_start: ESP-IDF:          v4.4.1-584-g91dc99a3ce-dirty
I (515) heap_init: Initializing. RAM available for dynamic allocation:
I (522) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (528) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (534) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (541) heap_init: At 3FFC7958 len 000186A8 (97 KiB): DRAM
I (547) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (553) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (560) heap_init: At 4009D63C len 000029C4 (10 KiB): IRAM
I (567) spi_flash: detected chip: generic
I (570) spi_flash: flash io: dio
I (575) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (589) stats: *********************************************************************
I (595) stats:                 ESP-Hosted Firmware version :: 1.0.2
I (603) stats:                 Transport used :: SPI only
I (609) stats: *********************************************************************
I (615) FW_MAIN: Supported features are:
I (619) FW_MAIN: - WLAN over SPI
I (623) FW_BT: - BT/BLE
I (625) FW_BT:    - HCI Over SPI
I (627) FW_BT:    - BT/BLE dual mode
I (631) FW_MAIN: Capabilities: 0xf8
I (643) wifi:wifi driver task: 3ffca200, prio:23, stack:6656, core=1
I (643) system_api: Base MAC address is not set
I (643) system_api: read default base MAC address from EFUSE
I (649) wifi:wifi firmware version: 9f5e450
I (651) wifi:wifi certification version: v7.0
I (655) wifi:config NVS flash: disabled
I (657) wifi:config nano formating: disabled
I (661) wifi:Init data frame dynamic rx buffer num: 32
I (665) wifi:Init management frame dynamic rx buffer num: 32
I (669) wifi:Init management short buffer num: 32
I (673) wifi:Init dynamic tx buffer num: 64
I (675) wifi:Init static rx buffer size: 1600
I (679) wifi:Init static rx buffer num: 16
I (683) wifi:Init dynamic rx buffer num: 32
I (685) wifi_init: rx ba win: 6
I (689) wifi_init: tcpip mbox: 32
I (691) wifi_init: udp mbox: 6
I (695) wifi_init: tcp mbox: 6
I (697) wifi_init: tcp tx win: 5744
I (701) wifi_init: tcp rx win: 5744
I (705) wifi_init: tcp mss: 1440
I (707) wifi_init: WiFi IRAM OP enabled
I (711) wifi_init: WiFi RX IRAM OP enabled
I (715) BTDM_INIT: BT controller compile version [425d342]
I (723) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1057) FW_MAIN: ESP Bluetooth MAC addr: 24-6f-28-a1-90-46

I (1057) FW_SPI: Using SPI interface
I (1059) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (1065) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (2073) FW_MAIN: Initial set up done
I (2111) FW_MAIN: INIT Interface command

I (2113) wifi:mode : sta (24:6f:28:a1:90:44)
I (2113) wifi:enable tsf
I (2115) FW_CMD: Wifi Sta mode set

@in-text
Copy link
Author

in-text commented Jan 12, 2023

@mantriyogesh Hello, could you help me please?

@mantriyogesh
Copy link
Collaborator

Apologies for the delay, will check it today and let you know..

@mantriyogesh
Copy link
Collaborator

Can you please:

  1. Let us know if any changes you have done in the Linux side code?
  2. Try commenting adjust_spi_clock() so as SPI freq will not change:
    adjust_spi_clock(*(pos + 2));
  3. Check if works if the SPI mode is changed to something other than 2
    esp_board.mode = SPI_MODE_2;

@in-text
Copy link
Author

in-text commented Jan 13, 2023

Can you please:

  1. Let us know if any changes you have done in the Linux side code?
  2. Try commenting adjust_spi_clock() so as SPI freq will not change:
    adjust_spi_clock(*(pos + 2));
  3. Check if works if the SPI mode is changed to something other than 2
    esp_board.mode = SPI_MODE_2;
  1. Just change busnum to 1, and HANDSHAKE_PIN/SPI_DATA_READY_PIN macroses
  2. The same error: [ 30.411254] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22 [ 30.418511] esp32: add_network_iface() failure, ret: -1
  3. On SPI_MODE1 the same error, but I have new messages from driver from bluetooth hci:

[   35.371370] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
[   35.378624] esp32: add_network_iface() failure, ret: -1
[   35.383844] network iterface init failed
[   35.387821] ESP peripheral capabilities: 0xf8
[   35.607549] ESP Bluetooth init
[   35.611443] Capabilities: 0xf8. Features supported are:
[   35.616673]   * WLAN on SPI
[   35.619589]   * BT/BLE
[   35.621954]     - HCI over SPI
[   35.625000]     - BT/BLE dual mode
[   37.687506] Bluetooth: hci0: command 0x1003 tx timeout
[   39.767508] Bluetooth: hci0: command 0x1001 tx timeout
[   41.847649] Bluetooth: hci0: command 0x1009 tx timeout

SPI_MODE0:

# insmod esp32_spi.ko resetpin=128
[   22.611111] esp32_spi: loading out-of-tree module taints kernel.
[   22.850836] ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [10]
# [   25.859382]
[   25.859382] Received ESP bootup event
[   25.864598] EVENT: 3
[   25.866788] EVENT: 2
[   25.869077] EVENT: 0
[   25.871268] EVENT: 4
[   25.873451] EVENT: 1
[   25.875640] esp32: process_fw_data ESP chipset's last reset cause:
[   25.875649] SW_CPU_RESET
[   25.884477] esp32: ESP Firmware version: 1.0.2
[   25.888955] ESP chipset detected [esp32]
[   30.967343] esp32: Command[1] timed out
[   30.971213] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
[   30.978463] esp32: add_network_iface() failure, ret: -1
[   30.983683] network iterface init failed
[   30.987661] ESP peripheral capabilities: 0xf8
[   31.207404] ESP Bluetooth init
[   31.211348] Capabilities: 0xf8. Features supported are:
[   31.216578]   * WLAN on SPI
[   31.219490]   * BT/BLE
[   31.221855]     - HCI over SPI
[   31.224902]     - BT/BLE dual mode
[   31.847373] vcc3v0: disabling
[   31.850376] vcc3v3: disabling
[   31.853346] vcc5v0: disabling
[   33.287362] Bluetooth: hci0: command 0x1003 tx timeout
[   35.367369] Bluetooth: hci0: command 0x1001 tx timeout
[   37.447742] Bluetooth: hci0: command 0x1009 tx timeout

SPI_MODE3:

# insmod esp32_spi.ko resetpin=128
[   20.060180] esp32_spi: loading out-of-tree module taints kernel.
[   20.288738] ESP32 peripheral is registered to SPI bus [1],chip select [0], SPI Clock [10]

@in-text
Copy link
Author

in-text commented Jan 13, 2023

SPI_MODE1, log from logical analyzer:
DSLogic-la-230113-190137.dsl.zip

adjust_spi_clock(*(pos + 2)); was committed

ESP Log:

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:6680
load:0x40078000,len:14848
load:0x40080400,len:3792
entry 0x40080694
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 (98) 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 (122) boot_comm: chip revision: 1, min. application chip revision: 0
I (130) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=17a24h ( 96804p
I (173) esp_image: segment 1: paddr=00027a4c vaddr=3ffbdb60 size=05578h ( 21880d
I (182) esp_image: segment 2: paddr=0002cfcc vaddr=40080000 size=0304ch ( 12364d
I (187) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=89534h (562484p
I (393) esp_image: segment 4: paddr=000b955c vaddr=4008304c size=1a5f0h (108016d
I (438) esp_image: segment 5: paddr=000d3b54 vaddr=50000000 size=00010h (    16d
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
I (481) cpu_start: Application information:
I (485) cpu_start: Project name:     network_adapter
I (491) cpu_start: App version:      2027593
I (496) cpu_start: Compile time:     Dec 16 2022 17:12:03
I (502) cpu_start: ELF file SHA256:  e7d000f940d62741...
I (508) cpu_start: ESP-IDF:          v4.4.1-584-g91dc99a3ce-dirty
I (515) heap_init: Initializing. RAM available for dynamic allocation:
I (522) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (528) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (534) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (540) heap_init: At 3FFC7958 len 000186A8 (97 KiB): DRAM
I (546) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (553) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (559) heap_init: At 4009D63C len 000029C4 (10 KiB): IRAM
I (567) spi_flash: detected chip: generic
I (570) spi_flash: flash io: dio
I (575) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (589) stats: *****************************************************************
I (595) stats:                 ESP-Hosted Firmware version :: 1.0.2
I (603) stats:                 Transport used :: SPI only
I (609) stats: *****************************************************************
I (615) FW_MAIN: Supported features are:
I (619) FW_MAIN: - WLAN over SPI
I (623) FW_BT: - BT/BLE
I (625) FW_BT:    - HCI Over SPI
I (627) FW_BT:    - BT/BLE dual mode
I (631) FW_MAIN: Capabilities: 0xf8
I (643) wifi:wifi driver task: 3ffca200, prio:23, stack:6656, core=1
I (643) system_api: Base MAC address is not set
I (643) system_api: read default base MAC address from EFUSE
I (649) wifi:wifi firmware version: 9f5e450
I (651) wifi:wifi certification version: v7.0
I (655) wifi:config NVS flash: disabled
I (657) wifi:config nano formating: disabled
I (661) wifi:Init data frame dynamic rx buffer num: 32
I (665) wifi:Init management frame dynamic rx buffer num: 32
I (669) wifi:Init management short buffer num: 32
I (673) wifi:Init dynamic tx buffer num: 64
I (675) wifi:Init static rx buffer size: 1600
I (679) wifi:Init static rx buffer num: 16
I (683) wifi:Init dynamic rx buffer num: 32
I (685) wifi_init: rx ba win: 6
I (689) wifi_init: tcpip mbox: 32
I (691) wifi_init: udp mbox: 6
I (695) wifi_init: tcp mbox: 6
I (697) wifi_init: tcp tx win: 5744
I (701) wifi_init: tcp rx win: 5744
I (705) wifi_init: tcp mss: 1440
I (707) wifi_init: WiFi IRAM OP enabled
I (711) wifi_init: WiFi RX IRAM OP enabled
I (715) BTDM_INIT: BT controller compile version [425d342]
I (723) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1047) FW_MAIN: ESP Bluetooth MAC addr: 24-6f-28-a1-90-46

I (1047) FW_SPI: Using SPI interface
I (1047) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulld
I (1055) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulld
I (2063) FW_MAIN: Initial set up done
I (2101) FW_MAIN: INIT Interface command

I (2103) wifi:mode : sta (24:6f:28:a1:90:44)
I (2103) wifi:enable tsf
I (2105) FW_CMD: Wifi Sta mode set

@mantriyogesh
Copy link
Collaborator

Without changing spi mode and only commenting adjust_spi_clock(

@in-text
Copy link
Author

in-text commented Jan 13, 2023

Without changing spi mode and only commenting adjust_spi_clock(

I've try this, see previous comment at 2)

@in-text
Copy link
Author

in-text commented Jan 14, 2023

Without changing spi mode and only commenting adjust_spi_clock(

SPI_MODE2 (by default), adjust_spi_clock commented:

[   84.988138] esp32_spi: loading out-of-tree module taints kernel.
[   85.218388] ESP32 peripheral is registered to SPI bus [1],chip select [0], S]
# [   87.459873]
[   87.459873] Received ESP bootup event
[   87.465035] EVENT: 3
[   87.467357] EVENT: 2
[   87.469550] EVENT: 0
[   87.471733] EVENT: 4
[   87.473914] EVENT: 1
[   87.476102] esp32: process_fw_data ESP chipset's last reset cause:
[   87.476111] POWERON_RESET
[   87.485030] esp32: ESP Firmware version: 1.0.2
[   87.489506] ESP chipset detected [esp32]
[   92.567286] esp32: Command[1] timed out
[   92.571154] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
[   92.578397] esp32: add_network_iface() failure, ret: -1
[   92.583616] network iterface init failed
[   92.587592] ESP peripheral capabilities: 0xf8
[   92.807331] ESP Bluetooth init
[   92.811223] Capabilities: 0xf8. Features supported are:
[   92.816452]   * WLAN on SPI
[   92.819362]   * BT/BLE
[   92.821728]     - HCI over SPI
[   92.824775]     - BT/BLE dual mode

ESP Log:

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:6680
load:0x40078000,len:14848
load:0x40080400,len:3792
entry 0x40080694
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 (44) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) 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 ( 96804p
I (174) esp_image: segment 1: paddr=00027a4c vaddr=3ffbdb60 size=05578h ( 21880d
I (182) esp_image: segment 2: paddr=0002cfcc vaddr=40080000 size=0304ch ( 12364d
I (188) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=89534h (562484p
I (394) esp_image: segment 4: paddr=000b955c vaddr=4008304c size=1a5f0h (108016d
I (438) esp_image: segment 5: paddr=000d3b54 vaddr=50000000 size=00010h (    16d
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
I (481) cpu_start: Application information:
I (486) cpu_start: Project name:     network_adapter
I (491) cpu_start: App version:      2027593
I (496) cpu_start: Compile time:     Dec 16 2022 17:12:03
I (502) cpu_start: ELF file SHA256:  e7d000f940d62741...
I (508) cpu_start: ESP-IDF:          v4.4.1-584-g91dc99a3ce-dirty
I (515) heap_init: Initializing. RAM available for dynamic allocation:
I (522) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (528) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (534) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (541) heap_init: At 3FFC7958 len 000186A8 (97 KiB): DRAM
I (547) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (553) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (559) heap_init: At 4009D63C len 000029C4 (10 KiB): IRAM
I (567) spi_flash: detected chip: generic
I (570) spi_flash: flash io: dio
I (575) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (589) stats: *****************************************************************
I (595) stats:                 ESP-Hosted Firmware version :: 1.0.2
I (603) stats:                 Transport used :: SPI only
I (609) stats: *****************************************************************
I (615) FW_MAIN: Supported features are:
I (619) FW_MAIN: - WLAN over SPI
I (623) FW_BT: - BT/BLE
I (625) FW_BT:    - HCI Over SPI
I (627) FW_BT:    - BT/BLE dual mode
I (631) FW_MAIN: Capabilities: 0xf8
I (643) wifi:wifi driver task: 3ffca200, prio:23, stack:6656, core=1
I (643) system_api: Base MAC address is not set
I (643) system_api: read default base MAC address from EFUSE
I (649) wifi:wifi firmware version: 9f5e450
I (651) wifi:wifi certification version: v7.0
I (655) wifi:config NVS flash: disabled
I (657) wifi:config nano formating: disabled
I (661) wifi:Init data frame dynamic rx buffer num: 32
I (665) wifi:Init management frame dynamic rx buffer num: 32
I (669) wifi:Init management short buffer num: 32
I (673) wifi:Init dynamic tx buffer num: 64
I (675) wifi:Init static rx buffer size: 1600
I (679) wifi:Init static rx buffer num: 16
I (683) wifi:Init dynamic rx buffer num: 32
I (685) wifi_init: rx ba win: 6
I (689) wifi_init: tcpip mbox: 32
I (691) wifi_init: udp mbox: 6
I (695) wifi_init: tcp mbox: 6
I (697) wifi_init: tcp tx win: 5744
I (701) wifi_init: tcp rx win: 5744
I (705) wifi_init: tcp mss: 1440
I (707) wifi_init: WiFi IRAM OP enabled
I (711) wifi_init: WiFi RX IRAM OP enabled
I (715) BTDM_INIT: BT controller compile version [425d342]
I (723) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1071) FW_MAIN: ESP Bluetooth MAC addr: 24-6f-28-a1-90-46

I (1071) FW_SPI: Using SPI interface
I (1071) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulld
I (1079) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulld
I (2087) FW_MAIN: Initial set up done
I (2125) FW_MAIN: INIT Interface command

I (2127) wifi:mode : sta (24:6f:28:a1:90:44)
I (2127) wifi:enable tsf
I (2129) FW_CMD: Wifi Sta mode set

Logic analyzer log:
DSLogic-la-230114-130408.dsl.zip

@mantriyogesh
Copy link
Collaborator

mantriyogesh commented Jan 16, 2023

Thank you for investigating at your side & the analyser dump.

Observations

  1. The MISO is working fine (This conforms that SPI Lines are behaving as they should). But The MOSI doesn't send anything.
  2. Handshake was toggled but next transaction was never scheduled. Suspecting if Interrupt was raised / correctly handled for Handshake pin (also verify Data ready pin interrupt additionally)

Git Commit

Release you have used is ESP-Hosted-NG release 1.0.2
The Source code compatible for Linux side kernel building is at Source code (zip)
I hope you are using same to build the code at Linux.

GPIOs

Next thing to confirm is GPIOs. Below steps will help verify if the GPIOs are working or not:

Three GPIOs needed -

  1. Handshake pin:
    Please add a KERN_ERR log in https://github.com/espressif/esp-hosted/blob/release/ng-v1.0.2/esp_hosted_ng/host/spi/esp_spi.c#L76-L83

  2. Data Ready from ESP to Host:
    Similarly, please add a KER_ERR log in

    static irqreturn_t spi_data_ready_interrupt_handler(int irq, void * dev)
    {
    /* ESP peripheral has queued buffer for transmission */
    if (spi_context.spi_workqueue)
    queue_work(spi_context.spi_workqueue, &spi_context.spi_work);
    return IRQ_HANDLED;
    }

  3. ESP Reset pin:
    This pin will make sure ESP is reset on every fresh insert of kernel module esp32_spi.ko

Intention is to trigger next spi_sync_transfer() at

ret = spi_sync_transfer(spi_context.esp_spi_dev, &trans, 1);
using spi_work

@in-text
Copy link
Author

in-text commented Jan 16, 2023

@mantriyogesh
ESP-Hosted Release:

alexey@alexey-PC:~/esp-hosted$ git branch
* (HEAD detached at release/ng-v1.0.2)
  master

I Add KERN_ERR:

# insmod esp32_spi.ko resetpin=128
[   21.974930] esp32_spi: loading out-of-tree module taints kernel.
[   22.198492] ESP32 peripheral is registered to SPI bus [1],chip select [0], S]
# [   24.406231] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   24.412296] spi_interrupt_handler: SPI INT Handler
[   24.418888] spi_interrupt_handler: SPI INT Handler
[   24.425325]
[   24.425325] Received ESP bootup event
[   24.430606] spi_interrupt_handler: SPI INT Handler
[   24.435419] EVENT: 3
[   24.437681] EVENT: 2
[   24.439869] EVENT: 0
[   24.442050] EVENT: 4
[   24.444232] EVENT: 1
[   24.446417] esp32: process_fw_data ESP chipset's last reset cause:
[   24.446424] POWERON_RESET
[   24.455334] esp32: ESP Firmware version: 1.0.2
[   24.459810] ESP chipset detected [esp32]
[   24.473660] spi_interrupt_handler: SPI INT Handler
[   24.479591] spi_interrupt_handler: SPI INT Handler
[   24.484448] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   24.492224] spi_interrupt_handler: SPI INT Handler
[   24.497387] spi_interrupt_handler: SPI INT Handler
[   29.527420] esp32: Command[1] timed out
[   29.531289] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
[   29.538548] esp32: add_network_iface() failure, ret: -1
[   29.543768] network iterface init failed
[   29.547743] ESP peripheral capabilities: 0xf8
[   29.767359] ESP Bluetooth init
[   29.771261] Capabilities: 0xf8. Features supported are:
[   29.776490]   * WLAN on SPI
[   29.779402]   * BT/BLE
[   29.781766]     - HCI over SPI
[   29.784812]     - BT/BLE dual mode
[   29.796161] spi_interrupt_handler: SPI INT Handler
[   29.801131] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   29.809249] spi_interrupt_handler: SPI INT Handler
[   29.814081] spi_interrupt_handler: SPI INT Handler

ESP log:

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:6680
load:0x40078000,len:14848
load:0x40080400,len:3792
entry 0x40080694
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 ( 96804p
I (173) esp_image: segment 1: paddr=00027a4c vaddr=3ffbdb60 size=05578h ( 21880d
I (182) esp_image: segment 2: paddr=0002cfcc vaddr=40080000 size=0304ch ( 12364d
I (188) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=89534h (562484p
I (393) esp_image: segment 4: paddr=000b955c vaddr=4008304c size=1a5f0h (108016d
I (438) esp_image: segment 5: paddr=000d3b54 vaddr=50000000 size=00010h (    16d
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
I (481) cpu_start: Application information:
I (485) cpu_start: Project name:     network_adapter
I (491) cpu_start: App version:      2027593
I (496) cpu_start: Compile time:     Dec 16 2022 17:12:03
I (502) cpu_start: ELF file SHA256:  e7d000f940d62741...
I (508) cpu_start: ESP-IDF:          v4.4.1-584-g91dc99a3ce-dirty
I (515) heap_init: Initializing. RAM available for dynamic allocation:
I (522) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (528) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (534) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (540) heap_init: At 3FFC7958 len 000186A8 (97 KiB): DRAM
I (547) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (553) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (559) heap_init: At 4009D63C len 000029C4 (10 KiB): IRAM
I (567) spi_flash: detected chip: generic
I (570) spi_flash: flash io: dio
I (575) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (589) stats: *****************************************************************
I (595) stats:                 ESP-Hosted Firmware version :: 1.0.2
I (603) stats:                 Transport used :: SPI only
I (609) stats: *****************************************************************
I (615) FW_MAIN: Supported features are:
I (619) FW_MAIN: - WLAN over SPI
I (623) FW_BT: - BT/BLE
I (625) FW_BT:    - HCI Over SPI
I (627) FW_BT:    - BT/BLE dual mode
I (631) FW_MAIN: Capabilities: 0xf8
I (643) wifi:wifi driver task: 3ffca200, prio:23, stack:6656, core=1
I (643) system_api: Base MAC address is not set
I (643) system_api: read default base MAC address from EFUSE
I (649) wifi:wifi firmware version: 9f5e450
I (651) wifi:wifi certification version: v7.0
I (655) wifi:config NVS flash: disabled
I (657) wifi:config nano formating: disabled
I (661) wifi:Init data frame dynamic rx buffer num: 32
I (665) wifi:Init management frame dynamic rx buffer num: 32
I (669) wifi:Init management short buffer num: 32
I (673) wifi:Init dynamic tx buffer num: 64
I (675) wifi:Init static rx buffer size: 1600
I (679) wifi:Init static rx buffer num: 16
I (683) wifi:Init dynamic rx buffer num: 32
I (685) wifi_init: rx ba win: 6
I (689) wifi_init: tcpip mbox: 32
I (691) wifi_init: udp mbox: 6
I (695) wifi_init: tcp mbox: 6
I (697) wifi_init: tcp tx win: 5744
I (701) wifi_init: tcp rx win: 5744
I (705) wifi_init: tcp mss: 1440
I (707) wifi_init: WiFi IRAM OP enabled
I (711) wifi_init: WiFi RX IRAM OP enabled
I (715) BTDM_INIT: BT controller compile version [425d342]
I (723) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1041) FW_MAIN: ESP Bluetooth MAC addr: 24-6f-28-a1-90-46

I (1041) FW_SPI: Using SPI interface
I (1041) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulld
I (1047) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulld
I (2057) FW_MAIN: Initial set up done
I (2113) FW_MAIN: INIT Interface command

I (2115) wifi:mode : sta (24:6f:28:a1:90:44)
I (2115) wifi:enable tsf
I (2117) FW_CMD: Wifi Sta mode set

Logical analyzer:
DSLogic-la-230116-122610.dsl.zip

  1. Reset PIN work normally, blue LED on ESP Dev Board disable after module insertion.

@in-text
Copy link
Author

in-text commented Jan 16, 2023

Also i found a bug. If I call rmmod, kernel crashed:

# insmod esp32_spi.ko resetpin=128
[   25.446675] esp32_spi: loading out-of-tree module taints kernel.
[   25.668823] ESP32 peripheral is registered to SPI bus [1],chip select [0], S]
# [   27.884706] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   27.884789] spi_interrupt_handler: SPI INT Handler
[   27.893579] spi_interrupt_handler: SPI INT Handler
[   27.898534] spi_interrupt_handler: SPI INT Handler
[   27.904163]
[   27.904163] Received ESP bootup event
[   27.914215] EVENT: 3
[   27.916403] EVENT: 2
[   27.918643] EVENT: 0
[   27.920830] EVENT: 4
[   27.923013] EVENT: 1
[   27.925202] esp32: process_fw_data ESP chipset's last reset cause:
[   27.925208] POWERON_RESET
[   27.934113] esp32: ESP Firmware version: 1.0.2
[   27.938584] ESP chipset detected [esp32]
[   27.949156] spi_interrupt_handler: SPI INT Handler
[   27.949753] spi_interrupt_handler: SPI INT Handler
[   27.957024] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   27.963759] spi_interrupt_handler: SPI INT Handler
[   27.977496] spi_interrupt_handler: SPI INT Handler
[   31.847825] vcc3v0: disabling
[   31.855599] vcc3v3: disabling
[   31.858678] vcc5v0: disabling
[   32.967867] esp32: Command[1] timed out
[   32.971737] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
[   32.979044] esp32: add_network_iface() failure, ret: -1
[   32.984266] network iterface init failed
[   32.988247] ESP peripheral capabilities: 0xf8
[   33.207730] ESP Bluetooth init
[   33.211682] Capabilities: 0xf8. Features supported are:
[   33.216910]   * WLAN on SPI
[   33.219829]   * BT/BLE
[   33.222197]     - HCI over SPI
[   33.225242]     - BT/BLE dual mode
[   33.236832] spi_interrupt_handler: SPI INT Handler
[   33.237212] spi_interrupt_handler: SPI INT Handler
[   33.242085] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   33.248680] spi_interrupt_handler: SPI INT Handler
# rmmod esp32_spi.ko
[   33.255640] spi_interrupt_handler: SPI INT Handler
[   41.924377] 8<--- cut here ---
[   41.932238] Unable to handle kernel paging request at virtual address e59d20c
[   41.939450] pgd = 73cee544
[   41.942161] [e59d200c] *pgd=00000000
[   41.945745] Internal error: Oops: 5 [#1] ARM
[   41.950004] Modules linked in: esp32_spi(O-)
[   41.954291] CPU: 0 PID: 170 Comm: rmmod Tainted: G           O      5.4.99 #2
[   41.961404] Hardware name: Allwinner suniv Family
[   41.966192] PC is at prepare_command_request+0x54/0x190 [esp32_spi]
[   41.972497] LR is at cmd_deinit_interface+0x30/0xcc [esp32_spi]
[   41.978404] pc : [<bf0018e4>]    lr : [<bf002a4c>]    psr: 80000013
[   41.984654] sp : c2baff28  ip : 00000000  fp : 00000000
[   41.989866] r10: 00000000  r9 : c2bae000  r8 : c0101208
[   41.995081] r7 : 00000007  r6 : 00000008  r5 : c0b03228  r4 : e59d200c
[   42.001591] r3 : c068f0f4  r2 : e59d200c  r1 : 00000122  r0 : 00000100
[   42.008104] Flags: Nzcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment none
[   42.015222] Control: 0005317f  Table: 82bdc000  DAC: 00000051
[   42.020960] Process rmmod (pid: 170, stack limit = 0xb2e08489)
[   42.026781] Stack: (0xc2baff28 to 0xc2bb0000)
[   42.031146] ff20:                   c2b354a0 c0b03228 00000000 00000081 c010c
[   42.039317] ff40: bf0077a0 c0b03228 00000000 bf004e40 bf0075e0 c016d7c0 33702
[   42.047487] ff60: 00010069 c0b06730 00000005 c010ee24 b6efec80 c2baffb0 00000
[   42.055657] ff80: 00000000 c010efb8 b6fcb578 00000000 00000000 e49f6ef7 00025
[   42.063828] ffa0: 70735f32 c0101000 0002f308 33707365 beceebe8 00000880 00008
[   42.071997] ffc0: 0002f308 33707365 70735f32 00000081 00000000 00000000 b6fc0
[   42.080167] ffe0: beceebe0 beceebd0 0002f1fc b6efeca0 60000010 beceebe8 00000
[   42.088435] [<bf0018e4>] (prepare_command_request [esp32_spi]) from [<bf002a)
[   42.099796] [<bf002a4c>] (cmd_deinit_interface [esp32_spi]) from [<bf004e40>)
[   42.109917] [<bf004e40>] (esp_exit [esp32_spi]) from [<c016d7c0>] (sys_delet)
[   42.118788] [<c016d7c0>] (sys_delete_module) from [<c0101000>] (ret_fast_sys)
[   42.127028] Exception stack(0xc2baffa8 to 0xc2bafff0)
[   42.132084] ffa0:                   0002f308 33707365 beceebe8 00000880 00008
[   42.140254] ffc0: 0002f308 33707365 70735f32 00000081 00000000 00000000 b6fc0
[   42.148414] ffe0: beceebe0 beceebd0 0002f1fc b6efeca0
[   42.153472] Code: 0a00002b e3a00c01 e5944044 e59f1110 (e894000c)
[   42.159556] ---[ end trace b4bb533d49c18a6e ]---
[   42.164168] Kernel panic - not syncing: Fatal exception in interrupt
[   42.170512] ---[ end Kernel panic - not syncing: Fatal exception in interrup-

@in-text
Copy link
Author

in-text commented Jan 16, 2023

@mantriyogesh
Sometimes interface show up (after 4-5 reboot):

# insmod esp32_spi.ko resetpin=128
[   49.341600] esp32_spi: loading out-of-tree module taints kernel.
[   49.568928] ESP32 peripheral is registered to SPI bus [1],chip select [0], S]
# [   51.788112] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   51.788212] spi_interrupt_handler: SPI INT Handler
[   51.796047] spi_interrupt_handler: SPI INT Handler
[   51.800987]
[   51.800987] Received ESP bootup event
[   51.810954] EVENT: 3
[   51.813143] EVENT: 2
[   51.815326] EVENT: 0
[   51.817509] EVENT: 4
[   51.819736] EVENT: 1
[   51.821926] esp32: process_fw_data ESP chipset's last reset cause:
[   51.821933] POWERON_RESET
[   51.830835] esp32: ESP Firmware version: 1.0.2
[   51.835268] ESP chipset detected [esp32]
[   51.849821] spi_interrupt_handler: SPI INT Handler
[   51.850200] spi_interrupt_handler: SPI INT Handler
[   51.857928] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   51.864586] spi_interrupt_handler: SPI INT Handler
[   51.872451] spi_interrupt_handler: SPI INT Handler
[   51.879809] spi_interrupt_handler: SPI INT Handler
[   51.884649] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   51.894486] spi_interrupt_handler: SPI INT Handler
[   51.900635] spi_interrupt_handler: SPI INT Handler
[   51.906777] spi_interrupt_handler: SPI INT Handler
[   51.913100] ESP peripheral capabilities: 0xf8
[   52.137898] ESP Bluetooth init
[   52.175710] Capabilities: 0xf8. Features supported are:
[   52.181060]   * WLAN on SPI
[   52.183857]   * BT/BLE
[   52.186213]     - HCI over SPI
[   52.189331]     - BT/BLE dual mode
[   52.200193] spi_interrupt_handler: SPI INT Handler
[   52.200498] spi_interrupt_handler: SPI INT Handler
[   52.205366] spi_data_ready_interrupt_handler: SPI DR INT Handler
[   52.212108] spi_interrupt_handler: SPI INT Handler

# ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
2: espsta0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop qlen 1000
    link/ether 24:6f:28:a1:90:44 brd ff:ff:ff:ff:ff:ff

Logical analyzer log:
DSLogic-la-230116-184245.dsl.zip

@mantriyogesh
Copy link
Collaborator

Okay. So interrupts are coming.
But something is strange. Despite of the interrupts sometimes I do not see that the transactions are not happening. MOSI line doesn't behave as it should.

Are you using jumper wires? If yes, how long are they?
If nothing works, We will go into debug mode, where I will have to provide binary with log and patch to use at Linux kernel module, to understand till what point the things are moving.

@mantriyogesh
Copy link
Collaborator

The capture looks not consistent with the general expectations.
The Data ready is not high after ESP reset -> ESP is the one to do first transaction. so DR pin should be high at the first place. otherwise first transaction would not take place.
Screenshot 2023-01-16 at 9 57 13 PM
Screenshot 2023-01-16 at 10 05 08 PM

First thing is MISO on ESP reset (ESP needs to send data and will set DR high. On host's first transaction, MISO will be the receiver. Then further with next message exchanges, MOSI would have some data to send.

Without any transaction DR is going down?
Screenshot 2023-01-16 at 9 54 17 PM

Can you please verify if DataReady, Handshake and reset pin GPIOs are not used by other peripherals or alternatively change them to ones not in use?
Wires for SPI should be < 10 cm, possibly 5-6cm or less.

@in-text
Copy link
Author

in-text commented Jan 16, 2023

Okay. So interrupts are coming. But something is strange. Despite of the interrupts sometimes I do not see that the transactions are not happening. MOSI line doesn't behave as it should.

Are you using jumper wires? If yes, how long are they? If nothing works, We will go into debug mode, where I will have to provide binary with log and patch to use at Linux kernel module, to understand till what point the things are moving.

Originally I used jump wires, but then reduce wire size.
Now ESP32 and Host Dev Board are connected to the breadboard. SPI wires pins reduced maximally (1-2cm). But Handshake and Data Ready pins use jump wires (approx 15cm).

I can take a picture, if need, but everything is very confusing there, because of the connected logic analyzer.

@mantriyogesh
Copy link
Collaborator

Also worth cross checking if wire connections are not touching each other (in case manually cut and joined by hand) & connections are as per

Screenshot 2023-01-16 at 10 08 12 PM

@mantriyogesh
Copy link
Collaborator

For SPI you can have comfortable wire size like 5-6 cm. it is better if e have all wires at (almost) same length..
As I said, You can try these things first.
Don't worry, we will get thing working. But might need debugging, which generally takes some time. worth to cross check the GPIOs not being used by any other peripheral, Connections exactly as per the documentation.

As you are anyway using ESP32, Just for trial, can you use NG release 1.0.1? For that, please use the source code from Source (zip).

Note: NG release 1.0.2 is not backward compatible. Use firmware binaries and 'Source Code(zip)' exactly from same release.

@in-text
Copy link
Author

in-text commented Jan 16, 2023

For SPI you can have comfortable wire size like 5-6 cm. it is better if e have all wires at (almost) same length.. As I said, You can try these things first. Don't worry, we will get thing working. But might need debugging, which generally takes some time. worth to cross check the GPIOs not being used by any other peripheral, Connections exactly as per the documentation.

As you are anyway using ESP32, Just for trial, can you use NG release 1.0.1? For that, please use the source code from Source (zip).

Note: NG release 1.0.2 is not backward compatible. Use firmware binaries and 'Source Code(zip)' exactly from same release.

On Release 1.0.2

I reduce wires, see picture:
IMG_1970

All the same, from launch to launch, the interface either appears or does not appear. Once I even managed to scan the network and get two access points on the output of the iw (although in fact there are many more).

The next step is to upload version 1.0.1 to the ESP32 and build the kernel module version 1.0.1?

@mantriyogesh
Copy link
Collaborator

1.0.1 to 1.0.2 there is design change.
Just to understand from the issue perspective, if older release works for you or not.

There is one more possibility of using FG if in case cfg80211 is not must for you. NG is comparatively newer than FG. The FG solution has been present since very long and you should get it up easily. The hardware setup should be same. In case of FG you also can get access to the ESP source code.

For FG, if want to build and flash, can use master at both ESP & host.
alternativly you can also use release binary and sourced code from release 0.0.5.

@mantriyogesh
Copy link
Collaborator

Have you tried any of these two?

@in-text
Copy link
Author

in-text commented Jan 17, 2023

1.0.1 to 1.0.2 there is design change. Just to understand from the issue perspective, if older release works for you or not.

There is one more possibility of using FG if in case cfg80211 is not must for you. NG is comparatively newer than FG. The FG solution has been present since very long and you should get it up easily. The hardware setup should be same. In case of FG you also can get access to the ESP source code.

For FG, if want to build and flash, can use master at both ESP & host. alternativly you can also use release binary and sourced code from release 0.0.5.

1.0.1 not working too:

# insmod esp32_spi.ko resetpin=128
[   27.188458] esp32_spi: loading out-of-tree module taints kernel.
[   27.418750] ESP32 peripheral is registered to SPI bus [1],chip select [0], S]
# [   29.515778]
[   29.515778] Received ESP bootup event
[   29.521050] EVENT: 3
[   29.523247] EVENT: 2
[   29.525430] EVENT: 0
[   29.527612] EVENT: 1
[   29.529872] esp32: process_fw_data ESP chipset's last reset cause:
[   29.529882] POWERON_RESET
[   29.538792] esp32: ESP Firmware version: 1.0.1
[   29.543230] ESP chipset detected [esp32]
[   31.847832] vcc3v0: disabling
[   31.850836] vcc3v3: disabling
[   31.853857] vcc5v0: disabling
[   34.567735] esp32: Command[1] timed out
[   34.571604] esp32: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: 0xa
[   34.579463] ESP peripheral capabilities: 0x78
[   34.797781] ESP Bluetooth init
[   34.801721] Capabilities: 0x78. Features supported are:
[   34.806954]   * WLAN on SPI
[   34.809873]   * BT/BLE
[   34.812238]     - HCI over SPI
[   34.815285]     - BT/BLE dual mode

@in-text
Copy link
Author

in-text commented Jan 17, 2023

1.0.1 to 1.0.2 there is design change. Just to understand from the issue perspective, if older release works for you or not.

There is one more possibility of using FG if in case cfg80211 is not must for you. NG is comparatively newer than FG. The FG solution has been present since very long and you should get it up easily. The hardware setup should be same. In case of FG you also can get access to the ESP source code.

For FG, if want to build and flash, can use master at both ESP & host. alternativly you can also use release binary and sourced code from release 0.0.5.

On *_FG version all works fine:

# insmod esp32_spi.ko resetpin=128
[   29.528391] esp32_spi: loading out-of-tree module taints kernel.
[   29.540390] ESP32 peripheral is registered to SPI bus [1],chip select [0], S]
# [   31.847795] vcc3v0: disabling
[   31.850799] vcc3v3: disabling
[   31.853769] vcc5v0: disabling
[   31.962030]
[   31.962030] Received INIT event from ESP32 peripheral
[   31.962074] EVENT: 2
[   31.970895] EVENT: 1
[   31.973082] EVENT: 0
[   31.975267] ESP peripheral capabilities: 0xf8
[   32.198563] EVENT: 3
ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
2: ethsta0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop qlen 1000
    link/ether 00:00:00:00:00:00 brd ff:ff:ff:ff:ff:ff
3: ethap0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop qlen 1000
    link/ether 00:00:00:00:00:00 brd ff:ff:ff:ff:ff:ff

But do I understand correctly that in the FG version I can't use wpa_supplicant and/or iw?
Also, I could not raise the interface, is this also done differently in this version?

# ip link set ethsta0 up
ip: SIOCSIFFLAGS: Cannot assign requested address
# ip link set ethap0 up
ip: SIOCSIFFLAGS: Cannot assign requested address

@mantriyogesh
Copy link
Collaborator

That is correct. The FG is oriented to more of API based approach. It is not connected with wpa_supplicant or iw. It is solution where your user space application can create and maintain the wifi connection just by simple function calls. In contrast to wpa_supplicant, we have open sourced custom control path.

We created demo app which should be usable directly. In that you can use python based or c based applicantion, whichever is more suitable for your end application.

For the documentation, please follow https://github.com/espressif/esp-hosted/tree/master/esp_hosted_fg.

This is simple to use python app demo :
https://github.com/espressif/esp-hosted/blob/master/esp_hosted_fg/docs/common/python_demo.md#demo-app-in-python. Check the gif or image in this page..

@in-text
Copy link
Author

in-text commented Jan 17, 2023

That is correct. The FG is oriented to more of API based approach. It is not connected with wpa_supplicant or iw. It is solution where your user space application can create and maintain the wifi connection just by simple function calls. In contrast to wpa_supplicant, we have open sourced custom control path.

We created demo app which should be usable directly. In that you can use python based or c based applicantion, whichever is more suitable for your end application.

For the documentation, please follow https://github.com/espressif/esp-hosted/tree/master/esp_hosted_fg.

This is simple to use python app demo : https://github.com/espressif/esp-hosted/blob/master/esp_hosted_fg/docs/common/python_demo.md#demo-app-in-python. Check the gif or image in this page..

In this case, the FG version does not suit me. Can we return to fixing the problem with the NG version?

@mantriyogesh
Copy link
Collaborator

Positive about it.
Is it possible to quickly try NG 1.0.1 ?

That is something with would let us know to focus if new code is to be suspected or not.
Just repeating myself, please use source code from release 1.0.1 page for host side kernel buildingwhen you use 1.0.1 ESP firmware..

@mantriyogesh
Copy link
Collaborator

@renyeguo ,
I hope the original issues are solved for you now?

@mantriyogesh
Copy link
Collaborator

#222

@renyeguo
Copy link

renyeguo commented Apr 24, 2023 via email

@mantriyogesh
Copy link
Collaborator

@wizath

You are using ESP32 - SPI
Can you please send esp side logs as well?
It will be better to create separate issue.
Later point of time it gets unmanageable and confusing.
This issue is already being worked on.

@renyeguo
Copy link

#191 (comment) Did you try to switch spi mode?

@renyeguo
Copy link

@mantriyogesh
Now I am modifying the control logic of the cpu spi controller, but it may not look ideal at the moment. Can esp try to make a change?

@renyeguo
Copy link

@mantriyogesh I have solved this problem. As communicated before, this problem was caused by spi block transmission fragmentation. Now the spi clock can correctly run to 30Mhz.However, the esp side should also need to handle this situation. Ensure the integrity of data reception.

@mantriyogesh
Copy link
Collaborator

Integrity of data is only dependent upon the spi protocol exchange below.
If you face issues at protocol itself, you need to focus there.

We have data integrity checks with checksum.
But that only to filter out any noise coming. We do not observe Noise in general once developers correct timing issues across many deployments.

Also please be assured that timing graph is correct. Cs line is stable, clock and all transitions are correct. We term this as porting the solution. porting, need to be done for host integration one time by user.

@mantriyogesh
Copy link
Collaborator

Your software should not need fragmentation at all in general for working.

Optimisations are all open but basic transport should really not be dependent on fragmentation in place.
Once transport is correct enough, you can do all optimization you need on top of open source code.

@renyeguo
Copy link

@mantriyogesh Some time ago, I was delayed in the development of esp32 due to other things. Now I find that there are several problems:

  1. The wpa_cli or iwlist tool cannot obtain the ap signal strength information, which is always "0"

  2. I did an experiment. When the ap was successfully connected with wifi, the ap was turned off. The WiFi connection information of eps32 was always connected, and the ap that was just closed could still be scanned after scan operation

@renyeguo
Copy link

renyeguo commented May 11, 2023

iwlist_scan_signal
wpa_cli_scan_signal

@mantriyogesh
Copy link
Collaborator

Hello @renyeguo ,

This might be open issue #204
As, There is workaround available for now, we are taking this on medium priority.

@renyeguo
Copy link

Yes, I agree with the phenomenon of #204. Please help me look at the second question ”I did an experiment. When the ap was successfully connected with wifi, the ap was turned off. The WiFi connection information of eps32 was always connected, and the ap that was just closed could still be scanned after scan operation“

@mantriyogesh
Copy link
Collaborator

You might have to check if disconnection is identified immediately by wpa_supplicant or not.
We inform cfg80211 about disconnection as soon as we get event.

wpa_spplicant can be run with extra debugs to understand the scenario.

@mantriyogesh
Copy link
Collaborator

also, please verify if multiple APs with same SSID in vicinity.
Can you try with some other AP and SSID (your own SSID)?

@renyeguo
Copy link

renyeguo commented May 11, 2023

wpa_cli_status
My steps are as follows:

1.wpa_cli -i espsta0

add_network

set_network 0 ssid "mate40pro+"

set_network 0 key_mgmt WPA-PSK

set_network 0 psk "1234567890"

enable_network 0

2.udhcpc -i espsta0 -B

3."mate40pro+" is the hotspot with my phone ,then turn off the hotspot.

3.wpa_cli -i espsta0 status (Repeat the process)

wpa_state is always COMPLETED, and no matter how many times I get the state, it will be completed after a few minutes

@mantriyogesh
Copy link
Collaborator

mantriyogesh commented May 11, 2023

@renyeguo Ideally wpa_cli should behave same way, but can you please check once with wpa_supplicant logs on and test with iw like in 204

@kapilkedawat
Copy link
Contributor

@renyeguo Can you please check if you are still facing the issue? #204 is resolved in the latest FG changes. Please note that it takes around 6 secs to detect beacon miss on esp devices.

@renyeguo
Copy link

@kapilkedawat this modify fix it

@renyeguo
Copy link

@mantriyogesh How to adjust the transmitting power of wifi? I use iwconfig to set this up, but an error occurs,like this:

@renyeguo
Copy link

"iwconfig espsta0 txpower 30”
Error for wireless request "Set Tx Power" (8B26) :
SET failed on device espsta0 ; Operation not supported.

@mantriyogesh
Copy link
Collaborator

Hello @renyeguo,

That API needs to be added.
Keep you posted once available.

@kapilkedawat
Copy link
Contributor

@renyeguo Request to create new github issues for non related items. This will help us to track those in better way.

@renyeguo
Copy link

What is the current default transmission power? @kapilkedawat I have created a new issue。

@kapilkedawat
Copy link
Contributor

What is the current default transmission power? @kapilkedawat I have created a new issue。

Default Tx power is maximum tx power allowed based on channel/region. ESP devices supports upto 20dbm.

@renyeguo
Copy link

Could you please separately modify a version with the maximum transmitting power to me? I need to do tests to verify the signal problem @mantriyogesh

@kapilkedawat
Copy link
Contributor

@renyeguo , esp chips works on max power by default. What do you mean by version with the maximum transmitting power?

@renyeguo
Copy link

renyeguo commented Jun 1, 2023

sorry, maybe there is something wrong with my expression. What I mean is that the connection between esp and ap is not stable at 8-9 meters when there is a distance between esp and AP, because I am not quite sure how much tx power is by default in the ESP-Hosted scheme at present. We hope to get a debug image of esp-hosted with maximum tx power to confirm whether the problem is caused by our design or insufficient tx power

@kapilkedawat
Copy link
Contributor

Hi @renyeguo , We are working on setting of tx_power using iw. However please note that current image uses maximum tx power available.

Can you share the logs when connection is not stable, I can take a look. Please enable FW logs and set the log levels to debug.

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

5 participants