Hi All,
Sorry for bring back this old topic again.
On Thu, Jan 28, 2016 at 05:27:46PM +0100, Thomas Gleixner wrote:
>On Thu, 28 Jan 2016, Thomas Gleixner wrote:
>> On Thu, 28 Jan 2016, Ulf Hansson wrote:
>> > Therefore, the only way we currently can make sure to don't get the
>> > IRQ is to free and later re-request it. Now, apparently that has
>> > issues when using threaded IRQ handlers.
>>
>> What's the issue?
>
>Ah, you mean that one:
>
>> Currently sdhci driver free irq in host suspend, and call
>> request_threaded_irq() in host resume. But during host resume,
>> Ctrl+C can impact sdhci host resume, see the error log:
>
>> CPU1 is up
>> PM: noirq resume of devices complete after 0.637 msecs imx-sdma 30bd0000.sdma: loaded firmware 4.1
>> PM: early resume of devices complete after 0.774 msecs
>> dpm_run_callback(): platform_pm_resume+0x0/0x44 returns -4
>> PM: Device 30b40000.usdhc failed to resume: error -4
>> dpm_run_callback(): platform_pm_resume+0x0/0x44 returns -4
>> PM: Device 30b50000.usdhc failed to resume: error -4
>> dpm_run_callback(): platform_pm_resume+0x0/0x44 returns -4
>> PM: Device 30b60000.usdhc failed to resume: error -4 fec 30be0000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx
>> mmc0: Timeout waiting for hardware interrupt.
>> mmc0: Timeout waiting for hardware interrupt.
>> mmc0: Timeout waiting for hardware interrupt.
>> mmc0: Timeout waiting for hardware interrupt.
>> mmc0: Timeout waiting for hardware interrupt.
>> mmc0: Timeout waiting for hardware interrupt.
>> mmc0: error -110 during resume (card was removed?)
>> mmc2: Timeout waiting for hardware interrupt.
>> mmc2: Timeout waiting for hardware interrupt.
>> mmc2: error -110 during resume (card was removed?)
>
>In request_threaded_irq-> __setup_irq-> kthread_create
>->kthread_create_on_node, the comment shows that SIGKILLed will
>impact the kthread create, and return -EINTR.
>
>And how should that thread be SIGKILLed? Hitting Ctrl+C on the console does
>not affect any kernel internal thread. Hitting Ctrl+C affects solely the
>process which is running on that console.
>
>And if it would, then that would be a completely different, serious bug which
>needs to be fixed.
>
>How was verified, that the thread was not created and that the creation failed
>due to a SIGKILL?
This is the testcase.
"/unit_tests/SRTC/rtcwakeup.out -d rtc0 -m mem -s 2;"
it acts "echo mem > /sys/power/state", then rtc interrupt will wakeup the system.
My understanding is:
The issue is during suspend resume, it is in rtwakeup.out process space,
during resume, "get_current()->comm" shows "rtcwakeup.out", so if we
send SIGKILL from userspace, a interrupt will occur, interrupt
handler will directly return to kernel space to continue resuming.
__setup_irq->kthread_create->wait_for_completion_killable, here
wait_for_completion_killable see SIGKILL pending and return -EINTR,
then sdhci resume process failure, because of sdhci interrupt thread
not created.
During suspend/resume, OOM Killer will be disabled and enalbed. When
request_threaded_irq in sdhci resume, OOM Killer is still disabled.
According to kthread_create comments for wait_for_completion_killable,
using killable is to catch OOM sigkill. But during resume, OOM Killer
is disabled, So how about the following patch to disable SIGKILL for
a short while?
diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
index e9290a3439d5..84c4c99b1acb 100644
--- a/drivers/mmc/host/sdhci.c
+++ b/drivers/mmc/host/sdhci.c
@@ -19,6 +19,7 @@
#include <linux/io.h>
#include <linux/module.h>
#include <linux/dma-mapping.h>
+#include <linux/signal.h>
#include <linux/slab.h>
#include <linux/scatterlist.h>
#include <linux/swiotlb.h>
@@ -2895,9 +2896,11 @@ int sdhci_resume_host(struct sdhci_host *host)
}
if (!device_may_wakeup(mmc_dev(host->mmc))) {
+ disallow_signal(SIGKILL);
ret = request_threaded_irq(host->irq, sdhci_irq,
sdhci_thread_irq, IRQF_SHARED,
mmc_hostname(host->mmc), host);
+ allow_signal(SIGKILL);
if (ret)
return ret;
} else {
Thanks,
Peng.
>
>Thanks,
>
> tglx
--
Dear all,
I have to resurrect this discussion once again. The issue is still present
in linux-next and can be reproduced easily on my imx25-based system.
Thus wrote Peng Fan ([email protected]):
> On Thu, Jan 28, 2016 at 05:27:46PM +0100, Thomas Gleixner wrote:
> >On Thu, 28 Jan 2016, Thomas Gleixner wrote:
> >> On Thu, 28 Jan 2016, Ulf Hansson wrote:
> >> > Therefore, the only way we currently can make sure to don't get the
> >> > IRQ is to free and later re-request it. Now, apparently that has
> >> > issues when using threaded IRQ handlers.
> >> What's the issue?
> >Ah, you mean that one:
> >> Currently sdhci driver free irq in host suspend, and call
> >> request_threaded_irq() in host resume. But during host resume,
> >> Ctrl+C can impact sdhci host resume, see the error log:
> >> [...]
My test setup uses rtc as a wakeup source. Additionally, I also define my
console uart as wakeup source
echo enabled > /sys/class/tty/ttymxc3/power/wakeup
and then run rtcwake in a loop
while true ; do rtcwake -s 2 -m mem ; done
Pressing Ctrl-C while the system is sleeping reproduces the problem quickly.
sdhci_resume_host fails because the kthread for the threaded irq can't be
created.
ps confirms that there's no [irq/25-mmc0] kernel thread any more and sdhci
starts printing register dumps periodically
[ 101.603339] mmc0: Timeout waiting for hardware cmd interrupt.
[ 101.609225] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
[ 101.615725] mmc0: sdhci: Sys addr: 0x00000008 | Version: 0x00001001
...
[ 101.700086] mmc0: sdhci: Host ctl2: 0x00000000
[ 101.704568] mmc0: sdhci-esdhc-imx: ========= ESDHC IMX DEBUG STATUS DUMP =========
[ 101.712179] mmc0: sdhci-esdhc-imx: cmd debug status: 0x0000
...
[ 101.746827] mmc0: sdhci-esdhc-imx: async fifo debug status: 0x0000
[ 101.753137] mmc0: sdhci: ============================================
I guest that we're taking this path from sdhci_resume_host
request_threaded_irq
__setup_irq
setup_irq_thread
kthread_create
kthread_create_on_node
__kthread_create_on_node
wake_up_process(kthreadd_task);
if (unlikely(wait_for_completion_killable(&done))) {
if (xchg(&create->done, NULL))
return ERR_PTR(-EINTR);
I can confirm Peng's observation that current->pid in
__kthread_create_on_node is the pid of the rtcwake process.
This is an ftrace log of the error case, I used
trace-cmd start -e task -e mmc -e power -e signal -p function -l tty_flip_buffer_push -l sdhci_resume_host -l __kthread_create_on_node
rtcwake-185 [000] .n.. 321.166724: device_pm_callback_start: imx-uart 50008000.serial, parent: 50000000.spba, bus [resume]
rtcwake-185 [000] dnh. 321.166823: tty_flip_buffer_push <-__imx_uart_rxint.constprop.0
rtcwake-185 [000] .n.. 321.166906: device_pm_callback_end: imx-uart 50008000.serial, err=0
...
rtcwake-185 [000] .n.. 321.167472: device_pm_callback_start: imx_rngc 53fb0000.rngb, parent: 53f00000.bus, bus [resume]
rtcwake-185 [000] .n.. 321.167486: device_pm_callback_end: imx_rngc 53fb0000.rngb, err=0
rtcwake-185 [000] .n.. 321.167502: device_pm_callback_start: sdhci-esdhc-imx 53fb4000.mmc, parent: 53f00000.bus, bus [resume]
rtcwake-185 [000] .n.. 321.167516: sdhci_resume_host <-sdhci_esdhc_resume
rtcwake-185 [000] .n.. 321.167584: __kthread_create_on_node <-kthread_create_on_node
rtcwake-185 [000] .n.. 321.167652: device_pm_callback_end: sdhci-esdhc-imx 53fb4000.mmc, err=-4
rtcwake-185 [000] .n.. 321.167922: device_pm_callback_start: imx-fb 53fbc000.lcdc, parent: 53f00000.bus, bus [resume]
rtcwake-185 [000] .n.. 321.167978: device_pm_callback_end: imx-fb 53fbc000.lcdc, err=0
If wakeup is successful, the irq's thread is created
rtcwake-168 [000] .n.. 320.566614: device_pm_callback_start: imx-uart 50008000.serial, parent: 50000000.spba, bus [resume]
rtcwake-168 [000] dnh. 320.566718: tty_flip_buffer_push <-__imx_uart_rxint.constprop.0
rtcwake-168 [000] .n.. 320.566808: device_pm_callback_end: imx-uart 50008000.serial, err=0
...
rtcwake-168 [000] .n.. 320.567359: device_pm_callback_start: imx_rngc 53fb0000.rngb, parent: 53f00000.bus, bus [resume]
rtcwake-168 [000] .n.. 320.567372: device_pm_callback_end: imx_rngc 53fb0000.rngb, err=0
rtcwake-168 [000] .n.. 320.567386: device_pm_callback_start: sdhci-esdhc-imx 53fb4000.mmc, parent: 53f00000.bus, bus [resume]
rtcwake-168 [000] .n.. 320.567402: sdhci_resume_host <-sdhci_esdhc_resume
rtcwake-168 [000] .n.. 320.567460: __kthread_create_on_node <-kthread_create_on_node
kthreadd-2 [000] .... 320.567922: task_newtask: pid=174 comm=kthreadd clone_flags=800700 oom_score_adj=0
kworker/u2:3-173 [000] .... 320.568183: __kthread_create_on_node <-kthread_create_on_node
kthreadd-2 [000] .... 320.568504: task_newtask: pid=175 comm=kthreadd clone_flags=800700 oom_score_adj=0
rtcwake-168 [000] .... 320.568659: task_rename: pid=174 oldcomm=kthreadd newcomm=irq/25-mmc0 oom_score_adj=0
rtcwake-168 [000] .n.. 320.568824: device_pm_callback_end: sdhci-esdhc-imx 53fb4000.mmc, err=0
> >In request_threaded_irq-> __setup_irq-> kthread_create
> >->kthread_create_on_node, the comment shows that SIGKILLed will
> >impact the kthread create, and return -EINTR.
> >And how should that thread be SIGKILLed? Hitting Ctrl+C on the console does
> >not affect any kernel internal thread. Hitting Ctrl+C affects solely the
> >process which is running on that console.
> >And if it would, then that would be a completely different, serious bug which
> >needs to be fixed.
> >How was verified, that the thread was not created and that the creation failed
> >due to a SIGKILL?
See above, the irq thread is missing, it was running before the
suspend+wakeup. I hope that the ftrace output confirms my assumption about
the code path that was taken. I didn't find any other way we could return
-EINTR in sdhci_resume_host.
> My understanding is:
> The issue is during suspend resume, it is in rtwakeup.out process space,
> during resume, "get_current()->comm" shows "rtcwakeup.out", so if we
> send SIGKILL from userspace, a interrupt will occur, interrupt
> handler will directly return to kernel space to continue resuming.
> __setup_irq->kthread_create->wait_for_completion_killable, here
> wait_for_completion_killable see SIGKILL pending and return -EINTR,
> then sdhci resume process failure, because of sdhci interrupt thread
> not created.
> During suspend/resume, OOM Killer will be disabled and enalbed. When
> request_threaded_irq in sdhci resume, OOM Killer is still disabled.
> According to kthread_create comments for wait_for_completion_killable,
> using killable is to catch OOM sigkill. But during resume, OOM Killer
> is disabled, So how about the following patch to disable SIGKILL for
> a short while?
I tried this patch, it didn't fix the problem for me.
I could make the problem disappear if I moved sdhci_resume_host's
request_threaded_irq call into a worker. Instead of calling
request_threaded_irq, I'd schedule the work on system_unbound_wq. The new
thread for sdhci's irq is then requested by someone other than rtcwake.
Generally, it makes sense to me that kthreadd aborts a request for a new
thread if the requester is killed during the request. However, in the case
of sdhci resume, the thread should always be created, regardless of the
requester's state...
Of course, the workqueue hack is not an acceptable way to fix this. I'd
appreciate if anyone could point me in the right direction for a proper fix.
Thanks in advance for your help,
Martin
> diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
> index e9290a3439d5..84c4c99b1acb 100644
> --- a/drivers/mmc/host/sdhci.c
> +++ b/drivers/mmc/host/sdhci.c
> @@ -19,6 +19,7 @@
> #include <linux/io.h>
> #include <linux/module.h>
> #include <linux/dma-mapping.h>
> +#include <linux/signal.h>
> #include <linux/slab.h>
> #include <linux/scatterlist.h>
> #include <linux/swiotlb.h>
> @@ -2895,9 +2896,11 @@ int sdhci_resume_host(struct sdhci_host *host)
> }
> if (!device_may_wakeup(mmc_dev(host->mmc))) {
> + disallow_signal(SIGKILL);
> ret = request_threaded_irq(host->irq, sdhci_irq,
> sdhci_thread_irq, IRQF_SHARED,
> mmc_hostname(host->mmc), host);
> + allow_signal(SIGKILL);
> if (ret)
> return ret;
> } else {
> Thanks,
> Peng.
> >Thanks,
> > tglx
> --