Slow login after updating from 17.04 to 17.10

[xonox]

I just did the upgrade from 17.04 to 17.10 and everything works fine.
The systems boots up quickly enough. But from the time i enter my password to the time i get to the desktop, it takes 40-60 seconds. It wasn't like this before.

I'm not that experienced with linux troubleshooting. I searched on google but i couldn't find what to do... I don't want to make things worse so i'm asking for help

I tried peeking in /var/log/syslog and it seems it could be rtkit taking some time to start when i log in.

Here's a glimpse of what's in /var/log/syslog after i login:

Jan 19 20:50:11 dubstation systemd[1]: Removed slice User Slice of sddm.
Jan 19 20:50:14 dubstation nm-dispatcher: req:3 'connectivity-change': start running ordered scripts...
Jan 19 20:50:20 dubstation systemd-timesyncd[705]: Synchronized to time server 91.189.89.199:123 (ntp.ubuntu.com).
Jan 19 20:51:02 dubstation dbus[921]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service'
Jan 19 20:51:02 dubstation systemd[1]: Starting RealtimeKit Scheduling Policy Service...
Jan 19 20:51:02 dubstation dbus[921]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Jan 19 20:51:02 dubstation systemd[1]: Started RealtimeKit Scheduling Policy Service.

Thanks a lot!

[xonox]

I also tried creating another user to see if the problem was still happening. Login is still slow. Logout is fast but logging in again with the same or another user is slow.

[oshunluvr]

Well,

systemd-analyze blame

can help determine what is taking so long to launch, but it seems you've found it. AFAIK rtkit-daemon isn't installed by default. Some other program must have it as a dependency. You might start looking there to see if you can eliminate or disable it.

[xonox]

Hi oshunluvr,
first : thanks for the help, i really appreciate it.

i didn't know what rtkit was but now i think it might have been installed when i installed the jack audio server.
However it seems pulse audio depends on it.

apt-cache rdepends rtkit :

rtkit
Reverse Depends:
pulseaudio
multimedia-jack

It's getting late here but i will investigate this tomorrow. I made a system image with clonezilla before upgrading so no worries if i mess up something.

systemd-analyze blame doesn't seem to be aware of what's taking 40+ seconds when i login however.

Here is it's output :

         10.030s systemd-resolved-update-resolvconf.service
        3.272s NetworkManager-wait-online.service
         587ms dev-sda2.device
         394ms keyboard-setup.service
         323ms systemd-timesyncd.service
         261ms mpd.service
         190ms accounts-daemon.service
         182ms grub-common.service
         172ms apport.service
         165ms systemd-logind.service
         162ms lm-sensors.service
         154ms gpu-manager.service
         154ms pppd-dns.service
         148ms rsyslog.service
         144ms avahi-daemon.service
         144ms winbind.service
         141ms thermald.service
         135ms apparmor.service
         111ms systemd-resolved.service
          86ms snapd.service
          85ms ModemManager.service
          82ms NetworkManager.service
          68ms udisks2.service
          49ms systemd-udevd.service
          46ms upower.service
          44ms virtualbox.service
          40ms systemd-journald.service
          36ms systemd-udev-trigger.service
          34ms systemd-tmpfiles-clean.service
          31ms systemd-tmpfiles-setup.service
          30ms binfmt-support.service
          24ms systemd-tmpfiles-setup-dev.service
          24ms polkit.service
          22ms networking.service
          22ms plymouth-quit-wait.service
          22ms systemd-modules-load.service
          22ms plymouth-quit.service
          21ms packagekit.service
          19ms alsa-restore.service
          17ms user@1000.service
          17ms plymouth-start.service
          10ms plymouth-read-write.service
           9ms resolvconf.service
           9ms systemd-journal-flush.service
           8ms nvidia-persistenced.service
           7ms systemd-sysctl.service
           7ms dev-mqueue.mount
           7ms dev-hugepages.mount
           7ms proc-sys-fs-binfmt_misc.mount
           7ms sys-kernel-debug.mount
           6ms console-setup.service
           6ms kerneloops.service
           5ms systemd-update-utmp.service
           5ms dev-disk-by\x2duuid-a748b6d9\x2d1ba5\x2d4249\x2d90de\x2de3afaacb1d54.swap
           5ms systemd-remount-fs.service
           4ms systemd-user-sessions.service
           3ms kmod-static-nodes.service
           3ms ufw.service
           3ms snapd.socket
           3ms sddm.service
           2ms systemd-random-seed.service
           2ms systemd-update-utmp-runlevel.service
           2ms rtkit-daemon.service
           2ms setvtrgb.service
           1ms sys-fs-fuse-connections.mount
           1ms sys-kernel-config.mount

I'll post back tommorow. I

[oshunluvr]

That all looks normal. Unless you really need the jack audio server, you might want to dump it and rtkit too. At least @here, rtkit doesn't show up as a depends with pulseaudio. I have pulseaudio installed but not rtkit.

[chimak111]

On Kubuntu 16.04 LTS with kubuntu-backports, I have quite a few rtkit entries:

$ locate rtkit
/lib/systemd/system/rtkit-daemon.service
/usr/lib/rtkit
/usr/lib/rtkit/rtkit-daemon
/usr/lib/rtkit/rtkit-test
/usr/sbin/rtkitctl
/usr/share/doc/rtkit
/usr/share/doc/rtkit/README.gz
/usr/share/doc/rtkit/changelog.Debian.gz
/usr/share/doc/rtkit/copyright
/usr/share/man/man8/rtkitctl.8.gz
/var/lib/dpkg/info/rtkit.conffiles
/var/lib/dpkg/info/rtkit.list
/var/lib/dpkg/info/rtkit.md5sums
/var/lib/dpkg/info/rtkit.postinst
/var/lib/dpkg/info/rtkit.postrm
/var/tmp/systemd-private-646c56fc45384f6cb1b9d8a163bafde3-rtkit-daemon.service-Ij52Ql
/var/tmp/systemd-private-cdff5fae077d4a9cb6341effda339414-rtkit-daemon.service-WIrwPF
$

I'll check 17.10 as well.

$ inxi -Fxz
System:    Host: vasa1-VirtualBox Kernel: 4.13.0-25-generic x86_64 bits: 64 gcc: 7.2.0
         Desktop: KDE Plasma 5.11.5 (Qt 5.9.1) Distro: Ubuntu 17.10

$ locate rtkit
/lib/systemd/system/rtkit-daemon.service
/usr/lib/rtkit
/usr/lib/rtkit/rtkit-daemon
/usr/lib/rtkit/rtkit-test
/usr/sbin/rtkitctl
/usr/share/doc/rtkit
/usr/share/doc/rtkit/README.gz
/usr/share/doc/rtkit/changelog.Debian.gz
/usr/share/doc/rtkit/copyright
/usr/share/man/man8/rtkitctl.8.gz
/var/lib/dpkg/info/rtkit.conffiles
/var/lib/dpkg/info/rtkit.list
/var/lib/dpkg/info/rtkit.md5sums
/var/lib/dpkg/info/rtkit.postinst
/var/lib/dpkg/info/rtkit.postrm
/var/lib/dpkg/info/rtkit.prerm
/var/lib/systemd/deb-systemd-helper-enabled/rtkit-daemon.service.dsh-also
/var/tmp/systemd-private-8819445579434334b6720175c7e9becf-rtkit-daemon.service-shvgqQ
$

And, as far as I can tell, pulseaudio is installed by default:

  Installed: 1:10.0-2ubuntu3

[xonox]

I removed rtkit and it did not fix the issue. When i use the console (ctrl-alt-f2), the login is super quick. It's something related to the desktop environment.

I'm still trying to figure out what's going on. Is there some other log file i could check to find out what the system is doing for the 40-50 seconds ?

The delay happens after i enter my password. The login screen stays at it is for a lot of time. The i see the plasma loading screen for a few seconds (as it was before). And the desktop shows up.

Here is another bit of syslog file, now it seems like the system is waiting for this:

org.a11y.Bus[1268]: Activating service name='org.a11y.atspi.Registry'

Bits of syslog file:

Jan 20 11:31:25 dubstation systemd[1]: Startup finished in 2.036s (kernel) + 7.015s (userspace) = 9.052s.
Jan 20 11:31:25 dubstation set-cpufreq[926]: Setting powersave scheduler for all CPUs
Jan 20 11:31:25 dubstation kernel: [    9.289249] logitech-hidpp-device 0003:046D:200D.0005: HID++ 1.0 device connected.
Jan 20 11:31:25 dubstation upowerd[1120]: treating change event as add on /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.5/2-1.5:1.2/0003:046D:C52B.0003/0003:046D:200D.0005/power_supply/hidpp_battery_0
Jan 20 11:31:26 dubstation sddm[1031]: Oops, secure memory pool already initialized
Jan 20 11:31:26 dubstation systemd[1]: Created slice User Slice of xonox.
Jan 20 11:31:26 dubstation systemd[1]: Starting User Manager for UID 1000...
Jan 20 11:31:26 dubstation systemd[1]: Started Session 3 of user xonox.
Jan 20 11:31:26 dubstation systemd[1191]: Reached target Paths.
Jan 20 11:31:26 dubstation systemd[1191]: Reached target Timers.
Jan 20 11:31:26 dubstation systemd[1191]: Reached target Sockets.
Jan 20 11:31:26 dubstation systemd[1191]: Reached target Basic System.
Jan 20 11:31:26 dubstation systemd[1191]: Reached target Default.
Jan 20 11:31:26 dubstation systemd[1191]: Startup finished in 13ms.
Jan 20 11:31:26 dubstation systemd[1]: Started User Manager for UID 1000.
Jan 20 11:31:26 dubstation sddm-helper[1190]: Starting: "/etc/sddm/Xsession /usr/bin/startkde"
Jan 20 11:31:26 dubstation systemd[1]: Stopping User Manager for UID 119...
Jan 20 11:31:26 dubstation systemd[1104]: Stopped target Default.
Jan 20 11:31:26 dubstation systemd[1104]: Stopped target Basic System.
Jan 20 11:31:26 dubstation systemd[1104]: Stopped target Paths.
Jan 20 11:31:26 dubstation systemd[1104]: Stopped target Sockets.
Jan 20 11:31:26 dubstation systemd[1104]: Reached target Shutdown.
Jan 20 11:31:26 dubstation systemd[1104]: Starting Exit the Session...
Jan 20 11:31:26 dubstation systemd[1104]: Stopped target Timers.
Jan 20 11:31:26 dubstation systemd[1104]: Received SIGRTMIN+24 from PID 1224 (kill).
Jan 20 11:31:26 dubstation systemd[1]: Stopped User Manager for UID 119.
Jan 20 11:31:26 dubstation systemd[1]: Removed slice User Slice of sddm.
Jan 20 11:31:29 dubstation NetworkManager[948]: <info>  [1516465889.6215] manager: rfkill: WiFi hardware radio set enabled
Jan 20 11:31:29 dubstation NetworkManager[948]: <info>  [1516465889.6216] manager: rfkill: WWAN hardware radio set enabled
Jan 20 11:32:18 dubstation org.a11y.Bus[1268]: Activating service name='org.a11y.atspi.Registry'
Jan 20 11:32:18 dubstation org.a11y.Bus[1268]: Successfully activated service 'org.a11y.atspi.Registry'
Jan 20 11:32:18 dubstation org.a11y.atspi.Registry[1431]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
Jan 20 11:32:18 dubstation sddm[1031]: Checking for pam module
Jan 20 11:32:18 dubstation sddm[1031]: Got pam-login
Jan 20 11:32:18 dubstation sddm[1031]: kwalletd: Waiting for hash on 14-
Jan 20 11:32:18 dubstation sddm[1031]: kwalletd: waitingForEnvironment on: 17
Jan 20 11:32:18 dubstation sddm[1031]: kwalletd: client connected
Jan 20 11:32:18 dubstation sddm[1031]: kwalletd: client disconnected

[GreyGeek]

Doing "systemd-analyze plot > plot.svg" will give you a graphic of your boot sequence which you can browse using a browser. Shows where services being and complete, which ones overlap, etc...

[xonox]

Doing "systemd-analyze plot > plot.svg" will give you a graphic of your boot sequence which you can browse using a browser. Shows where services being and complete, which ones overlap, etc...

Thanks for the help!

I did this and explorer what it showed but it seems to be related to the system booting only. The problem happens after i enter my password on the graphical login screen. Console login (crtl-alt-f2) works fine.

[GreyGeek]

ksystemlog gives you all the log info from bootup to the current moment. system, Kernel, xorg, journald ...

[xonox]

Thanks! I just spent some hours looking at the various logs from ksystemlog. I can't find anything that would clearly explain the delay when logging in. At least, not so far.

I tried various things like removing or reinstalling some packages. No fix.

I'm learning lots however