Re: [bug] RTC alarm vs system suspend race condition
From: Alexandre Belloni
Date: Thu Feb 18 2021 - 15:05:43 EST
Hello,
I just wanted to thank you for reporting this issue. I didn't yet have
the time to work on that but this is on my radar. There is also another
issue when resuming and I'm not yet sure how we can solve it for all
platforms.
On 12/01/2021 10:58:07+0300, Dmitry Osipenko wrote:
> Hello RTC maintainers,
>
> A day ago we were testing RTC alarm on NVIDIA Tegra devices and noticed that there is a problem in the RTC core where it schedules __rtc_set_alarm work when alarm is set, but this work isn't flushed before RTC drivers are suspended. In general RTC devices can't be accessed once driver's suspend is invoked, creating the problem.
>
> Please see this example:
>
> # rtcwake -s15 -mmem
>
> On Ouya board:
>
> PM: suspend entry (deep)
> Filesystems sync: 0.001 seconds
> Freezing user space processes ... (elapsed 0.002 seconds) done.
> OOM killer disabled.
> Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
> smsc95xx 1-1:1.0 enxb85af7003b21: entering SUSPEND2 mode
> ------------[ cut here ]------------
> WARNING: CPU: 1 PID: 1337 at drivers/i2c/i2c-core.h:54 __i2c_transfer+0x6d0/0x6ec
> i2c i2c-1: Transfer while suspended
> Modules linked in: brcmfmac brcmutil
> CPU: 1 PID: 1337 Comm: kworker/1:3 Not tainted 5.11.0-rc2-next-20210108-15881-g0baf1450b32d #196
> Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
> Workqueue: events rtc_timer_do_work
> [<c0110fd8>] (unwind_backtrace) from [<c010b90c>] (show_stack+0x10/0x14)
> [<c010b90c>] (show_stack) from [<c0c5ca44>] (dump_stack+0xc4/0xd8)
> [<c0c5ca44>] (dump_stack) from [<c0124c94>] (__warn+0xec/0x104)
> [<c0124c94>] (__warn) from [<c0c5a06c>] (warn_slowpath_fmt+0x98/0xc8)
> [<c0c5a06c>] (warn_slowpath_fmt) from [<c082e850>] (__i2c_transfer+0x6d0/0x6ec)
> [<c082e850>] (__i2c_transfer) from [<c082e908>] (i2c_transfer+0x9c/0x108)
> [<c082e908>] (i2c_transfer) from [<c06f43a4>] (regmap_i2c_read+0x60/0x9c)
> [<c06f43a4>] (regmap_i2c_read) from [<c06ef848>] (_regmap_raw_read+0x104/0x314)
> [<c06ef848>] (_regmap_raw_read) from [<c06efa9c>] (_regmap_bus_read+0x44/0x70)
> Disabling non-boot CPUs ...
> [<c06efa9c>] (_regmap_bus_read) from [<c06ee3a8>] (_regmap_read+0x60/0x180)
> [<c06ee3a8>] (_regmap_read) from [<c06eea38>] (_regmap_update_bits+0xbc/0xf8)
> [<c06eea38>] (_regmap_update_bits) from [<c06f004c>] (regmap_update_bits_base+0x4c/0x70)
> [<c06f004c>] (regmap_update_bits_base) from [<c082c2b8>] (tps65910_rtc_read_time+0x50/0x134)
> [<c082c2b8>] (tps65910_rtc_read_time) from [<c0822c94>] (__rtc_read_time+0x48/0x94)
> [<c0822c94>] (__rtc_read_time) from [<c0822ed8>] (__rtc_set_alarm+0x80/0x1dc)
> [<c0822ed8>] (__rtc_set_alarm) from [<c0824cf4>] (rtc_timer_do_work+0x254/0x448)
> [<c0824cf4>] (rtc_timer_do_work) from [<c0140b9c>] (process_one_work+0x1dc/0x5a0)
> [<c0140b9c>] (process_one_work) from [<c0140fac>] (worker_thread+0x4c/0x520)
> [<c0140fac>] (worker_thread) from [<c0148618>] (kthread+0x18c/0x190)
> [<c0148618>] (kthread) from [<c01001b0>] (ret_from_fork+0x14/0x24)
> Exception stack(0xc5709fb0 to 0xc5709ff8)
> 9fa0: 00000000 00000000 00000000 00000000
> 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> ---[ end trace 2df194007d41e38b ]---
> tps65910-rtc tps65910-rtc: RTC CTRL reg update failed with err:-108
> tps65910-rtc tps65910-rtc: RTC CTRL reg update failed with err:-108
> tps65910-rtc tps65910-rtc: RTC CTRL reg update failed with err:-108
> tps65910-rtc tps65910-rtc: RTC CTRL reg update failed with err:-108
> rtc rtc0: __rtc_set_alarm: err=-108
> tps65910-rtc tps65910-rtc: RTC CTRL reg update failed with err:-108
> IRQ 26: no longer affine to CPU1
> IRQ 27: no longer affine to CPU2
> IRQ 28: no longer affine to CPU3
> Entering suspend state LP1
> Enabling non-boot CPUs ...
> CPU1 is up
>
> On PAZ00 board:
>
> PM: suspend entry (deep)
> Filesystems sync: 0.697 seconds
> Freezing user space processes ... (elapsed 0.002 seconds) done.
> OOM killer disabled.
> Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
> printk: Suspending console(s) (use no_console_suspend to debug)
> Disabling non-boot CPUs ...
> IRQ 26: no longer affine to CPU1
> Entering suspend state LP1
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 83 at drivers/i2c/i2c-core.h:54 __i2c_transfer+0x400/0x458
> i2c i2c-2: Transfer while suspended
> Modules linked in: rt2800usb rt2x00usb rt2800lib rt2x00lib xfs libcrc32c fuse crc32_generic f2fs tegra_drm gpu_sched panel_simple tegra20_emc ci_hdrc_tegra host1x_drv iova
> CPU: 0 PID: 83 Comm: kworker/0:2 Not tainted 5.11.0-rc2-next-20210106-tegra+ #181
> Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
> Workqueue: events_power_efficient sync_hw_clock
> [<c010ec60>] (unwind_backtrace) from [<c010a1f8>] (show_stack+0x10/0x14)
> [<c010a1f8>] (show_stack) from [<c0a86fe4>] (dump_stack+0xc0/0xd4)
> [<c0a86fe4>] (dump_stack) from [<c0a83bc0>] (__warn+0xc0/0x11c)
> [<c0a83bc0>] (__warn) from [<c0a83cb4>] (warn_slowpath_fmt+0x98/0xc0)
> [<c0a83cb4>] (warn_slowpath_fmt) from [<c071a990>] (__i2c_transfer+0x400/0x458)
> [<c071a990>] (__i2c_transfer) from [<c071aa84>] (i2c_transfer+0x9c/0x108)
> [<c071aa84>] (i2c_transfer) from [<c05d66f4>] (regmap_i2c_read+0x60/0x90)
> [<c05d66f4>] (regmap_i2c_read) from [<c05d2060>] (_regmap_raw_read+0xe0/0x160)
> [<c05d2060>] (_regmap_raw_read) from [<c05d2124>] (_regmap_bus_read+0x44/0x70)
> [<c05d2124>] (_regmap_bus_read) from [<c05d1144>] (_regmap_read+0x60/0xb8)
> [<c05d1144>] (_regmap_read) from [<c05d160c>] (_regmap_update_bits+0xb0/0xec)
> [<c05d160c>] (_regmap_update_bits) from [<c05d2740>] (regmap_update_bits_base+0x50/0x74)
> [<c05d2740>] (regmap_update_bits_base) from [<c05e5b80>] (tps6586x_clr_bits+0x24/0x2c)
> [<c05e5b80>] (tps6586x_clr_bits) from [<c0718138>] (tps6586x_rtc_set_time+0x68/0x104)
> [<c0718138>] (tps6586x_rtc_set_time) from [<c071120c>] (rtc_set_time+0xcc/0x178)
> [<c071120c>] (rtc_set_time) from [<c01a3078>] (sync_hw_clock+0x1d0/0x250)
> [<c01a3078>] (sync_hw_clock) from [<c013e080>] (process_one_work+0x1e8/0x44c)
> [<c013e080>] (process_one_work) from [<c013e348>] (worker_thread+0x64/0x5a8)
> [<c013e348>] (worker_thread) from [<c014402c>] (kthread+0x148/0x14c)
> [<c014402c>] (kthread) from [<c01001b0>] (ret_from_fork+0x14/0x24)
> Exception stack(0xc59d5fb0 to 0xc59d5ff8)
> 5fa0: 00000000 00000000 00000000 00000000
> 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> ---[ end trace f97d91a3f84ea228 ]---
> tps6586x-rtc tps6586x-rtc: failed to clear RTC_ENABLE
> tps6586x-rtc tps6586x-rtc: read counter failed with err -108
> tps6586x-rtc tps6586x-rtc: read counter failed with err -108
> tps6586x-rtc tps6586x-rtc: read counter failed with err -108
> tps6586x-rtc tps6586x-rtc: read counter failed with err -108
> tps6586x-rtc tps6586x-rtc: read counter failed with err -108
> rtc rtc0: __rtc_set_alarm: err=-108
> tps6586x-rtc tps6586x-rtc: read counter failed with err -108
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 83 at drivers/mfd/tps6586x.c:266 tps6586x_irq_sync_unlock+0x6c/0x70
> Modules linked in: rt2800usb rt2x00usb rt2800lib rt2x00lib xfs libcrc32c fuse crc32_generic f2fs tegra_drm gpu_sched panel_simple tegra20_emc ci_hdrc_tegra host1x_drv iova
> CPU: 0 PID: 83 Comm: kworker/0:2 Tainted: G W 5.11.0-rc2-next-20210106-tegra+ #181
> Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
> Workqueue: events rtc_timer_do_work
> [<c010ec60>] (unwind_backtrace) from [<c010a1f8>] (show_stack+0x10/0x14)
> [<c010a1f8>] (show_stack) from [<c0a86fe4>] (dump_stack+0xc0/0xd4)
> [<c0a86fe4>] (dump_stack) from [<c0a83bc0>] (__warn+0xc0/0x11c)
> [<c0a83bc0>] (__warn) from [<c0a83c80>] (warn_slowpath_fmt+0x64/0xc0)
> [<c0a83c80>] (warn_slowpath_fmt) from [<c05e5d6c>] (tps6586x_irq_sync_unlock+0x6c/0x70)
> [<c05e5d6c>] (tps6586x_irq_sync_unlock) from [<c0182cb0>] (__disable_irq_nosync+0x58/0x88)
> [<c0182cb0>] (__disable_irq_nosync) from [<c01854b0>] (disable_irq+0xc/0x20)
> [<c01854b0>] (disable_irq) from [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable+0x4c/0x58)
> [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable) from [<c0711b38>] (rtc_timer_do_work+0xfc/0x1dc)
> [<c0711b38>] (rtc_timer_do_work) from [<c013e080>] (process_one_work+0x1e8/0x44c)
> [<c013e080>] (process_one_work) from [<c013e348>] (worker_thread+0x64/0x5a8)
> [<c013e348>] (worker_thread) from [<c014402c>] (kthread+0x148/0x14c)
> [<c014402c>] (kthread) from [<c01001b0>] (ret_from_fork+0x14/0x24)
> Exception stack(0xc59d5fb0 to 0xc59d5ff8)
> 5fa0: 00000000 00000000 00000000 00000000
> 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> ---[ end trace f97d91a3f84ea229 ]---
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 83 at drivers/mfd/tps6586x.c:266 tps6586x_irq_sync_unlock+0x6c/0x70
> Modules linked in: rt2800usb rt2x00usb rt2800lib rt2x00lib xfs libcrc32c fuse crc32_generic f2fs tegra_drm gpu_sched panel_simple tegra20_emc ci_hdrc_tegra host1x_drv iova
> CPU: 0 PID: 83 Comm: kworker/0:2 Tainted: G W 5.11.0-rc2-next-20210106-tegra+ #181
> Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
> Workqueue: events rtc_timer_do_work
> [<c010ec60>] (unwind_backtrace) from [<c010a1f8>] (show_stack+0x10/0x14)
> [<c010a1f8>] (show_stack) from [<c0a86fe4>] (dump_stack+0xc0/0xd4)
> [<c0a86fe4>] (dump_stack) from [<c0a83bc0>] (__warn+0xc0/0x11c)
> [<c0a83bc0>] (__warn) from [<c0a83c80>] (warn_slowpath_fmt+0x64/0xc0)
> [<c0a83c80>] (warn_slowpath_fmt) from [<c05e5d6c>] (tps6586x_irq_sync_unlock+0x6c/0x70)
> [<c05e5d6c>] (tps6586x_irq_sync_unlock) from [<c0182cb0>] (__disable_irq_nosync+0x58/0x88)
> [<c0182cb0>] (__disable_irq_nosync) from [<c01854b0>] (disable_irq+0xc/0x20)
> [<c01854b0>] (disable_irq) from [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable+0x4c/0x58)
> [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable) from [<c0711b38>] (rtc_timer_do_work+0xfc/0x1dc)
> [<c0711b38>] (rtc_timer_do_work) from [<c013e080>] (process_one_work+0x1e8/0x44c)
> [<c013e080>] (process_one_work) from [<c013e348>] (worker_thread+0x64/0x5a8)
> [<c013e348>] (worker_thread) from [<c014402c>] (kthread+0x148/0x14c)
> [<c014402c>] (kthread) from [<c01001b0>] (ret_from_fork+0x14/0x24)
> Exception stack(0xc59d5fb0 to 0xc59d5ff8)
> 5fa0: 00000000 00000000 00000000 00000000
> 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> ---[ end trace f97d91a3f84ea22a ]---
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 83 at drivers/mfd/tps6586x.c:266 tps6586x_irq_sync_unlock+0x6c/0x70
> Modules linked in: rt2800usb rt2x00usb rt2800lib rt2x00lib xfs libcrc32c fuse crc32_generic f2fs tegra_drm gpu_sched panel_simple tegra20_emc ci_hdrc_tegra host1x_drv iova
> CPU: 0 PID: 83 Comm: kworker/0:2 Tainted: G W 5.11.0-rc2-next-20210106-tegra+ #181
> Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
> Workqueue: events rtc_timer_do_work
> [<c010ec60>] (unwind_backtrace) from [<c010a1f8>] (show_stack+0x10/0x14)
> [<c010a1f8>] (show_stack) from [<c0a86fe4>] (dump_stack+0xc0/0xd4)
> [<c0a86fe4>] (dump_stack) from [<c0a83bc0>] (__warn+0xc0/0x11c)
> [<c0a83bc0>] (__warn) from [<c0a83c80>] (warn_slowpath_fmt+0x64/0xc0)
> [<c0a83c80>] (warn_slowpath_fmt) from [<c05e5d6c>] (tps6586x_irq_sync_unlock+0x6c/0x70)
> [<c05e5d6c>] (tps6586x_irq_sync_unlock) from [<c0182cb0>] (__disable_irq_nosync+0x58/0x88)
> [<c0182cb0>] (__disable_irq_nosync) from [<c01854b0>] (disable_irq+0xc/0x20)
> [<c01854b0>] (disable_irq) from [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable+0x4c/0x58)
> [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable) from [<c0711b38>] (rtc_timer_do_work+0xfc/0x1dc)
> [<c0711b38>] (rtc_timer_do_work) from [<c013e080>] (process_one_work+0x1e8/0x44c)
> [<c013e080>] (process_one_work) from [<c013e348>] (worker_thread+0x64/0x5a8)
> [<c013e348>] (worker_thread) from [<c014402c>] (kthread+0x148/0x14c)
> [<c014402c>] (kthread) from [<c01001b0>] (ret_from_fork+0x14/0x24)
> Exception stack(0xc59d5fb0 to 0xc59d5ff8)
> 5fa0: 00000000 00000000 00000000 00000000
> 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> ---[ end trace f97d91a3f84ea22b ]---
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 83 at drivers/mfd/tps6586x.c:266 tps6586x_irq_sync_unlock+0x6c/0x70
> Modules linked in: rt2800usb rt2x00usb rt2800lib rt2x00lib xfs libcrc32c fuse crc32_generic f2fs tegra_drm gpu_sched panel_simple tegra20_emc ci_hdrc_tegra host1x_drv iova
> CPU: 0 PID: 83 Comm: kworker/0:2 Tainted: G W 5.11.0-rc2-next-20210106-tegra+ #181
> Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
> Workqueue: events rtc_timer_do_work
> [<c010ec60>] (unwind_backtrace) from [<c010a1f8>] (show_stack+0x10/0x14)
> [<c010a1f8>] (show_stack) from [<c0a86fe4>] (dump_stack+0xc0/0xd4)
> [<c0a86fe4>] (dump_stack) from [<c0a83bc0>] (__warn+0xc0/0x11c)
> [<c0a83bc0>] (__warn) from [<c0a83c80>] (warn_slowpath_fmt+0x64/0xc0)
> [<c0a83c80>] (warn_slowpath_fmt) from [<c05e5d6c>] (tps6586x_irq_sync_unlock+0x6c/0x70)
> [<c05e5d6c>] (tps6586x_irq_sync_unlock) from [<c0182cb0>] (__disable_irq_nosync+0x58/0x88)
> [<c0182cb0>] (__disable_irq_nosync) from [<c01854b0>] (disable_irq+0xc/0x20)
> [<c01854b0>] (disable_irq) from [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable+0x4c/0x58)
> [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable) from [<c0711b38>] (rtc_timer_do_work+0xfc/0x1dc)
> [<c0711b38>] (rtc_timer_do_work) from [<c013e080>] (process_one_work+0x1e8/0x44c)
> [<c013e080>] (process_one_work) from [<c013e348>] (worker_thread+0x64/0x5a8)
> [<c013e348>] (worker_thread) from [<c014402c>] (kthread+0x148/0x14c)
> [<c014402c>] (kthread) from [<c01001b0>] (ret_from_fork+0x14/0x24)
> Exception stack(0xc59d5fb0 to 0xc59d5ff8)
> 5fa0: 00000000 00000000 00000000 00000000
> 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> ---[ end trace f97d91a3f84ea22c ]---
> Enabling non-boot CPUs ...
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 83 at drivers/mfd/tps6586x.c:266 tps6586x_irq_sync_unlock+0x6c/0x70
> Modules linked in: rt2800usb rt2x00usb rt2800lib rt2x00lib xfs libcrc32c fuse crc32_generic f2fs tegra_drm gpu_sched panel_simple tegra20_emc ci_hdrc_tegra host1x_drv iova
> CPU: 0 PID: 83 Comm: kworker/0:2 Tainted: G W 5.11.0-rc2-next-20210106-tegra+ #181
> Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
> Workqueue: events rtc_timer_do_work
> [<c010ec60>] (unwind_backtrace) from [<c010a1f8>] (show_stack+0x10/0x14)
> [<c010a1f8>] (show_stack) from [<c0a86fe4>] (dump_stack+0xc0/0xd4)
> [<c0a86fe4>] (dump_stack) from [<c0a83bc0>] (__warn+0xc0/0x11c)
> [<c0a83bc0>] (__warn) from [<c0a83c80>] (warn_slowpath_fmt+0x64/0xc0)
> [<c0a83c80>] (warn_slowpath_fmt) from [<c05e5d6c>] (tps6586x_irq_sync_unlock+0x6c/0x70)
> [<c05e5d6c>] (tps6586x_irq_sync_unlock) from [<c0182cb0>] (__disable_irq_nosync+0x58/0x88)
> [<c0182cb0>] (__disable_irq_nosync) from [<c01854b0>] (disable_irq+0xc/0x20)
> [<c01854b0>] (disable_irq) from [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable+0x4c/0x58)
> [<c0717e2c>] (tps6586x_rtc_alarm_irq_enable) from [<c0711b38>] (rtc_timer_do_work+0xfc/0x1dc)
> [<c0711b38>] (rtc_timer_do_work) from [<c013e080>] (process_one_work+0x1e8/0x44c)
> [<c013e080>] (process_one_work) from [<c013e348>] (worker_thread+0x64/0x5a8)
> [<c013e348>] (worker_thread) from [<c014402c>] (kthread+0x148/0x14c)
> [<c014402c>] (kthread) from [<c01001b0>] (ret_from_fork+0x14/0x24)
> Exception stack(0xc59d5fb0 to 0xc59d5ff8)
> 5fa0: 00000000 00000000 00000000 00000000
> 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
> ---[ end trace f97d91a3f84ea22d ]---
--
Alexandre Belloni, Bootlin
Embedded Linux and Kernel engineering
https://bootlin.com