| Message ID | 1442478527-29304-1-git-send-email-ideal.song@samsung.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Thu, Sep 17, 2015 at 05:28:47PM +0900, Inha Song wrote: > This patch call runtiem PM function manually if the state is runtime resumed > before enter suspend. > > This case has occurred when wake-up by the resume after entering to > suspend during the playback. > $ aplay -> runtime_resume() -> suspend() -> resume() > > In this case, Can occurred an error when enter suspend. > -- > [ 82.559234] PM: suspend of devices complete after 57.252 msecs > [ 82.567978] arizona spi1.0: Failed to read IRQ status: -108 > [ 82.567989] arizona spi1.0: Failed to read main IRQ status: -108 > [ 82.568027] arizona spi1.0: Failed to read IRQ status: -108 > [ 82.568036] arizona spi1.0: Failed to read main IRQ status: -108 Would it be possible to get some more detail on what is happening here? A full log would be nice with DEBUG enabled in arizona-core.c, also perhaps put some printk's in the SPI driver suspend/resume as well. It looks like what is happening is that the system is attempting to handle an IRQ before the SPI has been resumed. But that is exactly what the irq enables/disables in the system PM ops in Arizona are trying to avoid. > .... > So, we should call runtime_suspend() manually when enter suspend > if the state is runtime resume. There are many use-cases where we want to leave the CODEC enabled whilst the system is suspended so we really don't want to be doing a runtime suspend with every system suspend. Thanks, Charles
Hi, It is a log: # aplay [ 79.590767] s3c64xx_spi_runtime_resume [ 79.592288] arizona spi1.0: ASRC underclocked [ 79.592331] s3c64xx_spi_runtime_suspend --- -> suspend () [ 83.348754] s3c64xx_spi_runtime_resume [ 83.367711] s3c64xx_spi_suspend [ 83.368420] PM: suspend of devices complete after 59.666 msecs [ 83.375584] arizona spi1.0: Failed to read IRQ status: -108 [ 83.375595] arizona spi1.0: Failed to read main IRQ status: -108 [ 83.375672] arizona spi1.0: Failed to read IRQ status: -108 [ 83.375679] arizona spi1.0: Failed to read main IRQ status: -108 [ 83.375749] arizona spi1.0: Failed to read IRQ status: -108 ..... [ 83.580360] Call trace: [ 83.580369] [<ffffffc000089f8c>] dump_backtrace+0x0/0x12c [ 83.580373] [<ffffffc00008a0c8>] show_stack+0x10/0x1c [ 83.580380] [<ffffffc0009f10e4>] dump_stack+0x78/0xc8 [ 83.580386] [<ffffffc00009ade8>] warn_slowpath_common+0x98/0xd0 [ 83.580390] [<ffffffc00009ae6c>] warn_slowpath_fmt+0x4c/0x58 [ 83.580394] [<ffffffc0000e7f1c>] __enable_irq+0x40/0x8c [ 83.580399] [<ffffffc0000e7f9c>] enable_irq+0x34/0x74 [ 83.580404] [<ffffffc0004d00d0>] arizona_resume+0x10/0x20 [ 83.580410] [<ffffffc0004b6bac>] dpm_run_callback+0x50/0x1a0 [ 83.580414] [<ffffffc0004b728c>] device_resume+0x90/0x268 [ 83.580418] [<ffffffc0004b88cc>] dpm_resume+0x120/0x350 [ 83.580422] [<ffffffc0004b8f1c>] dpm_resume_end+0x10/0x28 [ 83.580426] [<ffffffc0000e1bec>] suspend_devices_and_enter+0x138/0x7f4 [ 83.580430] [<ffffffc0000e25bc>] pm_suspend+0x314/0x5bc [ 83.580435] [<ffffffc0000e0bc8>] state_store+0x7c/0xf0 [ 83.580441] [<ffffffc00035ee58>] kobj_attr_store+0x10/0x24 [ 83.580448] [<ffffffc00020e1e0>] sysfs_kf_write+0x40/0x4c [ 83.580452] [<ffffffc00020d664>] kernfs_fop_write+0xb8/0x180 [ 83.580458] [<ffffffc0001a2ef4>] __vfs_write+0x2c/0x11c [ 83.580463] [<ffffffc0001a38f0>] vfs_write+0x90/0x170 [ 83.580467] [<ffffffc0001a422c>] SyS_write+0x40/0xa0 Best Regards, Inha Song. On Thu, 17 Sep 2015 09:25:42 +0100 Charles Keepax <ckeepax@opensource.wolfsonmicro.com> wrote: > On Thu, Sep 17, 2015 at 05:28:47PM +0900, Inha Song wrote: > > This patch call runtiem PM function manually if the state is runtime resumed > > before enter suspend. > > > > This case has occurred when wake-up by the resume after entering to > > suspend during the playback. > > $ aplay -> runtime_resume() -> suspend() -> resume() > > > > In this case, Can occurred an error when enter suspend. > > -- > > [ 82.559234] PM: suspend of devices complete after 57.252 msecs > > [ 82.567978] arizona spi1.0: Failed to read IRQ status: -108 > > [ 82.567989] arizona spi1.0: Failed to read main IRQ status: -108 > > [ 82.568027] arizona spi1.0: Failed to read IRQ status: -108 > > [ 82.568036] arizona spi1.0: Failed to read main IRQ status: -108 > > Would it be possible to get some more detail on what is happening > here? A full log would be nice with DEBUG enabled in > arizona-core.c, also perhaps put some printk's in the SPI driver > suspend/resume as well. > > It looks like what is happening is that the system is attempting > to handle an IRQ before the SPI has been resumed. But that is > exactly what the irq enables/disables in the system PM ops in > Arizona are trying to avoid. > > > .... > > So, we should call runtime_suspend() manually when enter suspend > > if the state is runtime resume. > > There are many use-cases where we want to leave the CODEC enabled > whilst the system is suspended so we really don't want to be > doing a runtime suspend with every system suspend. > > Thanks, > Charles
On Thu, Sep 17, 2015 at 06:05:30PM +0900, Inha Song wrote: > Hi, > > > It is a log: > > # aplay > [ 79.590767] s3c64xx_spi_runtime_resume > [ 79.592288] arizona spi1.0: ASRC underclocked > [ 79.592331] s3c64xx_spi_runtime_suspend > --- > -> suspend () > > [ 83.348754] s3c64xx_spi_runtime_resume > [ 83.367711] s3c64xx_spi_suspend > [ 83.368420] PM: suspend of devices complete after 59.666 msecs > [ 83.375584] arizona spi1.0: Failed to read IRQ status: -108 > [ 83.375595] arizona spi1.0: Failed to read main IRQ status: -108 > [ 83.375672] arizona spi1.0: Failed to read IRQ status: -108 > [ 83.375679] arizona spi1.0: Failed to read main IRQ status: -108 > [ 83.375749] arizona spi1.0: Failed to read IRQ status: -108 > ..... > [ 83.580360] Call trace: > [ 83.580369] [<ffffffc000089f8c>] dump_backtrace+0x0/0x12c > [ 83.580373] [<ffffffc00008a0c8>] show_stack+0x10/0x1c > [ 83.580380] [<ffffffc0009f10e4>] dump_stack+0x78/0xc8 > [ 83.580386] [<ffffffc00009ade8>] warn_slowpath_common+0x98/0xd0 > [ 83.580390] [<ffffffc00009ae6c>] warn_slowpath_fmt+0x4c/0x58 > [ 83.580394] [<ffffffc0000e7f1c>] __enable_irq+0x40/0x8c > [ 83.580399] [<ffffffc0000e7f9c>] enable_irq+0x34/0x74 > [ 83.580404] [<ffffffc0004d00d0>] arizona_resume+0x10/0x20 > [ 83.580410] [<ffffffc0004b6bac>] dpm_run_callback+0x50/0x1a0 > [ 83.580414] [<ffffffc0004b728c>] device_resume+0x90/0x268 > [ 83.580418] [<ffffffc0004b88cc>] dpm_resume+0x120/0x350 > [ 83.580422] [<ffffffc0004b8f1c>] dpm_resume_end+0x10/0x28 > [ 83.580426] [<ffffffc0000e1bec>] suspend_devices_and_enter+0x138/0x7f4 > [ 83.580430] [<ffffffc0000e25bc>] pm_suspend+0x314/0x5bc > [ 83.580435] [<ffffffc0000e0bc8>] state_store+0x7c/0xf0 > [ 83.580441] [<ffffffc00035ee58>] kobj_attr_store+0x10/0x24 > [ 83.580448] [<ffffffc00020e1e0>] sysfs_kf_write+0x40/0x4c > [ 83.580452] [<ffffffc00020d664>] kernfs_fop_write+0xb8/0x180 > [ 83.580458] [<ffffffc0001a2ef4>] __vfs_write+0x2c/0x11c > [ 83.580463] [<ffffffc0001a38f0>] vfs_write+0x90/0x170 > [ 83.580467] [<ffffffc0001a422c>] SyS_write+0x40/0xa0 OK so this is definitely that the SPI driver hasn't resumed yet. Could we also get DEBUG turned on in arizona-core here. I am interested to check where in the process the arizona suspend/resume ops are being called. Thanks, Charles
Hi, I just change dev_err() to dev_info() in arizona-core. root@localhost:~# aplay test.wav [ 42.731358] arizona spi1.0: Leaving AoD mode .... [ 42.823514] s3c64xx_spi_runtime_resume [ 42.828270] arizona spi1.0: ASRC underclocked [ 42.828281] s3c64xx_spi_runtime_suspend .... -> suspend () [ 72.398152] arizona spi1.0: Suspend, disabling IRQ [ 72.410471] s3c64xx_spi_runtime_resume [ 72.429045] s3c64xx_spi_suspend -> spi suspended [ 72.429905] PM: suspend of devices complete after 67.309 msecs [ 72.440084] arizona spi1.0: Late suspend, reenabling IRQ -> try to access spi irq after spi suspend() [ 72.440165] arizona spi1.0: Failed to read IRQ status: -108 [ 72.440174] arizona spi1.0: Failed to read main IRQ status: -108 [ 72.440242] arizona spi1.0: Failed to read IRQ status: -108 [ 72.440249] arizona spi1.0: Failed to read main IRQ status: -108 [ 72.440275] arizona spi1.0: Failed to read IRQ status: -108 [ 72.440282] arizona spi1.0: Failed to read main IRQ status: -108 [ 72.440304] arizona spi1.0: Failed to read IRQ status: -108 .... [ 72.465525] s3c64xx_spi_resume [ 72.650760] arizona spi1.0: Late resume, reenabling IRQ [ 72.650819] [<ffffffc000089f8c>] dump_backtrace+0x0/0x12c [ 72.650824] [<ffffffc00008a0c8>] show_stack+0x10/0x1c [ 72.650832] [<ffffffc0009f1398>] dump_stack+0x78/0xc8 [ 72.650838] [<ffffffc00009ade8>] warn_slowpath_common+0x98/0xd0 [ 72.650842] [<ffffffc00009ae6c>] warn_slowpath_fmt+0x4c/0x58 [ 72.650847] [<ffffffc0000e7f1c>] __enable_irq+0x40/0x8c [ 72.650851] [<ffffffc0000e7f9c>] enable_irq+0x34/0x74 [ 72.650858] [<ffffffc0004d013c>] arizona_resume+0x24/0x38 [ 72.650865] [<ffffffc0004b6bac>] dpm_run_callback+0x50/0x1a0 [ 72.650870] [<ffffffc0004b728c>] device_resume+0x90/0x268 [ 72.650874] [<ffffffc0004b88cc>] dpm_resume+0x120/0x350 [ 72.650878] [<ffffffc0004b8f1c>] dpm_resume_end+0x10/0x28 [ 72.650884] [<ffffffc0000e1bec>] suspend_devices_and_enter+0x138/0x7f4 [ 72.650887] [<ffffffc0000e25bc>] pm_suspend+0x314/0x5bc [ 72.650893] [<ffffffc0000e0bc8>] state_store+0x7c/0xf0 [ 72.650901] [<ffffffc00035ee58>] kobj_attr_store+0x10/0x24 [ 72.650910] [<ffffffc00020e1e0>] sysfs_kf_write+0x40/0x4c [ 72.650914] [<ffffffc00020d664>] kernfs_fop_write+0xb8/0x180 [ 72.650922] [<ffffffc0001a2ef4>] __vfs_write+0x2c/0x11c [ 72.650926] [<ffffffc0001a38f0>] vfs_write+0x90/0x170 [ 72.650931] [<ffffffc0001a422c>] SyS_write+0x40/0xa0 ----- This irq failed errors are occured in enable_irq() that in arizona_suspend_late(). Becase of access the irq after spi suspend. (arizona->irq == spi->irq) Best Regards, Inha Song. On Thu, 17 Sep 2015 10:16:32 +0100 Charles Keepax <ckeepax@opensource.wolfsonmicro.com> wrote: > > OK so this is definitely that the SPI driver hasn't resumed > yet. Could we also get DEBUG turned on in arizona-core here. I am > interested to check where in the process the arizona > suspend/resume ops are being called. > > Thanks, > Charles
diff --git a/drivers/mfd/arizona-core.c b/drivers/mfd/arizona-core.c index 908c69b..de55706 100644 --- a/drivers/mfd/arizona-core.c +++ b/drivers/mfd/arizona-core.c @@ -683,6 +683,10 @@ static int arizona_suspend(struct device *dev) struct arizona *arizona = dev_get_drvdata(dev); dev_dbg(arizona->dev, "Suspend, disabling IRQ\n"); + + if (!pm_runtime_status_suspended(dev)) + arizona_runtime_suspend(dev); + disable_irq(arizona->irq); return 0; @@ -713,6 +717,10 @@ static int arizona_resume(struct device *dev) struct arizona *arizona = dev_get_drvdata(dev); dev_dbg(arizona->dev, "Late resume, reenabling IRQ\n"); + + if (!pm_runtime_status_suspended(dev)) + arizona_runtime_resume(dev); + enable_irq(arizona->irq); return 0;
This patch call runtiem PM function manually if the state is runtime resumed before enter suspend. This case has occurred when wake-up by the resume after entering to suspend during the playback. $ aplay -> runtime_resume() -> suspend() -> resume() In this case, Can occurred an error when enter suspend. -- [ 82.559234] PM: suspend of devices complete after 57.252 msecs [ 82.567978] arizona spi1.0: Failed to read IRQ status: -108 [ 82.567989] arizona spi1.0: Failed to read main IRQ status: -108 [ 82.568027] arizona spi1.0: Failed to read IRQ status: -108 [ 82.568036] arizona spi1.0: Failed to read main IRQ status: -108 .... So, we should call runtime_suspend() manually when enter suspend if the state is runtime resume. Also should call runtime_resume() when wake-up by resume if the state was runtime resume before entering suspend. Signed-off-by: Inha Song <ideal.song@samsung.com> --- drivers/mfd/arizona-core.c | 8 ++++++++ 1 file changed, 8 insertions(+)