Ubuntu 18.04 HWE Kernel 4.18 / 5.0 / 5.3 - Standby wakeup user session crash

My mistake, I know now how to add the files separately without using an archive.

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1818974

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

apport information

What is the symptom? From dmesg everything looks fine.

Every time my external HDD is connected via USB the wakeup takes a bit, showing a black screen.
Then I see my login window, and after login I don't see any window I opened. Everything is like a fresh computer restart, except the webdav mount I mounted before.

The /dev/sdb4 has some ext4 file system errors fsk.ext4 can't fix.
Maybe there is a relationship.

(Sorry, can't edit my previous post to add an information.)

Now it happened even with my external HDD detached.
The laptop was in standby for 8 hours.

It starts to happen more often.
The symptom is a black screen with only "Started Bpfilter", a blinking cursor and a long waiting time, before showing the login screen.

And I have a HiDPI Monitor, but i lowered the resolution to a normal one for 14".
But if this problem happen, the monitor has the 2k resolution at login, while the login window itself has my lowered resolution.
Meaning a little login screen attached to the left upper corner of the screen and the unused rest of the screen is just black.

Other than offline fsck, it's a good idea to run full SMART test.

SMART long offline test was successful.
Everything is fine.
I formatted the ext4 partition.
I assume the corruption came, because I turned of the external HDD hub too early several times.

But this weird bug happened one time I unplugged the external HDD before waking up my ThinkPad T460P.

PS:
I hope the issue can be found and fixed.
A crashing user session is a bit weird.

Happens too with fixed hdd filesystem.

But now it was forever at "Started Bpfilter" until I switched to the terminal screen and executed a shutdown.

Possible to reproduce the issue and attach dmesg? #30 is hard to read.

Are #31 and #25 enough?
or do you miss something else? :)

If i don't forget it I can make it a third time.

#4 and #26 are containing journals too.

X crashed after resume. Do you see the issue when i915 is used instead?

I'll switch now form permanently nvidia gtx 940mx to permanently i7-6700hq iGPU.
May take a bit until I can see if the bug happens or not, because it doesn't happen every time.
Luckily or badly it happens not often.

I don't know if it is the same bug.

I wanted to use my computer again, I left on the thinkpad docking station, connected with the same external HDD.
I got only a black screen on the main monitor and the other two monitors didn't got an image signal.

PS:
I am running now the intel gpu driver as default, it seems it uses the nvidia gpu automatically in games.
This black screen behaviour looks new to me.

Sadly my screen was again black and my external monitors in standby.
Something happened while the laptop did go into auto standby this morning, so a forced reboot was needed at 10:24.

I also now updated to the newest 18.04 HWE 4.18 kernel and disabled all mitigations to speed up my computer.

Very weird.
I detached the awake laptop from my docking station, then i worked with it without attached power supply.
I watched something without using my laptop.
My laptop turned into standby.
Then I woke it up and the screen was just black, but the power LED indicated a awake laptop.
Only a forced shutdown by pressing the power button until ended this bug.

And again, I woke my thinkpad t460p just from standby/suspend to ram and i first saw a black screen, then "starting bpfilter", then my user session crashed.

$ uname -a
Linux deus-ex-machina 4.18.0-25-generic #26~18.04.1-Ubuntu SMP Thu Jun 27 07:28:31 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

The suspend time is between Jul 11 01:47:24 and Jul 11 11:52:12

Please test latest mainline kernel:
https://kernel.ubuntu.com/~kernel-ppa/mainline/v5.2-rc7/

Thank you for your help.

4.18.0-25-generic kernel:
The last 2 times I put my laptop over night into sleep mode via the Kodi menu and woke it up the next day I got the bpfilter and my user session was killed.

5.2.0-050200rc7-generic kernel:
Now I made a short test, put it into sleep mode via Kodi, did wait 20 minutes and woke it up without problems.

It may be coincidence, I may should wait longer or test it over a longer time period.

I'm only running LTS ubuntu versions with HWE, should I test it with 5.0, too?

Yes, please test hwe-edge kernel.

Still getting the issue in 5.2.
Do you think I should still test the Ubuntu HWE 5.0 for 18.04?

$ uname -a
Linux deus-ex-machina 5.2.0-050200rc7-generic #201906300430 SMP Sun Jun 30 04:32:31 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

Please compare /sys/kernel/debug/wakeup_sources before and after suspend to see which device wakes the system up.

Done.

I think I can reproduce it, if I hibernate in the Kodi application shutdown menu.
From https://kodi.tv/
Using 18.3

Hibernate (S4) is not the same as S3. S4 wakeup is mostly controlled by BIOS.

Sorry, I think I translated it wrong. The menu entry is named "Bereitschaft", which means standby / suspend.
The stuff gets saved into the RAM, not the storage drive/disk.

I think the quickest way is to do a kernel bisection.

How to do that?
I would need a guide. :)

Oh
https://wiki.ubuntu.com/Kernel/KernelBisection
You mean I should install a specific previous version?
Which version do you want to get tested?

First, find the last good -rc kernel and the first bad -rc kernel from http://kernel.ubuntu.com/~kernel-ppa/mainline/

Then,
$ sudo apt build-dep linux
$ git clone git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
$ cd linux
$ git bisect start
$ git bisect good $(the good version you found)
$ git bisect bad $(the bad version found)
$ make localmodconfig
$ make -j`nproc` deb-pkg
Install the newly built kernel, then reboot with it.
If the issue still happens,
$ git bisect bad
Otherwise,
$ git bisect good
Repeat to "make -j`nproc` deb-pkg" until you find the commit that causes the regression.

I'm sorry, that I still had no time to bisect the kernel (job/studies).

But I've got another log.
I don't know, if it is the same bug, but it also caused my user session to crash.

I see several service kills and that I get a new user session in this log.

Again, my laptop was in standby over night.

I updated now to kernel 5.0.0-29-generic.

Xorg.log before crash

Xorg.log after crash

Maybe error in DRM i915 by intel causes this weird behaviour.

Put my laptop into standby, decouple from docking station, 6 hours later wake up and user session destroyed.

Maybe it is this bug?
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1802578

I see "kernel: [drm:intel_display_resume [i915]] *ERROR* Restoring old state failed with -22", too.

Hoping the dumps are useful

Sep 29 09:30:34 deus-ex-machina goa-daemon[3249]: secret_password_lookup_sync() returned NULL
Sep 29 09:30:35 deus-ex-machina goa-daemon[3249]: secret_password_lookup_sync() returned NULL
Sep 29 09:30:58 deus-ex-machina NetworkManager[1213]: <info> [1569742258.9328] connectivity: (wlp3s0) timed out
Sep 29 09:31:15 deus-ex-machina acpid[1227]: client 1524[0:0] has disconnected
Sep 29 09:31:16 deus-ex-machina gnome-terminal-[6176]: gnome-terminal-server: Fatal IO error 11 (Die Ressource ist zur Zeit nicht verfügbar) on X server :0.
Sep 29 09:31:16 deus-ex-machina xdg-desktop-por[24386]: xdg-desktop-portal-gtk: Fatal IO error 11 (Die Ressource ist zur Zeit nicht verfügbar) on X server :0.
Sep 29 09:31:16 deus-ex-machina cinnamon-screen[3085]: cinnamon-screensaver-main.py: Fatal IO error 11 (Die Ressource ist zur Zeit nicht verfügbar) on X server :0.
Sep 29 09:31:16 deus-ex-machina at-spi-bus-launcher[3073]: XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
Sep 29 09:31:16 deus-ex-machina at-spi-bus-launcher[3073]: after 238829 requests (238829 known processed) with 0 events remaining.
Sep 29 09:31:16 deus-ex-machina org.gtk.vfs.Daemon[24363]: A connection to the bus can't be made
Sep 29 09:31:16 deus-ex-machina polkitd(authority=local)[1287]: Unregistered Authentication Agent for unix-session:c2 (system bus name :1.65, object path /org/gnome/PolicyKit1/AuthenticationAgent, locale de_DE.UTF-8) (disconnected from bus)
Sep 29 09:31:16 deus-ex-machina systemd[2976]: gnome-terminal-server.service: Main process exited, code=exited, status=1/FAILURE
Sep 29 09:31:16 deus-ex-machina systemd[2976]: gnome-terminal-server.service: Failed with result 'exit-code'.
Sep 29 09:31:16 deus-ex-machina systemd[2976]: keybase.gui.service: Main process exited, code=exited, status=1/FAILURE
Sep 29 09:31:16 deus-ex-machina systemd[2976]: keybase.gui.service: Failed with result 'exit-code'.
Sep 29 09:31:16 deus-ex-machina lightdm[2923]: pam_unix(lightdm:session): session closed for user martin
Sep 29 09:31:16 deus-ex-machina lightdm[1441]: Error: can't open /lib/modules/5.0.0-29-generic/updates/dkms
Sep 29 09:31:16 deus-ex-machina dbus-daemon[3008]: [session uid=1000 pid=3008] Monitoring connection :1.576 closed.
Sep 29 09:31:17 deus-ex-machina assert_20190929093116_52.dmp[29569]: Uploading dump (out-of-process)
                                                                     /tmp/dumps/assert_20190929093116_52.dmp
Sep 29 09:31:17 deus-ex-machina assert_20190929093117_54.dmp[29572]: Uploading dump (out-of-process)
                                                                     /tmp/dumps/assert_20190929093117_54.dmp
Sep 29 09:31:17 deus-ex-machina kernel: steam[22959]: segfault at 17 ip 00000000ed78309f sp 00000000fff49df0 error 6 in steamclient.so[ed304000+187c000]
Sep 29 09:31:17 deus-ex-machina kernel: Code: 47 14 89 44 24 2c 89 41 08 8d 04 1d 70 30 00 00 e8 d6 64 ca ff 89 c6 8b 00 85 c0 0f 84 6a 01 00 00 25 ff ff ff 1f 89 c5 31 c0 <f0> 0f b1 2f 85 c0 89 c1 89 c2 0f 84 88 00 00 00 25 ff ff ff 1f 39
Sep 29 09:31:17 deus-ex-machina crash_20190926165711_1.dmp[29575]: Uploading dump (out-of-proces...

Now my laptop connected to dockingstation connected to (the monitors and) the usb hdd hub connected to my HDD did go to standby.
I slept the night.
Next day I detached it from the docking station and connected the usb hdd hub with my directly to it before waking it up.
User session died.

Again the
Okt 03 12:03:14 deus-ex-machina lightdm[3008]: pam_unix(lightdm:session): session closed for user martin
in the journal and the error messages surrounding it.

[ 19109.693] (II) NVIDIA(0): Setting mode "NULL"
[ 19109.707] (EE) modeset(G0): failed to set mode: No such file or directory
[ 19109.707] (EE)
Fatal server error:
[ 19109.707] (EE) EnterVT failed for gpu screen 0
[ 19109.707] (EE)
[ 19109.707] (EE)
Please consult the The X.Org Foundation support
  at http://wiki.x.org
 for help.
[ 19109.707] (EE) Please also check the log file at "/var/log/Xorg.0.log" for additional information.
[ 19109.707] (EE)
[ 19109.731] (EE) Server terminated with error (1). Closing log file.

Oct 3 12:03:14 deus-ex-machina systemd[1]: Stopped target Suspend.
Oct 3 12:03:14 deus-ex-machina NetworkManager[1342]: <info> [1570096994.1383] manager: sleep: wake requested (sleeping: yes enabled: yes)
Oct 3 12:03:14 deus-ex-machina NetworkManager[1342]: <info> [1570096994.1384] device (enp0s31f6): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'managed')
Oct 3 12:03:14 deus-ex-machina acpid: client connected from 1556[0:0]
Oct 3 12:03:14 deus-ex-machina acpid: 1 client rule loaded
Oct 3 12:03:14 deus-ex-machina upowerd[2964]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3
Oct 3 12:03:14 deus-ex-machina kernel: [19109.240526] usb 2-1: new SuperSpeed Gen 1 USB device number 8 using xhci_hcd
Oct 3 12:03:14 deus-ex-machina kernel: [19109.261148] usb 2-1: New USB device found, idVendor=174c, idProduct=55aa, bcdDevice= 1.00
Oct 3 12:03:14 deus-ex-machina kernel: [19109.261149] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=1
Oct 3 12:03:14 deus-ex-machina kernel: [19109.261150] usb 2-1: Product: ASM1156-PM
Oct 3 12:03:14 deus-ex-machina kernel: [19109.261151] usb 2-1: Manufacturer: ASMT
Oct 3 12:03:14 deus-ex-machina kernel: [19109.261152] usb 2-1: SerialNumber: 00000000000000000000
Oct 3 12:03:14 deus-ex-machina kernel: [19109.265543] scsi host6: uas
Oct 3 12:03:14 deus-ex-machina kernel: [19109.265737] usb 2-4: USB disconnect, device number 6
Oct 3 12:03:14 deus-ex-machina kernel: [19109.265739] usb 2-4.1: USB disconnect, device number 7
Oct 3 12:03:14 deus-ex-machina kernel: [19109.266028] print_req_error: I/O error, dev sdc, sector 0 flags 801
Oct 3 12:03:14 deus-ex-machina kernel: [19109.268614] scsi 6:0:0:0: Direct-Access ASMT ASM1156-PM 0 PQ: 0 ANSI: 6
Oct 3 12:03:14 deus-ex-machina kernel: [19109.273083] sd 6:0:0:0: Attached scsi generic sg1 type 0
Oct 3 12:03:14 deus-ex-machina kernel: [19109.278705] sd 6:0:0:0: [sdd] 5860533168 512-byte logical blocks: (3.00 TB/2.73 TiB)
Oct 3 12:03:14 deus-ex-machina kernel: [19109.278707] sd 6:0:0:0: [sdd] 4096-byte physical blocks
Oct 3 12:03:14 deus-ex-machina kernel: [19109.278828] sd 6:0:0:0: [sdd] Write Protect is off
Oct 3 12:03:14 deus-ex-machina kernel: [19109.278829] sd 6:0:0:0: [sdd] Mode Sense: 43 00 00 00
Oct 3 12:03:14 deus-ex-machina kernel: [19109.278988] sd 6:0:0:0: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 3 12:03:14 deus-ex-machina kernel: [19109.280494] sd 6:0:0:0: [sdd] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes)
Oct 3 12:03:14 deus-ex-machina NetworkManager[1342]: <info> [1570096994.3234] device (wlp3s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'managed')
Oct 3 12:03:14 deus-ex-machina cinnamon-screen[3238]: cinnamon-screensaver-main.py: Fatal IO error 11 (Die Ressource ist zur Zeit nicht verfügbar) on X server :0.
Oct 3 12:03:14 deus-ex-machina at-spi-bus-launcher[3226]: XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0"
Oct 3 12:03:14 deus-ex-machina at-spi-bus-launcher[3226]: after 8633 requests (8633 known pro...

ERROR: apport (pid 19009) Thu Oct 3 12:03:14 2019: called for pid 1556, signal 6, core limit 18446744073709551615, dump mode 1
ERROR: apport (pid 19009) Thu Oct 3 12:03:14 2019: ignoring implausibly big core limit, treating as unlimited
ERROR: apport (pid 19009) Thu Oct 3 12:03:14 2019: executable: /usr/lib/xorg/Xorg (command line "/usr/lib/xorg/Xorg -core :0 -seat seat0 -auth /var/run/lightdm/root/:0 -nolisten tcp vt7 -novtswitch")
ERROR: apport (pid 19009) Thu Oct 3 12:03:14 2019: is_closing_session(): no DBUS_SESSION_BUS_ADDRESS in environment
ERROR: apport (pid 19009) Thu Oct 3 12:03:14 2019: this executable already crashed 2 times, ignoring
ERROR: apport (pid 19155) Thu Oct 3 12:03:14 2019: called for pid 19150, signal 7, core limit 0, dump mode 1
ERROR: apport (pid 19155) Thu Oct 3 12:03:14 2019: Unhandled exception:
Traceback (most recent call last):
  File "/usr/share/apport/apport", line 483, in <module>
    exe_mtime = os.stat('/proc/%s/exe' % pid).st_mtime
PermissionError: [Errno 13] Permission denied: '/proc/19150/exe'
ERROR: apport (pid 19155) Thu Oct 3 12:03:14 2019: pid: 19155, uid: 1000, gid: 1000, euid: 0, egid: 0
ERROR: apport (pid 19155) Thu Oct 3 12:03:14 2019: environment: environ({})
ERROR: apport (pid 19153) Thu Oct 3 12:03:14 2019: called for pid 4599, signal 7, core limit 0, dump mode 1
ERROR: apport (pid 19153) Thu Oct 3 12:03:14 2019: Unhandled exception:
Traceback (most recent call last):
  File "/usr/share/apport/apport", line 483, in <module>
    exe_mtime = os.stat('/proc/%s/exe' % pid).st_mtime
PermissionError: [Errno 13] Permission denied: '/proc/4599/exe'
ERROR: apport (pid 19153) Thu Oct 3 12:03:14 2019: pid: 19153, uid: 1000, gid: 1000, euid: 0, egid: 0
ERROR: apport (pid 19153) Thu Oct 3 12:03:14 2019: environment: environ({})

Kernel 5.0.0-32-generic
Put in standby on docking station
disconnected
wake up
user session crashed

[ 14158.623] (II) NVIDIA(0): Setting mode "NULL"
[ 14159.837] (EE) modeset(G0): failed to set mode: No such file or directory
[ 14159.837] (EE)
Fatal server error:
[ 14159.837] (EE) EnterVT failed for gpu screen 0
[ 14159.837] (EE)
[ 14159.837] (EE)

Can you confirm it doesn't happen under 4.15 based kernel?

Kernel 4.15.0-66-generic
Put in standby on docking station
disconnected
wake up
user session crashed

5.0.0-36-generic -> Still happening

Status changed to 'Confirmed' because the bug affects multiple users.

5.3.0-42-generic -> still happening.
Put my thinkpad in standby,
disconnect it from the docking station,
woke it up,
user session crashed.

Starting at
Mar 20 09:59:52 deus-ex-machina at-spi-bus-launcher[6411]: XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0"

5.3.0-46-generic -> still happening.