On Tue, Dec 11, 2018 at 6:12 PM Tony Lindgren <tony@xxxxxxxxxxx> wrote: > > * John Stultz <john.stultz@xxxxxxxxxx> [181211 19:51]: > > On Tue, Dec 11, 2018 at 11:25 AM Ricardo Salveti <rsalveti@xxxxxxxxxxxx> wrote: > > > Then tried to reproduce with a simple 'while true; do ip link set dev > > > wlan0 down; ip link set dev wlan0 up; done;' and it was already enough > > > to cause the same hang. Adding a simple sleep 1 after down/up is > > > already enough to make it work, so something might be missing during > > > the down/up process that only happens when they get called right after > > > the other. > > With while true test above, I'm getting: > > wlcore: ERROR timeout waiting for the hardware to complete initialization > > Then after ctrl-c, wlan0 connects to the access point just fine > for me. > > Is that what you're seeing or some oops? I'm getting the following oops with the while true test: [ 1088.565996] INFO: task ifconfig:941 blocked for more than 120 seconds. [ 1088.572552] Not tainted 4.20.0-rc6-lmp-standard #1 [ 1088.577913] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1088.585777] ifconfig D 0 941 916 0x00000008 [ 1088.591316] Call trace: [ 1088.593772] __switch_to+0xa0/0xf8 [ 1088.597200] __schedule+0x2ac/0x948 [ 1088.600715] schedule+0x38/0x98 [ 1088.603882] schedule_timeout+0x288/0x458 [ 1088.607918] wait_for_common+0x148/0x170 [ 1088.611866] wait_for_completion+0x28/0x38 [ 1088.616013] mmc_wait_for_req_done+0x38/0x198 [ 1088.620397] mmc_wait_for_req+0xb0/0xf0 [ 1088.624259] mmc_io_rw_extended+0x1d0/0x2c0 [ 1088.628469] sdio_io_rw_ext_helper+0x180/0x1f8 [ 1088.633112] sdio_memcpy_toio+0x44/0x58 [ 1088.636979] wl12xx_sdio_raw_write+0xe0/0x1b0 [ 1088.641386] wlcore_boot_upload_firmware+0x1a8/0x4c0 [ 1088.646378] wl18xx_boot+0x7dc/0xbc0 [ 1088.649986] wl1271_op_add_interface+0x558/0x910 [ 1088.654659] drv_add_interface+0x5c/0x1e8 [ 1088.658716] ieee80211_do_open+0x220/0x7f8 [ 1088.662857] ieee80211_open+0x4c/0x68 [ 1088.666591] __dev_open+0xdc/0x158 [ 1088.670034] __dev_change_flags+0x15c/0x1c0 [ 1088.674246] dev_change_flags+0x34/0x70 [ 1088.678131] devinet_ioctl+0x3fc/0x740 [ 1088.681908] inet_ioctl+0x108/0x278 [ 1088.685425] sock_do_ioctl+0x5c/0x240 [ 1088.689133] sock_ioctl+0x1e8/0x3f0 [ 1088.692652] do_vfs_ioctl+0xc4/0x868 [ 1088.696253] ksys_ioctl+0x84/0xb8 [ 1088.699594] __arm64_sys_ioctl+0x28/0x38 [ 1088.703545] el0_svc_common+0x94/0xe8 [ 1088.707233] el0_svc_handler+0x74/0x90 [ 1088.711031] el0_svc+0x8/0xc Added some more debugging, and this is what I'm getting when I add some delay between down/up (working behavior): wlan0 down: Dec 11 20:17:06 hikey kernel: wlcore: mac80211 remove interface Dec 11 20:17:06 hikey kernel: wlcore: mac80211 configure filter changed 0 total 80000000 Dec 11 20:17:06 hikey kernel: wlcore: down Dec 11 20:17:06 hikey kernel: wlcore: waking up chip from elp Dec 11 20:17:06 hikey kernel: wlcore: wakeup time: 12 ms Dec 11 20:17:06 hikey kernel: wlcore: cmd role disable Dec 11 20:17:06 hikey kernel: wlcore: mac80211 stop Dec 11 20:17:06 hikey kernel: wlcore: IRQ work Dec 11 20:17:06 hikey kernel: wlcore: intr: 0x20 (fw_rx_counter = 172, drv_rx_counter = 11, tx_results_counter = 0) Dec 11 20:17:06 hikey kernel: wlcore: WL1271_ACX_INTR_HW_AVAILABLE wlan0 up: Dec 11 20:17:11 hikey kernel: wlcore: mac80211 start Dec 11 20:17:11 hikey kernel: wlcore: mac80211 add interface type 2 mac 84:dd:20:92:54:5b Dec 11 20:17:11 hikey kernel: wlcore: allocating hw queue base: 0 Dec 11 20:17:11 hikey kernel: mmc_host mmc2: Bus speed (slot 0) = 24800000Hz (slot req 300000Hz, actual 295238HZ div = 42) Dec 11 20:17:11 hikey kernel: mmc_host mmc2: Bus speed (slot 0) = 24800000Hz (slot req 25000000Hz, actual 24800000HZ div = 0) Dec 11 20:17:12 hikey kernel: wlcore: clock freq 5 (13, 120, 0, 0, spit) Dec 11 20:17:12 hikey kernel: wlcore: chip id 0x6030111 Dec 11 20:17:12 hikey kernel: wlcore: firmware chunks to be uploaded: 15 Dec 11 20:17:12 hikey kernel: wlcore: chunk 14 addr 0x0 len 120432 Dec 11 20:17:12 hikey kernel: wlcore: starting firmware upload Dec 11 20:17:12 hikey kernel: wlcore: fw_data_len 120432 chunk_size 16384 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw chunk 0x000000002d8a6a40 to 0x0 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw chunk 0x0000000048dff62f to 0x4000 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw chunk 0x00000000f9372750 to 0x8000 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw chunk 0x00000000f2685ee4 to 0xc000 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw chunk 0x00000000c4fc484d to 0x10000 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw chunk 0x00000000a6d3c9bf to 0x14000 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw chunk 0x000000007404dc0f to 0x18000 Dec 11 20:17:12 hikey kernel: wlcore: uploading fw last chunk (5744 B) 0x00000000d7beb1f6 to 0x1c000 ... And now with while true: Dec 11 20:18:13 hikey kernel: wlcore: mac80211 configure filter changed 0 total 80000000 Dec 11 20:18:13 hikey kernel: wlcore: waking up chip from elp Dec 11 20:18:13 hikey kernel: wlcore: wakeup time: 8 ms Dec 11 20:18:13 hikey kernel: wlcore: acx group address tbl Dec 11 20:18:13 hikey kernel: wlcore: cmd configure (63) Dec 11 20:18:13 hikey kernel: wlcore: mac80211 remove interface Dec 11 20:18:13 hikey kernel: wlcore: down Dec 11 20:18:13 hikey kernel: wlcore: cmd role disable Dec 11 20:18:13 hikey kernel: wlcore: IRQ work Dec 11 20:18:13 hikey kernel: wlcore: mac80211 stop Dec 11 20:18:13 hikey kernel: wlcore: intr: 0x20 (fw_rx_counter = 0, drv_rx_counter = 0, tx_results_counter = 0) Dec 11 20:18:13 hikey kernel: wlcore: WL1271_ACX_INTR_HW_AVAILABLE Dec 11 20:18:13 hikey kernel: wlcore: mac80211 start Dec 11 20:18:13 hikey kernel: wlcore: mac80211 add interface type 2 mac 84:dd:20:92:54:5b Dec 11 20:18:13 hikey kernel: wlcore: allocating hw queue base: 0 Dec 11 20:18:13 hikey kernel: wlcore: clock freq 5 (13, 120, 0, 0, spit) Dec 11 20:18:13 hikey kernel: wlcore: chip id 0x6030111 Dec 11 20:18:13 hikey kernel: wlcore: firmware chunks to be uploaded: 15 Dec 11 20:18:13 hikey kernel: wlcore: chunk 14 addr 0x0 len 120432 Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 120432 chunk_size 16384 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x000000002d8a6a40 to 0x0 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x0000000048dff62f to 0x4000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000f9372750 to 0x8000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000f2685ee4 to 0xc000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000c4fc484d to 0x10000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000a6d3c9bf to 0x14000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x000000007404dc0f to 0x18000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (5744 B) 0x00000000d7beb1f6 to 0x1c000 Dec 11 20:18:13 hikey kernel: wlcore: chunk 13 addr 0x100000 len 131072 Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 131072 chunk_size 16384 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000c3cad69f to 0x100000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000a9e4f338 to 0x104000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x000000003169e0a1 to 0x108000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000cc5b7549 to 0x10c000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x000000009c0bb98a to 0x110000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000f4d0b2c2 to 0x114000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x0000000026e1d203 to 0x118000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000a3905e9c to 0x11c000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (0 B) 0x00000000f0c022b6 to 0x120000 Dec 11 20:18:13 hikey kernel: wlcore: chunk 12 addr 0x20400000 len 52600 Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 52600 chunk_size 16384 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x000000004f52801e to 0x20400000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x0000000066503358 to 0x20404000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000433fff1b to 0x20408000 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (3448 B) 0x00000000a38c9bd9 to 0x2040c000 Dec 11 20:18:13 hikey kernel: wlcore: chunk 11 addr 0xb00000 len 536 Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 536 chunk_size 16384 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (536 B) 0x00000000ced82f93 to 0xb00000 Dec 11 20:18:13 hikey kernel: wlcore: chunk 10 addr 0xb0ae40 len 28120 Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 28120 chunk_size 16384 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x00000000d6832925 to 0xb0ae40 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (11736 B) 0x0000000037ae96d5 to 0xb0ee40 Dec 11 20:18:13 hikey kernel: wlcore: chunk 9 addr 0x80900000 len 61140 Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 61140 chunk_size 16384 Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk 0x0000000096b9ba67 to 0x80900000 -------> hangs See the missing 'mmc_host mmc2' messages, which probably indicates that mmc_host wasn't properly set after the down/up sequence, causing the hang when uploading the firmware. Thanks, -- Ricardo Salveti de Araujo
