実PC debian 9.6 起動時間を短縮するその2 (完)

実PC の debian 9.6 の起動に30秒以上の時間を要しており、毎日の起動の際にストレスを感じていた。systemd-analyze で項目毎の要した時間を調べて、 kernel 起因である事、initramfs の展開後に発生している事、Suspend 先に指定されていた partition の UUID が違っている事を一つずつ調査し、grub 画面が消えてから GUI の login prompt が出るまでの時間を 46 秒から 9.6 秒に短縮させた。
hiro20180901.hatenablog.com
userspace の中の networking.service も他と比べて時間を要していたので、調査、対処してみた。

現状の systemd-analyze

kernel の対処が済んだ状態の systemd-analyze の結果は次の通り:

$ systemd-analyze 
Startup finished in 3.972s (kernel) + 6.025s (userspace) = 9.998s
$ systemd-analyze blame
          4.683s networking.service
           698ms apt-daily.service
           488ms dev-sdb1.device
           341ms apt-daily-upgrade.service
...略...

やはり、networking.service の起動に時間を要している。

また、GUI の login 画面が出る直前に、systemd らしき赤文字の error が一瞬だが出ているのが気になっていた。

networking.service の中身

/etc/systemd/system/multi-user.target.wants/networking.service は symbolic link になっていて、実体は以下のファイルになっている。
/lib/systemd/system/networking.service:

[Unit]
Description=Raise network interfaces
Documentation=man:interfaces(5)
DefaultDependencies=no
Wants=network.target
After=local-fs.target network-pre.target apparmor.service systemd-sysctl.service
 systemd-modules-load.service
Before=network.target shutdown.target network-online.target
Conflicts=shutdown.target

[Install]
WantedBy=multi-user.target
WantedBy=network-online.target

[Service]
Type=oneshot
EnvironmentFile=-/etc/default/networking
ExecStartPre=-/bin/sh -c '[ "$CONFIGURE_INTERFACES" != "no" ] && [ -n "$(ifquery
 --read-environment --list --exclude=lo)" ] && udevadm settle'
ExecStart=/sbin/ifup -a --read-environment
ExecStop=/sbin/ifdown -a --read-environment --exclude=lo
RemainAfterExit=true
TimeoutStartSec=5min

ifupdown を使っているが、--read-environment が付いている。Undocumented な機能で manpage にも記載はないが、systemd 環境で debian の network 設定ファイルの /etc/network/interfaces を読み込む為の機能らしい。であれば特に問題ないと思うが、実際には networking.service の起動に時間を要している。

journalctl による log の確認

gihyo.jp
systemd のlog は systemd-journald が収集している。journalctl で log を見る事ができる。

$ sudo journalctl --no-pager -u networking.service
-- Logs begin at Wed 2019-03-06 19:15:17 JST, end at Wed 2019-03-06 22:10:21 JST. --
Mar 06 19:15:17 debian systemd[1]: Starting Raise network interfaces...
Mar 06 19:15:18 debian ifup[494]: Waiting for br0 to get ready (MAXWAIT is 32 seconds).
Mar 06 19:15:18 debian dhclient[534]: Internet Systems Consortium DHCP Client 4.3.5
Mar 06 19:15:18 debian ifup[494]: Internet Systems Consortium DHCP Client 4.3.5
Mar 06 19:15:18 debian ifup[494]: Copyright 2004-2016 Internet Systems Consortium.
Mar 06 19:15:18 debian ifup[494]: All rights reserved.
Mar 06 19:15:18 debian ifup[494]: For info, please visit https://www.isc.org/software/dhcp/
Mar 06 19:15:18 debian dhclient[534]: Copyright 2004-2016 Internet Systems Consortium.
Mar 06 19:15:18 debian dhclient[534]: All rights reserved.
Mar 06 19:15:18 debian dhclient[534]: For info, please visit https://www.isc.org/software/dhcp/
Mar 06 19:15:18 debian dhclient[534]: 
Mar 06 19:15:18 debian dhclient[534]: Listening on LPF/br0/aa:bb:cc:dd:ee:ff
Mar 06 19:15:18 debian ifup[494]: Listening on LPF/br0/aa:bb:cc:dd:ee:ff
Mar 06 19:15:18 debian ifup[494]: Sending on   LPF/br0/aa:bb:cc:dd:ee:ff
Mar 06 19:15:18 debian ifup[494]: Sending on   Socket/fallback
Mar 06 19:15:18 debian ifup[494]: DHCPDISCOVER on br0 to 255.255.255.255 port 67 interval 3
Mar 06 19:15:18 debian dhclient[534]: Sending on   LPF/br0/aa:bb:cc:dd:ee:ff
Mar 06 19:15:18 debian dhclient[534]: Sending on   Socket/fallback
Mar 06 19:15:18 debian dhclient[534]: DHCPDISCOVER on br0 to 255.255.255.255 port 67 interval 3
Mar 06 19:15:21 debian dhclient[534]: DHCPDISCOVER on br0 to 255.255.255.255 port 67 interval 6
Mar 06 19:15:21 debian ifup[494]: DHCPDISCOVER on br0 to 255.255.255.255 port 67 interval 6
Mar 06 19:15:21 debian dhclient[534]: DHCPREQUEST of 192.168.n.n on br0 to 255.255.255.255 port 67
Mar 06 19:15:21 debian ifup[494]: DHCPREQUEST of 192.168.n.n on br0 to 255.255.255.255 port 67
Mar 06 19:15:21 debian ifup[494]: DHCPOFFER of 192.168.n.n from 192.168.n.1
Mar 06 19:15:21 debian dhclient[534]: DHCPOFFER of 192.168.n.n from 192.168.n.1
Mar 06 19:15:21 debian dhclient[534]: DHCPACK of 192.168.n.n from 192.168.n.1
Mar 06 19:15:21 debian ifup[494]: DHCPACK of 192.168.n.n from 192.168.n.1
Mar 06 19:15:21 debian ifup[494]: bound to 192.168.n.n -- renewal in 1529 seconds.
Mar 06 19:15:21 debian systemd[1]: Started Raise network interfaces.

特に変な所はないように見えるが...

/etc/network/interfaces から systemd-networkd への切り替え

なんとなく、network の設定を debian の /etc/network/interfaces で行なっている事が原因の様な感触がある。network の設定を systemd で行えば解消できるのではないかと考えてやってみた。
wiki.debian.org
こちらに、bridge を含めて systemd-networkd で設定する方法が書かれていたので、その通りにやってみた。

/etc/network/interfaces 無効

$ sudo mv /etc/network/interfaces /etc/network/interfaces.save

systemd-networkd を有効にする。

$ systemctl list-unit-files --type service | grep networkd
systemd-networkd-wait-online.service   disabled
systemd-networkd.service               disabled
$ sudo systemctl enable systemd-networkd
Created symlink /etc/systemd/system/multi-user.target.wants/systemd-networkd.service -> /lib/systemd/system/systemd-networkd.service.
Created symlink /etc/systemd/system/sockets.target.wants/systemd-networkd.socket -> /lib/systemd/system/systemd-networkd.socket.

lan0.network を作成する。先ずは bridge を使わない状態で設定してみた。

/etc/systemd/network/lan0.network:

[Match]
Name=enp3s0

[Network]
DHCP=ipv4

再起動してみた。

$ systemd-analyze 
Startup finished in 3.916s (kernel) + 758ms (userspace) = 4.674s
$ systemd-analyze blame
           376ms dev-sdb1.device
           176ms systemd-timesyncd.service
           159ms networking.service
           139ms ssh.service
...略...

10 秒から 4.7 秒に短縮された。体感出来る程に早くなった。
bridge 有効な設定に変更してみた。

$ cat /etc/systemd/network/br0.netdev 
[NetDev]
Name=br0
Kind=bridge

$ cat /etc/systemd/network/br0.network 
[Match]
Name=enp3s0

[Network]
Bridge=br0

$ cat /etc/systemd/network/lan0.network 
[Match]
Name=br0

[Network]
DHCP=ipv4

$ sudo systemctl restart systemd-networkd
$ ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever
2: enp3s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast master br0 state UP group default qlen 1000
    link/ether aa:bb:cc:dd:ee:ff brd ff:ff:ff:ff:ff:ff
    inet6 fe80::aaaa:bbbb:cccc:dddd/64 scope link 
       valid_lft forever preferred_lft forever
3: br0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
    link/ether aa:bb:cc:dd:ee:ff brd ff:ff:ff:ff:ff:ff
    inet 192.168.n.n/24 brd 192.168.n.255 scope global dynamic br0
       valid_lft 3348sec preferred_lft 3348sec
    inet6 aaaa:bb:ccc:d:eeee:ffff:1111:2222/64 scope global mngtmpaddr noprefixroute dynamic 
       valid_lft 296sec preferred_lft 296sec
    inet6 fe80::aaaa:bbbb:cccc:dddd/64 scope link 
       valid_lft forever preferred_lft forever

ちゃんと設定できた。仮想マシンからの接続もOK。

Guest qemu(kvm):

$ ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever
2: ens3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000
    link/ether aa:bb:cc:dd:ee:ff brd ff:ff:ff:ff:ff:ff
    inet 192.168.n.n/24 brd 192.168.n.255 scope global dynamic ens3
       valid_lft 3270sec preferred_lft 3270sec
    inet6 aaaa:bb:ccc:d:eeee:ffff:1111:2222/64 scope global dynamic mngtmpaddr noprefixroute 
       valid_lft 259sec preferred_lft 259sec
    inet6 fe80::aaaa:bbbb:cccc:dddd/64 scope link 
       valid_lft forever preferred_lft forever

bridge 有効な状態で再起動してみた。

$ systemd-analyze
Startup finished in 3.874s (kernel) + 823ms (userspace) = 4.697s
$ systemd-analyze blame
           398ms dev-sdb1.device
           224ms networking.service
           196ms binfmt-support.service
           159ms lightdm.service
...略...

bridge 無効の場合と同じ4.7 秒、元の 10 秒から5.3秒短縮された。

変更後の journald の結果

$ sudo journalctl --no-pager -u networking.service
-- Logs begin at Thu 2019-03-07 18:36:03 JST, end at Thu 2019-03-07 18:40:05 JST. --
Mar 07 18:36:03 debian systemd[1]: Starting Raise network interfaces...
Mar 07 18:36:03 debian sh[307]: ifquery: couldn't open interfaces file "/etc/network/interfaces": No such file or directory
Mar 07 18:36:03 debian ifup[312]: ifup: couldn't open interfaces file "/etc/network/interfaces": No such file or directory
Mar 07 18:36:03 debian systemd[1]: Started Raise network interfaces.

/etc/network/interfaces が見つからなくなり、設定しない状態となっている。こちらは無効にしても良いのかな?

$ sudo journalctl --no-pager -u systemd-networkd.service
-- Logs begin at Thu 2019-03-07 18:36:03 JST, end at Thu 2019-03-07 18:41:02 JST. --
Mar 07 18:36:03 debian systemd[1]: Starting Network Service...
Mar 07 18:36:03 debian systemd-networkd[276]: br0: netdev ready
Mar 07 18:36:03 debian systemd-networkd[276]: Enumeration completed
Mar 07 18:36:03 debian systemd[1]: Started Network Service.
Mar 07 18:36:03 debian systemd-networkd[276]: enp3s0: IPv6 disabled for interface: Success
Mar 07 18:36:03 debian systemd-networkd[276]: br0: IPv6 enabled for interface: Success
Mar 07 18:36:05 debian systemd-networkd[276]: enp3s0: Gained carrier
Mar 07 18:36:05 debian systemd-networkd[276]: br0: Gained carrier
Mar 07 18:36:06 debian systemd-networkd[276]: br0: Gained IPv6LL
Mar 07 18:36:07 debian systemd-networkd[276]: br0: DHCPv4 address 192.168.n.n/24 via 192.168.n.1
Mar 07 18:36:07 debian systemd-networkd[276]: br0: Configured

こちらで br と enp3s0 が設定されている。

結果

debian の /etc/network/interfaces の設定を無効とし、systemd-networkd の設定を有効にする事で、起動時に systemd-networking で時間を要す状況を解消できた。
bridge も問題なく設定できた。
kernel (initramfs)、及び systemd-networkd を適切に設定した事で、起動時間が 46 秒から 4.7 秒に 40 秒以上短縮できた。

128GB SSD に debian 9.6 を入れてからずっと気になっていた事項が解消できた。今の状態であれば、(もちろん POST には時間かかるが) Linux を快適に使用することが出来るようになった。

systemd についても少し触れる事ができ、折角なので SysVinit と systemd の違いについて、これから調べてみたい。

hiroの長い冒険日記

主にコンピュータ周辺の興味を持った内容を綴ります