Bug 1269581

Created attachment 1080742 [details]
journal of system booting with delay and shutting down with delay (VM)

Somewhere around 15:28:24 is probably where plymouth transitions to black screen and I wait 90 seconds before user session appears. 15:32:16 is where X crashes and systemd starts waiting 90 seconds before shut down.

Created attachment 1080743 [details]
list of installed packages

This is coredump captured using coredumpctl, which happens during reboot:

           PID: 1180 (Xorg)
           UID: 1000 (kparal)
           GID: 1000 (kparal)
        Signal: 6 (ABRT)
     Timestamp: Wed 2015-10-07 15:32:13 CEST (34min ago)
  Command Line: /usr/libexec/Xorg vt1 -displayfd 3 -auth /run/user/1000/gdm/Xauthority -nolisten tcp -background none -noreset -keeptty -verbose 3
    Executable: /usr/libexec/Xorg
 Control Group: /user.slice/user-1000.slice/session-1.scope
          Unit: session-1.scope
         Slice: user-1000.slice
       Session: 1
     Owner UID: 1000 (kparal)
       Boot ID: a2d56fff400a423ca71c0d39ca105d02
    Machine ID: 5e6876234deaa74093559f88adbbd66f
      Hostname: localhost.localdomain
      Coredump: /var/lib/systemd/coredump/core.Xorg.1000.a2d56fff400a423ca71c0d39ca105d02.1180.1444224733000000.xz
       Message: Process 1180 (Xorg) of user 1000 dumped core.
                
                Stack trace of thread 1180:
                #0  0x00007f7648b4ba98 raise (libc.so.6)
                #1  0x00007f7648b4d69a abort (libc.so.6)
                #2  0x000000000059d48e OsAbort (Xorg)
                #3  0x00000000005a3e77 FatalError (Xorg)
                #4  0x000000000049d721 switch_to (Xorg)
                #5  0x000000000049e103 xf86CloseConsole (Xorg)
                #6  0x0000000000479305 ddxGiveUp (Xorg)
                #7  0x00000000005a3072 AbortServer (Xorg)
                #8  0x00000000005a3ead FatalError (Xorg)
                #9  0x000000000049d721 switch_to (Xorg)
                #10 0x000000000049e103 xf86CloseConsole (Xorg)
                #11 0x0000000000479305 ddxGiveUp (Xorg)
                #12 0x000000000043aab9 dix_main (Xorg)
                #13 0x00007f7648b37580 __libc_start_main (libc.so.6)
                #14 0x0000000000424b79 _start (Xorg)


I'll try to attach a full traceback using gdb soon.

I propose this for a blocker or at least freeze exception discussion. These criteria seem to be relevant:
"Shutting down, logging out and rebooting must work using standard console commands and the mechanisms offered (if any) by all release-blocking desktops. "
https://fedoraproject.org/wiki/Fedora_23_Beta_Release_Criteria#Shutdown.2C_reboot.2C_logout
Shut down "works", but takes extremely long and the PC often looks frozen (or even in a state of hardware failure, when display is off but the PC doesn't want to shut down) during that time. If at least systemd was showing "Waiting for foo service to shut down" message on the screen, it would be better, but it doesn't.

"All applications that can be launched using the standard graphical mechanism of a release-blocking desktop after a default installation of that desktop must start successfully and withstand a basic functionality test. "
https://fedoraproject.org/wiki/Fedora_23_Final_Release_Criteria#Default_application_functionality
Or alternatively default panel functionality, whether you want to consider gnome-control-center part of apps or system panel. It exposes autologin feature quite visibly, but it doesn't work properly (I know, it's far fetched, but I don't see any better fitting 'login' criterion.)

The problem is that autologin is quite popular functionality in home use and currently it's quite broken. Users won't tolerate waiting 90 seconds for boot and 90 seconds for shutdown.

In case the boot and shut down issues are separate (the second seems to be an Xorg crash, not sure what the first is), it might make sense to discuss them and decide on them separately.

I was able to reproduce this on bare metal with classic HDD. Startup delay seems to be quite random (from ~ 15s to 60s longer boot). Shutdown is consistent, every reboot/shutdown after auto login results in long delay and core dump (as in comment #3).

(In reply to Kamil Páral from comment #3)
> I'll try to attach a full traceback using gdb soon.

The Xorg crash is now reported by abrt as bug 1269819. We can use that bug for shutdown issue tracking, if it turns out to be non-related to login issue.

Discussed during the 2015-10-12 blocker review meeting [1]:

Consensus was not reached WRT blocker status and the discussion will be resumed at the next blocker review meeting when more information is available.

[1] https://meetbot-raw.fedoraproject.org/fedora-blocker-review/2015-10-12/f23-blocker-review.2015-10-12-16.01.html

Discussed during the 2015-10-12 blocker review meeting [1]:

While blocker status consensus was not reached, a tested fix would be considered for inclusion in F23 final after freeze.

[1] https://meetbot-raw.fedoraproject.org/fedora-blocker-review/2015-10-12/f23-blocker-review.2015-10-12-16.01.html

I have now verified that this affects F23 TC6 Workstation Live as well. The boot delay is again random (I have seen 60 seconds and I have seen 0 seconds), the shutdown delay is consistently 90 seconds.

We have other reports as well:
https://lists.fedoraproject.org/pipermail/test/2015-October/128110.html
(again, people consider the PC to be stuck and power it off forcefully)

This will probably make our blocker decision a bit easier :)

I have narrowed this down to gnome-keyring (and most likely, gnome-keyring-pam). F23 Beta Live works perfectly, and it contains gnome-keyring-3.16.0-2.fc23. If you install it and update to gnome-keyring-3.18.0-1.fc23, the random boot delay occurs.

The shutdown xorg crash is also caused by gnome-keyring, but it only occurs with combination with other updated packages (not sure which, it's not just newer gnome-keyring + xorg, there's more to it). However, if I downgrade gnome-keyring on a fully updated F23 system, not just the boot delay, but also the shutdown delay disappears. That allows me to blame gnome-keyring for both these issues :)

I also tested gnome-keyring-3.17.91-1.fc23, it's broken as well. So the problem occurred somewhere between gnome-keyring-3.16.0-2.fc23 and gnome-keyring-3.17.91-1.fc23.

duping this to bug because Owen looked into this a bit and has some deeper analysis on that bug.

*** This bug has been marked as a duplicate of bug 1266650 ***

*** Bug 1266650 has been marked as a duplicate of this bug. ***

making this side the master bug because it has all the blocker tracking on it.

The important bits from the other bug are these quotes from owen:

(In reply to Owen Taylor from bug 1266650 comment #1)
> I was able to reproduce this easily, and partially have this tracked own
> now. The basic problem is multiple different attempts to start the
> gnome-keyring daemon interfering with each other. When pam_gnome_keyring is
> used (for normal with-password login), gnome-keyring is started differently
> and the issue doesn't occur.
> 
> What happens, as I see it, is that there are two processes of
> gnome-keyring-daemon --secrets running. (Caveat emptor in the below... it's
> something *sort of* like this.)
> 
>  Copy A) - run by D-Bus activation from the service file, D-Bus thinks it
> has the service name, but it *doesn't*, and because of the --foreground
> option passed in the service file, it is waiting in a blocking sleep forever.
> 
>  Copy B) - run by the desktop file in /etc/xdg/autostart
> 
> For GNOME alone, what might work is to make the service files in
> /etc/xdg/autostart DBusActivatable=true so everything is launched via D-Bus
> in a race-free fashion. But the autostart files are also used by Unity and
> MATE - so perhaps what would be better is to do:
> 
>  Exec=gdbus introspect --session --dest org.freedesktop.secrets
> --object-path /org/freedesktop/secrets
> 
> Or have starting by activation be part of an executable shipped with
> gnome-keyring.

(In reply to Owen Taylor from comment #3)
> It's possible that unsplitting the autostart and starting only a single
> gnome-keyring to handle secrets/ssh/pkcs11 would hide the issue. It seems
> that is how things end up working when pam_gnome_keyring is in effect. (And
> the autostart jobs just exit immediately?)
> 
> But I do think the setup is conceptually problematical - the service file
> has:
> 
> [D-BUS Service]
> Name=org.freedesktop.secrets
> Exec=/usr/bin/gnome-keyring-daemon --start --foreground --components=secrets
> 
> But the Exec line does *not* necessarily* provide the service - it can look
> on the bus, see the name already there, and just sleep forever. I think this
> inherently runs afoul of the race-free singleton handling in the DBus server.

With autologin enabled, I see these processes running:

$ pgrep -fa keyring
1149 /usr/bin/gnome-keyring-daemon --start --components=pkcs11
1151 /usr/bin/gnome-keyring-daemon --start --components=secrets
1154 /usr/bin/gnome-keyring-daemon --start --components=ssh
2129 /usr/bin/gnome-keyring-daemon --start --foreground --components=secrets

> > For GNOME alone, what might work is to make the service files in
> > /etc/xdg/autostart DBusActivatable=true so everything is launched via D-Bus

I tried to add this to /etc/xdg/autostart/gnome-keyring-* but it didn't help. Maybe I was doing something wrong.

I also tried deleting all those files. That resolved boot and shutdown problems. It also reduced the number of running gnome-keyring processes to one::

$ pgrep -fa keyring
2080 /usr/bin/gnome-keyring-daemon --start --foreground --components=secrets

ABRT seems to store and retrieve bugzilla credentials correctly (seahorse also displays the login keyring, after reboot, correctly).

This seems to confirm that this problem is related to what Owen described.

There seem to be this problem in the F23 Final TC6 x86_64 Desktop liveCD.
I booted the liveCD, installed TC6
onto an external disk, clicked on shutdown in the menue the liveCD displays, the
screen becomes black, but the signal (a blue lamp on my Acer laptop) is still on
PC running. I had to manually unplug the PC. This is easy to verify again.

Could someone try if http://koji.fedoraproject.org/koji/taskinfo?taskID=11447212 improves things, please?

(In reply to Kalev Lember from comment #16)
> Could someone try if
> http://koji.fedoraproject.org/koji/taskinfo?taskID=11447212 improves things,
> please?


I tried this out - but the problems persist

# rpm -q gnome-keyring gnome-keyring-pam
gnome-keyring-3.18.0-2.fc23.x86_64
gnome-keyring-pam-3.18.0-2.fc23.x86_64

- google-chrome still takes a long time to start [ as reported in #1266650 ]
- bootup and shutdown times are noticeably longer

(In reply to Kalev Lember from comment #16)
> Could someone try if
> http://koji.fedoraproject.org/koji/taskinfo?taskID=11447212 improves things,
> please?

I've tried to install the package to see if the mentioned delays go away, but was kicked out of the session the second gnome-software installed it. I can't login now, on boot I end up with the console. startx gives me 'oh no!' screen. tried downgrading with no luck. does your package alter any other settings which could prevent my system from starting properly? thanks

(In reply to core bots from comment #18)
> does your package alter any other settings which could prevent my system from starting properly? thanks

The only difference between 3.18.0-1 and 3.18.0-2 is that -2 has the patch from https://git.gnome.org/browse/gnome-keyring/commit/?id=3cf744f67939dc23c2cc8715cda999a7ec13f1b6

Created attachment 1083205 [details]
journal with gnome-keyring-3.18.0-2.fc23

(In reply to Kalev Lember from comment #16)
> Could someone try if
> http://koji.fedoraproject.org/koji/taskinfo?taskID=11447212 improves things,
> please?

Doesn't seem to help. Both boot and shutdown are still delayed by 90 seconds. After boot, I see:

[kparal@localhost ~]$ pgrep -fa keyring
1446 /usr/bin/gnome-keyring-daemon --start --components=ssh
1450 /usr/bin/gnome-keyring-daemon --start --components=pkcs11
1454 /usr/bin/gnome-keyring-daemon --start --components=secrets
2139 /usr/bin/gnome-keyring-daemon --start --foreground --components=secrets

Journal from boot & reboot attached.

(In reply to Kalev Lember from comment #19)
> (In reply to core bots from comment #18)
> > does your package alter any other settings which could prevent my system from starting properly? thanks
> 
> The only difference between 3.18.0-1 and 3.18.0-2 is that -2 has the patch
> from
> https://git.gnome.org/browse/gnome-keyring/commit/
> ?id=3cf744f67939dc23c2cc8715cda999a7ec13f1b6

thanks, after downgrading to 3.18.0-1, running ' dnf groupinstall "Fedora Workstation" ' and disabling selinux i can boot normally again; also chrome starts promptly and there are no delays when shutting down again, surprisingly.

I think we should consider reverting to gnome-keyring 3.16 at this point.

Lets wait a few more hours before doing so... Ray wants to have a look

Hi,

> > > For GNOME alone, what might work is to make the service files in
> > > /etc/xdg/autostart DBusActivatable=true so everything is launched via D-Bus
> 
> I tried to add this to /etc/xdg/autostart/gnome-keyring-* but it didn't
> help. Maybe I was doing something wrong.
So in order for DBusActivatable to work, the files have to be named using a specific convention (the name of the dbus name they'll take).  so the files have the wrong names, but only one of them gets dbus activated anyway..

> I also tried deleting all those files. That resolved boot and shutdown
> problems.
So I think this is actually right. well not all the files, but the secrets one. there's no point in autostarting the secrets service since it's used via dbus anyway. The things that should be autostarted are the agents accessed via sockets.

So the easy fix here is to not ship the gnome-keyring-secrets autostart file...

okay i've pushed two changes that I think should fix this (at least for now):

1) no longer ship gnome-keyring-secrets.desktop for the reason mentioned in comment 24

2) kparal also discovered, on irc, a deadlock that causes the same symptoms but for a different reason: gnome-keyring is forking after initializing glib which is a big no no. I wrote a patch to make it fork earlier.

Unfortunately i'm the world's worst person when it comes to being able to reproduce bugs, so i'd appreciate if someone who's good at hitting bugs would try out the latest build and make sure it actually resolves the issues.

http://koji.fedoraproject.org/koji/taskinfo?taskID=11463977

so playing with this in non-autologin mode i see i somehow broke the password hand off from pam

so i figured out how i broke the hand off (I moved some code that closed file descriptors to an earlier place).

will do some testing and push a new fix.

gnome-keyring-3.18.0-4.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2015-cb9d7bac15

Discussed at 2015-10-15 blocker review meeting: https://meetbot-raw.fedoraproject.org/fedora-blocker-review/2015-10-15/f23-blocker-review.2015-10-15-20.11.log.txt . Accepted as a blocker: the most relevant criterion - "Shutting down, logging out and rebooting must work using standard console commands and the mechanisms offered (if any) by all release-blocking desktops" - only applies to post-install, but we agreed in principle that extending at least the 'shutdown' requirement to installer images made sense, and that will be proposed on the mailing list.

We agreed that while it's usually safe to force shutdown a live image, requiring everyone who ever boots an f23 Workstation live image to do this or wait 90 seconds is a pretty bad look and not acceptable for a final release OS.

gnome-keyring-3.18.0-4.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update gnome-keyring'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-cb9d7bac15

gnome-keyring-3.18.0-4.fc23 fixes all the issues for me. Great work, Ray. I tested both autologin and passworded-login, I spotted no issues. Seahorse worked fine, ABRT saved and loaded from keyring, and I saw no login or reboot delays (tested with many many reboots).

One thing, though. Ray, in gnome-keyring-3.18.0-3.fc23 you removed gnome-keyring-secrets.desktop file, in gnome-keyring-3.18.0-4.fc23 you added it back. Is that intentional? I tested both with and without this file and haven't spotted any issues. Still, I wonder if it's a simple mistake and the file should not be there.

It's actually intentional:

* Thu Oct 15 2015 Ray Strode <rstrode> 3.18.0-4•
...
- Remove unneccessary part of autologin fix•

Turns, out the second file doesn't cause problems when we fix the deadlock, and I'd rather keep changes as minimal as possible at this stage to minimize risk.  Sorry for forgetting to mention that, and thanks for the keen eye/careful review. Appreciated.

Just run the F23 Final Desktop TC11 Live CD on an usb flash medium.
Shutdown by power off via menue successful. PC automatical totally shut down.

We have another bug report, https://bugzilla.redhat.com/show_bug.cgi?id=1272646 where people are saying that they are unable to log in to Xfce and MATE with lightdm. Stef thinks that the gnome-keyring fixes that went upstream might possibly fix this.

I'm doing a 3.18.1 build with the upstreamed fixes, let's see how it goes. Hopefully it doesn't auto-obsolete the update in bodhi so that we can choose which one to pick for the images.

gnome-keyring-3.18.1-1.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2015-b63ce6ef7b

gnome-keyring-3.18.1-1.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update gnome-keyring'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-b63ce6ef7b

gnome-keyring-3.18.1-2.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2015-b63ce6ef7b

gnome-keyring-3.18.1-2.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
If you want to test the update, you can install it with
$ su -c 'dnf --enablerepo=updates-testing update gnome-keyring'
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2015-b63ce6ef7b

Seems to work well with gnome-keyring-3.18.1-2.fc23.

gnome-keyring-3.18.1-2.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.