al177 / esp8089

Linux kernel module driver for the ESP8089 WiFi chip
GNU General Public License v2.0
185 stars 114 forks source link

esp_init_all failed: -110 #5

Closed Manawyrm closed 7 years ago

Manawyrm commented 8 years ago

Hi,

I have built an ESP03 wifi module. Used 4bit mode and I have soldered 33 ohm resistors inline for the data lines. Reset is on ID_SD.

Is this an hardware issue? If so: Any ideas where I should look?

[   11.331384] 
***** EAGLE DRIVER VER:bdf5087c3deb*****

[   11.331517] ESP8089 reset via GPIO 0
[   11.353706] systemd-journald[112]: Received request to flush runtime journal from PID 1
[   11.539624] eagle_sdio_dummy: probe of mmc1:0001:1 failed with error -110
[   12.205823] mmc1: card 0001 removed
[   12.281011] mmc1: queuing unknown CIS tuple 0x01 (3 bytes)
[   12.290120] mmc1: queuing unknown CIS tuple 0x1a (5 bytes)
[   12.293855] mmc1: queuing unknown CIS tuple 0x1b (8 bytes)
[   12.298342] mmc1: queuing unknown CIS tuple 0x80 (1 bytes)
[   12.298489] mmc1: queuing unknown CIS tuple 0x81 (1 bytes)
[   12.298634] mmc1: queuing unknown CIS tuple 0x82 (1 bytes)
[   12.298704] mmc1: new high speed SDIO card at address 0001
[   12.299342] esp_sdio_dummy_probe enter
[   12.515414] esp_sdio_init power up OK
[   12.708746] cfg80211: World regulatory domain updated:
[   12.708790] cfg80211:  DFS Master region: unset
[   12.708801] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   12.708819] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   12.708831] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   12.708843] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[   12.708857] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[   12.708885] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[   12.708899] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[   12.708911] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[   12.708923] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[   23.245350] resetting event timeout
[   23.245390] esp_init_all failed: -110
[   23.245401] first error exit
[   25.028489] Adding 102396k swap on /var/swap.  Priority:-1 extents:4 across:184316k SSFS
[   25.569123] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   27.953292] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
noahwilliamsson commented 8 years ago

What does your /sys/kernel/debug/mmc1/ios look like? When the SDIO link is OK, it should look similar to this:

clock:      50000000 Hz
actual clock:   41666666 Hz
vdd:        21 (3.3 ~ 3.4 V)
bus mode:   2 (push-pull)
chip select:    0 (don't care)
power mode: 2 (on)
bus width:  2 (4 bits)
timing spec:    2 (sd high-speed)
signal voltage: 0 (3.30 V)
driver type:    0 (driver type B)

If your have a problem with your SDIO link (bad connections, signal integrity issues, ..) it will instead look like this:

clock:          0 Hz
vdd:            0 (invalid)
bus mode:       2 (push-pull)
chip select:    0 (don't care)
power mode:     0 (off)
bus width:      0 (1 bits)
timing spec:    0 (legacy)
signal voltage: 0 (3.30 V)
driver type:    0 (driver type B)

You can keep an eye on the values with a command such as:

watch -n1 cat /sys/kernel/debug/mmc1/ios   # Display contents of the file every 1 second

Make sure your chip boots up with GPIO15 (MTD0) high (tied to Vcc via resistor) so the chip boots up in SDIO mode and can accept new firmware. Reset the chip manually (RST -> GND momentarily) if needed.

You can verify in which mode the chip boots up by listening on the UART at 74600 baud and look for the string boot mode: (X, Y). See https://github.com/esp8266/esp8266-wiki/wiki/Boot-Process for details on what X corresponds to.

Manawyrm commented 8 years ago
clock:      50000000 Hz
actual clock:   41666666 Hz
vdd:        21 (3.3 ~ 3.4 V)
bus mode:   2 (push-pull)
chip select:    0 (don't care)
power mode: 2 (on)
bus width:  2 (4 bits)
timing spec:    2 (sd high-speed)
signal voltage: 0 (3.30 V)
driver type:    0 (driver type B)

Looks good so far.. I hadn't had the GPIO15 boot mode resistor inplace, I added that now, but it didn't change anything unfortunatly. The boot mode is 7, which seems about right.

Manually resetting the ESP doesn't really seem like a good idea:

[   27.879181] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[  345.328106] esp_sdio_remove enter
[  345.329222] sif_disable_irq release irq failed
[  345.334623] mmc1: card 0001 removed
[  345.392781] mmc1: queuing unknown CIS tuple 0x01 (3 bytes)
[  345.402149] mmc1: queuing unknown CIS tuple 0x1a (5 bytes)
[  345.405392] mmc1: queuing unknown CIS tuple 0x1b (8 bytes)
[  345.410743] mmc1: queuing unknown CIS tuple 0x80 (1 bytes)
[  345.410865] mmc1: queuing unknown CIS tuple 0x81 (1 bytes)
[  345.411182] mmc1: queuing unknown CIS tuple 0x82 (1 bytes)
[  345.411245] mmc1: new high speed SDIO card at address 0001
[  345.415639] Unable to handle kernel NULL pointer dereference at virtual address 0000002c
[  345.427360] pgd = c0004000
[  345.431888] [0000002c] *pgd=00000000
[  345.437206] Internal error: Oops: 5 [#1] ARM
[  345.443231] Modules linked in: esp8089(O) mac80211 snd_bcm2835 cdc_ether snd_pcm r8152 cfg80211 snd_timer snd rfkill bcm2835_gpiomem bcm2835_wdt uio_pdrv_genirq uio i2c_dev ipv6
[  345.464882] CPU: 0 PID: 65 Comm: kworker/u2:2 Tainted: G           O    4.4.21+ #911
[  345.476449] Hardware name: BCM2708
[  345.481836] Workqueue: kmmcd mmc_rescan
[  345.487578] task: dafd9b40 ti: dafe4000 task.ti: dafe4000
[  345.494983] PC is at esp_sdio_probe+0x58/0x3f4 [esp8089]
[  345.502213] LR is at sdio_bus_probe+0x10c/0x124
[  345.508614] pc : [<bf276420>]    lr : [<c043949c>]    psr: 20000013
sp : dafe5d08  ip : dafe5d38  fp : dafe5d34
[  345.523938] r10: 00000000  r9 : bf282600  r8 : bf27f4f8
[  345.531096] r7 : da5a5c60  r6 : d893f200  r5 : bf2aeca4  r4 : d895c700
[  345.539600] r3 : d893f208  r2 : 00000002  r1 : 00000000  r0 : d893f200
[  345.548112] Flags: nzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment kernel
[  345.557415] Control: 00c5387d  Table: 1a624008  DAC: 00000055
[  345.565110] Process kworker/u2:2 (pid: 65, stack limit = 0xdafe4188)
[  345.573465] Stack: (0xdafe5d08 to 0xdafe6000)
[  345.579851] 5d00:                   c042d3cc c0373e30 d893f208 00000000 d893f200 bf282664
[  345.592121] 5d20: bf27f4f8 00000000 dafe5d5c dafe5d38 c043949c bf2763d4 c0439390 c0918bbc
[  345.604379] 5d40: d893f208 00000000 bf282664 00000009 dafe5d84 dafe5d60 c036a754 c043939c
[  345.616708] 5d60: 00000000 bf282664 dafe5dd0 d893f208 00000001 c0918b98 dafe5da4 dafe5d88
[  345.629183] 5d80: c036a9d0 c036a560 d8a42760 00000000 dafe5dd0 c036a940 dafe5dcc dafe5da8
[  345.641937] 5da0: c0368aa8 c036a94c dad6a11c d8a42754 00000000 d893f208 d893f208 d893f23c
[  345.654921] 5dc0: dafe5df4 dafe5dd0 c036a49c c0368a40 d893f208 00000001 d893f210 d893f208
[  345.668076] 5de0: c08767cc 00000000 dafe5e04 dafe5df8 c036ab40 c036a3f8 dafe5e24 dafe5e08
[  345.681402] 5e00: c0369ad8 c036ab30 db3c4a80 d893f210 d893f208 d8ae8008 dafe5e64 dafe5e28
[  345.694818] 5e20: c0367a94 c0369a50 dade7000 00000001 dafe5e64 dafe5e40 c042f078 d893f200
[  345.708400] 5e40: d893f208 00000001 00000001 d8ae8000 d8ae82dc d8ae8000 dafe5e7c dafe5e68
[  345.722060] 5e60: c04397e4 c03676e0 00000000 dade7000 dafe5ec4 dafe5e80 c0438a7c c0439798
[  345.735756] 5e80: 00000000 dafe5e93 00000000 00000000 00000000 10ffff00 00000000 dade7238
[  345.749416] 5ea0: c05b0744 dade7000 00061a80 c05b0750 dad40600 dac02a00 dafe5eec dafe5ec8
[  345.763036] 5ec0: c042fdf0 c04387f0 c042fa98 dade7238 dafa9000 dac02a00 00000000 00000000
[  345.776690] 5ee0: dafe5f2c dafe5ef0 c00375b4 c042faa4 dac02a00 dac02a10 00000088 c088513c
[  345.790382] 5f00: dafa9000 dac02a00 dafa9018 dac02a10 00000088 c088513c dafa9000 dac02a00
[  345.804063] 5f20: dafe5f64 dafe5f30 c0037874 c00374a4 c0037834 00000000 00000000 00000000
[  345.817737] 5f40: dafb88c0 dafa9000 c0037834 00000000 00000000 00000000 dafe5fac dafe5f68
[  345.831369] 5f60: c003d1f8 c0037840 00050403 00000000 dafb88c0 dafa9000 00000000 dafe5f7c
[  345.844998] 5f80: dafe5f7c 00000000 dafe5f88 dafe5f88 dafb88c0 c003d11c 00000000 00000000
[  345.858685] 5fa0: 00000000 dafe5fb0 c000f8a8 c003d128 00000000 00000000 00000000 00000000
[  345.872370] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[  345.886050] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000 55555555 55555555
[  345.899808] [<bf276420>] (esp_sdio_probe [esp8089]) from [<c043949c>] (sdio_bus_probe+0x10c/0x124)
[  345.914282] [<c043949c>] (sdio_bus_probe) from [<c036a754>] (driver_probe_device+0x200/0x304)
[  345.928318] [<c036a754>] (driver_probe_device) from [<c036a9d0>] (__device_attach_driver+0x90/0x9c)
[  345.942933] [<c036a9d0>] (__device_attach_driver) from [<c0368aa8>] (bus_for_each_drv+0x74/0xa8)
[  345.957279] [<c0368aa8>] (bus_for_each_drv) from [<c036a49c>] (__device_attach+0xb0/0x114)
[  345.971092] [<c036a49c>] (__device_attach) from [<c036ab40>] (device_initial_probe+0x1c/0x20)
[  345.985163] [<c036ab40>] (device_initial_probe) from [<c0369ad8>] (bus_probe_device+0x94/0x9c)
[  345.999294] [<c0369ad8>] (bus_probe_device) from [<c0367a94>] (device_add+0x3c0/0x56c)
[  346.012686] [<c0367a94>] (device_add) from [<c04397e4>] (sdio_add_func+0x58/0x70)
[  346.025694] [<c04397e4>] (sdio_add_func) from [<c0438a7c>] (mmc_attach_sdio+0x298/0x35c)
[  346.039346] [<c0438a7c>] (mmc_attach_sdio) from [<c042fdf0>] (mmc_rescan+0x358/0x41c)
[  346.052731] [<c042fdf0>] (mmc_rescan) from [<c00375b4>] (process_one_work+0x11c/0x39c)
[  346.066172] [<c00375b4>] (process_one_work) from [<c0037874>] (worker_thread+0x40/0x4d0)
[  346.079745] [<c0037874>] (worker_thread) from [<c003d1f8>] (kthread+0xdc/0xf8)
[  346.089835] [<c003d1f8>] (kthread) from [<c000f8a8>] (ret_from_fork+0x14/0x2c)
[  346.099875] Code: e5851014 e5947004 e2863008 e5971004 (e591102c) 
[  346.108878] ---[ end trace c55a8899e195f2e4 ]---
Manawyrm commented 8 years ago

I have tried to supply an external stable 3.3V to the ESP, which didn't change anything. Now trying to use a different pin for CH_PD.

noahwilliamsson commented 8 years ago

What does dmesg look like if you do rmmod esp8089 and then reset the chip?

(Regarding the NULL dereference, it's a known issue; the driver can't handle an unexpected reset while it's loaded)

Manawyrm commented 8 years ago

Hm, after an rmmod esp8089 the module just gets reloaded. Using a different pin (i tried pin 5) doesn't change anything either. Any ideas left? ;)

al177 commented 8 years ago

The module forces a reset on unload. This is to clear out the ESP firmware before a reboot so that the module loads properly on the next boot. Unfortunately systemd sees the ESP re-enumerate on the SDIO bus after the reset and attempts to load the module.

I don't know of a way to prevent this reloading without losing the ESP after a warm reboot.