[nvidia] Logging in results in a black screen for many minutes after which the login screen reappears and I am able to login fine.

[Jonathan]

** Ubuntu Bionic; Nvidia GTX 1050 w/`nvidia-390` drivers

** Problem: Logging in results in a black screen for many minutes after which the login screen reappears and I am able to login fine. The below log seems to be the earliest error when this occurs.
Note: This happened twice today so far, presumably each time I reboot.

May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE) NVIDIA(GPU-0): Failed to acquire modesetting permission.
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE) NVIDIA(0): Failing initialization of X screen 0
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (II) UnloadModule: "nvidia"
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (II) UnloadSubModule: "wfb"
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (II) UnloadSubModule: "fb"
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE) Screen(s) found, but none have a usable configuration.
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE)
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: Fatal server error:
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE) no screens found(EE)
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE)

** A systemd-logind watchdog seems to be responsible for the login screen reappearing

May 9 11:20:02 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Watchdog timeout (limit 3min)!
May 9 11:20:02 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Killing process 1697 (systemd-logind) with signal SIGABRT.
May 9 11:20:03 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Main process exited, code=dumped, status=6/ABRT
May 9 11:20:03 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Failed with result 'watchdog'.

** The Xorg.0.log doesn't seem to have any problem finding the screens just before the above error.

29406:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (II) NVIDIA(0): NVIDIA GPU GeForce GTX 1050 (GP107-A) at PCI:23:0:0 (GPU-0)
29407:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (--) NVIDIA(0): Memory: 2097152 kBytes
29408:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (--) NVIDIA(0): VideoBIOS: 86.07.2f.00.68
29409:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (II) NVIDIA(0): Detected PCI Express Link width: 16X
29412:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (--) NVIDIA(GPU-0): Acer AL1917 (DFP-0): connected
29413:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (--) NVIDIA(GPU-0): Acer AL1917 (DFP-0): Internal TMDS
29414:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (--) NVIDIA(GPU-0): Acer AL1917 (DFP-0): 330.0 MHz maximum pixel clock
29415:May 9 11:03:47 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[1742]: (--) NVIDIA(GPU-0):

** Note that I also saw the watchdog kick in while I was logged in and working when I was suddenly sent back to the login screen. I believe that lines up with the syslog timestamp below:

May 9 10:31:24 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Watchdog timeout (limit 3min)!
May 9 10:31:24 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Killing process 1691 (systemd-logind) with signal SIGABRT.
May 9 10:31:25 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Main process exited, code=dumped, status=6/ABRT
May 9 10:31:25 jcormier-MS-7A93 systemd[1]: systemd-logind.service: Failed with result 'watchdog'.
May 9 10:31:25 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2607]: (EE)
May 9 10:31:25 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2607]: Fatal server error:
May 9 10:31:25 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2607]: (EE) systemd-logind disappeared (stopped/restarted?)
May 9 10:31:25 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2607]: (EE)
May 9 10:31:25 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2607]: (EE)

** I also experienced the computer reboot when I tried to open the calculator app sometime between these two timestamps.

May 9 13:18:27 jcormier-MS-7A93 org.gnome.Shell.desktop[3311]: Window manager warning: Buggy client sent a _NET_ACTIVE_WINDOW message with a timestamp of 0 for 0x2605a63 (Find/Repla)
May 9 13:20:06 jcormier-MS-7A93 systemd-modules-load[437]: Inserted module 'lp'

 $ sudo ubuntu-drivers devices
== /sys/devices/pci0000:16/0000:16:00.0/0000:17:00.0 ==
modalias : pci:v000010DEd00001C81sv00001458sd0000372Cbc03sc00i00
vendor : NVIDIA Corporation
model : GP107 [GeForce GTX 1050]
driver : nvidia-driver-390 - distro non-free recommended
driver : xserver-xorg-video-nouveau - distro free builtin

It seems similar to this bug: https://bugs.launchpad.net/ubuntu/+source/xorg/+bug/1748656

ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: gdm3 3.28.0-0ubuntu1
ProcVersionSignature: Ubuntu 4.15.0-20.21-generic 4.15.17
Uname: Linux 4.15.0-20-generic x86_64
NonfreeKernelModules: nvidia_modeset nvidia
ApportVersion: 2.20.9-0ubuntu7
Architecture: amd64
CurrentDesktop: ubuntu:GNOME
Date: Wed May 9 13:57:37 2018
InstallationDate: Installed on 2018-04-10 (28 days ago)
InstallationMedia: Ubuntu 18.04 LTS "Bionic Beaver" - Beta amd64 (20180404)
ProcEnviron:
 LANG=en_US.UTF-8
 SHELL=/bin/bash
 TERM=xterm-256color
 XDG_RUNTIME_DIR=<set>
 PATH=(custom, no user)
SourcePackage: gdm3
UpgradeStatus: No upgrade log present (probably fresh install)
mtime.conffile..etc.gdm3.custom.conf: 2018-05-09T11:02:19.660695

[Jonathan (jjcf89)]

Tried to run the calculator app again and system crashed...

After system startup and login ended up in black screen again.

I was able to ssh into the machine and manually restart systemd-logind. The login screen reappeared after a couple seconds and I was able to login without being stuck in the black screen.

sudo systemctl restart systemd-logind.service

[Daniel van Vugt (vanvugt)]

1. You don't have an integrated GPU, do you? I am reminded of bug 1705369.

2. In case something is crashing, check /var/crash for files and run 'ubuntu-bug YOURFILE.crash' on each. And tell us here the IDs of new bugs created.

3. As soon as the problem happens again, please take a copy of ~/.local/share/xorg/* and attach them here.

[Jonathan (jjcf89)]

> 1. You don't have an integrated GPU, do you? I am reminded of bug 1705369.

No I'm running the i7-7820X which has no option for integrated GPU. Motherboard MSI X299 SLI PLUS.

> 2. In case something is crashing, check /var/crash for files and run 'ubuntu-bug YOURFILE.crash' on each. And tell us here the IDs of new bugs created.

There appear to be some crashes but not from yesterday. Last week I had been seeing some UI crashes when the desktop was sitting idle after logged in (before I started using it as my main PC). I had installed the nvidia drivers which seemed to prevent the crashes. Though perhaps I was wrong.

How do I find the IDs for bugs created?

 $ ll /var/crash/
total 26700
drwxrwsrwt 1 root whoopsie 776 May 10 00:06 ./
drwxr-xr-x 1 root root 126 Apr 11 11:20 ../
-rw-r----- 1 root whoopsie 1064044 May 8 17:21 _lib_systemd_systemd-logind.0.crash
-rw-r--r-- 1 root whoopsie 0 May 8 17:22 _lib_systemd_systemd-logind.0.upload
-rw------- 1 whoopsie whoopsie 0 May 8 17:22 _lib_systemd_systemd-logind.0.uploaded
-rw-r----- 1 gdm whoopsie 20579804 May 2 11:09 _usr_bin_gnome-shell.119.crash
-rw-r--r-- 1 root whoopsie 0 May 2 11:09 _usr_bin_gnome-shell.119.upload
-rw------- 1 whoopsie whoopsie 0 May 2 11:09 _usr_bin_gnome-shell.119.uploaded
-rw-r----- 1 gdm whoopsie 3030664 May 2 11:10 _usr_bin_Xwayland.119.crash
-rw-r--r-- 1 root whoopsie 0 May 2 11:10 _usr_bin_Xwayland.119.upload
-rw------- 1 whoopsie whoopsie 0 May 2 11:10 _usr_bin_Xwayland.119.uploaded
-rw-r----- 1 root whoopsie 2660730 May 8 17:21 _usr_lib_udisks2_udisksd.0.crash
-rw-r--r-- 1 root whoopsie 0 May 8 17:21 _usr_lib_udisks2_udisksd.0.upload
-rw------- 1 whoopsie whoopsie 0 May 8 17:21 _usr_lib_udisks2_udisksd.0.uploaded

> 3. As soon as the problem happens again, please take a copy of ~/.local/share/xorg/* and attach them here.

Okay will do. What's the difference between the /var/log/Xorg* files and the ~/.local/share/xorg/* files?

[Jonathan (jjcf89)]

 $ ll ~/.local/share/xorg/*
-rw-r--r-- 1 jcormier engineer 122164 May 2 10:52 /home/jcormier/.local/share/xorg/Xorg.0.log
-rw-r--r-- 1 jcormier engineer 34006 Apr 27 14:05 /home/jcormier/.local/share/xorg/Xorg.0.log.old
-rw-r--r-- 1 jcormier engineer 40953 Mar 14 14:16 /home/jcormier/.local/share/xorg/Xorg.1.log

It looks like these logs haven't been updated in a while.

[Daniel van Vugt (vanvugt)]

If you find *.uploaded then you can review what bugs were found by going to:

https://errors.ubuntu.com/user/ID

where ID is the contents of /var/lib/whoopsie/whoopsie-id

That page is private to you. But if you find links there to a crash you think is relevant then please share the links here.

[Jonathan (jjcf89)]

Computer locked up and rebooted this morning. After computer rebooted and I tried to login, I got the black screen again. I'm assuming i'll get this black login every time I logout or reboot.

I was able to restart the logind service again and login afterwards. Hmm why does Xorg.0 consistently find the monitors but Xorg.1 doesn't until its restarted...

Attaching syslog, xorg.0.log and xorg.1.log. Note the logs in ~/.local/ haven't been updated since I posted above.

[Jonathan (jjcf89)]

A crash report was generated. https://errors.ubuntu.com/oops/ed192104-5779-11e8-87e6-fa163e192766

[Jonathan (jjcf89)]

I rebooted. This time I tried to pro actively restart the logind service. This still resulted in the black screen and eventually getting returned to the login screen. However the error log looks a little different since it claims the gdm-x-session was terminated successfully...

May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: dbus-daemon[4763]: [session uid=9338 pid=4763] Activated service 'org.freedesktop. systemd1' failed: Process org.freedesktop.systemd1 exited with status 1
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: Unable to register display with display manager
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) event2 - Power Button: device removed
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) event1 - Power Button: device removed
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) event0 - Sleep Button: device removed
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) event3 - Logitech USB Trackball: device removed
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) event4 - Logitech USB Optical Mouse: device removed
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) event5 - Logitech USB Keyboard: device removed
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) event6 - Logitech USB Keyboard: device removed
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) UnloadModule: "libinput"
May 14 09:28:09 jcormier-MS-7A93 kernel: [ 167.479107] snd_hda_codec_hdmi hdaudioC1D0: HDMI: invalid ELD data byte 28
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: message repeated 6 times: [ (II) UnloadModule: "libinput"]
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) NVIDIA(GPU-0): Deleting GPU-0
May 14 09:28:09 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[4506]: (II) Server terminated successfully (0). Closing log file.

[Jonathan (jjcf89)]

Re-enabled Wayland for login manager. /etc/gdm3/custom.conf

# Uncoment the line below to force the login screen to use Xorg
#WaylandEnable=false

I uncommented this before for since I was seeing that it took a long time to login after entering password and a post suggested this as a fix.

After re-enabling this, I don't see the black screen when I login...

[Jonathan (jjcf89)]

Hmm but now a few minutes after logging in I was suddenly sent back to the login screen. Maybe this is the relevant log line from attached syslog...

May 14 09:52:20 jcormier-MS-7A93 gnome-shell[3498]: Object St.Button (0x557e81f797e0), has been already finalized. Impossible to set any property to it.
May 14 09:52:20 jcormier-MS-7A93 gnome-shell[3498]: Object St.Button (0x557e81f797e0), has been already finalized. Impossible to set any property to it.
May 14 09:52:20 jcormier-MS-7A93 org.gnome.Shell.desktop[3498]: == Stack trace for context 0x557e7fe8f330 ==
May 14 09:52:20 jcormier-MS-7A93 org.gnome.Shell.desktop[3498]: #0 0x557e8031f530 i resource:///org/gnome/shell/ui/messageList.js:504 (0x7f89dc2b4de0 @

I was able to log right back in afterwards...

[Jonathan (jjcf89)]

Interestingly, after re-enabling wayland, the gnome-calculator no longer causes the system to hang and reboot.

I re-disabled wayland just to verify and the calculator again hung the system and caused a reboot...

The only thing printed to the syslog when this happened was the following. Note this was captured via a tail -f running over ssh. After computer rebooted the following lines were no longer in the syslog so didn't get flushed to disk...

May 14 10:08:35 jcormier-MS-7A93 kernel: [ 134.890941] audit: type=1400 audit(1526306915.482:60): apparmor="DENIED" operation="open" profile="snap.gnome-calculator.gnome-calculator" name="/home/jcormier/Desktop/" pid=4518 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338
May 14 10:08:35 jcormier-MS-7A93 kernel: [ 134.895457] audit: type=1400 audit(1526306915.486:61): apparmor="DENIED" operation="open" profile="snap.gnome-calculator.gnome-calculator" name="/home/jcormier/Music/" pid=4522 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338
May 14 10:08:35 jcormier-MS-7A93 kernel: [ 134.901838] audit: type=1400 audit(1526306915.494:62): apparmor="DENIED" operation="open" profile="snap.gnome-calculator.gnome-calculator" name="/home/jcormier/Videos/" pid=4526 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338
May 14 10:08:35 jcormier-MS-7A93 kernel: [ 134.904203] audit: type=1400 audit(1526306915.498:63): apparmor="DENIED" operation="open" profile="snap.gnome-calculator.gnome-calculator" name="/home/jcormier/Templates/" pid=4528 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338

Re-enabled wayland.

However the same apparmor errors appear when the calculator doesn't crash the system...

May 14 10:17:15 jcormier-MS-7A93 kernel: [ 104.654560] audit: type=1400 audit(1526307435.332:60): apparmor="DENIED" operation="open" profile="snap.gnome-ca
lculator.gnome-calculator" name="/home/jcormier/Desktop/" pid=4527 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338
May 14 10:17:15 jcormier-MS-7A93 kernel: [ 104.660729] audit: type=1400 audit(1526307435.340:61): apparmor="DENIED" operation="open" profile="snap.gnome-ca
lculator.gnome-calculator" name="/home/jcormier/Music/" pid=4531 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338
May 14 10:17:15 jcormier-MS-7A93 kernel: [ 104.666792] audit: type=1400 audit(1526307435.344:62): apparmor="DENIED" operation="open" profile="snap.gnome-ca
lculator.gnome-calculator" name="/home/jcormier/Videos/" pid=4535 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338
May 14 10:17:15 jcormier-MS-7A93 kernel: [ 104.668727] audit: type=1400 audit(1526307435.348:63): apparmor="DENIED" operation="open" profile="snap.gnome-ca
lculator.gnome-calculator" name="/home/jcormier/Templates/" pid=4537 comm="head" requested_mask="r" denied_mask="r" fsuid=9338 ouid=9338

[Jonathan (jjcf89)]

A new Xorg crash was uploaded which appears to pre-date my calculator testing.

https://errors.ubuntu.com/oops/1a7a233e-5782-11e8-baa0-fa163ebeb28a

[Jonathan (jjcf89)]

Another crash? where I was logged out of gnome. This time I had enabled debug in /etc/gdm3/custom.conf

https://errors.ubuntu.com/oops/d1415efe-5785-11e8-bf54-fa163eec78fa

[Jonathan (jjcf89)]

I'm seeing more crashes where either my desktop locks up and the computer reboots. Or I get returned to the login screen.

Why do some of the "DuplicateOf" links shown by the ubuntu bug report tool not work?
https://bugs.launchpad.net/bugs/1745664

Two more error reports
https://errors.ubuntu.com/oops/9a5971bc-5869-11e8-ac5b-fa163e30221b
https://errors.ubuntu.com/oops/ace611be-5869-11e8-9c14-fa163ef911dc

[Daniel van Vugt (vanvugt)]

Thanks for the links. Note that each of those links themselves contains links to the main problem reports at the bottom of the page. So you are experiencing bug 1771485, bug 1543192, bug 1771486 and bug 1771484 at least.

As we know those bugs are often about login failures and black screen problems I think it is more useful to continue with those specific bugs instead of this one. Especially bug 1543192, which other Nvidia users are reporting.

P.S. Some duplicate bug links don't work because the main bug is marked as Private. Just let us know which ones and we can make the public...

[Jonathan (jjcf89)]

I cannot view my own error reports, it just tells me I don't have permission and am not part of the correct group. I filled out the form to request access so we shall see.

I'm not sure if my original error is a duplicate of bug #154192. There doesn't appear to be a crash involved. gdm-x-session just seems to shut itself down because it couldn't find monitors. Even though it works after a system reload.

 May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE) Screen(s) found, but none have a usable configuration.

It definitely does seem I am being hit by a miriad of bugs. Its getting pretty frustrating to keep using it. And its also hard to tell the difference between them.

Issues as far as I can tell:
* First login fails due to no usable monitors, if wayland is disabled. (Workaround, don't disable wayland)
* gnome-calculator and possibly other snap apps lock up the computer when opened if wayland is disabled. (Workaround, don't disable wayland)
* System locks up and reboots. (Unknown cause, no errors appear in logs as they don't get flushed to disk.)
* Gnome locks up and I am returned to login screen (Unknown cause but seems to generate a variety of different crash reports)

[Daniel van Vugt (vanvugt)]

Thanks for pointing that out. The error you mention is actually right before bug 1543192 happens to you:

May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE) Screen(s) found, but none have a usable configuration.
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE)
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: Fatal server error:
May 9 11:04:06 jcormier-MS-7A93 /usr/lib/gdm3/gdm-x-session[2581]: (EE) no screens found(EE)

So still bug 1543192. Maybe worth commenting on that one about the above.

[Jonathan (jjcf89)]

Posted some info on this bug: https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1745664/comments/7

[Jonathan (jjcf89)]

Daniel,

> If you do not have access to the Ubuntu Error Tracker and are a software developer, you can request it at http://forms.canonical.com/reports/.

Trying to follow these instructions, but its unclear what the answer to the following questions are for the Error Tracker. Does it have a project name? What would my role be? Debugger, customer, developer?
> What software project are you requesting access for?
>
> What is your role within that software project?

[Daniel van Vugt (vanvugt)]

I think your answers would be:

> Does it have a project name?
Yes, "xorg-server". https://launchpad.net/xorg-server

> What would my role be? Debugger, customer, developer?
Customer / debugger.

> What software project are you requesting access for?
"xorg-server". https://launchpad.net/ubuntu/+source/xorg-server

> What is your role within that software project?
User.

[Jonathan (jjcf89)]

Okay thanks. I guess I was thinking that I had to request access specifically to see my error reports in general and not for a specific project. Does that mean that I should request access in each project that I have a error report in order to see them.

[Daniel van Vugt (vanvugt)]

I didn't know normal users had limited access, but that would make sense.

[Jonathan (jjcf89)]

Still no response to my access request...