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 を取った時には確認が必要という教訓となった。
