[systemd-devel] Trying systemd with Debian Sid/unstable on ASRock E350M1 with Crucial m4 SSD

[Paul Menzel]

Dear systemd folks,


hopefully it is alright to report my findings here. If you have any
suggestions to improve the startup time, please do not hesitate to tell
me. ;-)

Hardware
========
• ASRock E350M1 with dual core 1.6 GHz Fusion CPU [1]
• Crucial m4 SSD connected via SATA-3-cable [2]
• one Ext4 partition

Software
========
• default Debian Sid/unstable installed using `grml-debootstrap` and
Grml live system
• `aptitude purge mdadm lvm2`
• `aptitude install systemd` (version 44-1)
• `linux-image-3.2.0-2-amd64` (version 3.2.17-1)

Results
=======
1. Passing `init=/bin/systemd` to the Linux kernel command line the GDM
3 login screen showed up noticeably faster.

2. GDM 3 did not list the available users though, which had to be
entered manually. After logging out again users are displayed fine.

3. Systemd says start up took 7.5 seconds.

$ systemd-analyze
Startup finished in 4077ms (kernel) + 3390ms (userspace) =
7468ms

4. All units take less than a second to start.

$ systemd-analyze blame
948ms avahi-daemon.service
729ms postfix.service
656ms rsyslog.service
632ms systemd-logind.service
559ms console-kit-log-system-start.service
523ms bootlogs.service
520ms chrony.service
467ms udev.service
451ms rc.local.service
436ms loadcpufreq.service
427ms keymap.service
424ms ssh.service
396ms cron.service
388ms dev-mqueue.mount
367ms systemd-modules-load.service
360ms sys-kernel-debug.mount
340ms udev-trigger.service
327ms systemd-sysctl.service
324ms dev-hugepages.mount
296ms sys-kernel-security.mount
281ms network-manager.service
279ms saned.service
279ms systemd-user-sessions.service
277ms gdm3.service
264ms media.mount
247ms systemd-remount-api-vfs.service
215ms pppd-dns.service
211ms resolvconf.service
199ms systemd-tmpfiles-setup.service
195ms screen-cleanup.service
191ms kbd.service
159ms networking.service
151ms console-setup.service
147ms pulseaudio.service
143ms cpufrequtils.service
91ms hdparm.service
91ms mountoverflowtmp.service
88ms keyboard-setup.service
87ms sysfsutils.service
87ms debian-fixup.service
59ms remount-rootfs.service
59ms colord-sane.service
56ms console-kit-daemon.service
48ms colord.service
44ms polkitd.service
31ms accounts-daemon.service
26ms upower.service
22ms udisks.service
19ms boot-efi.mount
13ms rtkit-daemon.service

5. Also I experience the sudo issue [3].

Conclusions
===========
1. I should follow the optimization suggestions in the systemd Wiki [4].

2. Improving loading time of the Linux kernel should be my priority
right now. With four seconds it take more than half of the total Debian
startup time. I would not have expected that.

I guess I need to use `bootchart` to check if the long time is due to
the slow 1.6 GHz dual Fusion CPU or if the storage is not set up
correctly.

3. It will be interesting if GNOME 3.4 will speed up things too as
mentioned in the Wiki [4]. Currently `gnome-shell` 3.2.2.1-4+b1 is
installed.


Thank you very much for this promising piece of software,

Paul


[1] http://www.asrock.com/mb/overview.asp?Model=E350M1
[2] http://www.crucial.com/store/partspecs.aspx?imodule=CT256M4SSD2
[3] http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=667470
[4] http://freedesktop.org/wiki/Software/systemd/Optimizations

[Michael Biebl]

Post by Paul Menzel
2. GDM 3 did not list the available users though, which had to be
entered manually. After logging out again users are displayed fine.

The user list is populated via accountsservice.
A D-Bus activated system service. accounts-daemon.service shows up in
your list above. So I'm wondering if there is genuine bug / race in
the way gdm interacts with accountsdaemon.

[Paul Menzel]

Post by Michael Biebl

Post by Paul Menzel
2. GDM 3 did not list the available users though, which had to be
entered manually. After logging out again users are displayed fine.

The user list is populated via accountsservice.
A D-Bus activated system service. accounts-daemon.service shows up in
your list above. So I'm wondering if there is genuine bug / race in
the way gdm interacts with accountsdaemon.

It looks like a race. The next two system starts the user list was
correctly populated and now it is not populated again.


Thanks,

Paul

[Paul Menzel]

Post by Paul Menzel

Post by Michael Biebl

Post by Paul Menzel
2. GDM 3 did not list the available users though, which had to be
entered manually. After logging out again users are displayed fine.

The user list is populated via accountsservice.
A D-Bus activated system service. accounts-daemon.service shows up in
your list above. So I'm wondering if there is genuine bug / race in
the way gdm interacts with accountsdaemon.

It looks like a race. The next two system starts the user list was
correctly populated and now it is not populated again.

After the third boot it worked too, but after the fourth it failed
again.

I do not know where to look for causes for this problem. I just found
the following.

# less /var/log/gdm3/\:0-greeter.log
gnome-session[951]: WARNING: Failed to start app: Unable to start application: Kindprozess »gnome-power-manager« konnte nicht ausgefÌhrt werden (Datei oder Verzeichnis nicht gefunden)
Gtk-Message: Failed to load module "atk-bridge"
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: /tmp/buildd/gtk+3.0-3.4.2/./gtk/gtkwidget.c:7117: widget not within a GtkWindow
gdm-simple-greeter[1138]: Gtk-CRITICAL: gtk_widget_get_preferred_height_for_width: assertion `width >= 0' failed
gdm-simple-greeter[1138]: Gtk-CRITICAL: gtk_widget_get_preferred_height_for_width: assertion `width >= 0' failed
gdm-simple-greeter[1138]: Gtk-WARNING: gtk_widget_size_allocate(): attempt to allocate widget with width -47 and height -47
Warnung der Fensterverwaltung:Buggy client sent a _NET_ACTIVE_WINDOW message with a timestamp of 0 for 0x1000007 (Anmeldefen)
Warnung der Fensterverwaltung:meta_window_activate called by a pager with a 0 timestamp; the pager needs to be fixed.


Thanks,

Paul

[Paul Menzel]

Post by Paul Menzel

Post by Paul Menzel

Post by Michael Biebl

Post by Paul Menzel
2. GDM 3 did not list the available users though, which had to be
entered manually. After logging out again users are displayed fine.

The user list is populated via accountsservice.
A D-Bus activated system service. accounts-daemon.service shows up in
your list above. So I'm wondering if there is genuine bug / race in
the way gdm interacts with accountsdaemon.

It looks like a race. The next two system starts the user list was
correctly populated and now it is not populated again.

After the third boot it worked too, but after the fourth it failed
again.
I do not know where to look for causes for this problem. I just found
the following.
# less /var/log/gdm3/\:0-greeter.log
gnome-session[951]: WARNING: Failed to start app: Unable to start application: Kindprozess »gnome-power-manager« konnte nicht ausgefÌhrt werden (Datei oder Verzeichnis nicht gefunden)
Gtk-Message: Failed to load module "atk-bridge"
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: Overriding tab label for notebook
gdm-simple-greeter[1138]: Gtk-WARNING: /tmp/buildd/gtk+3.0-3.4.2/./gtk/gtkwidget.c:7117: widget not within a GtkWindow
gdm-simple-greeter[1138]: Gtk-CRITICAL: gtk_widget_get_preferred_height_for_width: assertion `width >= 0' failed
gdm-simple-greeter[1138]: Gtk-CRITICAL: gtk_widget_get_preferred_height_for_width: assertion `width >= 0' failed
gdm-simple-greeter[1138]: Gtk-WARNING: gtk_widget_size_allocate(): attempt to allocate widget with width -47 and height -47
Warnung der Fensterverwaltung:Buggy client sent a _NET_ACTIVE_WINDOW message with a timestamp of 0 for 0x1000007 (Anmeldefen)
Warnung der Fensterverwaltung:meta_window_activate called by a pager with a 0 timestamp; the pager needs to be fixed.

I reported that problem in GNOME’s Bugzilla as #677476 but it was closed
right away because the version of GDM is too old.


Thanks,

Paul


[1] https://bugzilla.gnome.org/show_bug.cgi?id=677476
[Bug 677476] New: Races with GDM3 and accountsservice

[Paul Menzel]

Dear systemd folks,


Am Dienstag, den 22.05.2012, 11:06 +0200 schrieb Paul Menzel:

[
]

Post by Paul Menzel
4. All units take less than a second to start.
$ systemd-analyze blame
948ms avahi-daemon.service
729ms postfix.service
656ms rsyslog.service
632ms systemd-logind.service
559ms console-kit-log-system-start.service
523ms bootlogs.service

[
]

in Debian the init.d script bootlogs was split up and a separate init.d
script `motd` was created [1].

sysvinit (2.88dsf-24) experimental; urgency=low

[ Roger Leigh ]
* initscripts:
- Don't generate or touch /etc/motd. Instead, the dynamic part of
/etc/motd is created as /run/motd.dynamic, leaving /etc/motd
entirely under the control of the system administrator. If
/etc/motd is a symlink to /run/motd, /etc/motd.tail is moved
back to /etc/motd. Closes: #353229, #624391, #668307. /etc/motd
is not removed if initscripts is purged, since it's not owned by
initscripts.
- By default, /run/motd is just the output of uname, preserving the
existing behaviour. However, should the administrator wish to
include dynamic information in the motd, they may write scripts
to update /run/motd.dynamic as they please. Closes: #437176.
- motd generation is split from bootlogs into a separate motd
init script.
- bootlogs init script has been removed; current logging daemons
handle this themselves, making this script redundant.
- tmpfs mounts are never cleaned by bootclean.sh. Cleaning /run
can lead to nonfunctional input when Xorg starts. Closes: #669949.
* sysvinit-utils:
- Suggest rather than Recommend bootlogd.

`systemd-analyze blame` shows that the init.d script `motd` still takes
quite a lot of time.

363ms motd.service

There is not much going on in that script.

#!/bin/sh
### BEGIN INIT INFO
# Provides: motd
# Required-Start: hostname $local_fs
# Required-Stop:
# Should-Start:
# Default-Start: 1 2 3 4 5
# Default-Stop:
# Short-Description: Create dynamic part of /etc/motd
# Description: /etc/motd is user-editable and static. This script
# creates the initial dynamic part, by default the
# output of uname, and stores it in /var/run/motd.dynamic.
# Both parts are output by pam_motd.
### END INIT INFO

PATH=/sbin:/usr/sbin:/bin:/usr/bin
. /lib/init/vars.sh

do_start () {
# Update motd
uname -snrvm > /var/run/motd.dynamic
}

do_status () {
if [ -f /var/run/motd.dynamic ] ; then
return 0
else
return 4
fi
}

case "$1" in
start|"")
do_start
;;
restart|reload|force-reload)
echo "Error: argument '$1' not supported" >&2
exit 3
;;
stop)
# No-op
;;
status)
do_status
exit $?
;;
*)
echo "Usage: bootlogs [start|stop|status]" >&2
exit 3
;;
esac

:

So is systemd’s conversion of that init.d script to a unit file take so
long? Can someone point me to a unit/service file for motd so that I can
compare it? Unfortunately I could not find one on the net when searching
for »fedora systemd motd service file«.

[
]


Thanks,

Paul


[1] http://packages.debian.org/changelogs/pool/main/s/sysvinit/sysvinit_2.88dsf-27/changelog#version2.88dsf-24
[2] http://wiki.gentoo.org/wiki/Systemd

[Kay Sievers]

On Sun, Jun 10, 2012 at 2:40 PM, Paul Menzel

Post by Paul Menzel
Dear systemd folks,
[…]

Post by Paul Menzel
4. All units take less than a second to start.
        $ systemd-analyze blame
           948ms avahi-daemon.service
           729ms postfix.service
           656ms rsyslog.service
           632ms systemd-logind.service
           559ms console-kit-log-system-start.service
           523ms bootlogs.service

[…]
in Debian the init.d script bootlogs was split up and a separate init.d
script `motd` was created [1].
       sysvinit (2.88dsf-24) experimental; urgency=low
         [ Roger Leigh ]
           - Don't generate or touch /etc/motd.  Instead, the dynamic part of
             /etc/motd is created as /run/motd.dynamic, leaving /etc/motd
             entirely under the control of the system administrator.  If
             /etc/motd is a symlink to /run/motd, /etc/motd.tail is moved
             back to /etc/motd.  Closes: #353229, #624391, #668307.  /etc/motd
             is not removed if initscripts is purged, since it's not owned by
             initscripts.
           - By default, /run/motd is just the output of uname, preserving the
             existing behaviour.  However, should the administrator wish to
             include dynamic information in the motd, they may write scripts
             to update /run/motd.dynamic as they please.  Closes: #437176.
           - motd generation is split from bootlogs into a separate motd
             init script.
           - bootlogs init script has been removed; current logging daemons
             handle this themselves, making this script redundant.
           - tmpfs mounts are never cleaned by bootclean.sh.  Cleaning /run
             can lead to nonfunctional input when Xorg starts.  Closes: #669949.
           - Suggest rather than Recommend bootlogd.
`systemd-analyze blame` shows that the init.d script `motd` still takes
quite a lot of time.
  363ms motd.service
There is not much going on in that script.
       #!/bin/sh
       ### BEGIN INIT INFO
       # Provides:          motd
       # Required-Start:    hostname $local_fs
       # Default-Start:     1 2 3 4 5
       # Short-Description: Create dynamic part of /etc/motd
       # Description:       /etc/motd is user-editable and static.  This script
       #                    creates the initial dynamic part, by default the
       #                    output of uname, and stores it in /var/run/motd.dynamic.
       #                    Both parts are output by pam_motd.
       ### END INIT INFO
       PATH=/sbin:/usr/sbin:/bin:/usr/bin
       . /lib/init/vars.sh
       do_start () {
               # Update motd
               uname -snrvm > /var/run/motd.dynamic
       }
       do_status () {
               if [ -f /var/run/motd.dynamic ] ; then
                       return 0
               else
                       return 4
               fi
       }
       case "$1" in
         start|"")
               do_start
               ;;
         restart|reload|force-reload)
               echo "Error: argument '$1' not supported" >&2
               exit 3
               ;;
         stop)
               # No-op
               ;;
         status)
               do_status
               exit $?
               ;;
         *)
               echo "Usage: bootlogs [start|stop|status]" >&2
               exit 3
               ;;
       esac
So is systemd’s conversion of that init.d script to a unit file take so
long? Can someone point me to a unit/service file for motd so that I can
compare it? Unfortunately I could not find one on the net when searching
for »fedora systemd motd service file«.

In Fedora motd is just plain left to login(1), or pam_motd if people want that.

Making motd a service, a systemd entity of any kind, or init script is
unlikely a common

[Lennart Poettering]

On Sun, 10.06.12 14:40, Paul Menzel (***@users.sourceforge.net) wrote:

heya,

Post by Paul Menzel
[ Roger Leigh ]
- Don't generate or touch /etc/motd. Instead, the dynamic part of
/etc/motd is created as /run/motd.dynamic, leaving /etc/motd
entirely under the control of the system administrator. If
/etc/motd is a symlink to /run/motd, /etc/motd.tail is moved
back to /etc/motd. Closes: #353229, #624391, #668307. /etc/motd
is not removed if initscripts is purged, since it's not owned by
initscripts.
- By default, /run/motd is just the output of uname, preserving the
existing behaviour. However, should the administrator wish to
include dynamic information in the motd, they may write scripts
to update /run/motd.dynamic as they please. Closes: #437176.

Yikes, baroque.

Post by Paul Menzel
So is systemd’s conversion of that init.d script to a unit file take so
long? Can someone point me to a unit/service file for motd so that I can
compare it? Unfortunately I could not find one on the net when searching
for »fedora systemd motd service file«.

Honestly I always found that this mangling of motd in Debian is
quite confused. /etc should be considered read-only. Always writing
to the root fs just because you boot the machine is a really bad idea.

if the Debian folks really want to show the uname next to motd, then
they should stop mucking with /etc/motd and instead hack pam_motd to
simply optionally show the uname next to /etc/motd. That way it is
guaranteed to be fully up-to-date, doesn't result in writing IO, is
compatible with read-only root, and generally more robust and elegant.

Getting rid of this shell script would probably mean adding about 5
lines of code to pam_motd, a super trivial patch.

So, to make this very clear: we have no interest in the feature to be
available in systemd, and we dislike the implementation of it very
much. If Debian wants to keep this feature around it really should get
it implemented at the right place, and that is most likely pam_motd.

Hope this makes sense,

Lennart

[Paul Menzel]

Dear Lennart,

Post by Lennart Poettering

Post by Paul Menzel
[ Roger Leigh ]
- Don't generate or touch /etc/motd. Instead, the dynamic part of
/etc/motd is created as /run/motd.dynamic, leaving /etc/motd
entirely under the control of the system administrator. If
/etc/motd is a symlink to /run/motd, /etc/motd.tail is moved
back to /etc/motd. Closes: #353229, #624391, #668307. /etc/motd
is not removed if initscripts is purged, since it's not owned by
initscripts.
- By default, /run/motd is just the output of uname, preserving the
existing behaviour. However, should the administrator wish to
include dynamic information in the motd, they may write scripts
to update /run/motd.dynamic as they please. Closes: #437176.

Yikes, baroque.

Post by Paul Menzel
So is systemd’s conversion of that init.d script to a unit file take so
long? Can someone point me to a unit/service file for motd so that I can
compare it? Unfortunately I could not find one on the net when searching
for »fedora systemd motd service file«.

Honestly I always found that this mangling of motd in Debian is
quite confused. /etc should be considered read-only. Always writing
to the root fs just because you boot the machine is a really bad idea.

Reading this changelog entry and the init.d script, I could not find
anything that is written dynamically to `/etc` and just to `/run`.

$ ls -al /etc/motd*
lrwxrwxrwx 1 root root 13 Apr 3 2008 /etc/motd -> /var/run/motd
-rw-r--r-- 1 root root 286 Apr 3 2008 /etc/motd.tail
$ more /etc/motd*
::::::::::::::
/etc/motd
::::::::::::::
Linux debian-sid 3.2.0-2-686-pae #1 SMP Mon Jun 11 18:27:04 UTC 2012 i686

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
::::::::::::::
/etc/motd.tail
::::::::::::::

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.

[
]


Thanks,

Paul

[Lennart Poettering]

Post by Paul Menzel
Reading this changelog entry and the init.d script, I could not find
anything that is written dynamically to `/etc` and just to `/run`.

Hmm, yeah, I think a symlink for this is really a hack, this really
should be added to pam_motd instead of playing redirection games...

Lennart

[Josh Triplett]

Post by Lennart Poettering

Post by Paul Menzel
[ Roger Leigh ]
- Don't generate or touch /etc/motd. Instead, the dynamic part of
/etc/motd is created as /run/motd.dynamic, leaving /etc/motd
entirely under the control of the system administrator. If
/etc/motd is a symlink to /run/motd, /etc/motd.tail is moved
back to /etc/motd. Closes: #353229, #624391, #668307. /etc/motd
is not removed if initscripts is purged, since it's not owned by
initscripts.
- By default, /run/motd is just the output of uname, preserving the
existing behaviour. However, should the administrator wish to
include dynamic information in the motd, they may write scripts
to update /run/motd.dynamic as they please. Closes: #437176.

Yikes, baroque.

Incremental improvement over the previous state, though. I worked with
Roger Leigh to improve the current state of affairs here; the above
represents a compatible change possible without patches to PAM, since I
haven't yet gotten the necessary patches into PAM. The previous
behavior had /etc/motd as a symlink to a dynamically generated motd that
included the admin's motd from /etc/motd.tail. The new behavior leaves
/etc/motd as a normal file under admin control, and just generates a
separate /run/motd.dynamic shown via a separate pam_motd:

~$ grep pam_motd /etc/pam.d/login
session optional pam_motd.so motd=/run/motd.dynamic
session optional pam_motd.so

I agree that this hasn't yet reached an optimal state, but it does
improve on the previous approach.

Post by Lennart Poettering
Honestly I always found that this mangling of motd in Debian is
quite confused. /etc should be considered read-only. Always writing
to the root fs just because you boot the machine is a really bad idea.

This does not write to /etc at all, nor does it have a confusing symlink
from /etc; it writes to /run/motd.dynamic, and configures pam_motd to
read the dynamic motd directly from there.

Post by Lennart Poettering
if the Debian folks really want to show the uname next to motd, then
they should stop mucking with /etc/motd and instead hack pam_motd to
simply optionally show the uname next to /etc/motd. That way it is
guaranteed to be fully up-to-date, doesn't result in writing IO, is
compatible with read-only root, and generally more robust and elegant.

I've actually written a PAM patch to fix this problem, in a slightly
more general way: I patched pam_exec to support displaying the output of
the exec'd command, which would allow an arbitrary dynamic motd. As a
result, you can achieve the exact behavior of Debian's dynamic motd with
the following pam configuration:

session optional pam_exec.so type=open_session stdout /bin/uname -snrvm

See http://bugs.debian.org/670147 . Debian's PAM maintainer doesn't
plan to include the patch unless PAM upstream does. I've submitted the
patch to upstream PAM, but haven't managed to get any response yet.

As soon as that patch or something like it makes it into PAM, the PAM
scripts for login and similar services can switch to pam_exec, and
Debian's sysvinit can get rid of /etc/init.d/motd.

- Josh Triplett