| Message ID | DM5PR06MB313235E97731D97AB813F65D92FB0@DM5PR06MB3132.namprd06.prod.outlook.com |
|---|---|
| State | New |
| Headers | show |
| Series | Kernel hangs when powering up/down drive using sysfs | expand |
On Sat, Mar 14, 2020 at 02:19:44PM +0000, Hoyer, David wrote: > We have come across what we believe to be a kernel bug (using 4.19.98-1 kernel in Debian Buster). > > We are seeing an issue with the latest kernel when it comes to powering up/down drives. If you use /sys/bus/pci/slots/<N>/power to power up/down a drive, the command is hanging with this latest version of the kernel. We have found that applying the following change appears to fix it. We are not finding any bug reports upstream yet. > > diff --git a/drivers/pci/hotplug/pciehp_hpc.c b/drivers/pci/hotplug/pciehp_hpc.c > index c3e3f53..c4d230a 100644 > --- a/drivers/pci/hotplug/pciehp_hpc.c > +++ b/drivers/pci/hotplug/pciehp_hpc.c > @@ -637,6 +637,8 @@ static irqreturn_t pciehp_ist(int irq, void *dev_id) > events = atomic_xchg(&ctrl->pending_events, 0); > if (!events) { > pci_config_pm_runtime_put(pdev); > + ctrl->ist_running = false; > + wake_up(&ctrl->requester); > return IRQ_NONE; > } > > We believe the reason we see this (and not the others who introduced it) are because of our timings on our PLX-based switch. Since we fan things out over I2C transactions instead of direct GPIOs, there are different timings than most folks would see. > > We've instrumented the code and we do see that pciehp_ist() runs twice, once exiting with IRQ_HANDLED and then again with IRQ_NONE. We believe that is due to the timing differences. Adding debug in here changes the timings enough that the hang goes away, so we are having troubles proving this 100% at the moment. But just based on code inspection, if pciehp_ist() exits with the IRQ_NONE case, then nothing will ever set ist_running=false until a subsequent hotplug event happens that causes the IRQ_HANDLED case to run. (We were able to prove that will cause things to "unhang" and progress at that point - if you're hung and you remove a drive, the slot status change will then unstick things.) > > So we currently believe the problem is: > pciehp_sysfs_enable/disable_slot() each have a wait_event() that checks for ctrl->pending_events and ctrl->ist_running to both be false. We run through pciehp_ist() the first time, return with IRQ_HANDLED, pending_events==0, ist_running==0. While pciehp_sysfs_enable/disable_slot() are waking up, pciehp_ist() runs a 2nd time, setting ist_running==1, (pending_events is still 0) and returning IRQ_NONE. Now that ist_running==1, the original wait_event() goes back to waiting and will not be woken up until something causes pciehp_ist() to run again with a pending_events!=0 that will result in returning IRQ_HANDLED. > > Setting ist_running=0 and issuing a wake_up() for the IRQ_NONE return case in pciehp_ist() seems to fix this. I follow what you're saying. I'm not sure why the hard-irq context is even setting the thread running flag while it can still exit without handling anything. Shouldn't it leave the flag cleared until knows it's actually going to do something? --- diff --git a/drivers/pci/hotplug/pciehp_hpc.c b/drivers/pci/hotplug/pciehp_hpc.c index 8a2cb1764386..adf13657b3d2 100644 --- a/drivers/pci/hotplug/pciehp_hpc.c +++ b/drivers/pci/hotplug/pciehp_hpc.c @@ -618,7 +618,6 @@ static irqreturn_t pciehp_ist(int irq, void *dev_id) irqreturn_t ret; u32 events; - ctrl->ist_running = true; pci_config_pm_runtime_get(pdev); /* rerun pciehp_isr() if the port was inaccessible on interrupt */ @@ -638,6 +637,7 @@ static irqreturn_t pciehp_ist(int irq, void *dev_id) return IRQ_NONE; } + ctrl->ist_running = true; /* Check Attention Button Pressed */ if (events & PCI_EXP_SLTSTA_ABP) { ctrl_info(ctrl, "Slot(%s): Attention button pressed\n", --
On Mon, Mar 16, 2020 at 09:15:43AM -0700, Keith Busch wrote: > I'm not sure why the hard-irq context is even setting the thread running > flag while it can still exit without handling anything. Shouldn't it leave > the flag cleared until knows it's actually going to do something? No, ist_running must be set to true before the invocation of atomic_xchg(&ctrl->pending_events, 0). There's a time window between the atomic_xchg() and actually turning off the slot when pending_events is 0. Previously we only checked in the sysfs functions that pending_events is 0. That was insufficient as we risked returning prematurely from the sysfs functions. The point of ist_running is to prevent that. Thanks, Lukas
On Sat, Mar 14, 2020 at 02:19:44PM +0000, Hoyer, David wrote: > --- a/drivers/pci/hotplug/pciehp_hpc.c > +++ b/drivers/pci/hotplug/pciehp_hpc.c > @@ -637,6 +637,8 @@ static irqreturn_t pciehp_ist(int irq, void *dev_id) > events = atomic_xchg(&ctrl->pending_events, 0); > if (!events) { > pci_config_pm_runtime_put(pdev); > + ctrl->ist_running = false; > + wake_up(&ctrl->requester); > return IRQ_NONE; > } Thanks David for the report and sorry for the breakage. The above LGTM, please submit it as a proper patch and feel free to add my Reviewed-by. Please add the same two lines before the "return ret" a little further up in the function. If it's too cumbersome for you to submit a proper patch I can do it for you. > We've instrumented the code and we do see that pciehp_ist() runs > twice, once exiting with IRQ_HANDLED and then again with IRQ_NONE. > We believe that is due to the timing differences. Adding debug in > here changes the timings enough that the hang goes away, so we are > having troubles proving this 100% at the moment. But just based on > code inspection, if pciehp_ist() exits with the IRQ_NONE case, then > nothing will ever set ist_running=false until a subsequent hotplug > event happens that causes the IRQ_HANDLED case to run. (We were > able to prove that will cause things to "unhang" and progress at > that point - if you're hung and you remove a drive, the slot status > change will then unstick things.) The question is, why is pciehp_ist() run once more. Most likely because another event is signaled from the slot. Try adding a printk() at the top of pciehp_ist() which emits ctrl->pending_events to understand what's going on. Thanks, Lukas
We were not sure about the return just a few lines up so we did not add the 2 lines. I will try what you suggested to better understand why we are getting the extra interrupt. I am not as familiar with submitting a "proper patch" and ask that you do it if you would be so kind. -----Original Message----- From: Lukas Wunner <lukas@wunner.de> Sent: Monday, March 16, 2020 1:20 PM To: Hoyer, David <David.Hoyer@netapp.com> Cc: linux-pci@vger.kernel.org; Keith Busch <kbusch@kernel.org> Subject: Re: Kernel hangs when powering up/down drive using sysfs NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe. On Sat, Mar 14, 2020 at 02:19:44PM +0000, Hoyer, David wrote: > --- a/drivers/pci/hotplug/pciehp_hpc.c > +++ b/drivers/pci/hotplug/pciehp_hpc.c > @@ -637,6 +637,8 @@ static irqreturn_t pciehp_ist(int irq, void *dev_id) > events = atomic_xchg(&ctrl->pending_events, 0); > if (!events) { > pci_config_pm_runtime_put(pdev); > + ctrl->ist_running = false; > + wake_up(&ctrl->requester); > return IRQ_NONE; > } Thanks David for the report and sorry for the breakage. The above LGTM, please submit it as a proper patch and feel free to add my Reviewed-by. Please add the same two lines before the "return ret" a little further up in the function. If it's too cumbersome for you to submit a proper patch I can do it for you. > We've instrumented the code and we do see that pciehp_ist() runs > twice, once exiting with IRQ_HANDLED and then again with IRQ_NONE. > We believe that is due to the timing differences. Adding debug in > here changes the timings enough that the hang goes away, so we are > having troubles proving this 100% at the moment. But just based on > code inspection, if pciehp_ist() exits with the IRQ_NONE case, then > nothing will ever set ist_running=false until a subsequent hotplug > event happens that causes the IRQ_HANDLED case to run. (We were able > to prove that will cause things to "unhang" and progress at that point > - if you're hung and you remove a drive, the slot status change will > then unstick things.) The question is, why is pciehp_ist() run once more. Most likely because another event is signaled from the slot. Try adding a printk() at the top of pciehp_ist() which emits ctrl->pending_events to understand what's going on. Thanks, Lukas
On Mon, Mar 16, 2020 at 07:10:58PM +0100, Lukas Wunner wrote: > On Mon, Mar 16, 2020 at 09:15:43AM -0700, Keith Busch wrote: > > I'm not sure why the hard-irq context is even setting the thread running > > flag while it can still exit without handling anything. Shouldn't it leave > > the flag cleared until knows it's actually going to do something? > > No, ist_running must be set to true before the invocation of > atomic_xchg(&ctrl->pending_events, 0). Okay, I see what you mean. Even with David's patch, there's still another condition that could exit with ist_running set. It may make sense to move the setting just above the atomic_xchg() so that clearing it doesn't need to be duplicated for the remaining uncommon exit case. > There's a time window between the atomic_xchg() and actually > turning off the slot when pending_events is 0. Previously we > only checked in the sysfs functions that pending_events is 0. > That was insufficient as we risked returning prematurely from > the sysfs functions. The point of ist_running is to prevent > that. Oh, right, I'm remembering now. And since we've a polled option for pciehp, using synchronize_irq() from the sysfs path isn't possible.
I ran the suggested experiment. The first interrupt is reporting non-zero pending event (either 0x08 or 0x1000 depending on power up or power down). The second interrupt is always zero. So it sounds like we are getting an interrupt indicating work complete. Power up: Mar 16 21:10:15 eos-a kernel: pending events x8 Mar 16 21:10:15 eos-a kernel: pciehp 0000:66:09.0:pcie204: Slot(9): Card present Mar 16 21:10:15 eos-a kernel: pci 0000:6f:00.0: Max Payload Size set to 256 (was 128, max 256) Mar 16 21:10:15 eos-a kernel: iommu: Adding device 0000:6f:00.0 to group 70 Mar 16 21:10:15 eos-a kernel: pcieport 0000:66:09.0: BAR 13: no space for [io size 0x1000] Mar 16 21:10:15 eos-a kernel: pcieport 0000:66:09.0: BAR 13: failed to assign [io size 0x1000] Mar 16 21:10:15 eos-a kernel: pcieport 0000:66:09.0: BAR 13: no space for [io size 0x1000] Mar 16 21:10:15 eos-a kernel: pcieport 0000:66:09.0: BAR 13: failed to assign [io size 0x1000] Mar 16 21:10:15 eos-a kernel: pci 0000:6f:00.0: BAR 0: assigned [mem 0xe0b00000-0xe0b03fff 64bit] Mar 16 21:10:15 eos-a kernel: pcieport 0000:66:09.0: PCI bridge to [bus 6f] Mar 16 21:10:15 eos-a kernel: pcieport 0000:66:09.0: bridge window [mem 0xe0b00000-0xe0bfffff] Mar 16 21:10:15 eos-a kernel: pcieport 0000:66:09.0: bridge window [mem 0x3ac00c000000-0x3ac00dffffff 64bit pref] Mar 16 21:10:15 eos-a kernel: pending events x0 Mar 16 21:10:16 eos-a kernel: vfio-pci 0000:6f:00.0: enabling device (0100 -> 0102) Mar 16 21:10:16 eos-a kernel: pcieport 0000:64:00.0: can't derive routing for PCI INT A Mar 16 21:10:16 eos-a kernel: vfio-pci 0000:6f:00.0: PCI INT A: not connected Mar 16 21:10:16 eos-a kernel: vfio_ecap_init: 0000:6f:00.0 hiding ecap 0x19@0x178 Power down: Mar 16 21:10:47 eos-a kernel: pending events x10000 Mar 16 21:10:47 eos-a kernel: iommu: Removing device 0000:6f:00.0 from group 70 Mar 16 21:10:48 eos-a kernel: pending events x0 -----Original Message----- From: linux-pci-owner@vger.kernel.org <linux-pci-owner@vger.kernel.org> On Behalf Of Hoyer, David Sent: Monday, March 16, 2020 1:26 PM To: Lukas Wunner <lukas@wunner.de> Cc: linux-pci@vger.kernel.org; Keith Busch <kbusch@kernel.org> Subject: RE: Kernel hangs when powering up/down drive using sysfs NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe. We were not sure about the return just a few lines up so we did not add the 2 lines. I will try what you suggested to better understand why we are getting the extra interrupt. I am not as familiar with submitting a "proper patch" and ask that you do it if you would be so kind. -----Original Message----- From: Lukas Wunner <lukas@wunner.de> Sent: Monday, March 16, 2020 1:20 PM To: Hoyer, David <David.Hoyer@netapp.com> Cc: linux-pci@vger.kernel.org; Keith Busch <kbusch@kernel.org> Subject: Re: Kernel hangs when powering up/down drive using sysfs NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe. On Sat, Mar 14, 2020 at 02:19:44PM +0000, Hoyer, David wrote: > --- a/drivers/pci/hotplug/pciehp_hpc.c > +++ b/drivers/pci/hotplug/pciehp_hpc.c > @@ -637,6 +637,8 @@ static irqreturn_t pciehp_ist(int irq, void *dev_id) > events = atomic_xchg(&ctrl->pending_events, 0); > if (!events) { > pci_config_pm_runtime_put(pdev); > + ctrl->ist_running = false; > + wake_up(&ctrl->requester); > return IRQ_NONE; > } Thanks David for the report and sorry for the breakage. The above LGTM, please submit it as a proper patch and feel free to add my Reviewed-by. Please add the same two lines before the "return ret" a little further up in the function. If it's too cumbersome for you to submit a proper patch I can do it for you. > We've instrumented the code and we do see that pciehp_ist() runs > twice, once exiting with IRQ_HANDLED and then again with IRQ_NONE. > We believe that is due to the timing differences. Adding debug in > here changes the timings enough that the hang goes away, so we are > having troubles proving this 100% at the moment. But just based on > code inspection, if pciehp_ist() exits with the IRQ_NONE case, then > nothing will ever set ist_running=false until a subsequent hotplug > event happens that causes the IRQ_HANDLED case to run. (We were able > to prove that will cause things to "unhang" and progress at that point > - if you're hung and you remove a drive, the slot status change will > then unstick things.) The question is, why is pciehp_ist() run once more. Most likely because another event is signaled from the slot. Try adding a printk() at the top of pciehp_ist() which emits ctrl->pending_events to understand what's going on. Thanks, Lukas
On Mon, Mar 16, 2020 at 06:25:53PM +0000, Hoyer, David wrote: > I am not as familiar with submitting a "proper patch" and ask that you > do it if you would be so kind. I've just submitted a patch to address this issue. Does it work for you? The term "proper patch" is just kernel slang for a patch which can be applied with "git am" by the PCI maintainer, Bjorn Helgaas. Such a patch can be generated with "git format-patch" and sent out with "msmtp" or "git send-email". There are some formal requirements which the patch needs to satisfy, they are listed here: https://www.kernel.org/doc/html/latest/process/submitting-patches.html https://www.kernel.org/doc/html/latest/process/development-process.html https://marc.info/?l=linux-pci&m=150905742808166 Never mind all these details if you do not intend to submit patches yourself. In this case, I introduced this embarrassing mistake, so it's my job to provide a solution if you don't want to. Thanks for all the debugging work you have done and once again sorry for the breakage. Lukas
On Mon, Mar 16, 2020 at 11:42:00AM -0700, Keith Busch wrote: > On Mon, Mar 16, 2020 at 07:10:58PM +0100, Lukas Wunner wrote: > > On Mon, Mar 16, 2020 at 09:15:43AM -0700, Keith Busch wrote: > > > I'm not sure why the hard-irq context is even setting the thread running > > > flag while it can still exit without handling anything. Shouldn't it > > > leave the flag cleared until knows it's actually going to do something? > > > > No, ist_running must be set to true before the invocation of > > atomic_xchg(&ctrl->pending_events, 0). > > Okay, I see what you mean. > > Even with David's patch, there's still another condition that could exit > with ist_running set. It may make sense to move the setting just above > the atomic_xchg() so that clearing it doesn't need to be duplicated for > the remaining uncommon exit case. Right, or introduce a goto label before the teardown code at the end of pciehp_ist() and replace the return statements with gotos. I've compared both approaches and the goto solution required the least lines of code and subjectively looked the nicest, so I went with that. > > There's a time window between the atomic_xchg() and actually > > turning off the slot when pending_events is 0. Previously we > > only checked in the sysfs functions that pending_events is 0. > > That was insufficient as we risked returning prematurely from > > the sysfs functions. The point of ist_running is to prevent > > that. > > Oh, right, I'm remembering now. And since we've a polled option for > pciehp, using synchronize_irq() from the sysfs path isn't possible. Precisely. :-) Thanks, Lukas
Thank you for the information and for submitting the patch. I will review this so that I can do this better in the future. I appreciate all the help! -----Original Message----- From: Lukas Wunner <lukas@wunner.de> Sent: Wednesday, March 18, 2020 6:50 AM To: Hoyer, David <David.Hoyer@netapp.com> Cc: linux-pci@vger.kernel.org; Keith Busch <kbusch@kernel.org> Subject: Re: Kernel hangs when powering up/down drive using sysfs NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe. On Mon, Mar 16, 2020 at 06:25:53PM +0000, Hoyer, David wrote: > I am not as familiar with submitting a "proper patch" and ask that you > do it if you would be so kind. I've just submitted a patch to address this issue. Does it work for you? The term "proper patch" is just kernel slang for a patch which can be applied with "git am" by the PCI maintainer, Bjorn Helgaas. Such a patch can be generated with "git format-patch" and sent out with "msmtp" or "git send-email". There are some formal requirements which the patch needs to satisfy, they are listed here: https://www.kernel.org/doc/html/latest/process/submitting-patches.html https://www.kernel.org/doc/html/latest/process/development-process.html https://marc.info/?l=linux-pci&m=150905742808166 Never mind all these details if you do not intend to submit patches yourself. In this case, I introduced this embarrassing mistake, so it's my job to provide a solution if you don't want to. Thanks for all the debugging work you have done and once again sorry for the breakage. Lukas
diff --git a/drivers/pci/hotplug/pciehp_hpc.c b/drivers/pci/hotplug/pciehp_hpc.c index c3e3f53..c4d230a 100644 --- a/drivers/pci/hotplug/pciehp_hpc.c +++ b/drivers/pci/hotplug/pciehp_hpc.c @@ -637,6 +637,8 @@ static irqreturn_t pciehp_ist(int irq, void *dev_id) events = atomic_xchg(&ctrl->pending_events, 0); if (!events) { pci_config_pm_runtime_put(pdev); + ctrl->ist_running = false; + wake_up(&ctrl->requester); return IRQ_NONE; }