CloudEndure でAmazon EC2インスタンスからGCEインスタンスに移行する記事の中で、「GCEインスタンスの起動を早くする」方法を紹介しました。
通常であれば、LinuxのGCEインスタンスの起動は1分程度でSSH接続できるのですが、CloudEndure で移行したインスタンスだとSSH接続できるようになるまで5分程度もかかってしまっていました。
本記事では遅くなっていた原因について調査履歴を載せています。
対象OSは Ubuntu 14.04 LTS です。
コンソールログを見る
GCEインスタンスの起動時に何が起こっているのか、コンソールログを見てみます。コンソールログはブラウザから「VMインスタンスの詳細」→「シリアルポート 1（コンソール）」から確認できます。
# Before Cloud-init v. 0.7.5 running 'init-local' at Fri, 24 Aug 2018 08:44:55 +0000. Up 6.15 seconds. Cloud-init v. 0.7.5 running 'init' at Fri, 24 Aug 2018 08:47:05 +0000. Up 136.37 seconds. Cloud-init v. 0.7.5 running 'modules:config' at Fri, 24 Aug 2018 08:47:06 +0000. Up 137.53 seconds. Cloud-init v. 0.7.5 running 'modules:final' at Fri, 24 Aug 2018 08:49:12 +0000. Up 263.01 seconds. Cloud-init v. 0.7.5 finished at Fri, 24 Aug 2018 08:49:12 +0000. Datasource DataSourceGCE. Up 263.09 seconds # After Cloud-init v. 0.7.5 running 'init-local' at Fri, 24 Aug 2018 09:52:11 +0000. Up 6.10 seconds. Cloud-init v. 0.7.5 running 'init' at Fri, 24 Aug 2018 09:52:12 +0000. Up 7.07 seconds. Cloud-init v. 0.7.5 running 'modules:config' at Fri, 24 Aug 2018 09:52:13 +0000. Up 7.88 seconds. Cloud-init v. 0.7.5 running 'modules:final' at Fri, 24 Aug 2018 09:52:18 +0000. Up 13.26 seconds. Cloud-init v. 0.7.5 finished at Fri, 24 Aug 2018 09:52:18 +0000. Datasource DataSourceGCE. Up 13.31 seconds
Beforeが起動を早くする前のログ、Afterが起動を早くするようにした後のログです。
Afterだと起動までに13秒なのに対し、Beforeは4分以上かかっていることがわかります。
Beforeのログをもう少し追ってみます。
cloud-init-nonet[16.33]: waiting 120 seconds for network device cloud-init-nonet[136.33]: gave up waiting for a network device. Cloud-init v. 0.7.5 running 'init' at Fri, 24 Aug 2018 09:09:28 +0000. Up 136.47 seconds. ci-info: ++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++ ci-info: +--------+------+-----------+-----------------+-------------------+ ci-info: | Device | Up | Address | Mask | Hw-Address | ci-info: +--------+------+-----------+-----------------+-------------------+ ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | . | ci-info: | eth0 | True | 10.63.0.2 | 255.255.255.255 | 42:01:0a:3f:00:02 | ci-info: +--------+------+-----------+-----------------+-------------------+ ci-info: +++++++++++++++++++++++++++++++Route info++++++++++++++++++++++++++++++++ ci-info: +-------+-------------+-----------+-----------------+-----------+-------+ ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | ci-info: +-------+-------------+-----------+-----------------+-----------+-------+ ci-info: | 0 | 0.0.0.0 | 10.63.0.1 | 0.0.0.0 | eth0 | UG | ci-info: | 1 | 10.63.0.1 | 0.0.0.0 | 255.255.255.255 | eth0 | UH | ci-info: +-------+-------------+-----------+-----------------+-----------+-------+ ... Waiting for network configuration... * Stopping System Security Services Daemon[74G[ OK ] Waiting up to 60 more seconds for network configuration... Booting system without full network configuration... * Stopping Failsafe Boot Delay[74G[ OK ] * Starting System V initialisation compatibility[74G[ OK ] * Starting early crypto disks...
waiting 120 seconds for network device で2分も待たされていますね。
さらに Waiting up to 60 more seconds for network configuration... で1分も待たされていますね。
ここだけで3分も待たされているのでそりゃ起動が遅くなるわけです。
さて、このSleepがどこでやっているかを特定していきましょう。
# /etc/init/cloud-init-nonet.conf 16 static_network_up() { 17 local emitted="/run/network/static-network-up-emitted" 18 # /run/network/static-network-up-emitted is written by 19 # upstart (via /etc/network/if-up.d/upstart). its presense would 20 # indicate that static-network-up has already fired. 21 [ -e "$emitted" -o -e "/var/$emitted" ] 22 } ... 48 dowait() { 49 msg "waiting $1 seconds for network device" 50 sleep "$1" & 51 SLEEP_CHILD=$! 52 wait $SLEEP_CHILD 53 SLEEP_CHILD="" 54 } 55 56 trap handle_sigterm TERM 57 58 # static_network_up already occurred 59 static_network_up && exit 0 60 61 dowait 10 62 dowait 120 63 msg "gave up waiting for a network device." 64 : > /var/lib/cloud/data/no-net
static_network_up が正常に終了しない場合に dowait が呼ばれて2分10秒も待たされてしまっています。
static_network_up を見ると、 /run/network/static-network-up-emitted もしくは /var/run/network/static-network-up-emitted が存在しているかを判定しています。
/run/network/static-network-up-emitted は /etc/network/if-up.d/upstart によって生成されているとのことなので、 /etc/network/if-up.d/upstart を見ていきます。
# /etc/network/if-up.d/upstart 1 #!/bin/sh -e 2 MARK_DEV_PREFIX="/run/network/ifup." 3 MARK_STATIC_NETWORK_EMITTED="/run/network/static-network-up-emitted" 4 5 if [ -e /lib/lsb/init-functions ]; then 6 . /lib/lsb/init-functions 7 fi 8 9 if ! init_is_upstart; then 10 exit 0 11 fi 12 13 # Let's ignore meta entries (ifup -a) 14 if [ "$ADDRFAM" = "meta" ]; then 15 exit 0 16 fi 17 18 # lo emission handled by /etc/init/network-interface.conf 19 if [ "$IFACE" != lo ]; then 20 initctl emit -n net-device-up \ 21 "IFACE=$IFACE" \ 22 "LOGICAL=$LOGICAL" \ 23 "ADDRFAM=$ADDRFAM" \ 24 "METHOD=$METHOD" 25 fi 26 27 get_auto_interfaces() { 28 # write to stdout a list of interfaces configured as 'auto' in interfaces(5) 29 local found="" 30 # stderr redirected as it outputs things like: 31 # Ignoring unknown interface eth0=eth0. 32 found=$(ifquery --list --allow auto 2>/dev/null) || return 33 set -- ${found} 34 echo "$@" 35 } 36 37 all_interfaces_up() { 38 # return true if all interfaces listed in /etc/network/interfaces as 'auto' 39 # are up. if no interfaces are found there, then "all [given] were up" 40 local prefix="$1" iface="" 41 for iface in $(get_auto_interfaces); do 42 # if cur interface does is not up, then all have not been brought up 43 [ -f "${prefix}${iface}" ] || return 1 44 done 45 return 0 46 } 47 48 # touch our own "marker" indicating that this interface has been brought up. 49 : > "${MARK_DEV_PREFIX}$IFACE" 50 51 if all_interfaces_up "${MARK_DEV_PREFIX}" && 52 mkdir "${MARK_STATIC_NETWORK_EMITTED}" 2>/dev/null; then 53 initctl emit --no-wait static-network-up 54 fi
/run/network/ifup.* に /etc/network/interfaces で設定されたインターフェイスがある(=起動している)ことを確認しているようですね。
/etc/network/interfaces を見ると、このようになっていました。
# /etc/network/interfaces auto lo iface lo inet loopback auto eth0 iface eth0 inet dhcp # for gcp auto ens4 iface ens4 inet dhcp # for aws C5,M5 auto ens5 iface ens5 inet dhcp
ens4 、ens5 と、余計なインタフェースが生えていますね。移行元のAmazon EC2インスタンスにはこの記載がないので、CloudEndureによるVM移行した影響で、ens4 と ens5 が追加されてしまったようです。ifconfig で見てもこのインターフェイスは設定されていなかったので明らかに不要なので、コメントアウトします。
--- /etc/network/interfaces.orig 2018-08-24 18:43:17.153359456 +0900 +++ /etc/network/interfaces 2018-08-24 18:49:38.936352074 +0900 @@ -5,10 +5,10 @@ iface eth0 inet dhcp # for gcp -auto ens4 -iface ens4 inet dhcp +#auto ens4 +#iface ens4 inet dhcp # for aws C5,M5 -auto ens5 -iface ens5 inet dhcp +#auto ens5 +#iface ens5 inet dhcp
これで対策できたと思いますが、念の為こちらのファイルの Sleep 処理もコメントアウトしておきましょう。
--- /etc/init/failsafe.conf.orig 2014-04-12 06:54:15.000000000 +0900
+++ /etc/init/failsafe.conf 2018-08-24 17:24:33.341265857 +0900
@@ -29,10 +29,10 @@
# the end of this script to avoid letting the system spin forever
# waiting on it to start.
$PLYMOUTH message --text="Waiting for network configuration..." || :
- sleep 40
+ #sleep 40
$PLYMOUTH message --text="Waiting up to 60 more seconds for network configuration..." || :
- sleep 59
+ #sleep 59
$PLYMOUTH message --text="Booting system without full network configuration..." || :
# give user 1 second to see this message since plymouth will go
設定変更後、GCEインスタンスを再起動して、SSH接続可能時間が短縮されたこと、コンソールログでSleepされた形跡が無いことを確認します。
最後に
CloudEndure によるVM移行は便利ですが、思わぬ落とし穴もあるので、色々検証していかないとですね。
