All of lore.kernel.org
 help / color / mirror / Atom feed
* armmmci rmmod causes hung tasks
@ 2020-11-29 18:20 ` Martin DEVERA
  0 siblings, 0 replies; 8+ messages in thread
From: Martin DEVERA @ 2020-11-29 18:20 UTC (permalink / raw)
  To: linux-kernel, linux-arm-kernel, linux-mmc; +Cc: Ulf Hansson

Hello,

on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
modprobe armmmci ; rmmod armmmci

causes rmmod and kworker to hang. I should note that no MMC is detected
on the board (SDIO device on MMC bus is not responding).
On another board (where SDIO is responding) rmmod works.

It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945

Thanks.

INFO: task kworker/0:1:12 blocked for more than 368 seconds.
       Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:1     D    0    12      2 0x00000000
Workqueue: events_freezable mmc_rescan
(__schedule) from (schedule+0x5b/0x90)
(schedule) from (schedule_timeout+0x1b/0xa0)
(schedule_timeout) from (__wait_for_common+0x7d/0xdc)
(__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
(mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
(mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
(mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
(sdio_reset) from (mmc_rescan+0x15d/0x1d4)
(mmc_rescan) from (process_one_work+0xdd/0x168)
(process_one_work) from (worker_thread+0x17d/0x1ec)
(worker_thread) from (kthread+0x9b/0xa4)
(kthread) from (ret_from_fork+0x11/0x28)

INFO: task rmmod:308 blocked for more than 368 seconds.
       Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
rmmod           D    0   308    222 0x00000000
(__schedule) from (schedule+0x5b/0x90)
(schedule) from (schedule_timeout+0x1b/0xa0)
(schedule_timeout) from (__wait_for_common+0x7d/0xdc)
(__wait_for_common) from (__flush_work+0xb3/0x110)
(__flush_work) from (__cancel_work_timer+0x97/0xf0)
(__cancel_work_timer) from (mmc_stop_host+0x29/0x88)
(mmc_stop_host) from (mmc_remove_host+0x9/0x22)
(mmc_remove_host) from (mmci_remove+0x19/0x92 [armmmci])
(mmci_remove [armmmci]) from (amba_remove+0x13/0x42)
(amba_remove) from (device_release_driver_internal+0x89/0xe4)
(device_release_driver_internal) from (driver_detach+0x57/0x60)
(driver_detach) from (bus_remove_driver+0x53/0x84)
(bus_remove_driver) from (mmci_driver_exit+0x9/0x11dc [armmmci])
(mmci_driver_exit [armmmci]) from (sys_delete_module+0x115/0x154)
(sys_delete_module) from (ret_fast_syscall+0x1/0x5a)


^ permalink raw reply	[flat|nested] 8+ messages in thread

* armmmci rmmod causes hung tasks
@ 2020-11-29 18:20 ` Martin DEVERA
  0 siblings, 0 replies; 8+ messages in thread
From: Martin DEVERA @ 2020-11-29 18:20 UTC (permalink / raw)
  To: linux-kernel, linux-arm-kernel, linux-mmc; +Cc: Ulf Hansson

Hello,

on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
modprobe armmmci ; rmmod armmmci

causes rmmod and kworker to hang. I should note that no MMC is detected
on the board (SDIO device on MMC bus is not responding).
On another board (where SDIO is responding) rmmod works.

It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945

Thanks.

INFO: task kworker/0:1:12 blocked for more than 368 seconds.
       Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:1     D    0    12      2 0x00000000
Workqueue: events_freezable mmc_rescan
(__schedule) from (schedule+0x5b/0x90)
(schedule) from (schedule_timeout+0x1b/0xa0)
(schedule_timeout) from (__wait_for_common+0x7d/0xdc)
(__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
(mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
(mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
(mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
(sdio_reset) from (mmc_rescan+0x15d/0x1d4)
(mmc_rescan) from (process_one_work+0xdd/0x168)
(process_one_work) from (worker_thread+0x17d/0x1ec)
(worker_thread) from (kthread+0x9b/0xa4)
(kthread) from (ret_from_fork+0x11/0x28)

INFO: task rmmod:308 blocked for more than 368 seconds.
       Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
rmmod           D    0   308    222 0x00000000
(__schedule) from (schedule+0x5b/0x90)
(schedule) from (schedule_timeout+0x1b/0xa0)
(schedule_timeout) from (__wait_for_common+0x7d/0xdc)
(__wait_for_common) from (__flush_work+0xb3/0x110)
(__flush_work) from (__cancel_work_timer+0x97/0xf0)
(__cancel_work_timer) from (mmc_stop_host+0x29/0x88)
(mmc_stop_host) from (mmc_remove_host+0x9/0x22)
(mmc_remove_host) from (mmci_remove+0x19/0x92 [armmmci])
(mmci_remove [armmmci]) from (amba_remove+0x13/0x42)
(amba_remove) from (device_release_driver_internal+0x89/0xe4)
(device_release_driver_internal) from (driver_detach+0x57/0x60)
(driver_detach) from (bus_remove_driver+0x53/0x84)
(bus_remove_driver) from (mmci_driver_exit+0x9/0x11dc [armmmci])
(mmci_driver_exit [armmmci]) from (sys_delete_module+0x115/0x154)
(sys_delete_module) from (ret_fast_syscall+0x1/0x5a)


_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: armmmci rmmod causes hung tasks
  2020-11-29 18:20 ` Martin DEVERA
@ 2020-11-30 15:08   ` Ulf Hansson
  -1 siblings, 0 replies; 8+ messages in thread
From: Ulf Hansson @ 2020-11-30 15:08 UTC (permalink / raw)
  To: Martin DEVERA; +Cc: Linux Kernel Mailing List, Linux ARM, linux-mmc

On Sun, 29 Nov 2020 at 19:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
>
> Hello,
>
> on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
> modprobe armmmci ; rmmod armmmci
>
> causes rmmod and kworker to hang. I should note that no MMC is detected
> on the board (SDIO device on MMC bus is not responding).
> On another board (where SDIO is responding) rmmod works.
>
> It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945
>
> Thanks.
>
> INFO: task kworker/0:1:12 blocked for more than 368 seconds.
>        Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> kworker/0:1     D    0    12      2 0x00000000
> Workqueue: events_freezable mmc_rescan
> (__schedule) from (schedule+0x5b/0x90)
> (schedule) from (schedule_timeout+0x1b/0xa0)
> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
> (__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
> (mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
> (mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
> (mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
> (sdio_reset) from (mmc_rescan+0x15d/0x1d4)
> (mmc_rescan) from (process_one_work+0xdd/0x168)
> (process_one_work) from (worker_thread+0x17d/0x1ec)
> (worker_thread) from (kthread+0x9b/0xa4)
> (kthread) from (ret_from_fork+0x11/0x28)

It looks like the worker thread, which runs mmc_rescan() to try to
detect the SDIO card is hanging. Exactly why, I don't know.

Could be a misconfigured clock, pinctrl or a power domain being
suddenly gated...

>
> INFO: task rmmod:308 blocked for more than 368 seconds.
>        Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> rmmod           D    0   308    222 0x00000000
> (__schedule) from (schedule+0x5b/0x90)
> (schedule) from (schedule_timeout+0x1b/0xa0)
> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
> (__wait_for_common) from (__flush_work+0xb3/0x110)
> (__flush_work) from (__cancel_work_timer+0x97/0xf0)
> (__cancel_work_timer) from (mmc_stop_host+0x29/0x88)
> (mmc_stop_host) from (mmc_remove_host+0x9/0x22)
> (mmc_remove_host) from (mmci_remove+0x19/0x92 [armmmci])
> (mmci_remove [armmmci]) from (amba_remove+0x13/0x42)
> (amba_remove) from (device_release_driver_internal+0x89/0xe4)
> (device_release_driver_internal) from (driver_detach+0x57/0x60)
> (driver_detach) from (bus_remove_driver+0x53/0x84)
> (bus_remove_driver) from (mmci_driver_exit+0x9/0x11dc [armmmci])
> (mmci_driver_exit [armmmci]) from (sys_delete_module+0x115/0x154)
> (sys_delete_module) from (ret_fast_syscall+0x1/0x5a)
>

When unbinding the mmc host, mmc_stop_host() needs to make sure that
mmc_rescan() becomes disabled. This is to prevent a card from being
detected/removed at same time as when the host is being removed.

In any case, when we call...

cancel_delayed_work_sync(&host->detect);

...it seems like we end up waiting for the currently running
mmc_rescan() work to be completed.

Kind regards
Uffe

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: armmmci rmmod causes hung tasks
@ 2020-11-30 15:08   ` Ulf Hansson
  0 siblings, 0 replies; 8+ messages in thread
From: Ulf Hansson @ 2020-11-30 15:08 UTC (permalink / raw)
  To: Martin DEVERA; +Cc: linux-mmc, Linux Kernel Mailing List, Linux ARM

On Sun, 29 Nov 2020 at 19:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
>
> Hello,
>
> on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
> modprobe armmmci ; rmmod armmmci
>
> causes rmmod and kworker to hang. I should note that no MMC is detected
> on the board (SDIO device on MMC bus is not responding).
> On another board (where SDIO is responding) rmmod works.
>
> It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945
>
> Thanks.
>
> INFO: task kworker/0:1:12 blocked for more than 368 seconds.
>        Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> kworker/0:1     D    0    12      2 0x00000000
> Workqueue: events_freezable mmc_rescan
> (__schedule) from (schedule+0x5b/0x90)
> (schedule) from (schedule_timeout+0x1b/0xa0)
> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
> (__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
> (mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
> (mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
> (mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
> (sdio_reset) from (mmc_rescan+0x15d/0x1d4)
> (mmc_rescan) from (process_one_work+0xdd/0x168)
> (process_one_work) from (worker_thread+0x17d/0x1ec)
> (worker_thread) from (kthread+0x9b/0xa4)
> (kthread) from (ret_from_fork+0x11/0x28)

It looks like the worker thread, which runs mmc_rescan() to try to
detect the SDIO card is hanging. Exactly why, I don't know.

Could be a misconfigured clock, pinctrl or a power domain being
suddenly gated...

>
> INFO: task rmmod:308 blocked for more than 368 seconds.
>        Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> rmmod           D    0   308    222 0x00000000
> (__schedule) from (schedule+0x5b/0x90)
> (schedule) from (schedule_timeout+0x1b/0xa0)
> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
> (__wait_for_common) from (__flush_work+0xb3/0x110)
> (__flush_work) from (__cancel_work_timer+0x97/0xf0)
> (__cancel_work_timer) from (mmc_stop_host+0x29/0x88)
> (mmc_stop_host) from (mmc_remove_host+0x9/0x22)
> (mmc_remove_host) from (mmci_remove+0x19/0x92 [armmmci])
> (mmci_remove [armmmci]) from (amba_remove+0x13/0x42)
> (amba_remove) from (device_release_driver_internal+0x89/0xe4)
> (device_release_driver_internal) from (driver_detach+0x57/0x60)
> (driver_detach) from (bus_remove_driver+0x53/0x84)
> (bus_remove_driver) from (mmci_driver_exit+0x9/0x11dc [armmmci])
> (mmci_driver_exit [armmmci]) from (sys_delete_module+0x115/0x154)
> (sys_delete_module) from (ret_fast_syscall+0x1/0x5a)
>

When unbinding the mmc host, mmc_stop_host() needs to make sure that
mmc_rescan() becomes disabled. This is to prevent a card from being
detected/removed at same time as when the host is being removed.

In any case, when we call...

cancel_delayed_work_sync(&host->detect);

...it seems like we end up waiting for the currently running
mmc_rescan() work to be completed.

Kind regards
Uffe

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: armmmci rmmod causes hung tasks
  2020-11-30 15:08   ` Ulf Hansson
@ 2020-11-30 17:20     ` Martin DEVERA
  -1 siblings, 0 replies; 8+ messages in thread
From: Martin DEVERA @ 2020-11-30 17:20 UTC (permalink / raw)
  To: Ulf Hansson; +Cc: Linux Kernel Mailing List, Linux ARM, linux-mmc

On 11/30/20 4:08 PM, Ulf Hansson wrote:
> On Sun, 29 Nov 2020 at 19:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
>> Hello,
>>
>> on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
>> modprobe armmmci ; rmmod armmmci
>>
>> causes rmmod and kworker to hang. I should note that no MMC is detected
>> on the board (SDIO device on MMC bus is not responding).
>> On another board (where SDIO is responding) rmmod works.
>>
>> It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945
>>
>> Thanks.
>>
>> INFO: task kworker/0:1:12 blocked for more than 368 seconds.
>>         Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
>> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>> kworker/0:1     D    0    12      2 0x00000000
>> Workqueue: events_freezable mmc_rescan
>> (__schedule) from (schedule+0x5b/0x90)
>> (schedule) from (schedule_timeout+0x1b/0xa0)
>> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
>> (__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
>> (mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
>> (mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
>> (mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
>> (sdio_reset) from (mmc_rescan+0x15d/0x1d4)
>> (mmc_rescan) from (process_one_work+0xdd/0x168)
>> (process_one_work) from (worker_thread+0x17d/0x1ec)
>> (worker_thread) from (kthread+0x9b/0xa4)
>> (kthread) from (ret_from_fork+0x11/0x28)
> It looks like the worker thread, which runs mmc_rescan() to try to
> detect the SDIO card is hanging. Exactly why, I don't know.
>
> Could be a misconfigured clock, pinctrl or a power domain being
> suddenly gated...

I turned some logging on (see below), IIUC pl18x is starting CMD52 with arg
SDIO_CCCR_ABORT read and it got IRQ later along with response. Then sending
again SDIO_CCCR_ABORT write but no IRQ comes back.

[  135.810802] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
[  135.810832] mmc0: starting CMD52 arg 00000c00 flags 00000195
[  135.810862] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
[  135.811155] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000040
[  135.811178] mmc0: req done (CMD52): 0: 00000000 00000000 00000000 
00000000
[  135.811202] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
[  135.816487] mmc0: starting CMD52 arg 80000c08 flags 00000195
[  135.816506] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
[  172.150614] random: crng init done
[  172.150642] random: 6 urandom warning(s) missed due to ratelimiting
[  173.290565] INFO: task kworker/0:0:5 blocked for more than 20 seconds.

Here is the same system, only with different (working) SDIO device on 
the same bus:

[  495.654596] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
[  495.654628] mmc0: starting CMD52 arg 00000c00 flags 00000195
[  495.654658] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
[  495.654996] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
[  495.655017] mmc0: req done (CMD52): -110: 00000000 00000000 00000000 
00000000
[  495.655042] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
[  495.660201] mmc0: starting CMD52 arg 80000c08 flags 00000195
[  495.660222] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
[  495.660549] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
[  495.660567] mmc0: req done (CMD52): -110: 00000000 00000000 00000000 
00000000
[  495.660591] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000

Should it be expected, that invalid (probably non-responding) device on 
the SDIO bus
causes it to be locked up forever ?
Or is it bug in pl18x driver not handling the error correctly ?

best regards,
Martin


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: armmmci rmmod causes hung tasks
@ 2020-11-30 17:20     ` Martin DEVERA
  0 siblings, 0 replies; 8+ messages in thread
From: Martin DEVERA @ 2020-11-30 17:20 UTC (permalink / raw)
  To: Ulf Hansson; +Cc: linux-mmc, Linux Kernel Mailing List, Linux ARM

On 11/30/20 4:08 PM, Ulf Hansson wrote:
> On Sun, 29 Nov 2020 at 19:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
>> Hello,
>>
>> on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
>> modprobe armmmci ; rmmod armmmci
>>
>> causes rmmod and kworker to hang. I should note that no MMC is detected
>> on the board (SDIO device on MMC bus is not responding).
>> On another board (where SDIO is responding) rmmod works.
>>
>> It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945
>>
>> Thanks.
>>
>> INFO: task kworker/0:1:12 blocked for more than 368 seconds.
>>         Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
>> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>> kworker/0:1     D    0    12      2 0x00000000
>> Workqueue: events_freezable mmc_rescan
>> (__schedule) from (schedule+0x5b/0x90)
>> (schedule) from (schedule_timeout+0x1b/0xa0)
>> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
>> (__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
>> (mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
>> (mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
>> (mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
>> (sdio_reset) from (mmc_rescan+0x15d/0x1d4)
>> (mmc_rescan) from (process_one_work+0xdd/0x168)
>> (process_one_work) from (worker_thread+0x17d/0x1ec)
>> (worker_thread) from (kthread+0x9b/0xa4)
>> (kthread) from (ret_from_fork+0x11/0x28)
> It looks like the worker thread, which runs mmc_rescan() to try to
> detect the SDIO card is hanging. Exactly why, I don't know.
>
> Could be a misconfigured clock, pinctrl or a power domain being
> suddenly gated...

I turned some logging on (see below), IIUC pl18x is starting CMD52 with arg
SDIO_CCCR_ABORT read and it got IRQ later along with response. Then sending
again SDIO_CCCR_ABORT write but no IRQ comes back.

[  135.810802] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
[  135.810832] mmc0: starting CMD52 arg 00000c00 flags 00000195
[  135.810862] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
[  135.811155] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000040
[  135.811178] mmc0: req done (CMD52): 0: 00000000 00000000 00000000 
00000000
[  135.811202] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
[  135.816487] mmc0: starting CMD52 arg 80000c08 flags 00000195
[  135.816506] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
[  172.150614] random: crng init done
[  172.150642] random: 6 urandom warning(s) missed due to ratelimiting
[  173.290565] INFO: task kworker/0:0:5 blocked for more than 20 seconds.

Here is the same system, only with different (working) SDIO device on 
the same bus:

[  495.654596] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
[  495.654628] mmc0: starting CMD52 arg 00000c00 flags 00000195
[  495.654658] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
[  495.654996] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
[  495.655017] mmc0: req done (CMD52): -110: 00000000 00000000 00000000 
00000000
[  495.655042] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
[  495.660201] mmc0: starting CMD52 arg 80000c08 flags 00000195
[  495.660222] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
[  495.660549] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
[  495.660567] mmc0: req done (CMD52): -110: 00000000 00000000 00000000 
00000000
[  495.660591] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000

Should it be expected, that invalid (probably non-responding) device on 
the SDIO bus
causes it to be locked up forever ?
Or is it bug in pl18x driver not handling the error correctly ?

best regards,
Martin


_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: armmmci rmmod causes hung tasks
  2020-11-30 17:20     ` Martin DEVERA
@ 2020-12-01 11:51       ` Ulf Hansson
  -1 siblings, 0 replies; 8+ messages in thread
From: Ulf Hansson @ 2020-12-01 11:51 UTC (permalink / raw)
  To: Martin DEVERA; +Cc: Linux Kernel Mailing List, Linux ARM, linux-mmc

On Mon, 30 Nov 2020 at 18:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
>
> On 11/30/20 4:08 PM, Ulf Hansson wrote:
> > On Sun, 29 Nov 2020 at 19:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
> >> Hello,
> >>
> >> on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
> >> modprobe armmmci ; rmmod armmmci
> >>
> >> causes rmmod and kworker to hang. I should note that no MMC is detected
> >> on the board (SDIO device on MMC bus is not responding).
> >> On another board (where SDIO is responding) rmmod works.
> >>
> >> It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945
> >>
> >> Thanks.
> >>
> >> INFO: task kworker/0:1:12 blocked for more than 368 seconds.
> >>         Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
> >> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> >> kworker/0:1     D    0    12      2 0x00000000
> >> Workqueue: events_freezable mmc_rescan
> >> (__schedule) from (schedule+0x5b/0x90)
> >> (schedule) from (schedule_timeout+0x1b/0xa0)
> >> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
> >> (__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
> >> (mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
> >> (mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
> >> (mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
> >> (sdio_reset) from (mmc_rescan+0x15d/0x1d4)
> >> (mmc_rescan) from (process_one_work+0xdd/0x168)
> >> (process_one_work) from (worker_thread+0x17d/0x1ec)
> >> (worker_thread) from (kthread+0x9b/0xa4)
> >> (kthread) from (ret_from_fork+0x11/0x28)
> > It looks like the worker thread, which runs mmc_rescan() to try to
> > detect the SDIO card is hanging. Exactly why, I don't know.
> >
> > Could be a misconfigured clock, pinctrl or a power domain being
> > suddenly gated...
>
> I turned some logging on (see below), IIUC pl18x is starting CMD52 with arg
> SDIO_CCCR_ABORT read and it got IRQ later along with response. Then sending
> again SDIO_CCCR_ABORT write but no IRQ comes back.
>
> [  135.810802] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
> [  135.810832] mmc0: starting CMD52 arg 00000c00 flags 00000195
> [  135.810862] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
> [  135.811155] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000040
> [  135.811178] mmc0: req done (CMD52): 0: 00000000 00000000 00000000
> 00000000
> [  135.811202] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
> [  135.816487] mmc0: starting CMD52 arg 80000c08 flags 00000195
> [  135.816506] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
> [  172.150614] random: crng init done
> [  172.150642] random: 6 urandom warning(s) missed due to ratelimiting
> [  173.290565] INFO: task kworker/0:0:5 blocked for more than 20 seconds.
>
> Here is the same system, only with different (working) SDIO device on
> the same bus:
>
> [  495.654596] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
> [  495.654628] mmc0: starting CMD52 arg 00000c00 flags 00000195
> [  495.654658] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
> [  495.654996] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
> [  495.655017] mmc0: req done (CMD52): -110: 00000000 00000000 00000000
> 00000000
> [  495.655042] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
> [  495.660201] mmc0: starting CMD52 arg 80000c08 flags 00000195
> [  495.660222] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
> [  495.660549] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
> [  495.660567] mmc0: req done (CMD52): -110: 00000000 00000000 00000000
> 00000000
> [  495.660591] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
>
> Should it be expected, that invalid (probably non-responding) device on
> the SDIO bus
> causes it to be locked up forever ?
> Or is it bug in pl18x driver not handling the error correctly ?

Honestly, it's hard to tell without further debugging. It looks like a
bug in pl18x driver, but perhaps also on the SDIO device side.

Kind regards
Uffe

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: armmmci rmmod causes hung tasks
@ 2020-12-01 11:51       ` Ulf Hansson
  0 siblings, 0 replies; 8+ messages in thread
From: Ulf Hansson @ 2020-12-01 11:51 UTC (permalink / raw)
  To: Martin DEVERA; +Cc: linux-mmc, Linux Kernel Mailing List, Linux ARM

On Mon, 30 Nov 2020 at 18:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
>
> On 11/30/20 4:08 PM, Ulf Hansson wrote:
> > On Sun, 29 Nov 2020 at 19:20, Martin DEVERA <devik@eaxlabs.cz> wrote:
> >> Hello,
> >>
> >> on STM32MP1 with almost vanilla 5.7.7 in single CPU mode. Pair of
> >> modprobe armmmci ; rmmod armmmci
> >>
> >> causes rmmod and kworker to hang. I should note that no MMC is detected
> >> on the board (SDIO device on MMC bus is not responding).
> >> On another board (where SDIO is responding) rmmod works.
> >>
> >> It seems as another manifestation of https://lkml.org/lkml/2019/8/27/945
> >>
> >> Thanks.
> >>
> >> INFO: task kworker/0:1:12 blocked for more than 368 seconds.
> >>         Not tainted 5.7.7kdb-00003-g10397828596c-dirty #224
> >> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> >> kworker/0:1     D    0    12      2 0x00000000
> >> Workqueue: events_freezable mmc_rescan
> >> (__schedule) from (schedule+0x5b/0x90)
> >> (schedule) from (schedule_timeout+0x1b/0xa0)
> >> (schedule_timeout) from (__wait_for_common+0x7d/0xdc)
> >> (__wait_for_common) from (mmc_wait_for_req_done+0x1b/0x8c)
> >> (mmc_wait_for_req_done) from (mmc_wait_for_cmd+0x4d/0x68)
> >> (mmc_wait_for_cmd) from (mmc_io_rw_direct_host+0x87/0xc8)
> >> (mmc_io_rw_direct_host) from (sdio_reset+0x3b/0x58)
> >> (sdio_reset) from (mmc_rescan+0x15d/0x1d4)
> >> (mmc_rescan) from (process_one_work+0xdd/0x168)
> >> (process_one_work) from (worker_thread+0x17d/0x1ec)
> >> (worker_thread) from (kthread+0x9b/0xa4)
> >> (kthread) from (ret_from_fork+0x11/0x28)
> > It looks like the worker thread, which runs mmc_rescan() to try to
> > detect the SDIO card is hanging. Exactly why, I don't know.
> >
> > Could be a misconfigured clock, pinctrl or a power domain being
> > suddenly gated...
>
> I turned some logging on (see below), IIUC pl18x is starting CMD52 with arg
> SDIO_CCCR_ABORT read and it got IRQ later along with response. Then sending
> again SDIO_CCCR_ABORT write but no IRQ comes back.
>
> [  135.810802] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
> [  135.810832] mmc0: starting CMD52 arg 00000c00 flags 00000195
> [  135.810862] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
> [  135.811155] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000040
> [  135.811178] mmc0: req done (CMD52): 0: 00000000 00000000 00000000
> 00000000
> [  135.811202] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
> [  135.816487] mmc0: starting CMD52 arg 80000c08 flags 00000195
> [  135.816506] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
> [  172.150614] random: crng init done
> [  172.150642] random: 6 urandom warning(s) missed due to ratelimiting
> [  173.290565] INFO: task kworker/0:0:5 blocked for more than 20 seconds.
>
> Here is the same system, only with different (working) SDIO device on
> the same bus:
>
> [  495.654596] mmc0: mmc_rescan_try_freq: trying to init card at 400000 Hz
> [  495.654628] mmc0: starting CMD52 arg 00000c00 flags 00000195
> [  495.654658] mmci-pl18x 48004000.sdmmc: op 34 arg 00000c00 flags 00000195
> [  495.654996] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
> [  495.655017] mmc0: req done (CMD52): -110: 00000000 00000000 00000000
> 00000000
> [  495.655042] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
> [  495.660201] mmc0: starting CMD52 arg 80000c08 flags 00000195
> [  495.660222] mmci-pl18x 48004000.sdmmc: op 34 arg 80000c08 flags 00000195
> [  495.660549] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000004
> [  495.660567] mmc0: req done (CMD52): -110: 00000000 00000000 00000000
> 00000000
> [  495.660591] mmci-pl18x 48004000.sdmmc: irq0 (data+cmd) 00000000
>
> Should it be expected, that invalid (probably non-responding) device on
> the SDIO bus
> causes it to be locked up forever ?
> Or is it bug in pl18x driver not handling the error correctly ?

Honestly, it's hard to tell without further debugging. It looks like a
bug in pl18x driver, but perhaps also on the SDIO device side.

Kind regards
Uffe

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, other threads:[~2020-12-01 11:54 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-11-29 18:20 armmmci rmmod causes hung tasks Martin DEVERA
2020-11-29 18:20 ` Martin DEVERA
2020-11-30 15:08 ` Ulf Hansson
2020-11-30 15:08   ` Ulf Hansson
2020-11-30 17:20   ` Martin DEVERA
2020-11-30 17:20     ` Martin DEVERA
2020-12-01 11:51     ` Ulf Hansson
2020-12-01 11:51       ` Ulf Hansson

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.