Bug 1747845 - when the screen blanks (powersave), it can't be resumed
Summary: when the screen blanks (powersave), it can't be resumed
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: mutter
Version: 31
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Florian Müllner
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: AcceptedBlocker AcceptedFreezeException
Depends On: 1748145
Blocks: F31BetaFreezeException F31FinalBlocker
TreeView+ depends on / blocked
 
Reported: 2019-09-02 03:53 UTC by Chris Murphy
Modified: 2019-09-06 17:25 UTC (History)
18 users (show)

Fixed In Version: mutter-3.33.91-2.fc31 mutter-3.33.92-1.fc31
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-09-06 17:25:59 UTC
Type: Bug


Attachments (Terms of Use)
journal (2.88 MB, text/plain)
2019-09-02 04:33 UTC, Chris Murphy
no flags Details
journalctl -b -o short-monotonic (1.61 MB, text/plain)
2019-09-02 05:04 UTC, Chris Murphy
no flags Details
journalctl -b -o short-monotonic, with log_level debug (9.49 MB, text/plain)
2019-09-02 05:31 UTC, Chris Murphy
no flags Details
journal4 (1.13 MB, text/plain)
2019-09-03 00:29 UTC, Chris Murphy
no flags Details
gdb stacktrace of hanging gnome-shell (432.22 KB, text/plain)
2019-09-03 18:33 UTC, Chris Murphy
no flags Details


Links
System ID Priority Status Summary Last Updated
GNOME Gitlab GNOME gdm issues 511 None None None 2019-09-02 03:53:32 UTC
GNOME Gitlab GNOME mutter issues 735 None None None 2019-09-03 18:45:28 UTC

Description Chris Murphy 2019-09-02 03:53:32 UTC
Description of problem:
While at gdm, screen goes black (expected) after period of time, backlight turns off. When I tap a key, e.g. spacebar, backlight comes on, I see a mouse arrow which is frozen, but no other UI. I cannot switch to a tty. I do have access via ssh.

Version-Release number of selected component (if applicable):
kernel-5.3.0-0.rc6.git1.1.fc32.x86_64
gdm-3.33.90-3.fc31.x86_64
gnome-settings-daemon-3.33.90-1.fc31.x86_64
gnome-shell-3.33.91-1.fc31.x86_64
mutter-3.33.91-1.fc31.x86_64
clutter-1.26.2-9.fc31.x86_64
mesa-dri-drivers-19.2.0~rc1-2.fc31.x86_64


How reproducible:
Often but not on demand.


Steps to Reproduce:
1. Log out
2. Wait for backlight to turn off
3. Tap a key

Actual results:

Backlight comes on, frozen mouse arrow appears, GDM fails to appear, can't switch to a tty. ssh is responsive.


Expected results:

I should be at GDM and able to login and also able to switch to a tty.

Additional info:

Comment 1 Chris Murphy 2019-09-02 03:54:27 UTC
Upstream bug has attachment.

Comment 2 Fedora Blocker Bugs Application 2019-09-02 03:56:49 UTC
Proposed as a Blocker for 31-final by Fedora user chrismurphy using the blocker tracking app because:

 "All elements of the default panel (or equivalent) configuration in all release-blocking desktops must function correctly in typical use. "

Comment 3 Chris Murphy 2019-09-02 04:33:34 UTC
Created attachment 1610647 [details]
journal

Note this journal is a full continuation of the one I attached upstream. So I set gdm debugging, isolated multi-user.target, then graphical.target. 

[ 7903.182052]  gdm is now up with debugging enabled, I see the graphical login.

I login and press some backlight keys, [ 7950.056942], and then log out ~ [ 7958.857656]  and I never get to graphical gdm again, just a black screen with a bunch of @@@@'s which eventually give way to a black screen (backlight stays on)

The section starting with this looks interesting
[ 7948.796479] fmac.local gdm[6861]: GdmCommon: process (pid:6929) done (status:0)

I do still have a running gdm process PID 6861.

[ 7966.416603] fmac.local gdm-password][7308]: GdmSessionWorker: jumping to VT 1


At this point I've discovered possible dup bug 1745554.

Comment 4 Chris Murphy 2019-09-02 05:04:00 UTC
Created attachment 1610662 [details]
journalctl -b -o short-monotonic

Clean boot. Login. Logout - fail. gdm debugging is enabled.

Comment 5 Chris Murphy 2019-09-02 05:31:25 UTC
Created attachment 1610663 [details]
journalctl -b -o short-monotonic, with log_level debug

OK, it doesn't always happens. Yet another new boot, this time with systemd.log_level=debug set.

login, logout - this works, I see graphical gdm
login, logout - this fails, no gdm, I see text on screen 
[ 109.   ]
[  117.577471] fmac.local systemd[1]: systemd-journald.service: Got notification message from PID 592 (WATCHDOG=1)

And also I see in the journal an entry for the last time I pressed a brightness key, [   99.245937], right before logging out. So it's those ten seconds between [   99.245937] and 109 that contain whatever is going wrong.

Comment 6 Michael Catanzaro 2019-09-02 11:52:22 UTC
(In reply to Fedora Blocker Bugs Application from comment #2)
> Proposed as a Blocker for 31-final by Fedora user chrismurphy using the
> blocker tracking app because:
> 
>  "All elements of the default panel (or equivalent) configuration in all
> release-blocking desktops must function correctly in typical use. "

+1 blocker

Clever choice of blocker criterion. We've previously rejected having a blocker criterion for logout or switch users functionality, but I've never agreed with such pessimism that we can't expect basic desktop features to work properly. We surely can. And the functionality is indeed exposed via the default panel, so it should be covered.

Comment 7 Chris Murphy 2019-09-03 00:29:06 UTC
Created attachment 1611014 [details]
journal4

I'm going to focus this bug on the failure at gdm during blanking, rather than the logout. Monotonic times based on this attached journal.


screen goes blank (expected)

[  315.801361] fmac.local gnome-session-binary[1086]: gnome-session-binary[1086]: DEBUG(+): GsmPresence: setting idle: 1



Tap trackpad button and keys to wake it up - I see a text screen, I never see gdm

[  473.223349] fmac.local gnome-session-binary[1086]: gnome-session-binary[1086]: DEBUG(+): GsmPresence: setting idle: 0


What is this?
[  474.502461] fmac.local kernel: gnome-shell[1102]: segfault at 58 ip 00007f7daff6aa5a sp 00007ffca978ebb0 error 4 in libmutter-5.so.0.0.0[7f7dafe7b000+fa000]


[chris@fmac ~]$ sudo coredumpctl
No coredumps found.
[chris@fmac ~]$ sudo abrt-cli list
No problems

The auto-reporting feature is disabled. Please consider enabling it by issuing “abrt-auto-reporting enabled” as a user with root privileges.
[chris@fmac ~]$ 

Why no coredump collected?

[chris@fmac ~]$ systemctl list-unit-files | grep core
abrt-journal-core.service                    enabled        
abrt-vmcore.service                          enabled        
systemd-coredump@.service                    static         
systemd-coredump.socket                      static         
[chris@fmac ~]$ systemctl list-unit-files | grep abrt
abrt-ccpp.service                            disabled       
abrt-journal-core.service                    enabled        
abrt-oops.service                            enabled        
abrt-pstoreoops.service                      disabled       
abrt-vmcore.service                          enabled        
abrt-xorg.service                            enabled        
abrtd.service                                enabled        
[chris@fmac ~]$

Comment 8 Chris Murphy 2019-09-03 00:35:00 UTC
Arguably I've narrowed this incorrectly, the failure to come back to GDM is a bad bug to ship in a beta; where the failure to logout is a bad bug to ship in final. I'm gonna stop talking and let adamw sort out the mess :P

Comment 9 Michael Catanzaro 2019-09-03 00:52:07 UTC
(In reply to Chris Murphy from comment #7) 
> Why no coredump collected?

Yeah, WTF. :( The gnome-shell crash is definitely the problem here and the gnome-shell developers can't debug it without a core dump. (The login screen that you see has been gnome-shell for nearly a decade now, not the gdm process.)

Comment 10 Chris Murphy 2019-09-03 01:14:56 UTC
Darn, and gnome-shell doesn't always segfault. So far it always fails to cover from blanking when I touch trackpad or key, but there are two failures: segfault or this:


[  474.401408] fmac.local gnome-session-binary[1084]: gnome-session-binary[1084]: DEBUG(+): GsmPresence: setting idle: 0
[  474.401408] fmac.local gnome-session-binary[1084]: gnome-session-binary[1084]: DEBUG(+): Updating systemd idle status: 0
[  474.406159] fmac.local gnome-session-binary[1084]: DEBUG(+): GsmPresence: setting idle: 0
[  474.406421] fmac.local systemd[1]: systemd-journald.service: Got notification message from PID 593 (WATCHDOG=1)
[  474.407597] fmac.local gnome-session-binary[1084]: gnome-session-binary[1084]: DEBUG(+): GsmPresence: setting non-idle status 0
[  474.407718] fmac.local gnome-session-binary[1084]: DEBUG(+): Updating systemd idle status: 0
[  474.407909] fmac.local systemd-logind[974]: Got message type=method_call sender=:1.36 destination=org.freedesktop.login1 path=/org/freedesktop/login1/session/c1 interface=org.freedesktop.login1.Session member=SetIdleHint cookie=26 reply_cookie=0 signature=b error-name=n/a error-message=n/a
[  474.408982] fmac.local gnome-session-binary[1084]: DEBUG(+): GsmPresence: setting non-idle status 0
[  474.409168] fmac.local systemd-logind[974]: Sent message type=method_call sender=n/a destination=org.freedesktop.DBus path=/org/freedesktop/DBus interface=org.freedesktop.DBus member=GetConnectionUnixUser cookie=158 reply_cookie=0 signature=s error-name=n/a error-message=n/a
[  474.409510] fmac.local systemd-logind[974]: Got message type=method_return sender=org.freedesktop.DBus destination=:1.26 path=n/a interface=n/a member=n/a cookie=4294967295 reply_cookie=158 signature=u error-name=n/a error-message=n/a
[  474.409870] fmac.local systemd-logind[974]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/login1/session/c1 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=159 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  474.410149] fmac.local systemd-logind[974]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/login1/seat/seat0 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=160 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  474.410393] fmac.local systemd-logind[974]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/login1/user/_42 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=161 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  474.410628] fmac.local systemd-logind[974]: Sent message type=signal sender=n/a destination=n/a path=/org/freedesktop/login1 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=162 reply_cookie=0 signature=sa{sv}as error-name=n/a error-message=n/a
[  474.414594] fmac.local gnome-shell[1101]: (../src/backends/native/meta-renderer-native.c:2211):meta_onscreen_native_swap_buffers_with_damage: runtime check failed: (onscreen_native->gbm.next_fb == NULL)
[  474.421171] fmac.local pkexec[1527]: gdm: The value for the SHELL variable was not found the /etc/shells file [USER=root] [TTY=unknown] [CWD=/var/lib/gdm] [COMMAND=/usr/libexec/gsd-backlight-helper /sys/devices/pnp0/00:03/backlight/gmux_backlight 54605]
[  474.422599] fmac.local gsd-power[1182]: The value for the SHELL variable was not found the /etc/shells file
[  474.422599] fmac.local gsd-power[1182]: This incident has been reported.
[  474.423549] fmac.local gsd-power[1182]: Error executing backlight helper: Child process stopped by signal 0
[  474.471264] fmac.local gnome-shell[1101]: (../src/backends/native/meta-renderer-native.c:2211):meta_onscreen_native_swap_buffers_with_damage: runtime check failed: (onscreen_native->gbm.next_fb == NULL)
[  475.235402] fmac.local pkexec[1528]: gdm: The value for the SHELL variable was not found the /etc/shells file [USER=root] [TTY=unknown] [CWD=/var/lib/gdm] [COMMAND=/usr/libexec/gsd-backlight-helper /sys/devices/pnp0/00:03/backlight/gmux_backlight 48900]
[  475.236254] fmac.local gsd-power[1182]: The value for the SHELL variable was not found the /etc/shells file
[  475.236254] fmac.local gsd-power[1182]: This incident has been reported.
[  475.237166] fmac.local gsd-power[1182]: Error executing backlight helper: Child process stopped by signal 0


In the case of segfault, I see text on the screen instead of graphical login. In the case of no crash (above), I see a frozen mouse pointer but an otherwise black screen. I'd like to reproduce a crash while systemd.log_level=debug so I can file a bug against systemd for not capturing the coredump, but I'm not certain of the coredump mechanism either.

Comment 11 Chris Murphy 2019-09-03 03:36:25 UTC
"process segfaults but systemd-coredump does not capture it" - bug 1748145

Comment 12 Chris Murphy 2019-09-03 18:27:06 UTC
This happens while logged in too, not just as the login screen. While logged in, if I change Settings>Power>Blank screen, to 1 minute, let it blank the screen, then tap a key or touch the touchpad, the graphical session does not resume. I see a black screen with a frozen mouse pointer. This is all that's recorded.

(screen blanks)

Sep 03 12:18:50 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): GsmManager: CanShutdown called
Sep 03 12:18:50 fmac.local gnome-session-binary[1581]: DEBUG(+): GsmManager: CanShutdown called
Sep 03 12:18:56 fmac.local systemd[1]: Starting Hostname Service...
Sep 03 12:18:56 fmac.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Sep 03 12:18:56 fmac.local systemd[1]: Started Hostname Service.
Sep 03 12:19:01 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): GsmPresence: adding idle watch (1) for 60 secs
Sep 03 12:19:01 fmac.local gnome-session-binary[1581]: DEBUG(+): GsmPresence: adding idle watch (1) for 60 secs
Sep 03 12:19:36 fmac.local systemd[1]: systemd-hostnamed.service: Succeeded.
Sep 03 12:19:36 fmac.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting idle: 1
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting idle: 1
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): Updating systemd idle status: 1
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: DEBUG(+): Updating systemd idle status: 1
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting idle: 1
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): GsmPresence: already idle, ignoring
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting idle: 1
Sep 03 12:20:08 fmac.local gnome-session-binary[1581]: DEBUG(+): GsmPresence: already idle, ignoring
Sep 03 12:20:08 fmac.local gnome-shell[1595]: (../src/backends/native/meta-renderer-native.c:2211):meta_onscreen_native_swap_buffers_with_damage: runtime check failed: (onscreen_native->gbm.next_fb == NULL)



(touch trackpad and keyboard keys)

Sep 03 12:20:34 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting idle: 0
Sep 03 12:20:34 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): Updating systemd idle status: 0
Sep 03 12:20:34 fmac.local gnome-session-binary[1581]: gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting non-idle status 0
Sep 03 12:20:34 fmac.local gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting idle: 0
Sep 03 12:20:34 fmac.local gnome-session-binary[1581]: DEBUG(+): Updating systemd idle status: 0
Sep 03 12:20:34 fmac.local gnome-session-binary[1581]: DEBUG(+): GsmPresence: setting non-idle status 0
Sep 03 12:20:34 fmac.local gnome-shell[1595]: (../src/backends/native/meta-renderer-native.c:2211):meta_onscreen_native_swap_buffers_with_damage: runtime check failed: (onscreen_native->gbm.next_fb == NULL)



Is there a way to attach gdb to gnome-shell and get anything useful? When would I attach it?

Comment 13 Chris Murphy 2019-09-03 18:28:14 UTC
Sorry!

Comment 14 Chris Murphy 2019-09-03 18:33:40 UTC
Created attachment 1611261 [details]
gdb stacktrace of hanging gnome-shell

Starting off at the hung state in comment 12, I did

$ sudo gdb -p 1595
(gdb) thread apply all bt full


Full output of that is attached.

Comment 15 Chris Murphy 2019-09-03 19:07:30 UTC
Following bug 174554, updated systemd with these rpms https://koji.fedoraproject.org/koji/taskinfo?taskID=37436968 which has this https://github.com/systemd/systemd/pull/13454 

And now I can't reproduce this bug either.

Comment 16 Chris Murphy 2019-09-03 19:42:50 UTC
Spoke too soon, just got a failure;  meaning it's not as reproducible as I thought. I will test mutter-3.33.91-2.fc31 a few times and report back.

Comment 17 Chris Murphy 2019-09-03 20:21:04 UTC
mutter-3.33.91-2.fc31 has fixed this; 5 for 5 blanks and successful wake up at login screen; and 5 for 5 while logged in and blanking set for 1 minute.

Comment 18 Geoffrey Marr 2019-09-03 22:13:20 UTC
Discussed during the 2019-09-03 blocker review meeting: [1]

The decision to classify this bug as a "RejectedBlocker" and an "AcceptedFreezeException" was made as we believe it violates the Blocker criterion in comment 2 and is encountered immediately after install, so cannot be fixed with an update.

[1] https://meetbot.fedoraproject.org/fedora-blocker-review/2019-09-03/f31-blocker-review.2019-09-03-16.01.txt

Comment 19 Fedora Update System 2019-09-06 16:02:10 UTC
FEDORA-2019-18f7fc4f08 has been submitted as an update to Fedora 31. https://bodhi.fedoraproject.org/updates/FEDORA-2019-18f7fc4f08

Comment 20 Adam Williamson 2019-09-06 16:03:01 UTC
A later build of mutter is in the mega-update, so I've tagged the mega-update as fixing this.

Comment 21 Fedora Update System 2019-09-06 17:25:59 UTC
accerciser-3.33.92-1.fc31, at-spi2-atk-2.33.92-1.fc31, at-spi2-core-2.33.92-1.fc31, atomix-3.33.92-1.fc31, bijiben-3.33.92-1.fc31, epiphany-3.33.92-1.fc31, evolution-3.33.92-1.fc31, evolution-data-server-3.33.92-1.fc31, evolution-ews-3.33.92-1.fc31, four-in-a-row-3.33.92-1.fc31, gdm-3.33.92-1.fc31, geary-3.33.90-1.fc31, gedit-3.33.92-1.fc31, gedit-plugins-3.33.92-1.fc31, gjs-1.57.92-1.fc31, glib-networking-2.61.92-1.fc31, glib2-2.61.3-1.fc31, gnome-builder-3.33.92-1.fc31, gnome-calculator-3.33.92-1.fc31, gnome-contacts-3.33.92-1.fc31, gnome-desktop3-3.33.92.1-1.fc31, gnome-disk-utility-3.33.92-1.fc31, gnome-maps-3.33.92-1.fc31, gnome-mines-3.33.92-1.fc31, gnome-music-3.33.92-1.fc31, gnome-online-accounts-3.33.92-1.fc31, gnome-online-miners-3.33.92-1.fc31, gnome-session-3.33.92-1.fc31, gnome-shell-3.33.92-1.fc31, gnome-shell-extensions-3.33.92-1.fc31, gnome-terminal-3.33.90-1.fc31, gtk3-3.24.11-1.fc31, gtksourceview4-4.3.92-1.fc31, hitori-3.34.0-1.fc31, iagno-3.33.92-1.fc31, libgnome-games-support-1.4.4-1.fc31, libgweather-3.33.92-1.fc31, libpeas-1.23.92-1.fc31, librsvg2-2.45.92-1.fc31, libsoup-2.67.93-1.fc31, lightsoff-3.33.92-1.fc31, mutter-3.33.92-1.fc31, orca-3.33.91-1.fc31, pango-1.44.6-1.fc31, polari-3.33.92-1.fc31, pyatspi-2.33.92-1.fc31, simple-scan-3.33.92-1.fc31, swell-foop-3.33.92-1.fc31, sysprof-3.33.92-1.fc31, template-glib-3.33.92-1.fc31, yelp-3.33.92-1.fc31, yelp-xsl-3.33.92-1.fc31 has been pushed to the Fedora 31 stable repository. If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.