search

dmhacker / arch-linux-surface

Arch Linux kernel patcher for Surface devices
MIT License
334 stars 22 forks source link

[SB2] mwifiex_pcie intermittently timeout and hang on when `modprobe -r` or rebooting system #96

Open magodo opened 4 years ago

magodo commented 4 years ago

Issue

mwifiex_pcie intermittently timeout and hang on when modprobe -r or rebooting system. When issue happens, I have no way to recover but a hard reboot.

The dmesg log when issue happens is as below:

[27248.113793] mwifiex_pcie 0000:01:00.0: mwifiex_cmd_timeout_func: Timeout cmd id = 0xa4, act = 0x0
[27248.113799] mwifiex_pcie 0000:01:00.0: num_data_h2c_failure = 0
[27248.113803] mwifiex_pcie 0000:01:00.0: num_cmd_h2c_failure = 0
[27248.113806] mwifiex_pcie 0000:01:00.0: is_cmd_timedout = 1
[27248.113808] mwifiex_pcie 0000:01:00.0: num_tx_timeout = 0
[27248.113811] mwifiex_pcie 0000:01:00.0: last_cmd_index = 0
[27248.113814] mwifiex_pcie 0000:01:00.0: last_cmd_id: a4 00 16 00 a4 00 7f 00 16 00
[27248.113818] mwifiex_pcie 0000:01:00.0: last_cmd_act: 00 00 00 00 00 00 00 00 00 00
[27248.113820] mwifiex_pcie 0000:01:00.0: last_cmd_resp_index = 4
[27248.113823] mwifiex_pcie 0000:01:00.0: last_cmd_resp_id: 7f 80 16 80 a4 80 7f 80 16 80
[27248.113826] mwifiex_pcie 0000:01:00.0: last_event_index = 1
[27248.113829] mwifiex_pcie 0000:01:00.0: last_event: 58 00 74 00 58 00 58 00 58 00
[27248.113832] mwifiex_pcie 0000:01:00.0: data_sent=1 cmd_sent=1
[27248.113834] mwifiex_pcie 0000:01:00.0: ps_mode=0 ps_state=0
[27248.113927] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27248.114725] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27248.114732] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27248.114768] mwifiex_pcie 0000:01:00.0: ===mwifiex driverinfo dump start===
[27248.114775] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (15.68.19.p21) 
[27248.114788] mwifiex_pcie 0000:01:00.0: PCIE register dump start
[27248.114876] mwifiex_pcie 0000:01:00.0: pcie scratch register:
[27248.114888] mwifiex_pcie 0000:01:00.0: reg:0xcf0, value=0xfedcba00
               reg:0xcf8, value=0x94178
               reg:0xcfc, value=0x2aeae00

[27248.114891] mwifiex_pcie 0000:01:00.0: PCIE register dump end
[27248.114973] mwifiex_pcie 0000:01:00.0: ===mwifiex driverinfo dump end===
[27248.114976] mwifiex_pcie 0000:01:00.0: == mwifiex firmware dump start ==
[27248.115313] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27248.115319] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27248.115419] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27248.115424] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27254.003779] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27254.003781] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27254.003798] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27254.003799] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27260.003838] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27260.003841] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27260.003879] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27260.003880] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27266.000505] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27266.000508] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27266.000561] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27266.000563] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27272.003880] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27272.003886] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27272.003948] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27272.003951] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27278.003867] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27278.003871] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27278.003915] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27278.003917] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27284.004342] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27284.004346] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27284.004383] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27284.004385] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27290.003876] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27290.003880] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27290.003919] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27290.003921] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27296.003975] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27296.003978] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27296.004006] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27296.004008] mwifiex_pcie 0000:01:00.0: failed to get signal information
[27299.075835] mwifiex_pcie 0000:01:00.0: Firmware dump Finished!
[27299.075839] mwifiex_pcie 0000:01:00.0: == mwifiex firmware dump end ==
[27299.076171] mwifiex_pcie 0000:01:00.0: == mwifiex dump information to /sys/class/devcoredump start
[27299.076250] mwifiex_pcie 0000:01:00.0: == mwifiex dump information to /sys/class/devcoredump end
[27299.076256] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[27299.076329] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.076333] mwifiex_pcie 0000:01:00.0: deleting the crypto keys
[27299.076336] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.076339] mwifiex_pcie 0000:01:00.0: deleting the crypto keys
[27299.076342] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.076345] mwifiex_pcie 0000:01:00.0: deleting the crypto keys
[27299.076354] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.076357] mwifiex_pcie 0000:01:00.0: deleting the crypto keys
[27299.076361] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.076364] mwifiex_pcie 0000:01:00.0: deleting the crypto keys
[27299.076368] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.076371] mwifiex_pcie 0000:01:00.0: deleting the crypto keys
[27299.077042] mwifiex_pcie 0000:01:00.0: info: shutdown mwifiex...
[27299.077278] mwifiex_pcie 0000:01:00.0: rx_pending=0, tx_pending=1,   cmd_pending=0
[27299.085908] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.085915] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.085921] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[27299.156638] audit: type=1130 audit(1581064802.477:233): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[27299.184720] audit: type=1130 audit(1581064802.507:234): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[27300.200133] mwifiex_pcie 0000:01:00.0: WLAN FW already running! Skip FW dnld
[27300.200141] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[27304.156862] audit: type=1131 audit(1581064807.477:235): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[27309.014509] audit: type=1131 audit(1581064812.337:236): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[27310.407030] mwifiex_pcie 0000:01:00.0: mwifiex_cmd_timeout_func: Timeout cmd id = 0xfa, act = 0x1000
[27310.407036] mwifiex_pcie 0000:01:00.0: num_data_h2c_failure = 0
[27310.407039] mwifiex_pcie 0000:01:00.0: num_cmd_h2c_failure = 0
[27310.407042] mwifiex_pcie 0000:01:00.0: is_cmd_timedout = 1
[27310.407044] mwifiex_pcie 0000:01:00.0: num_tx_timeout = 0
[27310.407047] mwifiex_pcie 0000:01:00.0: last_cmd_index = 1
[27310.407050] mwifiex_pcie 0000:01:00.0: last_cmd_id: a4 00 fa 00 a4 00 7f 00 16 00
[27310.407054] mwifiex_pcie 0000:01:00.0: last_cmd_act: 00 00 00 10 00 00 00 00 00 00
[27310.407057] mwifiex_pcie 0000:01:00.0: last_cmd_resp_index = 4
[27310.407060] mwifiex_pcie 0000:01:00.0: last_cmd_resp_id: 7f 80 16 80 a4 80 7f 80 16 80
[27310.407063] mwifiex_pcie 0000:01:00.0: last_event_index = 1
[27310.407067] mwifiex_pcie 0000:01:00.0: last_event: 58 00 74 00 58 00 58 00 58 00
[27310.407070] mwifiex_pcie 0000:01:00.0: data_sent=0 cmd_sent=1
[27310.407073] mwifiex_pcie 0000:01:00.0: ps_mode=0 ps_state=0
[27310.407117] mwifiex_pcie 0000:01:00.0: info: _mwifiex_fw_dpc: unregister device
[27525.020679] INFO: task kworker/1:2:463945 blocked for more than 122 seconds.
[27525.020690]       Tainted: G         C        5.3.18-1-surface #1
[27525.020694] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27525.020699] kworker/1:2     D    0 463945      2 0x80004080
[27525.020719] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[27525.020723] Call Trace:
[27525.020740]  ? __schedule+0x27f/0x6d0
[27525.020746]  schedule+0x43/0xd0
[27525.020753]  schedule_timeout+0x299/0x3d0
[27525.020767]  ? __switch_to_asm+0x40/0x70
[27525.020781]  wait_for_common+0xeb/0x190
[27525.020789]  ? wake_up_q+0x60/0x60
[27525.020798]  __flush_work+0x130/0x1e0
[27525.020806]  ? flush_workqueue_prep_pwqs+0x130/0x130
[27525.020817]  __cancel_work_timer+0x123/0x1b0
[27525.020829]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[27525.020853]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[27525.020871]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[27525.020894]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[27525.020905]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[27525.020918]  pci_try_reset_function+0x38/0x70
[27525.020927]  process_one_work+0x1d1/0x3a0
[27525.020935]  worker_thread+0x4a/0x3d0
[27525.020942]  kthread+0xfb/0x130
[27525.020948]  ? process_one_work+0x3a0/0x3a0
[27525.020952]  ? kthread_park+0x80/0x80
[27525.020960]  ret_from_fork+0x35/0x40
[27647.900647] INFO: task kworker/1:2:463945 blocked for more than 245 seconds.
[27647.900657]       Tainted: G         C        5.3.18-1-surface #1
[27647.900660] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27647.900664] kworker/1:2     D    0 463945      2 0x80004080
[27647.900684] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[27647.900687] Call Trace:
[27647.900703]  ? __schedule+0x27f/0x6d0
[27647.900709]  schedule+0x43/0xd0
[27647.900715]  schedule_timeout+0x299/0x3d0
[27647.900722]  ? __switch_to_asm+0x40/0x70
[27647.900729]  wait_for_common+0xeb/0x190
[27647.900735]  ? wake_up_q+0x60/0x60
[27647.900743]  __flush_work+0x130/0x1e0
[27647.900749]  ? flush_workqueue_prep_pwqs+0x130/0x130
[27647.900755]  __cancel_work_timer+0x123/0x1b0
[27647.900764]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[27647.900781]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[27647.900793]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[27647.900808]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[27647.900814]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[27647.900824]  pci_try_reset_function+0x38/0x70
[27647.900829]  process_one_work+0x1d1/0x3a0
[27647.900835]  worker_thread+0x4a/0x3d0
[27647.900841]  kthread+0xfb/0x130
[27647.900846]  ? process_one_work+0x3a0/0x3a0
[27647.900849]  ? kthread_park+0x80/0x80
[27647.900856]  ret_from_fork+0x35/0x40
[27770.780462] INFO: task kworker/1:2:463945 blocked for more than 368 seconds.
[27770.780465]       Tainted: G         C        5.3.18-1-surface #1
[27770.780465] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27770.780467] kworker/1:2     D    0 463945      2 0x80004080
[27770.780473] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[27770.780474] Call Trace:
[27770.780478]  ? __schedule+0x27f/0x6d0
[27770.780479]  schedule+0x43/0xd0
[27770.780481]  schedule_timeout+0x299/0x3d0
[27770.780482]  ? __switch_to_asm+0x40/0x70
[27770.780484]  wait_for_common+0xeb/0x190
[27770.780486]  ? wake_up_q+0x60/0x60
[27770.780487]  __flush_work+0x130/0x1e0
[27770.780489]  ? flush_workqueue_prep_pwqs+0x130/0x130
[27770.780490]  __cancel_work_timer+0x123/0x1b0
[27770.780492]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[27770.780496]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[27770.780499]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[27770.780502]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[27770.780503]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[27770.780506]  pci_try_reset_function+0x38/0x70
[27770.780507]  process_one_work+0x1d1/0x3a0
[27770.780508]  worker_thread+0x4a/0x3d0
[27770.780509]  kthread+0xfb/0x130
[27770.780510]  ? process_one_work+0x3a0/0x3a0
[27770.780511]  ? kthread_park+0x80/0x80
[27770.780512]  ret_from_fork+0x35/0x40
[27893.660749] INFO: task kworker/1:2:463945 blocked for more than 491 seconds.
[27893.660759]       Tainted: G         C        5.3.18-1-surface #1
[27893.660762] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[27893.660766] kworker/1:2     D    0 463945      2 0x80004080
[27893.660785] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[27893.660789] Call Trace:
[27893.660805]  ? __schedule+0x27f/0x6d0
[27893.660811]  schedule+0x43/0xd0
[27893.660817]  schedule_timeout+0x299/0x3d0
[27893.660823]  ? __switch_to_asm+0x40/0x70
[27893.660830]  wait_for_common+0xeb/0x190
[27893.660837]  ? wake_up_q+0x60/0x60
[27893.660844]  __flush_work+0x130/0x1e0
[27893.660850]  ? flush_workqueue_prep_pwqs+0x130/0x130
[27893.660856]  __cancel_work_timer+0x123/0x1b0
[27893.660866]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[27893.660881]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[27893.660893]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[27893.660907]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[27893.660914]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[27893.660923]  pci_try_reset_function+0x38/0x70
[27893.660929]  process_one_work+0x1d1/0x3a0
[27893.660935]  worker_thread+0x4a/0x3d0
[27893.660940]  kthread+0xfb/0x130
[27893.660945]  ? process_one_work+0x3a0/0x3a0
[27893.660948]  ? kthread_park+0x80/0x80
[27893.660955]  ret_from_fork+0x35/0x40
[28016.540695] INFO: task kworker/1:2:463945 blocked for more than 614 seconds.
[28016.540704]       Tainted: G         C        5.3.18-1-surface #1
[28016.540708] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[28016.540712] kworker/1:2     D    0 463945      2 0x80004080
[28016.540731] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[28016.540735] Call Trace:
[28016.540750]  ? __schedule+0x27f/0x6d0
[28016.540757]  schedule+0x43/0xd0
[28016.540763]  schedule_timeout+0x299/0x3d0
[28016.540769]  ? __switch_to_asm+0x40/0x70
[28016.540775]  wait_for_common+0xeb/0x190
[28016.540781]  ? wake_up_q+0x60/0x60
[28016.540789]  __flush_work+0x130/0x1e0
[28016.540795]  ? flush_workqueue_prep_pwqs+0x130/0x130
[28016.540801]  __cancel_work_timer+0x123/0x1b0
[28016.540811]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[28016.540826]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[28016.540838]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[28016.540852]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[28016.540858]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[28016.540867]  pci_try_reset_function+0x38/0x70
[28016.540873]  process_one_work+0x1d1/0x3a0
[28016.540879]  worker_thread+0x4a/0x3d0
[28016.540884]  kthread+0xfb/0x130
[28016.540888]  ? process_one_work+0x3a0/0x3a0
[28016.540891]  ? kthread_park+0x80/0x80
[28016.540898]  ret_from_fork+0x35/0x40
[28139.420680] INFO: task kworker/1:2:463945 blocked for more than 737 seconds.
[28139.420690]       Tainted: G         C        5.3.18-1-surface #1
[28139.420693] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[28139.420697] kworker/1:2     D    0 463945      2 0x80004080
[28139.420717] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[28139.420721] Call Trace:
[28139.420737]  ? __schedule+0x27f/0x6d0
[28139.420743]  schedule+0x43/0xd0
[28139.420750]  schedule_timeout+0x299/0x3d0
[28139.420756]  ? __switch_to_asm+0x40/0x70
[28139.420763]  wait_for_common+0xeb/0x190
[28139.420769]  ? wake_up_q+0x60/0x60
[28139.420777]  __flush_work+0x130/0x1e0
[28139.420783]  ? flush_workqueue_prep_pwqs+0x130/0x130
[28139.420790]  __cancel_work_timer+0x123/0x1b0
[28139.420799]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[28139.420816]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[28139.420828]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[28139.420842]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[28139.420849]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[28139.420858]  pci_try_reset_function+0x38/0x70
[28139.420864]  process_one_work+0x1d1/0x3a0
[28139.420870]  worker_thread+0x4a/0x3d0
[28139.420876]  kthread+0xfb/0x130
[28139.420880]  ? process_one_work+0x3a0/0x3a0
[28139.420884]  ? kthread_park+0x80/0x80
[28139.420891]  ret_from_fork+0x35/0x40
[28262.300681] INFO: task kworker/1:2:463945 blocked for more than 860 seconds.
[28262.300690]       Tainted: G         C        5.3.18-1-surface #1
[28262.300693] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[28262.300698] kworker/1:2     D    0 463945      2 0x80004080
[28262.300717] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[28262.300720] Call Trace:
[28262.300736]  ? __schedule+0x27f/0x6d0
[28262.300743]  schedule+0x43/0xd0
[28262.300748]  schedule_timeout+0x299/0x3d0
[28262.300755]  ? __switch_to_asm+0x40/0x70
[28262.300761]  wait_for_common+0xeb/0x190
[28262.300768]  ? wake_up_q+0x60/0x60
[28262.300775]  __flush_work+0x130/0x1e0
[28262.300781]  ? flush_workqueue_prep_pwqs+0x130/0x130
[28262.300787]  __cancel_work_timer+0x123/0x1b0
[28262.300796]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[28262.300813]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[28262.300825]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[28262.300838]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[28262.300845]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[28262.300854]  pci_try_reset_function+0x38/0x70
[28262.300860]  process_one_work+0x1d1/0x3a0
[28262.300866]  worker_thread+0x4a/0x3d0
[28262.300871]  kthread+0xfb/0x130
[28262.300875]  ? process_one_work+0x3a0/0x3a0
[28262.300879]  ? kthread_park+0x80/0x80
[28262.300886]  ret_from_fork+0x35/0x40
[28385.183723] INFO: task kworker/1:2:463945 blocked for more than 983 seconds.
[28385.183730]       Tainted: G         C        5.3.18-1-surface #1
[28385.183732] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[28385.183734] kworker/1:2     D    0 463945      2 0x80004080
[28385.183745] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[28385.183747] Call Trace:
[28385.183756]  ? __schedule+0x27f/0x6d0
[28385.183760]  schedule+0x43/0xd0
[28385.183763]  schedule_timeout+0x299/0x3d0
[28385.183767]  ? __switch_to_asm+0x40/0x70
[28385.183771]  wait_for_common+0xeb/0x190
[28385.183774]  ? wake_up_q+0x60/0x60
[28385.183779]  __flush_work+0x130/0x1e0
[28385.183782]  ? flush_workqueue_prep_pwqs+0x130/0x130
[28385.183786]  __cancel_work_timer+0x123/0x1b0
[28385.183792]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[28385.183801]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[28385.183808]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[28385.183818]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[28385.183822]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[28385.183827]  pci_try_reset_function+0x38/0x70
[28385.183830]  process_one_work+0x1d1/0x3a0
[28385.183833]  worker_thread+0x4a/0x3d0
[28385.183837]  kthread+0xfb/0x130
[28385.183839]  ? process_one_work+0x3a0/0x3a0
[28385.183841]  ? kthread_park+0x80/0x80
[28385.183845]  ret_from_fork+0x35/0x40
[28508.060404] INFO: task kworker/1:2:463945 blocked for more than 1105 seconds.
[28508.060409]       Tainted: G         C        5.3.18-1-surface #1
[28508.060411] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[28508.060413] kworker/1:2     D    0 463945      2 0x80004080
[28508.060424] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[28508.060426] Call Trace:
[28508.060434]  ? __schedule+0x27f/0x6d0
[28508.060437]  schedule+0x43/0xd0
[28508.060440]  schedule_timeout+0x299/0x3d0
[28508.060444]  ? __switch_to_asm+0x40/0x70
[28508.060447]  wait_for_common+0xeb/0x190
[28508.060451]  ? wake_up_q+0x60/0x60
[28508.060455]  __flush_work+0x130/0x1e0
[28508.060458]  ? flush_workqueue_prep_pwqs+0x130/0x130
[28508.060461]  __cancel_work_timer+0x123/0x1b0
[28508.060466]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[28508.060474]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[28508.060480]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[28508.060487]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[28508.060491]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[28508.060496]  pci_try_reset_function+0x38/0x70
[28508.060499]  process_one_work+0x1d1/0x3a0
[28508.060502]  worker_thread+0x4a/0x3d0
[28508.060504]  kthread+0xfb/0x130
[28508.060507]  ? process_one_work+0x3a0/0x3a0
[28508.060508]  ? kthread_park+0x80/0x80
[28508.060512]  ret_from_fork+0x35/0x40
[28630.940385] INFO: task kworker/1:2:463945 blocked for more than 1228 seconds.
[28630.940389]       Tainted: G         C        5.3.18-1-surface #1
[28630.940390] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[28630.940391] kworker/1:2     D    0 463945      2 0x80004080
[28630.940400] Workqueue: events mwifiex_pcie_work [mwifiex_pcie]
[28630.940401] Call Trace:
[28630.940408]  ? __schedule+0x27f/0x6d0
[28630.940411]  schedule+0x43/0xd0
[28630.940413]  schedule_timeout+0x299/0x3d0
[28630.940415]  ? __switch_to_asm+0x40/0x70
[28630.940417]  wait_for_common+0xeb/0x190
[28630.940420]  ? wake_up_q+0x60/0x60
[28630.940422]  __flush_work+0x130/0x1e0
[28630.940424]  ? flush_workqueue_prep_pwqs+0x130/0x130
[28630.940426]  __cancel_work_timer+0x123/0x1b0
[28630.940429]  mwifiex_cleanup_pcie+0x28/0xd0 [mwifiex_pcie]
[28630.940436]  mwifiex_free_adapter+0x24/0xe0 [mwifiex]
[28630.940440]  _mwifiex_fw_dpc+0x28d/0x520 [mwifiex]
[28630.940445]  mwifiex_reinit_sw+0x15d/0x2c0 [mwifiex]
[28630.940447]  mwifiex_pcie_reset_done+0x50/0x80 [mwifiex_pcie]
[28630.940450]  pci_try_reset_function+0x38/0x70
[28630.940452]  process_one_work+0x1d1/0x3a0
[28630.940454]  worker_thread+0x4a/0x3d0
[28630.940456]  kthread+0xfb/0x130
[28630.940458]  ? process_one_work+0x3a0/0x3a0
[28630.940459]  ? kthread_park+0x80/0x80
[28630.940461]  ret_from_fork+0x35/0x40

System Info

                   -`                 
                  .o+`                 magodo@magodosurface
                 `ooo/                 OS: Arch Linux 
                `+oooo:                Kernel: x86_64 Linux 5.3.18-1-surface
               `+oooooo:               Uptime: 2m
               -+oooooo+:              Packages: 1134
             `/:-:++oooo+:             Shell: zsh 5.7.1
            `/++++/+++++++:            Resolution: 3000x2000
           `/++++++++++++++:           DE: GNOME 3.34.2
          `/+++ooooooooooooo/`         WM: Mutter
         ./ooosssso++osssssso+`        WM Theme: 
        .oossssso-````/ossssss+`       GTK Theme: X-Arc-White [GTK2/3]
       -osssssso.      :ssssssso.      Icon Theme: Adwaita
      :osssssss/        osssso+++.     Font: Cantarell 11
     /ossssssss/        +ssssooo/-     Disk: 79G / 465G (18%)
   `/ossssso+/:-        -:/+osssso+-   CPU: Intel Core i7-8650U @ 8x 4.2GHz [45.0°C]
  `+sso+:-`                 `.-/+oso:  GPU: Intel Corporation UHD Graphics 620 (rev 07)
Intel Corporation Sunrise Point-LP Integrated Sensor Hub (rev 21)
 `++:.                           `-/+/ RAM: 3467MiB / 15940MiB
 .`                                 `/
xorpix commented 4 years ago

I have the similar issue using Manjaro. When the pressure on wifi is high (torrents, for example), mwifiex_pcie crashes immediately and wifi stops working. Only reboot can make it work again. Also it might happen after waking up from lockscreen or randomly at all.

drkthomp commented 4 years ago

Same issue on manjaro. Happened for all versions of 5.3.18, but didn't happen on 5.4.6-1. I upgraded to 5.5.3-1 yesterday and have had mwifiex_pcie crash again (when torrenting). Does seem to only happen when pressure is "high" for me. On restart I usually have to do a hard reboot as just rebooting times out and then stops, though I haven't investigated why yet.

xorpix commented 4 years ago

Looks like 5.5.4 fixed this for me.