Amazon Linuxのcloud-initの実行順番を確認する

はじめに

まずはおさらいです。

cloud-initでシェルスクリプトとcloud-configを同時に使うで書いた通り、User-Dataにはシェルスクリプトとcloud-init形式(cloud-config)が併記できます。

またAmazon Linuxのcloud-initの動きについて調べてみたに書いた通り、EC2がLaunchする時のcloud-init起動スクリプトの実行順序は以下のようになります。

1. cloud-init-local
2. cloud-init
3. cloud-config
4. 各種サービスの起動
5. cloud-final

で、じゃあ各起動スクリプトで読み込まれているcloud-initのモジュールは実際にはどういう順番で実行しているのか、確認してみました。

確認してみる

User-Dataの内容は以下。シェルスクリプト、per-once、per-boot、per-instance、bootcmd、runcmdについて確認します。

Content-Type: multipart/mixed; boundary="===============1993995897=="
MIME-Version: 1.0

--===============1993995897==
Content-Type: text/x-shellscript; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment; filename="bash.txt"

#!/bin/bash

echo "User-Data:" `date` >> /var/tmp/test.txt
sleep 3s

exit

--===============1993995897==
Content-Type: text/cloud-config; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment; filename="cloud-config.txt"

#cloud-config
write_files:
 - content: |
      #!/bin/sh
      echo "Per-Once:" `date` >> /var/tmp/test.txt
      sleep 3s
   owner: root:root
   path: /var/lib/cloud/scripts/per-once/once.sh
   permissions: '0755'
 - content: |
      #!/bin/sh
      echo "Per-Boot:" `date` >> /var/tmp/test.txt
      sleep 3s
   owner: root:root
   path: /var/lib/cloud/scripts/per-boot/boot.sh
   permissions: '0755'
 - content: |
      #!/bin/sh
      echo "Per-Instance:" `date` >> /var/tmp/test.txt
      sleep 3s
   owner: root:root
   path: /var/lib/cloud/scripts/per-instance/instance.sh
   permissions: '0755'

bootcmd:
 - echo "BootCmd:" `date` >> /var/tmp/test.txt
 - sleep 3s

runcmd:
 - echo "RunCmd:" `date` >> /var/tmp/test.txt
 - sleep 3s
--===============1993995897==--

このUser-Dataを入力してEC2をLaunchし、/var/tmp/test.txtの内容を確認したところ、こうなりました。

$ cat /var/tmp/test.txt
BootCmd: Tue Aug 26 08:37:53 UTC 2014
Per-Once: Tue Aug 26 08:38:28 UTC 2014
Per-Boot: Tue Aug 26 08:38:31 UTC 2014
Per-Instance: Tue Aug 26 08:38:34 UTC 2014
User-Data: Tue Aug 26 08:38:37 UTC 2014
RunCmd: Tue Aug 26 08:38:40 UTC 2014

あれ？

runcmdが一番最後だった

/etc/cloud/cloud.cfg.d/00_defaults.cfgに記述された、cloud-initの各モジュール読み込みタイミングは、以下のようになっています。

# The modules that run in the 'init' stage
cloud_init_modules:
  - rsyslog
  - migrator
  - bootcmd
  - write-files
  - growpart
  - resizefs
  - set-hostname
  - update-hostname
  - update-etc-hosts
  - users-groups
 
# The modules that run in the 'config' stage
cloud_config_modules:
  - locale
  - ssh
  - set-passwords
  - mounts
  - yum-configure
  - yum-add-repo
  - package-update-upgrade-install
  - timezone
  - puppet
  - disable-ec2-metadata
  - runcmd
 
# The modules that run in the 'final' stage
cloud_final_modules:
  - scripts-per-once
  - scripts-per-boot
  - scripts-per-instance
  - scripts-user
  - ssh-authkey-fingerprints
  - keys-to-console
  - phone-home
  - final-message
  - power-state-change

この事から、runcmdはconfigステージで実行されるものとばかり思っていました。でも実際にはfinalステージで実行されています。

runcmdがfinalステージで実行された理由を調べてみる

/var/log/cloud-init.logを確認すると...まず、以下のように、disable-ec2-metadataモジュールの後にruncmdモジュールが読み込まれています。ここまでは想定通りです。

Aug 26 08:37:57 cloud-init[1446]: importer.py[DEBUG]: Looking for modules ['cc_disable_ec2_metadata', 'cloudinit.config.cc_disable_ec2_metadata'] that have attributes ['handle']
Aug 26 08:37:57 cloud-init[1446]: importer.py[DEBUG]: Found cc_disable_ec2_metadata with attributes ['handle'] in ['cloudinit.config.cc_disable_ec2_metadata']
Aug 26 08:37:57 cloud-init[1446]: importer.py[DEBUG]: Looking for modules ['cc_runcmd', 'cloudinit.config.cc_runcmd'] that have attributes ['handle']
Aug 26 08:37:57 cloud-init[1446]: importer.py[DEBUG]: Found cc_runcmd with attributes ['handle'] in ['cloudinit.config.cc_runcmd']

次に、runcmdモジュールは、コマンドをファイルとして出力しています。

Aug 26 08:38:24 cloud-init[1446]: util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-3f9ff026/sem/config_runcmd - wb: [420] 20 bytes
Aug 26 08:38:24 cloud-init[1446]: helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/i-3f9ff026/sem/config_runcmd'>)
Aug 26 08:38:24 cloud-init[1446]: util.py[DEBUG]: Shellified 2 commands.
Aug 26 08:38:24 cloud-init[1446]: util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-3f9ff026/scripts/runcmd - wb: [448] 62 bytes

で、この/var/lib/cloud/instances/インスタンスID/scripts/というディレクトリの下に、User-Dataで記載したシェルスクリプトと一緒に、runcmdで指定したコマンドがシェルスクリプト形式となって置かれます。

$ ls -alF /var/lib/cloud/instances/i-3f9ff026/scripts/
合計 16
drwxr-xr-x 2 root root 4096  8月 26 08:38 ./
drwxr-xr-x 5 root root 4096  8月 26 08:38 ../
-rwx------ 1 root root   74  8月 26 08:37 bash.txt*
-rwx------ 1 root root   62  8月 26 08:38 runcmd*

$ sudo cat /var/lib/cloud/instances/i-3f9ff026/scripts/bash.txt
#!/bin/bash

echo "User-Data:" `date` >> /var/tmp/test.txt
sleep 3s

exit

$ sudo cat /var/lib/cloud/instances/i-3f9ff026/scripts/runcmd
#!/bin/sh
echo "RunCmd:" `date` >> /var/tmp/test.txt
sleep 3s

このディレクトリ配下のファイル群がscripts-userモジュールによって実行されています。

Aug 26 08:38:37 cloud-init[1596]: util.py[DEBUG]: Writing to /var/lib/cloud/instances/i-3f9ff026/sem/config_scripts_user - wb: [420] 20 bytes
Aug 26 08:38:37 cloud-init[1596]: helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/i-3f9ff026/sem/config_scripts_user'>)
Aug 26 08:38:37 cloud-init[1596]: util.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts/bash.txt'] with allowed return codes [0] (shell=True, capture=False)
Aug 26 08:38:40 cloud-init[1596]: util.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts/runcmd'] with allowed return codes [0] (shell=True, capture=False)

これが、runcmdがfinalステージで実行された理由です。

まとめ

と、言うことはです。finalステージは各サービスのデーモンが起動した後に実行されるため、シェルスクリプトやruncmdでは、デーモン起動前に設定するための用途では使えない、ということになります。デーモン起動前に何かの設定を行いたい場合には、bootcmdを使うか、あるいはファイル書き込みであればwrite_filesを使う必要があるということですね。

なるほど、少しずつcloud-initと仲良く慣れてきた気がします。やはり手を動かすのは大事ですね。