GCEの起動スクリプトの注意点とStackdriver Loggingが二重起動してしまう話

Google Compute Engine (GCE)にはインスタンス起動時に自動的に実行される[起動スクリプト](https://cloud.google.com/compute/docs/startupscript?hl=ja)を定義することができます。起動スクリプトの用途は想像はつくと思いますが念の為引用しますと

> 独自の起動スクリプトを作成して仮想マシンで実行すると、インスタンスが起動するたびに自動タスクを実行できます。起動スクリプトでは、ソフトウェアのインストール、更新の実行、サービスの有効化など、さまざまなタスクを定義して実行できます。これにより、新しいインスタンスの作成時を含め、仮想マシン インスタンスをプログラムによって簡単にカスタマイズできます。
>
> たとえば、Apache サーバーをインストールして起動するだけの単純な起動スクリプトは次のようになります。

続いて以下のような例が示されています。

```sh
#! /bin/bash
apt-get update
apt-get install -y apache2
cat <<EOF > /var/www/html/index.html
<html><body><h1>Hello World</h1>
<p>This page was created from a simple startup script!</p>
</body></html>
EOF
```

これはかねがねうまく動作するのですが実は注意が必要です。それは起動スクリプトはその名の通り起動時に実行されるものだからです。GCEインスタンスを起動するのは一回だけで再起動は行わず、必要な場合はGCEインスタンスを破棄して作り直すという使い方なら良いのですが、例えばサーバーのメンテナンスやGCEの定期的な[ホストメンテナンス](https://cloud.google.com/compute/docs/instances/setting-instance-scheduling-options?hl=ja)でマイグレーションに失敗した時など再起動のみが行われる場合もあります。

上記の例の注意点は`apt-get update`を行っているため**再起動時にapache2のアップグレードが行われることがある**ということです。もちろんポリシーによってはその方が良い場合もあるでしょうが気をつける必要があります。

しかしそれ以上に厄介なのは**起動スクリプト実行のタイミングが[ネットワークが使用可能になった後](https://cloud.google.com/compute/docs/startupscript?hl=ja#startup_script_execution
)**だと言うところです。各サービスの起動前でも起動後でもありません。

> ネットワークが使用可能になった後、起動スクリプトは常にルートとして実行されます。

再起動時に起動スクリプトと（systemdによって自動起動する）apache2のどちらが先に実行されるかは定義されていません。並行して起動されます。つまり、起動スクリプトは

1. apache2の起動前に実行する
2. apache2の起動後に実行する
3. apache2の起動中に実行する

いずれの状態もあり得るわけです。上記の例ではエンドユーザーがアクセスするまで参照されないindex.htmlの作成なので実害はありませんが、例えば**設定ファイルを起動スクリプトで生成している場合**に問題が起きることがあります。起動スクリプトの実行のタイミングが上記の番号の場合に以下のような状態になります。

1. 問題なし
2. apache2は古い設定ファイルで起動している。
3. apache2は設定ファイルの読み込みで問題が発生する可能性がある。（例えば設定ファイル書き出し時に設定ファイルは一時的に消失しています。）

2に関しては一般的に設定ファイル生成後に起動スクリプトでサービスのreloadもしくはrestartを行うはずなので問題なさそうに思えますが、systemdによるサービスの自動起動に時間がかかった場合は、サービス起動中にrestartを行ってしまう可能性があります。

実は[Stackdriver Logging](https://cloud.google.com/logging/?hl=ja) (google-fluentd)でこの問題が発生していて、systemdによるgoogle-fluentdの自動起動中に、起動スクリプト（の中のインストールスクリプト）でgoogle-fluentdをrestartするとgoogle-fluentdが二重に起動しCPU使用率が異常に上昇しまいます。

これは[Stackdriver Logging エージェントのインストール](https://cloud.google.com/logging/docs/agent/installation?hl=ja#joint-install)に書かれているコードをそのまま起動スクリプトに書いてしまうことで簡単に発生してしまいます。

<details>
<summary>再現手順（そのうち修正されるかもしれませんが）</summary>
<div>あらかじめ`gcloud config`で使用するprojectとzoneを設定して下さい。

```console
$ # GCEインスタンス作成
$ gcloud compute instances create gce-startup-script-issue --machine-type=f1-micro \
--metadata=startup-script="curl -sSO https://dl.google.com/cloudagents/install-logging-agent.sh
sudo bash install-logging-agent.sh
rm install-logging-agent.sh" --image-family=debian-9 --image-project=debian-cloud

$ # しばらく待ってからGCEにログイン
$ gcloud compute ssh gce-startup-script-issue

$ ps axf # GCE上で実行してgoogle-fluentdが１つだけ起動していることを確認
長いので省略
1626 ? Sl 0:00 /opt/google-fluentd/embedded/bin/ruby /usr/sbin/google-fluentd
1631 ? Sl 0:02  \_ /opt/google-fluentd/embedded/bin/ruby -Eascii-8bit:ascii-8bit

$ sudo reboot # 再起動

$ # なにかキーを押すと切断されるのでしばらく待ってからGCEに再ログイン
$ gcloud compute ssh gce-startup-script-issue

$ ps axf # google-fluentdが２つ起動しているはずです
長いので省略
1108 ? Sl 0:00 /opt/google-fluentd/embedded/bin/ruby /usr/sbin/google-fluentd
1113 ? Sl 0:01  \_ /opt/google-fluentd/embedded/bin/ruby -Eascii-8bit:ascii-8bit
1118 ? Sl 0:00 /opt/google-fluentd/embedded/bin/ruby /usr/sbin/google-fluentd
1400 ? Rl 0:00  \_ /opt/google-fluentd/embedded/bin/ruby -Eascii-8bit:ascii-8bit

$ top # CPU使用率が頻繁に上昇します
$ exit

$ # 後片付け
$ gcloud compute instances delete gce-startup-script-issue
```
</div>
</details>

これを防ぐ手っ取り早い方法は、Stackdriver Loggingがインストールされているかを調べることです。公式で紹介されている[エージェントのアップグレード](https://cloud.google.com/logging/docs/agent/installation?hl=ja#upgrade)のやり方を踏まえると、この方法がより適切です。

```sh
# google-fluentdがインストールされてない場合にのみインストールする
if ! dpkg -s google-fluentd; then
  curl -sSO https://dl.google.com/cloudagents/install-logging-agent.sh
  bash install-logging-agent.sh
  rm install-logging-agent.sh
fi

# 再起動時にgoogle-fluentdをアップグレードしたい場合
apt-get update
if dpkg -s google-fluentd; then
  apt-get install -y --only-upgrade google-fluentd
  # 未検証ですがアップグレードするときにgoogle-fluentdの
  # restartが行われて問題が発生する可能性があるかもしれません
  # ただしアップグレードには時間がかかるのでその間にgoogle-fluentdの
  # 自動起動が終わっており問題は発生しないかもしれません
else
  curl -sSO https://dl.google.com/cloudagents/install-logging-agent.sh
  bash install-logging-agent.sh
  rm install-logging-agent.sh
fi
```

ですが、この問題の本質は再起動時に起動スクリプトとサービスが同時に起動してしまうところにあります。対処方法の一つは再起動時にパッケージの更新やサービスの設定を行わないようにすることです。初回起動時にのみパッケージのインストールや設定変更を行い再起動時には何もしません。構成済みのカスタムイメージを使うのも良いでしょう。初回起動が速くなるというメリットもあります。しかし場合によっては再起動時にパッケージの更新や設定の変更を行いたい場合もあると思います。その解決法を考えてみます。

最初に思いついたのがsystemdの定義ファイルで起動順序を定義するという方法です。サービスが起動するより前に起動スクリプトが実行されるようにすれば問題は発生しません。これでも実現できると思うのですが初回起動時と再起動時で処理を無駄なく共通化させるのが難しく、起動スクリプトが分かりづらいものとなってしまいました。そこでsystemdでサービスを自動起動するのをやめて起動スクリプトから起動するようにしました。

```sh
apt-get update
if dpkg -s google-fluentd; then
  apt-get install -y --only-upgrade google-fluentd
else
  curl -sSO https://dl.google.com/cloudagents/install-logging-agent.sh
  bash install-logging-agent.sh
  rm install-logging-agent.sh
fi
systemctl disable google-fluentd
# google-fluentdの設定ファイルを生成（内容省略）
systemctl restart google-fluentd --no-block

apt-get install -y apache2
systemctl disable apache2
# apache2の設定ファイルを生成（内容省略）
systemctl restart apache2 --no-block
```

起動スクリプトが実行されるまでサービスの起動が行われないので、7秒ほど再起動にかかる時間が増えてしまいましたが、これなら問題は発生しません。`systemctl restart`には`--no-block`オプションを使用しているのでサービスは並行起動します。（systemdより効率は悪いかもしれませんが）

念の為繰り返しておきますが、このような処理が必要なのは、**起動スクリプトでサービスのアップグレードや設定変更を行っている場合**です。サービスではないコマンドのインストールや再起動時に変更を行わないのものに関しては不要です。

[検証に使用したコード](https://github.com/ko1nksm/gcp-startup-script-issue)