espressif / esp-hosted

Hosted Solution (Linux/MCU) with ESP32 (Wi-Fi + BT + BLE)
Other
703 stars 167 forks source link

esp_sdio: probe of mmc1:0001:1 failed with error -110 #93

Open gediz opened 2 years ago

gediz commented 2 years ago

Hi. I've tried to make it work using SDIO after failing with SPI (#92) but it became another failure.

Using official ESP-WROVER-KIT (v3) board and Raspberry Pi 3 Model B V1.2.

On ESP32 I've tried both released binary files and self compiled up-to-date master branch of esp-hosted repository. Also using latest Raspberry Pi OS (2021-10-30-raspios-bullseye-armhf-lite) with Linux 5.10.63 on the RPi.

Connected the devices using female to female jumper wires. After reading previously submitted issues I've cutted them half to make them even shorter. Removed and re-wired all of them after every failure and checked them again.

But even though I can see ESP32 as a peripheral:

sudo cat /sys/devices/platform/soc/3f300000.mmc/mmc_host/mmc1/mmc1\:0001/mmc1\:0001\:1/uevent 
SDIO_CLASS=00
SDIO_ID=6666:2222
SDIO_REVISION=0.0
MODALIAS=sdio:c00v6666d2222

There is a problem during the probe of mmc1. esp_sdio: probe of mmc1:0001:2 failed with error -22

I have collected some logs with the hope of making the analyze easier:

Raspberry Pi - dmesg ``` [ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Linux version 5.10.63-v7+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1488 SMP Thu Nov 18 16:14:44 GMT 2021 [ 0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d [ 0.000000] CPU: div instructions available: patching division code [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache [ 0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Rev 1.2 [ 0.000000] random: fast init done [ 0.000000] Memory policy: Data cache writealloc [ 0.000000] Reserved memory: created CMA memory pool at 0x1ec00000, size 256 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] Normal empty [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] On node 0 totalpages: 242688 [ 0.000000] DMA zone: 2133 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 242688 pages, LIFO batch:63 [ 0.000000] percpu: Embedded 20 pages/cpu s50828 r8192 d22900 u81920 [ 0.000000] pcpu-alloc: s50828 r8192 d22900 u81920 alloc=20*4096 [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 240555 [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=Composite-1:720x480@60i vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyAMA0,115200 console=tty1 root=PARTUUID=2577b6ec-02 rootfstype=ext4 fsck.repair=yes rootwait [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] Memory: 681812K/970752K available (10240K kernel code, 1312K rwdata, 2948K rodata, 1024K init, 863K bss, 26796K reserved, 262144K cma-reserved) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 32054 entries in 63 pages [ 0.000000] ftrace: allocated 63 pages with 6 groups [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 [ 0.000000] random: get_random_bytes called from start_kernel+0x3ac/0x580 with crng_init=1 [ 0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns [ 0.000008] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns [ 0.000025] Switching to timer-based delay loop, resolution 52ns [ 0.000311] Console: colour dummy device 80x30 [ 0.001126] printk: console [tty1] enabled [ 0.001198] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000) [ 0.001257] pid_max: default: 32768 minimum: 301 [ 0.001474] LSM: Security Framework initializing [ 0.001733] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.001783] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.003273] cgroup: Disabling memory control group subsystem [ 0.003566] CPU: Testing write buffer coherency: ok [ 0.004092] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 [ 0.005367] Setting up static identity map for 0x100000 - 0x10003c [ 0.005576] rcu: Hierarchical SRCU implementation. [ 0.006527] smp: Bringing up secondary CPUs ... [ 0.007720] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 [ 0.009005] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 [ 0.010372] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 [ 0.010531] smp: Brought up 1 node, 4 CPUs [ 0.010585] SMP: Total of 4 processors activated (153.60 BogoMIPS). [ 0.010616] CPU: All CPU(s) started in HYP mode. [ 0.010643] CPU: Virtualization extensions available. [ 0.011659] devtmpfs: initialized [ 0.029268] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4 [ 0.029596] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.029656] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) [ 0.041160] pinctrl core: initialized pinctrl subsystem [ 0.042394] NET: Registered protocol family 16 [ 0.046559] DMA: preallocated 1024 KiB pool for atomic coherent allocations [ 0.052313] audit: initializing netlink subsys (disabled) [ 0.052632] audit: type=2000 audit(0.050:1): state=initialized audit_enabled=0 res=1 [ 0.053232] thermal_sys: Registered thermal governor 'step_wise' [ 0.054152] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. [ 0.054215] hw-breakpoint: maximum watchpoint size is 8 bytes. [ 0.054526] Serial: AMBA PL011 UART driver [ 0.078262] bcm2835-mbox 3f00b880.mailbox: mailbox enabled [ 0.090187] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-11-18T16:18:09, variant start [ 0.100198] raspberrypi-firmware soc:firmware: Firmware hash is d9b293558b4cef6aabedcc53c178e7604de90788 [ 0.144542] Kprobes globally optimized [ 0.149810] bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1 [ 0.152131] SCSI subsystem initialized [ 0.152439] usbcore: registered new interface driver usbfs [ 0.152526] usbcore: registered new interface driver hub [ 0.152619] usbcore: registered new device driver usb [ 0.154588] clocksource: Switched to clocksource arch_sys_counter [ 1.928130] VFS: Disk quotas dquot_6.6.0 [ 1.928277] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) [ 1.928504] FS-Cache: Loaded [ 1.928798] CacheFiles: Loaded [ 1.929662] simple-framebuffer 3eaa9000.framebuffer: framebuffer at 0x3eaa9000, 0x151800 bytes, mapped to 0x(ptrval) [ 1.929715] simple-framebuffer 3eaa9000.framebuffer: format=a8r8g8b8, mode=720x480x32, linelength=2880 [ 1.935956] Console: switching to colour frame buffer device 90x30 [ 1.944844] simple-framebuffer 3eaa9000.framebuffer: fb0: simplefb registered! [ 1.958784] NET: Registered protocol family 2 [ 1.962354] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 1.967304] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) [ 1.974193] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) [ 1.977877] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) [ 1.981534] TCP: Hash tables configured (established 8192 bind 8192) [ 1.985184] UDP hash table entries: 512 (order: 2, 16384 bytes, linear) [ 1.988711] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) [ 1.992845] NET: Registered protocol family 1 [ 1.997139] RPC: Registered named UNIX socket transport module. [ 2.000597] RPC: Registered udp transport module. [ 2.004088] RPC: Registered tcp transport module. [ 2.007591] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 2.012830] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available [ 2.023650] Initialise system trusted keyrings [ 2.027506] workingset: timestamp_bits=14 max_order=18 bucket_order=4 [ 2.040729] zbud: loaded [ 2.046431] FS-Cache: Netfs 'nfs' registered for caching [ 2.050826] NFS: Registering the id_resolver key type [ 2.054295] Key type id_resolver registered [ 2.057729] Key type id_legacy registered [ 2.061125] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 2.064424] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... [ 2.068958] Key type asymmetric registered [ 2.072190] Asymmetric key parser 'x509' registered [ 2.075439] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249) [ 2.078651] io scheduler mq-deadline registered [ 2.081755] io scheduler kyber registered [ 2.094244] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled [ 2.099928] bcm2835-rng 3f104000.rng: hwrng registered [ 2.103519] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) [ 2.110515] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000 [ 2.125996] brd: module loaded [ 2.141539] loop: module loaded [ 2.146709] Loading iSCSI transport class v2.0-870. [ 2.151566] libphy: Fixed MDIO Bus: probed [ 2.155075] usbcore: registered new interface driver lan78xx [ 2.158277] usbcore: registered new interface driver smsc95xx [ 2.161369] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) [ 2.892730] Core Release: 2.80a [ 2.895759] Setting default values for core params [ 2.898792] Finished setting default values for core params [ 3.102210] Using Buffer DMA mode [ 3.105230] Periodic Transfer Interrupt Enhancement - disabled [ 3.108352] Multiprocessor Interrupt Enhancement - disabled [ 3.111444] OTG VER PARAM: 0, OTG VER FLAG: 0 [ 3.114528] Dedicated Tx FIFOs mode [ 3.118042] WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = 9ed04000 dma = 0xded04000 len=9024 [ 3.126827] FIQ FSM acceleration enabled for : Non-periodic Split Transactions Periodic Split Transactions High-Speed Isochronous Endpoints Interrupt/Control Split Transaction hack enabled [ 3.141105] dwc_otg: Microframe scheduler enabled [ 3.141182] WARN::hcd_init_fiq:457: FIQ on core 1 [ 3.146343] WARN::hcd_init_fiq:458: FIQ ASM at 807c9984 length 36 [ 3.151542] WARN::hcd_init_fiq:497: MPHI regs_base at bb810000 [ 3.156818] dwc_otg 3f980000.usb: DWC OTG Controller [ 3.159609] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1 [ 3.162456] dwc_otg 3f980000.usb: irq 89, io mem 0x00000000 [ 3.165282] Init: Port Power? op_state=1 [ 3.168013] Init: Power Port (0) [ 3.171037] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10 [ 3.176580] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 3.179510] usb usb1: Product: DWC OTG Controller [ 3.182387] usb usb1: Manufacturer: Linux 5.10.63-v7+ dwc_otg_hcd [ 3.185339] usb usb1: SerialNumber: 3f980000.usb [ 3.189043] hub 1-0:1.0: USB hub found [ 3.191947] hub 1-0:1.0: 1 port detected [ 3.195968] dwc_otg: FIQ enabled [ 3.195982] dwc_otg: NAK holdoff enabled [ 3.195994] dwc_otg: FIQ split-transaction FSM enabled [ 3.196011] Module dwc_common_port init [ 3.196345] usbcore: registered new interface driver usb-storage [ 3.199405] mousedev: PS/2 mouse device common for all mice [ 3.203639] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer [ 3.209326] sdhci: Secure Digital Host Controller Interface driver [ 3.212284] sdhci: Copyright(c) Pierre Ossman [ 3.215958] mmc-bcm2835 3f300000.mmc: could not get clk, deferring probe [ 3.219733] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe [ 3.223055] sdhci-pltfm: SDHCI platform and OF driver helper [ 3.228035] ledtrig-cpu: registered to indicate activity on CPUs [ 3.231535] hid: raw HID events driver (C) Jiri Kosina [ 3.234825] usbcore: registered new interface driver usbhid [ 3.237894] usbhid: USB HID core driver [ 3.246187] Initializing XFRM netlink socket [ 3.249249] NET: Registered protocol family 17 [ 3.252377] Key type dns_resolver registered [ 3.255910] Registering SWP/SWPB emulation handler [ 3.259057] registered taskstats version 1 [ 3.261975] Loading compiled-in X.509 certificates [ 3.265723] Key type ._fscrypt registered [ 3.268468] Key type .fscrypt registered [ 3.271134] Key type fscrypt-provisioning registered [ 3.285359] uart-pl011 3f201000.serial: there is not valid maps for state default [ 3.288377] uart-pl011 3f201000.serial: cts_event_workaround enabled [ 3.291234] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2 [ 4.370792] printk: console [ttyAMA0] enabled [ 4.378588] Indeed it is in host mode hprt0 = 00021501 [ 4.448619] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver [ 4.460520] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0 [ 4.469318] mmc-bcm2835 3f300000.mmc: DMA channel allocated [ 4.504651] sdhost: log_buf @ (ptrval) (ded07000) [ 4.556817] mmc1: queuing unknown CIS tuple 0x01 (3 bytes) [ 4.565198] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1) [ 4.576662] of_cfs_init [ 4.581999] of_cfs_init: OK [ 4.588754] Waiting for root device PARTUUID=2577b6ec-02... [ 4.601015] mmc1: queuing unknown CIS tuple 0x1a (5 bytes) [ 4.612705] mmc1: queuing unknown CIS tuple 0x1b (8 bytes) [ 4.624664] usb 1-1: new high-speed USB device number 2 using dwc_otg [ 4.634303] Indeed it is in host mode hprt0 = 00001101 [ 4.705681] mmc1: queuing unknown CIS tuple 0x80 (1 bytes) [ 4.714128] mmc1: queuing unknown CIS tuple 0x81 (1 bytes) [ 4.725668] mmc1: queuing unknown CIS tuple 0x82 (1 bytes) [ 4.737586] mmc0: host does not support reading read-only switch, assuming write-enable [ 4.751677] mmc0: new high speed SDHC card at address 0001 [ 4.760366] mmc1: queuing unknown CIS tuple 0x80 (1 bytes) [ 4.769039] mmc1: queuing unknown CIS tuple 0x81 (1 bytes) [ 4.777766] mmcblk0: mmc0:0001 EB1QT 29.8 GiB [ 4.785799] mmc1: queuing unknown CIS tuple 0x82 (1 bytes) [ 4.794553] mmc1: new SDIO card at address 0001 [ 4.802897] mmcblk0: p1 p2 [ 4.828871] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) [ 4.842280] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. [ 4.860136] devtmpfs: mounted [ 4.872777] Freeing unused kernel memory: 1024K [ 4.905175] Run /sbin/init as init process [ 4.905420] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00 [ 4.911927] with arguments: [ 4.925607] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 4.925611] /sbin/init [ 4.925621] with environment: [ 4.935706] HOME=/ [ 4.935716] TERM=linux [ 4.936533] hub 1-1:1.0: USB hub found [ 4.943279] hub 1-1:1.0: 5 ports detected [ 5.264662] usb 1-1.1: new high-speed USB device number 3 using dwc_otg [ 5.405038] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00 [ 5.419379] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 5.432902] smsc95xx v2.0.0 [ 5.479395] systemd[1]: System time before build time, advancing clock. [ 5.575909] libphy: smsc95xx-mdiobus: probed [ 5.584442] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:f6:42:8c [ 5.663245] NET: Registered protocol family 10 [ 5.672957] Segment Routing with IPv6 [ 5.726716] systemd[1]: systemd 247.3-6+rpi1 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified) [ 5.769960] systemd[1]: Detected architecture arm. [ 5.804916] systemd[1]: Set hostname to . [ 6.017699] uart-pl011 3f201000.serial: no DMA platform data [ 6.945653] systemd[1]: Queued start job for default target Graphical Interface. [ 6.959205] random: systemd: uninitialized urandom read (16 bytes read) [ 6.972434] systemd[1]: Created slice system-getty.slice. [ 6.986392] random: systemd: uninitialized urandom read (16 bytes read) [ 6.998110] systemd[1]: Created slice system-modprobe.slice. [ 7.011740] random: systemd: uninitialized urandom read (16 bytes read) [ 7.023273] systemd[1]: Created slice system-serial\x2dgetty.slice. [ 7.038760] systemd[1]: Created slice system-systemd\x2dfsck.slice. [ 7.053943] systemd[1]: Created slice User and Session Slice. [ 7.068070] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ 7.084452] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ 7.101405] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. [ 7.123277] systemd[1]: Reached target Local Encrypted Volumes. [ 7.138288] systemd[1]: Reached target Paths. [ 7.151222] systemd[1]: Reached target Slices. [ 7.164080] systemd[1]: Reached target Swap. [ 7.177744] systemd[1]: Listening on Syslog Socket. [ 7.191417] systemd[1]: Listening on fsck to fsckd communication Socket. [ 7.206664] systemd[1]: Listening on initctl Compatibility Named Pipe. [ 7.222683] systemd[1]: Listening on Journal Audit Socket. [ 7.237132] systemd[1]: Listening on Journal Socket (/dev/log). [ 7.251980] systemd[1]: Listening on Journal Socket. [ 7.267038] systemd[1]: Listening on udev Control Socket. [ 7.280919] systemd[1]: Listening on udev Kernel Socket. [ 7.294858] systemd[1]: Condition check resulted in Huge Pages File System being skipped. [ 7.314411] systemd[1]: Mounting POSIX Message Queue File System... [ 7.333948] systemd[1]: Mounting RPC Pipe File System... [ 7.353792] systemd[1]: Mounting Kernel Debug File System... [ 7.373678] systemd[1]: Mounting Kernel Trace File System... [ 7.388688] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped. [ 7.416296] systemd[1]: Starting Restore / save the current clock... [ 7.438669] systemd[1]: Starting Set the console keyboard layout... [ 7.459898] systemd[1]: Starting Create list of static device nodes for the current kernel... [ 7.489013] systemd[1]: Starting Load Kernel Module configfs... [ 7.510578] systemd[1]: Starting Load Kernel Module drm... [ 7.531367] systemd[1]: Starting Load Kernel Module fuse... [ 7.551901] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. [ 7.576586] systemd[1]: Starting File System Check on Root Device... [ 7.614244] systemd[1]: Starting Journal Service... [ 7.615393] fuse: init (API version 7.32) [ 7.675606] systemd[1]: Starting Load Kernel Modules... [ 7.697532] systemd[1]: Starting Coldplug All udev Devices... [ 7.738542] systemd[1]: Mounted POSIX Message Queue File System. [ 7.754095] systemd[1]: Mounted RPC Pipe File System. [ 7.768437] systemd[1]: Mounted Kernel Debug File System. [ 7.783553] systemd[1]: Mounted Kernel Trace File System. [ 7.798920] systemd[1]: Finished Restore / save the current clock. [ 7.816765] systemd[1]: Finished Create list of static device nodes for the current kernel. [ 7.839245] systemd[1]: modprobe@configfs.service: Succeeded. [ 7.851057] systemd[1]: Finished Load Kernel Module configfs. [ 7.866937] systemd[1]: modprobe@drm.service: Succeeded. [ 7.877644] systemd[1]: Finished Load Kernel Module drm. [ 7.892860] systemd[1]: modprobe@fuse.service: Succeeded. [ 7.903845] systemd[1]: Finished Load Kernel Module fuse. [ 7.920226] systemd[1]: Finished Load Kernel Modules. [ 7.941305] systemd[1]: Mounting FUSE Control File System... [ 7.961190] systemd[1]: Mounting Kernel Configuration File System... [ 7.981741] systemd[1]: Started File System Check Daemon to report status. [ 8.006626] systemd[1]: Starting Apply Kernel Variables... [ 8.030534] systemd[1]: Started Journal Service. [ 8.318174] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null) [ 8.392099] systemd-journald[132]: Received client request to flush runtime journal. [ 8.427153] systemd-journald[132]: File /var/log/journal/56cc1a5f67954092b47d78ab165a2c27/system.journal corrupted or uncleanly shut down, renaming and replacing. [ 9.772731] mc: Linux media interface: v0.10 [ 9.843020] videodev: Linux video capture interface: v2.00 [ 9.875388] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. [ 9.908722] bcm2835_vc_sm_cma_probe: Videocore shared memory driver [ 9.908752] [vc_sm_connected_init]: start [ 9.910595] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. [ 9.911002] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. [ 9.913505] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. [ 9.913512] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. [ 9.915858] [vc_sm_connected_init]: installed successfully [ 9.920118] bcm2835_audio bcm2835_audio: card created with 8 channels [ 9.920873] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. [ 9.923398] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. [ 9.923635] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. [ 9.934791] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. [ 9.940134] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. [ 9.949562] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. [ 9.965590] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 [ 9.967070] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 [ 9.968455] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 [ 9.969471] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 [ 9.969505] bcm2835-isp bcm2835-isp: Register output node 0 with media controller [ 9.969530] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller [ 9.969551] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller [ 9.969571] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller [ 9.969765] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp [ 9.995393] bcm2835-codec bcm2835-codec: Device registered as /dev/video10 [ 9.995465] bcm2835-codec bcm2835-codec: Loaded V4L2 decode [ 10.013878] bcm2835-codec bcm2835-codec: Device registered as /dev/video11 [ 10.013934] bcm2835-codec bcm2835-codec: Loaded V4L2 encode [ 10.034724] bcm2835-codec bcm2835-codec: Device registered as /dev/video12 [ 10.034784] bcm2835-codec bcm2835-codec: Loaded V4L2 isp [ 10.056812] bcm2835-codec bcm2835-codec: Device registered as /dev/video18 [ 10.056866] bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx [ 10.928050] checking generic (3eaa9000 151800) vs hw (0 ffffffff) [ 10.928075] fb0: switching to vc4drmfb from simple [ 10.940597] Console: switching to colour dummy device 80x30 [ 10.964090] vc4-drm soc:gpu: bound 3f400000.hvs (ops vc4_hvs_ops [vc4]) [ 10.983430] Registered IR keymap rc-cec [ 10.983686] rc rc0: vc4 as /devices/platform/soc/3f902000.hdmi/rc/rc0 [ 10.983973] input: vc4 as /devices/platform/soc/3f902000.hdmi/rc/rc0/input0 [ 10.989588] vc4_hdmi 3f902000.hdmi: Could not register sound card: -517 [ 11.594704] random: crng init done [ 11.594729] random: 7 urandom warning(s) missed due to ratelimiting [ 11.603478] vc4-drm soc:gpu: bound 3f400000.hvs (ops vc4_hvs_ops [vc4]) [ 11.609986] Registered IR keymap rc-cec [ 11.610271] rc rc0: vc4 as /devices/platform/soc/3f902000.hdmi/rc/rc0 [ 11.610543] input: vc4 as /devices/platform/soc/3f902000.hdmi/rc/rc0/input1 [ 11.616006] vc4-drm soc:gpu: bound 3f902000.hdmi (ops vc4_hdmi_ops [vc4]) [ 11.616327] vc4-drm soc:gpu: bound 3f806000.vec (ops vc4_vec_ops [vc4]) [ 11.616686] vc4-drm soc:gpu: bound 3f004000.txp (ops vc4_txp_ops [vc4]) [ 11.616978] vc4-drm soc:gpu: bound 3f206000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 11.617275] vc4-drm soc:gpu: bound 3f207000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 11.617577] vc4-drm soc:gpu: bound 3f807000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 11.617815] vc4-drm soc:gpu: bound 3fc00000.v3d (ops vc4_v3d_ops [vc4]) [ 11.637165] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0 [ 11.680862] Console: switching to colour frame buffer device 90x30 [ 11.701245] vc4-drm soc:gpu: [drm] fb0: vc4drmfb frame buffer device [ 12.397876] 8021q: 802.1Q VLAN Support v1.8 [ 12.684777] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 12.827406] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS [ 12.858837] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 12.869382] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid [ 13.177442] SMSC LAN8700 usb-001:003:01: attached PHY driver [SMSC LAN8700] (mii_bus:phy_addr=usb-001:003:01, irq=POLL) [ 13.177890] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup [ 13.194007] smsc95xx 1-1.1:1.0 eth0: Link is Down [ 15.275861] smsc95xx 1-1.1:1.0 eth0: Link is Up - 100Mbps/Full - flow control off [ 15.275916] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 47.285158] Bluetooth: Core ver 2.22 [ 47.285295] NET: Registered protocol family 31 [ 47.285306] Bluetooth: HCI device and connection manager initialized [ 47.285948] Bluetooth: HCI socket layer initialized [ 47.285966] Bluetooth: L2CAP socket layer initialized [ 47.285998] Bluetooth: SCO socket layer initialized [ 77.186172] esp32_sdio: loading out-of-tree module taints kernel. [ 77.187547] esp_reset, ESP32: Resetpin of Host is 6 [ 77.187672] esp_reset, ESP32: Triggering ESP reset. [ 77.188073] esp_sdio: probe of mmc1:0001:1 failed with error -110 [ 77.188153] esp_sdio: probe of mmc1:0001:2 failed with error -110 [ 77.595210] mmc1: card 0001 removed [ 78.926303] mmc1: queuing unknown CIS tuple 0x01 (3 bytes) [ 78.934128] mmc1: queuing unknown CIS tuple 0x1a (5 bytes) [ 78.938027] mmc1: queuing unknown CIS tuple 0x1b (8 bytes) [ 78.941426] mmc1: queuing unknown CIS tuple 0x80 (1 bytes) [ 78.941586] mmc1: queuing unknown CIS tuple 0x81 (1 bytes) [ 78.941744] mmc1: queuing unknown CIS tuple 0x82 (1 bytes) [ 78.944658] mmc1: queuing unknown CIS tuple 0x80 (1 bytes) [ 78.945580] mmc1: queuing unknown CIS tuple 0x81 (1 bytes) [ 78.945767] mmc1: queuing unknown CIS tuple 0x82 (1 bytes) [ 78.946325] mmc1: new SDIO card at address 0001 [ 78.946962] esp_probe: ESP network device detected [ 84.316083] esp_read_multi_byte: esp_read_multi_byte - ret: -110 [ 84.316346] esp_sdio: probe of mmc1:0001:1 failed with error -110 [ 84.316756] esp_sdio: probe of mmc1:0001:2 failed with error -22 ```
ESP32 - Serial Port ``` rst:0x1 (POWERON_RESET),boot:0x3e (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:0x3fff0018,len:4 load:0x3fff001c,len:6960 ho 0 tail 12 room 4 load:0x40078000,len:14704 load:0x40080400,len:4292 entry 0x400806e4 I (75) boot: Chip Revision: 1 I (76) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (41) boot: ESP-IDF v4.0.2-206-g5630b17e1-dirty 2nd stage bootloader I (41) boot: compile time 22:23:52 I (44) boot: Enabling RNG early entropy source... I (47) boot: SPI Speed : 40MHz I (52) boot: SPI Mode : DIO I (56) boot: SPI Flash Size : 4MB I (60) boot: Partition Table: I (63) boot: ## Label Usage Type ST Offset Length I (70) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (78) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (85) boot: 2 factory factory app 00 00 00010000 00100000 I (93) boot: End of partition table I (97) boot_comm: chip revision: 1, min. application chip revision: 0 I (104) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1d9d8 (121304) map I (156) esp_image: segment 1: paddr=0x0002da00 vaddr=0x3ffbdb60 size=0x02610 ( 9744) load I (160) esp_image: segment 2: paddr=0x00030018 vaddr=0x400d0018 size=0x8d680 (579200) map I (368) esp_image: segment 3: paddr=0x000bd6a0 vaddr=0x3ffc0170 size=0x01038 ( 4152) load I (370) esp_image: segment 4: paddr=0x000be6e0 vaddr=0x40080000 size=0x00400 ( 1024) load I (375) esp_image: segment 5: paddr=0x000beae8 vaddr=0x40080400 size=0x1c50c (115980) load I (449) boot: Loaded app from partition at offset 0x10000 I (449) boot: Disabling RNG early entropy source... I (450) cpu_start: Pro cpu up. I (453) cpu_start: Application information: I (458) cpu_start: Project name: network_adapter_0.3 I (464) cpu_start: App version: release0.3-4-g5655a41 I (470) cpu_start: Compile time: Mar 5 2021 22:23:51 I (476) cpu_start: ELF file SHA256: 65d9f05897a3c2f7... I (482) cpu_start: ESP-IDF: v4.0.2-206-g5630b17e1-dirty I (489) cpu_start: Single core mode I (494) heap_init: Initializing. RAM available for dynamic allocation: I (500) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM I (507) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM I (513) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM I (519) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM I (525) heap_init: At 3FFD1DD0 len 0000E230 (56 KiB): DRAM I (531) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM I (537) heap_init: At 40078000 len 00008000 (32 KiB): IRAM I (544) heap_init: At 4009C90C len 000036F4 (13 KiB): IRAM I (550) cpu_start: Pro cpu start user code I (568) spi_flash: detected chip: gd I (568) spi_flash: flash io: dio I (568) cpu_start: Starting scheduler on PRO CPU. I (571) NETWORK_ADAPTER: ********************************************************************* I (571) NETWORK_ADAPTER: ESP-Hosted Firmware version :: 0.3 I (581) NETWORK_ADAPTER: Transport used :: SDIO I (591) NETWORK_ADAPTER: ********************************************************************* I (601) NETWORK_ADAPTER: Supported features are: I (611) NETWORK_ADAPTER: - WLAN over SDIO I (611) NETWORK_ADAPTER: - BT/BLE I (621) NETWORK_ADAPTER: - HCI Over SDIO I (621) NETWORK_ADAPTER: - BT/BLE dual mode I (631) BTDM_INIT: BT controller compile version [4bc0a8e] I (631) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE I (731) phy: phy_version: 4390, 6b3c1f2, Sep 10 2020, 15:09:07, 0, 0 I (1181) SDIO_SLAVE: Using SDIO interface I (1191) wifi:wifi driver task: 3ffded8c, prio:23, stack:6656, core=0 I (1191) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE I (1191) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE I (1201) wifi:wifi firmware version: 6e1f9e4 I (1201) wifi:config NVS flash: disabled I (1211) wifi:config nano formating: disabled I (1211) wifi:Init data frame dynamic rx buffer num: 32 I (1221) wifi:Init management frame dynamic rx buffer num: 32 I (1221) wifi:Init management short buffer num: 32 I (1231) wifi:Init dynamic tx buffer num: 32 I (1231) wifi:Init static rx buffer size: 1600 I (1231) wifi:Init static rx buffer num: 10 I (1241) wifi:Init dynamic rx buffer num: 32 I (1251) wifi:mode : null I (1251) NETWORK_ADAPTER: Initial set up done ```
Raspberry Pi - ap_scan_list.py ``` python ap_scan_list.py open: : No such device or address wifi_ap_scan_list:943 Failed to process rx data Failed to get AP scan list ```
Raspberry Pi - ifconfig ``` ifconfig eth0: flags=4163 mtu 1500 inet 192.168.1.112 netmask 255.255.255.0 broadcast 192.168.1.255 inet6 fe80::c4ec:c7bc:4f39:9586 prefixlen 64 scopeid 0x20 ether b8:27:eb:f6:42:8c txqueuelen 1000 (Ethernet) RX packets 1241 bytes 81798 (79.8 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 597 bytes 122871 (119.9 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 lo: flags=73 mtu 65536 inet 127.0.0.1 netmask 255.0.0.0 inet6 ::1 prefixlen 128 scopeid 0x10 loop txqueuelen 1000 (Local Loopback) RX packets 14 bytes 1842 (1.7 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 14 bytes 1842 (1.7 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 ```

Thanks in advance.

mantriyogesh commented 2 years ago

Hello @gediz ,

Apologies that we could not reply in due time. Were you able to resolve the issue?

From your logs I could see that SDIO is detected at host, but probing is not successful. This typically happens if wires are loose or longer. Have you tried with smaller wires like 6-7cm?

gediz commented 2 years ago

Hello @mantriyogesh, thanks for the reply. I've used shorter cables and even tried it on a perfboard with better wiring to no avail.

mantriyogesh commented 2 years ago

I could see the sdcard is detected by Linux but is not getting probed by the ESP32 driver. You can ignore -110 and -22 error as if now.

To get you going, some alternatives,

  1. Can you try with release/v4.0
  2. May be some issue with ESP32, is it possible to try with another ESP32?
  3. Alternatively, Is it possible to use SPI as transport?
gediz commented 2 years ago

I have actually tried it with different modules and different models. SPI works by the way. But I did not try it with release/v4.0. I will try it.

mantriyogesh commented 2 years ago

Some questions/comments:

  1. Could you please post your SDIO setup's /boot/config.txt here?
  2. How are you loading esp32 driver? Is it manual or as daemon/service?
  3. overall -110 shows signal integrity issue, can you please verify the connections and cables?
mantriyogesh commented 2 years ago

Also please have a look at https://github.com/espressif/esp-hosted/issues/26#issuecomment-819344162 if you have correct driver strength ?