From: Pavel Machek <pavel@ucw.cz>
To: kernel list <linux-kernel@vger.kernel.org>,
"Rafael J. Wysocki" <rjw@rjwysocki.net>,
Linux-pm mailing list <linux-pm@vger.kernel.org>
Cc: gregkh@linuxfoundation.org, linux-usb@vger.kernel.org
Subject: v4.15-rc5: resume took way too long, warning in syslog
Date: Fri, 29 Dec 2017 16:57:14 +0100 [thread overview]
Message-ID: <20171229155714.GA30656@amd> (raw)
[-- Attachment #1.1: Type: text/plain, Size: 8866 bytes --]
Hi!
v4.15-rc5.. resume took _way_ too long, and I have warn_on in dmesg as
a bonus. It looks like USB problem...? I never seen this before.
Pavel
[42266.070103] PM: Syncing filesystems ... done.
[42266.948883] Freezing user space processes ... (elapsed 0.003 seconds) done.
[42266.952336] OOM killer disabled.
[42266.952338] Freezing remaining freezable tasks ... (elapsed 0.003 seconds) done.
[42266.956273] Suspending console(s) (use no_console_suspend to debug)
[42267.148227] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[42267.148629] sd 0:0:0:0: [sda] Stopping disk
[42267.225212] e1000e: EEE TX LPI TIMER: 00000011
[42267.723975] PM: suspend devices took 0.764 seconds
[42267.796905] ACPI: Preparing to enter system sleep state S3
[42268.140237] ACPI: EC: event blocked
[42268.140242] ACPI: EC: EC stopped
[42268.140247] PM: Saving platform NVS memory
[42268.140275] Disabling non-boot CPUs ...
[42268.159546] smpboot: CPU 1 is now offline
[42268.183574] smpboot: CPU 2 is now offline
[42268.213618] IRQ 19: no longer affine to CPU3
[42268.214663] smpboot: CPU 3 is now offline
[42268.217690] ACPI: Low-level resume complete
[42268.217757] ACPI: EC: EC started
[42268.217758] PM: Restoring platform NVS memory
[42268.218070] Enabling non-boot CPUs ...
[42268.219625] x86: Booting SMP configuration:
[42268.219629] smpboot: Booting Node 0 Processor 1 APIC 0x1
[42268.220144] Disabled fast string operations
[42268.317954] cache: parent cpu1 should not be sleeping
[42268.318395] CPU1 is up
[42268.320852] smpboot: Booting Node 0 Processor 2 APIC 0x2
[42268.321562] Disabled fast string operations
[42268.421952] cache: parent cpu2 should not be sleeping
[42268.422447] CPU2 is up
[42268.424900] smpboot: Booting Node 0 Processor 3 APIC 0x3
[42268.425607] Disabled fast string operations
[42268.521949] cache: parent cpu3 should not be sleeping
[42268.522594] CPU3 is up
[42268.527660] ACPI: Waking up from system sleep state S3
[42269.202432] sdhci-pci 0000:0d:00.0: MMC controller base frequency changed to 50Mhz.
[42269.239534] iwlwifi 0000:03:00.0: RF_KILL bit toggled to disable radio.
[42269.240825] ACPI: EC: event unblocked
[42269.244977] sd 0:0:0:0: [sda] Starting disk
[42269.489765] usb 1-1.3: reset full-speed USB device number 3 using ehci-pci
[42269.577806] ata2: SATA link down (SStatus 0 SControl 300)
[42269.577851] ata5: SATA link down (SStatus 0 SControl 300)
[42269.677809] usb 1-1.6: reset high-speed USB device number 4 using ehci-pci
[42270.167923] psmouse serio1: synaptics: queried max coordinates: x [..5472], y [..4448]
[42270.361825] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[42270.363396] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[42270.363404] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[42270.363409] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[42270.366202] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[42270.366209] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[42270.366215] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[42270.367116] ata1.00: configured for UDMA/133
[42273.571626] e1000e: eth2 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
[42273.571638] e1000e 0000:00:19.0 eth2: 10/100 speed: disabling TSO
[42274.421868] usb 2-1.1.4: reset high-speed USB device number 55 using ehci-pci
[42279.541849] usb 2-1.1.4: device descriptor read/64, error -110
[42295.157864] usb 2-1.1.4: device descriptor read/64, error -110
[42295.345865] usb 2-1.1.4: reset high-speed USB device number 55 using ehci-pci
[42300.533867] usb 2-1.1.4: device descriptor read/64, error -110
[42316.149843] usb 2-1.1.4: device descriptor read/64, error -110
[42316.337864] usb 2-1.1.4: reset high-speed USB device number 55 using ehci-pci
[42327.029859] usb 2-1.1.4: device not accepting address 55, error -110
[42327.113863] usb 2-1.1.4: reset high-speed USB device number 55 using ehci-pci
[42337.781888] usb 2-1.1.4: device not accepting address 55, error -110
[42337.785431] PM: resume devices took 68.544 seconds
[42337.785436] ------------[ cut here ]------------
[42337.785441] Component: resume devices, time: 68544
[42337.785467] WARNING: CPU: 1 PID: 30277 at kernel/power/suspend_test.c:55 suspend_test_finish+0x73/0x80
[42337.785471] Modules linked in:
[42337.785483] CPU: 1 PID: 30277 Comm: systemd-sleep Not tainted 4.15.0-rc5 #146
[42337.785487] Hardware name: LENOVO 42872WU/42872WU, BIOS 8DET73WW (1.43 ) 10/12/2016
[42337.785495] RIP: 0010:suspend_test_finish+0x73/0x80
[42337.785500] RSP: 0000:ffffc9000f617cf8 EFLAGS: 00010292
[42337.785509] RAX: 0000000000000026 RBX: ffffffff84f9320a RCX: 000000004566332b
[42337.785514] RDX: 000000000b0ce99a RSI: ffff8801835a11f8 RDI: ffffffff85246380
[42337.785518] RBP: ffffc9000f617d08 R08: ffff8801835a11d0 R09: 0000000000000000
[42337.785523] R10: 00000000dc463ffc R11: 3a656d6974202c01 R12: 0000000000010bc0
[42337.785527] R13: 0000000000000000 R14: ffffc9000f617f00 R15: fffffffffffffff2
[42337.785533] FS: 0000000000000000(0000) GS:ffff88019e240000(0063) knlGS:00000000f7d1b700
[42337.785538] CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
[42337.785542] CR2: 0000000000000000 CR3: 000000017182e002 CR4: 00000000000606a0
[42337.785547] Call Trace:
[42337.785558] suspend_devices_and_enter+0x166/0x5e0
[42337.785566] pm_suspend+0x279/0x2f0
[42337.785573] state_store+0x62/0xa0
[42337.785583] kobj_attr_store+0xf/0x20
[42337.785594] sysfs_kf_write+0x40/0x50
[42337.785602] kernfs_fop_write+0x11a/0x1a0
[42337.785611] __vfs_write+0x23/0x130
[42337.785617] ? vfs_write+0x15c/0x180
[42337.785625] ? __sb_start_write+0xed/0x180
[42337.785631] ? vfs_write+0x15c/0x180
[42337.785638] vfs_write+0xaf/0x180
[42337.785646] ? up_read+0x1a/0x40
[42337.785653] SyS_write+0x44/0xb0
[42337.785664] do_int80_syscall_32+0x5b/0x120
[42337.785674] entry_INT80_compat+0x2c/0x40
[42337.785680] RIP: 0023:0xf7f0dc42
[42337.785685] RSP: 002b:00000000ffa274e4 EFLAGS: 00000246 ORIG_RAX: 0000000000000004
[42337.785694] RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 00000000f7f0a000
[42337.785698] RDX: 0000000000000004 RSI: 0000000000000004 RDI: 00000000f7f0a000
[42337.785702] RBP: 00000000565ab050 R08: 0000000000000000 R09: 0000000000000000
[42337.785707] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[42337.785711] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[42337.785718] Code: 29 c1 31 c0 e8 ca a7 00 00 41 81 fc 10 27 00 00 77 05 5b 41 5c 5d c3 44 89 e2 48 89 de 48 c7 c7 01 34 f9 84 31 c0 e8 7d 01 fb ff <0f> ff 5b 41 5c 5d c3 90 90 90 90 90 90 55 0f b6 05 4c 0d c9 01
[42337.785966] ---[ end trace a926c3e188989851 ]---
[42337.786889] OOM killer enabled.
[42337.786898] Restarting tasks ...
[42337.795617] systemd[1]: Starting Journal Service...
[42337.796629] usb 2-1.1.4: USB disconnect, device number 55
[42337.796819] cdc_ether 2-1.1.4:1.0 usb0: unregister 'cdc_ether' usb-0000:00:1d.0-1.1.4, CDC Ethernet Device
[42337.800341] done.
[42337.813790] PM: suspend exit
[42337.816608] systemd[1]: Started Suspend.
[42337.816671] systemd[1]: Requested transaction contradicts existing jobs: File exists
[42337.816682] systemd[1]: Service sleep.target is not needed anymore. Stopping.
[42337.817078] systemd[1]: Stopping Sleep.
[42337.817095] systemd[1]: Stopped target Sleep.
[42337.817125] systemd[1]: Reached target Suspend.
[42337.818135] systemd[1]: Starting Run anacron jobs at resume...
[42337.819217] systemd[1]: Started Run anacron jobs at resume.
[42337.913753] usb 2-1.1.4: new high-speed USB device number 56 using ehci-pci
[42338.395078] e1000e: eth2 NIC Link is Down
[42338.732172] systemd-journald[2470]: Received SIGTERM from PID 1 (systemd).
[42339.679602] systemd[1]: Unit systemd-journald.service entered failed state.
[42340.426957] systemd-journald[30462]: Received request to flush runtime journal from PID 1
[42343.029871] usb 2-1.1.4: device descriptor read/64, error -110
[42344.483918] e1000e: eth2 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
[42344.483927] e1000e 0000:00:19.0 eth2: 10/100 speed: disabling TSO
[42358.645164] usb 2-1.1.4: device descriptor read/64, error -110
[42358.833023] usb 2-1.1.4: new high-speed USB device number 57 using ehci-pci
[42364.018463] usb 2-1.1.4: device descriptor read/64, error -110
[42379.626669] usb 2-1.1.4: device descriptor read/64, error -110
[42379.735177] usb 2-1.1-port4: attempt power cycle
[42380.338299] usb 2-1.1.4: new high-speed USB device number 58 using ehci-pci
--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
[-- Attachment #1.2: delme.gz --]
[-- Type: application/gzip, Size: 27340 bytes --]
[-- Attachment #1.3: delme.gz --]
[-- Type: application/gzip, Size: 27340 bytes --]
[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 181 bytes --]
next reply other threads:[~2017-12-29 15:57 UTC|newest]
Thread overview: 4+ messages / expand[flat|nested] mbox.gz Atom feed top
2017-12-29 15:57 Pavel Machek [this message]
2017-12-29 16:23 ` v4.15-rc5: resume took way too long, warning in syslog Alan Stern
2017-12-29 16:23 ` Alan Stern
2017-12-29 22:04 ` Pavel Machek
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20171229155714.GA30656@amd \
--to=pavel@ucw.cz \
--cc=gregkh@linuxfoundation.org \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-pm@vger.kernel.org \
--cc=linux-usb@vger.kernel.org \
--cc=rjw@rjwysocki.net \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.