実PC debian 9.6 起動時間を短縮する

qemu (kvm) の仮想マシンと比較して、実PC の debian 9.6 の起動に時間を要していた。仮想マシンは GUI でも数秒で login prompt が出るのに対して、実PC では grub 画面が消えてから30秒以上かかっていた。

この原因を確かめ、対処してみた。

systemd-analyze

qiita.com
systemd-analyze で UEFI -> kernel -> systemd まで、どの部分で時間を要しているか調べられるようなのでやってみた。実PC は BIOS なので kernel と userspace だけになる。

$ dpkg -S `which systemd-analyze`
systemd: /usr/bin/systemd-analyze
$ systemd-analyze 
Startup finished in 35.510s (kernel) + 10.891s (userspace) = 46.402s
$ systemd-analyze blame
         10.494s networking.service
          1.163s dev-sdb1.device
           395ms systemd-logind.service
...略...

kernel と networking.service で時間を要していることが分かった。まずは kernel について対処した。

kernel 起動時間の調査

dmesg には kernel 起動時からの経過時間が、イベント毎に表示されている。
dmesg:

... 略 ...
[    0.362821] Unpacking initramfs...
[    0.652203] Freeing initrd memory: 18152K
... 略 ...
[    3.555804] sr 1:0:0:0: [sr0] scsi3-mmc drive: 125x/125x writer dvd-ram cd/rw xa/form2 cdda tray
[    3.555894] cdrom: Uniform CD-ROM driver Revision: 3.20
[    3.556116] sr 1:0:0:0: Attached scsi CD-ROM sr0
[   18.894540] random: crng init done
[   18.894599] random: 7 urandom warning(s) missed due to ratelimiting
[   35.532429] EXT4-fs (sdb1): mounted filesystem with ordered data mode. Opts: (null)
[   35.665677] ip_tables: (C) 2000-2006 Netfilter Core Team
... 略 ...

これを見ると sr0 (dvd-drive) の認識から random の初期化の間、及び random の初期化から ext4 fs (sdb1) の認識の間に時間を要していた。でも、random の初期化に時間を要するのであれば、仮想マシンでも同様のはず。これ以外に理由がある。initramfs が展開された後なので、kernel 本体ではなく initramfs の中なのかな?

kernel 起動 option の quiet を削除して起動

今の状態では何が悪さしているのか分からないので、kernel の起動 message を増やしてみた。

• 再起動して grub の entry が表示されている状態で、「e」を押して編集モードに入り、zImage を指定している linux 行の quiet を外して、Ctrl-x で起動させると、上記の時間が掛かっている箇所で別の message が表示されていた。
• quiet の代わりに debug を指定すると、/run/initramfs に initramfs.debug が作成された。中を見ると、上の項目で出ていた message が表示されていた。

/run/initramfs/initramfs.debug:

...略...
Begin: Waiting for suspend/resume device ... Begin: Running /scripts/local-block
 ... done.
Begin: Running /scripts/local-block ... done.
Begin: Running /scripts/local-block ... done.
Begin: Running /scripts/local-block ... done.
...略...

これを keyword にぐぐってみると、次のページが見つかった。
ubuntuforums.org
/etc/initramfs-tools/conf.d/resume:

RESUME=UUID=d6aa206d-8b46-4538-ba1e-e37d0be6000f

Suspend の際の UUID を指定するらしいが、この UUID に該当する partition が存在していない。これが理由か...該当行を comment にして initramfs を作成してみた。
変更前:

$ sudo update-initramfs -u
update-initramfs: Generating /boot/initrd.img-4.9.0-8-amd64
W: initramfs-tools configuration sets RESUME=UUID=d6aa206d-8b46-4538-ba1e-e37d0be6000f
W: but no matching swap device is available.

Warning が出ていたようだが気づかなかった。

変更後:

$ sudo update-initramfs -u
update-initramfs: Generating /boot/initrd.img-4.9.0-8-amd64

Warning が消えた。これで再起動してみた。

結果

$ systemd-analyze 
Startup finished in 3.932s (kernel) + 5.726s (userspace) = 9.659s

46秒から9.7秒に短縮された。この対処で合っていた模様。

毎日の事なので、起動時に待たされるのは気になっていたが、やっと原因が分かった。結局は、

• Suspend 用の partition が設定されていた。(設定した覚えはないが...)
• initramfs の処理の中で、指定されていた Suspend 用の partition を幾度も探していた。
• そのうち失敗して次の処理に進んだ。

という事だった。

元々、SSD 128GB に入れている debian 9.6 は、Hyper-V Path through 接続して install したものを、仮想マシンで動作させる為に raw image -> vhd に変換して、vhd -> raw image に戻してから SSD に書き込んでいた。
hiro20180901.hatenablog.com
raw image -> vhd 変換の際に容量が大きくなる現象が発生していて、最後の partition である swap を一旦削除して mkswap していた。その過程で UUID が変化したのにも関わらず、initramfs-tools の設定に反映させていなかった事が、今回の現象を発生させた理由だろう。

頻繁に発生する事例ではないと思うが、UUID が変化する action を取った時には確認が必要という教訓となった。