FS#62391 - System journal gets flooded after resume from hibernation.

Attached to Project: Arch Linux
Opened by Arnautov Illia (skidnik) - Thursday, 18 April 2019, 20:51 GMT
Last edited by Jan de Groot (JGC) - Tuesday, 28 May 2019, 10:47 GMT
Task Type Bug Report
Category Kernel
Status Closed
Assigned To No-one
Architecture x86_64
Severity Medium
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

Description:
System journal gets flooded after resume from hibernation.
Flooding doesn't stop until system is rebooted/power cycled. Produces significant ammount of system load.

Additional info:
hardware: Dell Inspiron 11 3168
CPU/Chipset: Intel Pentium N3710
kernel version: linux-5.0.7.arch1-1

Part of journalctl output:
Apr 18 22:33:29 systemd[1]: Starting Hibernate...
Apr 18 22:33:29 kernel: PM: Image not found (code -22)
Apr 18 22:33:29 kernel: PM: hibernation entry
Apr 18 22:33:29 systemd-sleep[1085]: Suspending system...
Apr 18 22:33:29 kernel: PM: Syncing filesystems ...
Apr 18 22:34:03 systemd-journald[261]: Missed 36688 kernel messages
Apr 18 22:34:03 kernel: i2c_designware 808622C1:00: Error i2c_dw_xfer call while suspended
Apr 18 22:34:03 systemd-journald[261]: Missed 263 kernel messages
Apr 18 22:34:03 kernel: i2c_designware 808622C1:00: Error i2c_dw_xfer call while suspended
Apr 18 22:34:03 systemd-journald[261]: Missed 131 kernel messages
Apr 18 22:34:03 kernel: i2c_designware 808622C1:00: Error i2c_dw_xfer call while suspended
Apr 18 22:34:03 systemd-journald[261]: Missed 30 kernel messages
Apr 18 22:34:03 kernel: i2c_designware 808622C1:00: Error i2c_dw_xfer call while suspended

May be related to this email on LKML: https://lkml.org/lkml/2019/4/4/518

Steps to reproduce:

- Have Dell Inspiron 3168 (any other N3710 based laptop?)
- Have kernel version linux-5.0.7.arch1-1
- Have hibernation configured
- `$ systemctl hibernate`
- Resume from hibernation
- Notice about 50% CPU load, `$ journalctl -f` outputs over 9000 messages/second mentioned above.

system log attached, I removed dulicate messages due to it not fitting into upload limit.
This task depends upon

Closed by  Jan de Groot (JGC)
Tuesday, 28 May 2019, 10:47 GMT
Reason for closing:  Fixed
Comment by Arnautov Illia (skidnik) - Thursday, 18 April 2019, 20:55 GMT
Attaching system log, apparently I failed to do so.
Comment by Arnautov Illia (skidnik) - Friday, 19 April 2019, 23:13 GMT
Did some additional digging:
$ cat /sys/bus/i2c/devices/i2c-0/name
Synopsys DesignWare I2C adapter
$ /sys/bus/i2c/devices/i2c-0/i2c-DELL074D:00/uevent
DRIVER=i2c_hid
MODALIAS=acpi:DELL074D:PNP0C50:
$ cat /sys/bus/i2c/devices/i2c-0/i2c-DELL074D:00/0018:06CB:7D47.0003/input/input17/uevent
PRODUCT=18/6cb/7d47/100
NAME="Synaptics TM3207-001"
PHYS="i2c-DELL074D:00"
UNIQ=""
PROP=5
EV=b
KEY=e520 10000 0 0 0 0
ABS=6f3800001000003
MODALIAS=input:b0018v06CBp7D47e0100-e0,1,3,k110,145,148,14A,14D,14E,14F,ra0,1,18,2F,30,31,34,35,36,37,39,3A,mlsfw
$ ls -l /sys/bus/i2c/devices/i2c-0/
total 0
--w------- 1 root root 4096 Apr 20 01:54 delete_device
lrwxrwxrwx 1 root root 0 Apr 20 01:54 device -> ../../808622C1:00
lrwxrwxrwx 1 root root 0 Apr 20 01:54 firmware_node -> ../../../LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/808622C1:00
drwxr-xr-x 4 root root 0 Apr 20 01:43 i2c-DELL074D:00
-r--r--r-- 1 root root 4096 Apr 20 01:54 name
--w------- 1 root root 4096 Apr 20 01:54 new_device
drwxr-xr-x 2 root root 0 Apr 20 01:54 power
lrwxrwxrwx 1 root root 0 Apr 20 01:54 subsystem -> ../../../../bus/i2c
-rw-r--r-- 1 root root 4096 Apr 20 01:54 uevent
Comment by loqs (loqs) - Saturday, 20 April 2019, 12:51 GMT
@skidnik have you tried contacting upstream via linux-i2c@vger.kernel.org seeing if upstream is aware of how many messages the change produces and possibly swiching to dev_err_once or dev_err_ratelimited ?
Edit:
Did you confirm 55bbe8fa7bfdd4230fb2731a66d9ecedab49d62b was the cause by reverting it?
Comment by Arnautov Illia (skidnik) - Sunday, 21 April 2019, 11:40 GMT
@loqs no. thanks for the directions thugh, I'll try contacting upstream. I'm aware that this issue is close to impossible to confirm as it relates to specific hardware.
I havent, building the kernel on N3710 will take qite a while. I solved the problem by installing linux-lts for now.
Comment by Arnautov Illia (skidnik) - Wednesday, 01 May 2019, 12:20 GMT
The issue has been resolved upstream.
For now these two pathces fix the issue:
___cut here___
diff --git a/drivers/i2c/busses/i2c-designware-master.c b/drivers/i2c/busses/i2c-designware-master.c
index bb8e3f149979..d464799e40a3 100644
--- a/drivers/i2c/busses/i2c-designware-master.c
+++ b/drivers/i2c/busses/i2c-designware-master.c
@@ -426,8 +426,7 @@ i2c_dw_xfer(struct i2c_adapter *adap, struct i2c_msg msgs[], int num)
pm_runtime_get_sync(dev->dev);
- if (dev->suspended) {
- dev_err(dev->dev, "Error %s call while suspended\n", __func__);
+ if (dev_WARN_ONCE(dev->dev, dev->suspended, "Transfer while suspended\n")) {
ret = -ESHUTDOWN;
goto done_nolock;
}
---cut here---

diff --git a/drivers/acpi/acpi_lpss.c b/drivers/acpi/acpi_lpss.c
index 1e2a10a06b9d..cf768608437e 100644
--- a/drivers/acpi/acpi_lpss.c
+++ b/drivers/acpi/acpi_lpss.c
@@ -1142,8 +1142,8 @@ static struct dev_pm_domain acpi_lpss_pm_domain = {
.thaw_noirq = acpi_subsys_thaw_noirq,
.poweroff = acpi_subsys_suspend,
.poweroff_late = acpi_lpss_suspend_late,
- .poweroff_noirq = acpi_subsys_suspend_noirq,
- .restore_noirq = acpi_subsys_resume_noirq,
+ .poweroff_noirq = acpi_lpss_suspend_noirq,
+ .restore_noirq = acpi_lpss_resume_noirq,
.restore_early = acpi_lpss_resume_early,
#endif
.runtime_suspend = acpi_lpss_runtime_suspend,
---cut here---
link to second patch: https://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm.git/commit/?id=c8afd03486c26accdda4846e5561aa3f8e862a9d
tested on linux-mainline-5.1.0-rc7.
edit:
> The patch is scheduled for inclusion into 5.2 and it has a Cc: stable, so it will get backported to older kernels like the 5.1.x and 5.0.x releases once it is merged into Linus' tree.
Comment by loqs (loqs) - Friday, 10 May 2019, 22:05 GMT Comment by Arnautov Illia (skidnik) - Saturday, 11 May 2019, 17:45 GMT Comment by Arnautov Illia (skidnik) - Friday, 17 May 2019, 16:52 GMT
Both commits are now in the [core] linux-5.1.2.arch1-1. I have verified the bug does not reproduce.

Loading...