i.MX8MM Detect Wakeup Cause

[friederschrempf]

Hi,

on a i.MX8MM-based system I'm trying to do detect which IRQ actually caused the system to wake up after it has been resumed.

If I read the code correctly the Linux kernel uses PSCI calls into the TF-A and TF-A uses the GPC registers to configure the wakeup sources (GPC_IMR) and suspend/disable the CPUs.

After resuming, execution is continued in the kernel and I'm wondering if it is possible to use the GPC_ISR registers to detect which IRQ actually caused the system to wake up. Reading those registers from Linux userspace only shows that the bit for the IRQ 89 (SRC Interrupt Request) is set and not any of the GPIO IRQs that triggered the wakeup.

:0x303a0070     =0x00000000
:0x303a0074     =0x00000000
:0x303a0078     =0x02000000
:0x303a007c     =0x00000000

Can anyone provide some advice if this is possible somehow or if there might be other approaches?

Thanks!

[laodzu]

Hi,

it seems that the Linux kernel has a generic solution for this. Unfortunately, the NXP kernel does not enable it by default, so you have to mess with the kernel build and enable this option (in kernel/power/Kconfig):

147 config PM_WAKELOCKS
148 bool "User space wakeup sources interface"
149 depends on PM_SLEEP
150 default n
151 help
152 Allow user space to create, activate and deactivate wakeup source
153 objects with the help of a sysfs-based interface.

I rebuilt the kernel with this option and booted it on imx8mmevk and sure enough I can access the data:

root@imx8mmevk:/sys/kernel/debug# cat wakeup_sources
name active_count event_count wakeup_count expire_count active_since total_time max_time last_change prevent_suspend_time
sap_dfs_wakelock 0 0 0 0 0 0 0 00
qcom_sap_wakelock 0 0 0 0 0 0 0 00
qcom_rx_wakelock 0 0 0 0 0 0 0 00
wlan_auto_shutdown_wl 0 0 0 0 0 0 0 00
wlan_ap_assoc_lost_wl 0 0 0 0 0 0 0 00
wlan_disassoc_rec_wl 0 0 0 0 0 0 0 00
wlan_deauth_rec_wl 0 0 0 0 0 0 0 00
wlan_assoc_req_wl 0 0 0 0 0 0 0 00
wlan_auth_req_wl 0 0 0 0 0 0 0 00
wlan_wow_wl 0 0 0 0 0 0 0 0 0
wlan_extscan_wl 0 0 0 0 0 0 0 0 0
wlan_pno_wl 0 0 0 0 0 0 0 0 0
wlan 1 1 0 0 0 1284 1284 7971 0
tcpm-source-psy-1-0050 3 3 0 0 0 11 11 2992 0
alarmtimer 0 0 0 0 0 0 0 0 0
30370000.snvs:snvs-rtc-lp 1 1 0 0 0 0 0 15356 0
30370000.snvs:snvs-powerkey 0 0 0 0 0 0 0 00
root@imx8mmevk:/sys/kernel/debug#

Suspending the board with "echo mem> /sys/power/state" and pressing the ONOFF button next to the reset button (next to the power switch), wakes the board and the event is registered as expected:

root@imx8mmevk:/sys/kernel/debug# grep powerkey wakeup_sources
30370000.snvs:snvs-powerkey 1 1 0 0 0 0 0 236334 0
root@imx8mmevk:/sys/kernel/debug#

It is a pity that this does not work with ttymxc1 but this is probably a bug and should be fixed over time

Best wishes

  Detlev

[friederschrempf]

Hi Detlev,

I probably should have mentioned that I'm working on 5.4 mainline instead of the NXP kernel, but I guess in this area it shouldn't make such a big difference.

Thanks for pointing out the PM_WAKELOCKS option. I didn't know it exists. I found out, that the data available in /sys/kernel/debug/wakeup_sources also seems to be available in the sysfs in the individual device nodes without enabling PM_WAKELOCKS. In my case I have a pushbutton on a GPIO as a wakeup source using the gpio-keys driver and I can read the same values from:

/sys/devices/platform/gpio-keys/power/wakeup_*

The problem I have with this approach is, that the most essential value "wakeup_count" isn't updated and it doesn't seem to be updated in your example either. I would expect that this value returns the number of actual wakeups caused by this source. The other values such as "active_count" and "event_count" are updated, but I can't really use them to detect the actual wakeup source as they are incremented every time the interrupt is triggered no matter if this causes a wakeup or not.

For example if I have two different wakeup sources enabled and both are triggered shortly after one another, only the first one actually causes the wakeup, but at the time the system is up and I read the active_count for both sources, both have been incremented and I can't tell which one actually was the reason.

So the direction is definitely the right one, but without wakeup_count being updated I can't see how to detect the wakeup cause reliably.

Best regards

Frieder

[laodzu]

Hi Frieder,

[I don't know why, but I posted this already yesterday but it never appeared here, so this is another test]

the single file solution looks attractive to me, because you can atomically save all the counts at once rather than walking all the sysfs files for your wake up sources.  If you look into the suspend code you will find that people think a lot about race conditions anyway, so we may as well try to minimize chances for them.

So in effect I was thinking about an approach like this:

root@imx8mmevk:~# cp /sys/kernel/debug/wakeup_sources /tmp ; echo mem > /sys/power/state ; diff -u {/tmp/,/sys/kernel/debug/}/wakeup_sources
[ 4636.322670] PM: suspend entry (deep)
[ 4636.395487] Filesystems sync: 0.069 seconds
[ 4636.401051] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 4636.409406] OOM killer disabled.
[ 4636.412638] Freezing remaining freezable tasks ... (elapsed 0.021 seconds) done.
[ 4636.441985] printk: Suspending console(s) (use no_console_suspend to debug)
[ 4636.459573] HIFsuspendwow TODO
[ 4636.615657] fec 30be0000.ethernet eth0: Link is Down
[ 4636.617407] PM: suspend devices took 0.168 seconds
[ 4636.619567] Disabling non-boot CPUs ...
[ 4636.619889] IRQ 6: no longer affine to CPU1
[ 4636.620006] CPU1: shutdown
[ 4636.621020] psci: CPU1 killed (polled 0 ms)
[ 4636.622919] CPU2: shutdown
[ 4636.623935] psci: CPU2 killed (polled 0 ms)
[ 4636.625636] CPU3: shutdown
[ 4636.625641] psci: CPU3 killed (polled 0 ms)
[ 4636.626989] Enabling non-boot CPUs ...
[ 4636.627383] Detected VIPT I-cache on CPU1
[ 4636.627403] GICv3: CPU1: found redistributor 1 region 0:0x00000000388a0000
[ 4636.627436] CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
[ 4636.627836] CPU1 is up
[ 4636.628156] Detected VIPT I-cache on CPU2
[ 4636.628167] GICv3: CPU2: found redistributor 2 region 0:0x00000000388c0000
[ 4636.628185] CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
[ 4636.628431] CPU2 is up
[ 4636.628767] Detected VIPT I-cache on CPU3
[ 4636.628779] GICv3: CPU3: found redistributor 3 region 0:0x00000000388e0000
[ 4636.628797] CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
[ 4636.629065] CPU3 is up
[ 4636.671554] PM: resume devices took 0.040 seconds
[ 4636.780941] OOM killer enabled.
[ 4636.784083] Restarting tasks ... done.
[ 4636.790976] PM: suspend exit
--- /tmp//wakeup_sources 2020-12-15 16:08:53.863608280 +0000
+++ /sys/kernel/debug//wakeup_sources 1970-01-01 00:00:00.188000000 +0000
@@ -15,4 +15,4 @@
tcpm-source-psy-1-0050 3 3 0 0 0 0 03012 0
alarmtimer 0 0 0 0 0 0 0 00
30370000.snvs:snvs-rtc-lp 7 7 0 0 0 0 04036444 0
-30370000.snvs:snvs-powerkey 1 1 0 0 0 0 03750926 0
+30370000.snvs:snvs-powerkey 2 2 0 0 0 0 04637103 0
root@imx8mmevk:~# [ 4638.662280] fec 30be0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[ 5899.388169] audit: type=1006 audit(1608049801.213:5): pid=1000 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=4 res=1
[ 9499.380057] audit: type=1006 audit(1608053401.273:6): pid=1015 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=5 res=1
[13099.357861] audit: type=1006 audit(1608057001.332:7): pid=1027 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=6 res=1
[16699.335179] audit: type=1006 audit(1608060601.396:8): pid=1040 uid=0 old-auid=4294967295 auid=0 tty=(none) old-ses=4294967295 ses=7 res=1

root@imx8mmevk:~#

In other words, take a snapshot of all counts immediatly before going to sleep and check them again immediatly after waking up.  This means the differences have been generated between going to sleep and before waking up.  That way I don't care if they are "event counts" or "wakeup counts". So even though there may be multiple differences, they should be treated all as a "wakeup cause" because they are by definition indistinguishible in this time frame.

[friederschrempf]

Hi Detlev,

thanks for the reply. I got an e-mail notification for your post yesterday, but it didn't show up for some reason.

Your proposal sounds reasonable and it might be enough for some applications. Still it would be nice to be able to detect the "real" wakeup cause.

I had a closer look at the kernel docs and code and I think I actually found two other possible solutions. I haven't tested them closely so far, but it looks promising.

1. Enable CONFIG_PM_DEBUG

This will add an additional property under /sys/power/pm_wakeup_irq. After a suspend/resume cycle I can read the index of the IRQ that triggered the wakeup. In my case I tested resume from the SNVS RTC alarm (IRQ 21) and from GPIO01_IO6 (IRQ51). I don't really know why I get a GPT interrupt for the GPIO. To match the IRQ indices with the device, I use the information from /proc/interrupts.

2. Use the wakeup_count of the wakeup source

The reason why wakeup_count isn't updated seems to be that it needs to be enabled first. The explanation in https://www.kernel.org/doc/Documentation/ABI/testing/sysfs-power is not really self-explanatory but the commands below seem to work for me and I get an updated value for the wakeup_count of the correct source.

I think with one of the three options in total we can achieve what we want and I will propose this to our customer.

Thanks a lot for your help!

Best regards

Frieder

~# cat /sys/kernel/debug/wakeup_sources
name            active_count    event_count     wakeup_count    expire_count    active_since    total_time      max_time        last_change     prevent_suspend_time
3-0028          0               0               0               0               0               0               0               0               0
gpio-keys       0               0               0               0               0               0               0               0               0
30370000.snvs:snvs-rtc-lp       0               0               0               0               0               0               0               0               0
alarmtimer      0               0               0               0               0               0               0               0               0
3-0032          2               2               2               0               0               14              7               6451            0
deleted         0               0               0               0               0               0               0               0               0

~# cat /sys/power/wakeup_count
2

~# echo 2 > /sys/power/wakeup_count

~# echo mem > /sys/power/state
[   62.279247] PM: suspend entry (deep)
[   62.282920] Filesystems sync: 0.000 seconds
[   62.290218] Freezing user space processes ... (elapsed 0.001 seconds) done.
[   62.298606] OOM killer disabled.
[   62.301844] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[   62.311109] mwifiex_sdio mmc2:0001:1: None of the WOWLAN triggers enabled
[   62.447461] Disabling non-boot CPUs ...
[   62.451798] CPU1: shutdown
[   62.454531] psci: CPU1 killed (polled 0 ms)
[   62.459785] CPU2: shutdown
[   62.462520] psci: CPU2 killed (polled 0 ms)
[   62.467624] CPU3: shutdown
[   62.470352] psci: CPU3 killed (polled 0 ms)
[   62.475192] Enabling non-boot CPUs ...
[   62.479233] Detected VIPT I-cache on CPU1
[   62.479255] GICv3: CPU1: found redistributor 1 region 0:0x00000000388a0000
[   62.479295] CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
[   62.479775] CPU1 is up
[   62.499728] Detected VIPT I-cache on CPU2
[   62.499739] GICv3: CPU2: found redistributor 2 region 0:0x00000000388c0000
[   62.499760] CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
[   62.500063] CPU2 is up
[   62.519995] Detected VIPT I-cache on CPU3
[   62.520008] GICv3: CPU3: found redistributor 3 region 0:0x00000000388e0000
[   62.520028] CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
[   62.520377] CPU3 is up
[   62.606753] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[   62.613419] [drm] No driver support for vblank timestamp query.
[   62.619355] OOM killer enabled.
[   62.622508] Restarting tasks ... done.
[   62.661659] PM: suspend exit

~# cat /sys/power/wakeup_count
4

~# cat /sys/kernel/debug/wakeup_sources
name            active_count    event_count     wakeup_count    expire_count    active_since    total_time      max_time        last_change     prevent_suspend_time
3-0028          0               0               0               0               0               0               0               0               0
gpio-keys       2               8               8               0               0               21              11              62696           0
30370000.snvs:snvs-rtc-lp       0               0               0               0               0               0               0               0               0
alarmtimer      0               0               0               0               0               0               0               0               0
3-0032          2               2               2               0               0               14              7               6451            0
deleted         0               0               0               0               0               0               0               0               0

[laodzu]

Hi Frieder,

I find the single file more attractive than walking all your wakeup sources and visiting individual files as this allows for even more races than neccessary.  If you read the code in this area you will notice that there are many possibilities for races anyway.

So what I essentially had in mind is this approach:

root@imx8mmevk:~# cp /sys/kernel/debug/wakeup_sources /tmp ; echo mem > /sys/power/state ; diff -u {/tmp/,/sys/kernel/debug/}/wakeup_sources
[ 4636.322670] PM: suspend entry (deep)
[ 4636.395487] Filesystems sync: 0.069 seconds
[ 4636.401051] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 4636.409406] OOM killer disabled.
[ 4636.412638] Freezing remaining freezable tasks ... (elapsed 0.021 seconds) done.
[ 4636.441985] printk: Suspending console(s) (use no_console_suspend to debug)
[ 4636.459573] HIFsuspendwow TODO
[ 4636.615657] fec 30be0000.ethernet eth0: Link is Down
[ 4636.617407] PM: suspend devices took 0.168 seconds
[ 4636.619567] Disabling non-boot CPUs ...
[ 4636.619889] IRQ 6: no longer affine to CPU1
[ 4636.620006] CPU1: shutdown
[ 4636.621020] psci: CPU1 killed (polled 0 ms)
[ 4636.622919] CPU2: shutdown
[ 4636.623935] psci: CPU2 killed (polled 0 ms)
[ 4636.625636] CPU3: shutdown
[ 4636.625641] psci: CPU3 killed (polled 0 ms)
[ 4636.626989] Enabling non-boot CPUs ...
[ 4636.627383] Detected VIPT I-cache on CPU1
[ 4636.627403] GICv3: CPU1: found redistributor 1 region 0:0x00000000388a0000
[ 4636.627436] CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
[ 4636.627836] CPU1 is up
[ 4636.628156] Detected VIPT I-cache on CPU2
[ 4636.628167] GICv3: CPU2: found redistributor 2 region 0:0x00000000388c0000
[ 4636.628185] CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
[ 4636.628431] CPU2 is up
[ 4636.628767] Detected VIPT I-cache on CPU3
[ 4636.628779] GICv3: CPU3: found redistributor 3 region 0:0x00000000388e0000
[ 4636.628797] CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
[ 4636.629065] CPU3 is up
[ 4636.671554] PM: resume devices took 0.040 seconds
[ 4636.780941] OOM killer enabled.
[ 4636.784083] Restarting tasks ... done.
[ 4636.790976] PM: suspend exit
--- /tmp//wakeup_sources 2020-12-15 16:08:53.863608280 +0000
+++ /sys/kernel/debug//wakeup_sources 1970-01-01 00:00:00.188000000 +0000
@@ -15,4 +15,4 @@
tcpm-source-psy-1-0050 3 3 0 0 0 0 03012 0
alarmtimer 0 0 0 0 0 0 0 00
30370000.snvs:snvs-rtc-lp 7 7 0 0 0 0 04036444 0
-30370000.snvs:snvs-powerkey 1 1 0 0 0 0 03750926 0
+30370000.snvs:snvs-powerkey 2 2 0 0 0 0 04637103 0
root@imx8mmevk:~# [ 4638.662280] fec 30be0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off

In other words, save all the counts immediatly before going to sleep and then determine the difference after waking.  This way the differences fall into the time between going to sleep and waking up.  Of course there may be multiple entries in the diff but I would simply treat them all as real "wakeups" even though technically only one of them woke up the system.