Re: "PM / wakeup: Show wakeup sources stats in sysfs" causes boot warnings

From: Stephen Boyd
Date: Wed Aug 14 2019 - 03:03:24 EST


Quoting Qian Cai (2019-08-13 14:32:56)
> The linux-next commit "PM / wakeup: Show wakeup sources stats in sysfs" [1]
> introduced some baddies during boot on several x86 servers. Reverted the commit
> fixed the issue.
>
> [1] https://lore.kernel.org/lkml/20190807014846.143949-4-trong@xxxxxxxxxxx/
>
> [ÂÂÂ39.195053][ÂÂÂÂT1] serio: i8042 KBD port at 0x60,0x64 irq 1
> [ÂÂÂ39.197347][ÂÂÂÂT1] kobject_add_internal failed for wakeup (error: -2 parent: serio0)
> [ÂÂÂ39.199845][ÂÂÂÂT1] INFO: trying to register non-static key.
> [ÂÂÂ39.201582][ÂÂÂÂT1] the code is fine but needs lockdep annotation.
> [ÂÂÂ39.203477][ÂÂÂÂT1] turning off the locking correctness validator.
> [ÂÂÂ39.205399][ÂÂÂÂT1] CPU: 12 PID: 1 Comm: swapper/0 Not tainted 5.3.0-rc4-
> next-20190813 #3
> [ÂÂÂ39.207938][ÂÂÂÂT1] Hardware name: HP ProLiant XL420 Gen9/ProLiant XL420
> Gen9, BIOS U19 12/27/2015
> [ÂÂÂ39.210606][ÂÂÂÂT1] Call Trace:
> [ÂÂÂ39.210606][ÂÂÂÂT1]ÂÂdump_stack+0x62/0x9a
> [ÂÂÂ39.210606][ÂÂÂÂT1]ÂÂregister_lock_class+0x95a/0x960
> [ÂÂÂ39.210606][ÂÂÂÂT1]ÂÂ? __platform_driver_probe+0xcd/0x230
> [ÂÂÂ39.210606][ÂÂÂÂT1]ÂÂ? __platform_create_bundle+0xc0/0xe0
> [ÂÂÂ39.210606][ÂÂÂÂT1]ÂÂ? i8042_init+0x4ec/0x578
> [ÂÂÂ39.210606][ÂÂÂÂT1]ÂÂ? do_one_initcall+0xfe/0x45a
> [ÂÂÂ39.219571][ÂÂÂÂT1]ÂÂ? kernel_init_freeable+0x614/0x6a7
> [ÂÂÂ39.219571][ÂÂÂÂT1]ÂÂ? kernel_init+0x11/0x138
> [ÂÂÂ39.219571][ÂÂÂÂT1]ÂÂ? ret_from_fork+0x35/0x40
> [ÂÂÂ39.219571][ÂÂÂÂT1]ÂÂ? is_dynamic_key+0xf0/0xf0
> [ÂÂÂ39.219571][ÂÂÂÂT1]ÂÂ? rwlock_bug.part.0+0x60/0x60
> [ÂÂÂ39.219571][ÂÂÂÂT1]ÂÂ? __debug_check_no_obj_freed+0x8e/0x250
> [ÂÂÂ39.219571][ÂÂÂÂT1]ÂÂ__lock_acquire.isra.13+0x5f/0x830
> [ÂÂÂ39.229491][ÂÂÂÂT1]ÂÂ? __debug_check_no_obj_freed+0x152/0x250
> [ÂÂÂ39.229491][ÂÂÂÂT1]ÂÂlock_acquire+0x107/0x220
> [ÂÂÂ39.229491][ÂÂÂÂT1]ÂÂ? __pm_relax.part.2+0x21/0xa0
> [ÂÂÂ39.229491][ÂÂÂÂT1]ÂÂ_raw_spin_lock_irqsave+0x35/0x50
> [ÂÂÂ39.229491][ÂÂÂÂT1]ÂÂ? __pm_relax.part.2+0x21/0xa0
> [ÂÂÂ39.229491][ÂÂÂÂT1]ÂÂ__pm_relax.part.2+0x21/0xa0
> [ÂÂÂ39.239588][ÂÂÂÂT1]ÂÂwakeup_source_destroy.part.3+0x18/0x190
> [ÂÂÂ39.239588][ÂÂÂÂT1]ÂÂwakeup_source_register+0x43/0x50
> [ÂÂÂ39.239588][ÂÂÂÂT1]ÂÂdevice_wakeup_enable+0x76/0x170
> [ÂÂÂ39.239588][ÂÂÂÂT1]ÂÂdevice_set_wakeup_enable+0x13/0x20
> [ÂÂÂ39.239588][ÂÂÂÂT1]ÂÂi80probe+0x921/0xa45
> [ÂÂÂ39.339546][ÂÂÂÂT1]ÂÂ? i8042_toggle_aux+0xeb/0xeb
> [ÂÂÂ39.349486][ÂÂÂÂT1]ÂÂ? kernfs_create_link+0xce/0x100
> [ÂÂÂ39.349486][ÂÂÂÂT1]ÂÂ? sysfs_do_create_link_sd+0x7b/0xe0
> [ÂÂÂ39.349486][ÂÂÂÂT1]ÂÂ? acpi_dev_pm_attach+0x31/0xf0
> [ÂÂÂ39.349486][ÂÂÂÂT1]ÂÂplatform_drv_probe+0x51/0xe0
> [ÂÂÂ39.349486][ÂÂÂÂT1]ÂÂreally_probe+0x1a2/0x630
> [ÂÂÂ39.349486][ÂÂÂÂT1]ÂÂ? device_driver_attach+0xa0/0xa0
> [ÂÂÂ39.349486][ÂÂÂÂT1]ÂÂdriver_probe_device+0xcd/0x1f0
> [ÂÂÂ39.359562][ÂÂÂÂT1]ÂÂ? device_driver_attach+0xa0/0xa0
> [ÂÂÂ39.359562][ÂÂÂÂT1]ÂÂdevice_driver_attach+0x8f/0xa0
> [ÂÂÂ39.359562][ÂÂÂÂT1]ÂÂ__driver_attach+0xc7/0x1a0
> [ÂÂÂ39.359562][ÂÂÂÂT1]ÂÂbus_for_each_dev+0xfe/0x160
> [ÂÂÂ39.359562][ÂÂÂÂT1]ÂÂ? subsys_dev_iter_init+0x80/0x80
> [ÂÂÂ39.359562][ÂÂÂÂT1]ÂÂ? __kasan_check_read+0x11/0x20
> [ÂÂÂ39.359562][ÂÂÂÂT1]ÂÂ? _raw_spin_unlock+0x27/0x40
> [ÂÂÂ39.369488][ÂÂÂÂT1]ÂÂdriver_attach+0x2b/0x30
> [ÂÂÂ39.369488][ÂÂÂÂT1]ÂÂbus_add_driver+0x298/0x350
> [ÂÂÂ39.369488][ÂÂÂÂT1]ÂÂdriver_register+0xdc/0x1d0
> [ÂÂÂ39.369488][ÂÂÂÂT1]ÂÂ? i8042_toggle_aux+0xeb/0xeb
> [ÂÂÂ39.369488][ÂÂÂÂT1]ÂÂ__platform_driver_probe+0xcd/0x230
> [ÂÂÂ39.3ÂÂ__platform_create_bundle+0xc0/0xe0
> [ÂÂÂ39.769489][ÂÂÂÂT1]ÂÂ? i8042_toggle_aux+0xeb/0xeb
> [ÂÂÂ39.779556][ÂÂÂÂT1]ÂÂ? i8042_probe+0xa45/0xa45
> [ÂÂÂ39.779556][ÂÂÂÂT1]ÂÂi8042_init+0x4ec/0x578
> [ÂÂÂ39.779556][ÂÂÂÂT1]ÂÂ? i8042_probe+0xa45/0xa45
> [ÂÂÂ39.779556][ÂÂÂÂT1]ÂÂ? netdev_run_todo+0x2f/0x4a0
> [ÂÂÂ39.779556][ÂÂÂÂT1]ÂÂ? qdisc_create_dflt+0xf0/0xf0
> [ÂÂÂ39.779556][ÂÂÂÂT1]ÂÂ? net_olddevs_init+0x67/0x67
> [ÂÂÂ39.779556][ÂÂÂÂT1]ÂÂ? i8042_probe+0xa45/0xa45
> [ÂÂÂ39.789486][ÂÂÂÂT1]ÂÂdo_one_initcall+0xfe/0x45a
> [ÂÂÂ39.789486][ÂÂÂÂT1]ÂÂ? initcall_blacklisted+0x150/0x150
> [ÂÂÂ39.789486][ÂÂÂÂT1]ÂÂ? __kasan_check_write+0x14/0x20
> [ÂÂÂ39.789486][ÂÂÂÂT1]ÂÂ? up_write+0xee/0x2a0
> [ÂÂÂ39.789486][ÂÂÂÂT1]ÂÂkernel_init_freeable+0x614/0x6a7
> [ÂÂÂ39.789486][ÂÂÂÂT1]ÂÂ? rest_init+0x188/0x188
> [ÂÂÂ39.789486][ÂÂÂÂT1]ÂÂkernel_init+0x11/0x138
> [ÂÂÂ39.799563][ÂÂÂÂT1]ÂÂ? rest_init+0x188/0x188
> [ÂÂÂ39.799563][ÂÂÂÂT1]ÂÂret_from_fork+0x35/0x40
> [ÂÂÂ39.803412][ÂÂÂÂT1] serio: i8042 AUX port at 0x60,0x64 irq 12

Besides the bad error path causing the big stack trace, I think there's
a race between when the serio device is added with device_add() in
serio_add_port() and when i8042_register_ports() calls
device_set_wakeup_enable(). The serio_add_port() function is called from
a workqueue that is schedule to run by i8042_register_ports() calling
serio_register_port(), but otherwise there isn't any guarantee that the
workqueue has actually run by the time the function returns and
i8042_register_ports() calls device_set_wakeup_enable().

This means that the device may not have actually been registered yet,
and thus doing other device like operations on the serio device before
the workqueue runs will lead to weird behavior because the parent device
isn't fully registered with the driver core. That causes the error
message above:

> [ÂÂÂ39.197347][ÂÂÂÂT1] kobject_add_internal failed for wakeup (error: -2 parent: serio0)

So maybe we need to add another hook after the device is added
successfully so we can do the wakeup things.

I also notice that device_set_wakeup_capable() has a check to see if the
device is registered yet and it skips creating sysfs entries for the
device if it isn't created in sysfs yet. Why? Just so it can be called
before the device is created? I guess the same logic is handled by
dpm_sysfs_add() if the device is registered after calling
device_set_wakeup_*().

There's two approaches I see:

1) Do a similar check for device_set_wakeup_enable() and skip
adding the wakeup class until dpm_sysfs_add().

2) Find each case where this happens and only call wakeup APIs
on the device after the device is added.

I guess it's better to let devices have wakeup modified on them before
they're registered with the device core?

Here's approach #1
----8<-----
diff --git a/drivers/base/power/sysfs.c b/drivers/base/power/sysfs.c
index 1b9c281cbe41..27ee00f50bd7 100644
--- a/drivers/base/power/sysfs.c
+++ b/drivers/base/power/sysfs.c
@@ -5,6 +5,7 @@
#include <linux/export.h>
#include <linux/pm_qos.h>
#include <linux/pm_runtime.h>
+#include <linux/pm_wakeup.h>
#include <linux/atomic.h>
#include <linux/jiffies.h>
#include "power.h"
@@ -661,14 +662,21 @@ int dpm_sysfs_add(struct device *dev)
if (rc)
goto err_runtime;
}
+ if (dev->power.wakeup) {
+ rc = wakeup_source_sysfs_add(dev, dev->power.wakeup);
+ if (rc)
+ goto err_wakeup;
+ }
if (dev->power.set_latency_tolerance) {
rc = sysfs_merge_group(&dev->kobj,
&pm_qos_latency_tolerance_attr_group);
if (rc)
- goto err_wakeup;
+ goto err_wakeup_source;
}
return 0;

+ err_wakeup_source:
+ wakeup_source_sysfs_remove(dev->power.wakeup);
err_wakeup:
sysfs_unmerge_group(&dev->kobj, &pm_wakeup_attr_group);
err_runtime:
diff --git a/drivers/base/power/wakeup.c b/drivers/base/power/wakeup.c
index f7925820b5ca..5817b51d2b15 100644
--- a/drivers/base/power/wakeup.c
+++ b/drivers/base/power/wakeup.c
@@ -220,10 +220,12 @@ struct wakeup_source *wakeup_source_register(struct device *dev,

ws = wakeup_source_create(name);
if (ws) {
- ret = wakeup_source_sysfs_add(dev, ws);
- if (ret) {
- wakeup_source_free(ws);
- return NULL;
+ if (!dev || device_is_registered(dev)) {
+ ret = wakeup_source_sysfs_add(dev, ws);
+ if (ret) {
+ wakeup_source_free(ws);
+ return NULL;
+ }
}
wakeup_source_add(ws);
}


And here's the second approach for serio.

---8<----
diff --git a/drivers/input/serio/i8042.c b/drivers/input/serio/i8042.c
index b695094290ab..f12bed00d6d0 100644
--- a/drivers/input/serio/i8042.c
+++ b/drivers/input/serio/i8042.c
@@ -439,6 +439,24 @@ static int i8042_start(struct serio *serio)
return 0;
}

+static int i8042_added(struct serio *serio)
+{
+ device_set_wakeup_capable(&serio->dev, true);
+
+ /*
+ * On platforms using suspend-to-idle, allow the keyboard to
+ * wake up the system from sleep by enabling keyboard wakeups
+ * by default. This is consistent with keyboard wakeup
+ * behavior on many platforms using suspend-to-RAM (ACPI S3)
+ * by default.
+ */
+ if (pm_suspend_default_s2idle() &&
+ serio == i8042_ports[I8042_KBD_PORT_NO].serio)
+ device_set_wakeup_enable(&serio->dev, true);
+
+ return 0;
+}
+
/*
* i8042_stop() marks serio port as non-existing so i8042_interrupt
* will not try to send data to the port that is about to go away.
@@ -1312,6 +1330,7 @@ static int __init i8042_create_kbd_port(void)
serio->id.type = i8042_direct ? SERIO_8042 : SERIO_8042_XL;
serio->write = i8042_dumbkbd ? NULL : i8042_kbd_write;
serio->start = i8042_start;
+ serio->added = i8042_added;
serio->stop = i8042_stop;
serio->close = i8042_port_close;
serio->ps2_cmd_mutex = &i8042_mutex;
@@ -1397,17 +1416,6 @@ static void __init i8042_register_ports(void)
(unsigned long) I8042_COMMAND_REG,
i8042_ports[i].irq);
serio_register_port(serio);
- device_set_wakeup_capable(&serio->dev, true);
-
- /*
- * On platforms using suspend-to-idle, allow the keyboard to
- * wake up the system from sleep by enabling keyboard wakeups
- * by default. This is consistent with keyboard wakeup
- * behavior on many platforms using suspend-to-RAM (ACPI S3)
- * by default.
- */
- if (pm_suspend_default_s2idle() && i == I8042_KBD_PORT_NO)
- device_set_wakeup_enable(&serio->dev, true);
}
}

diff --git a/drivers/input/serio/serio.c b/drivers/input/serio/serio.c
index 29f491082926..590639467ea3 100644
--- a/drivers/input/serio/serio.c
+++ b/drivers/input/serio/serio.c
@@ -544,6 +544,8 @@ static void serio_add_port(struct serio *serio)
dev_err(&serio->dev,
"device_add() failed for %s (%s), error: %d\n",
serio->phys, serio->name, error);
+ else if (serio->added)
+ serio->added(serio);
}

/*
diff --git a/include/linux/serio.h b/include/linux/serio.h
index 6c27d413da92..2e216ba881a9 100644
--- a/include/linux/serio.h
+++ b/include/linux/serio.h
@@ -35,6 +35,7 @@ struct serio {
int (*open)(struct serio *);
void (*close)(struct serio *);
int (*start)(struct serio *);
+ int (*added)(struct serio *);
void (*stop)(struct serio *);

struct serio *parent;