↓メインコンテンツへスキップ
  1. Blogs/

terraform applyが成功してもVMの中は設定されていなかった話

4 分
Terraform GoogleCloud Ansible ComputeEngine CloudLogging
0222-nnn
著者
0222-nnn
猫が好き
目次
Terraform-GoogleCloud - この記事は連載の一部です
パート 38: この記事

概要
#

「Terraformはマシンを作る、中で動くものはAnsible」という分担はよく聞きます。ところがその受け渡しは自動では繋がりません。

実際に、terraform applyが35 addedと出た一方で、VMの中ではAnsibleが失敗していました。terraform planも差分なしのままです。Terraformから見ると、この失敗はどこにも現れません。

GCEにOps AgentとNginxを入れる最小構成で、この境界を実測します。

対象読者は、TerraformでGCEを作ったことがあり、Ansibleを書いたことがある人です。それぞれの入門は扱いません。

Ansible制御ノードからのpush型実行、Ansible Vaultは扱いません。今回はVM上でのlocal実行です。

検証すること
#

  • startup scriptはいつ走るのか(初回だけか、毎回か)
  • Terraformの「成功」は中身を保証するか
  • playbookを更新したとき、既存のVMにどう反映するか
  • サービスが「正しく」動いているとどう確認するか

前提環境
#

  • Google Cloud CLI、Terraform
  • Billingが有効な検証用Google Cloud Project
  • GCE、GCS、IAPを操作できるGoogleアカウント
  • VM内でsudoを実行できること。掲載した手動再実行やログ確認に要る。roles/compute.osLoginだけでは足りず、roles/compute.osAdminLoginが要る
  • 検証時のバージョン:Terraform 1.14.5、google 7.46.0、Debian 12、nginx 1.22、Ansible 2.14(Debian 12 の apt が入れる版)、Ops Agent 2.x

Ansible と Ops Agent の細かい版は記録していません。挙動が変わりうるので、再現するなら ansible --version と google_cloud_ops_agent_engine --version を控えておきます。

使用するTerraformコード
#

役割分担と受け渡し
#

flowchart LR
    TF["Terraform"] -->|"作る"| VM["GCE VM
外部IPなし"] TF -->|"アップロード"| GCS["GCS
Ansible資材"] VM -->|"startup script
で同期"| GCS VM -->|"ansible-playbook"| CFG["nginx / Ops Agent
OS設定"]
担当
Terraform マシン、ID、ネットワーク、ファイアウォール
Ansible パッケージ、サービス設定、ディスク上のファイル

受け渡しはmetadata_startup_scriptです。GCSから資材を同期してansible-playbookを実行します。

Terraform の関与は2本目の矢印で終わります。 3本目から先はVMの中の話で、成否はTerraformに返りません。

sequenceDiagram
    participant TF as terraform apply
    participant GCS as GCS バケット
    participant VM as GCE VM
    participant AN as ansible-playbook

    TF->>GCS: playbook をアップロード
    TF->>VM: インスタンスを作る
    VM->>VM: boot のたびに startup script が走る
    VM->>GCS: 資材を同期
    GCS-->>VM: playbook
    VM->>AN: 実行
    AN->>VM: nginx / Ops Agent / OS 設定

1本目と2本目の順序も、Terraform は自分では決められません。理由は順序依存の節で扱います。

サービスアカウントは専用に作る
#

既定のCompute Engine SAは使いません。権限は組織ポリシーと付与済みのロールで変わりますが、用途ごとに分けたいためです。

resource "google_service_account" "vm" {
  account_id = "${var.instance_name}-sa"
}

# バケット単位。プロジェクト全体には付けない
resource "google_storage_bucket_iam_member" "vm_read" {
  bucket = google_storage_bucket.ansible.name
  role   = "roles/storage.objectViewer"
  member = "serviceAccount:${google_service_account.vm.email}"
}

Ops Agent のログ・メトリクス送信権限を、roles/logging.logWriterとroles/monitoring.metricWriterで与えます。logging.logEntries.createはほかのロールにも含まれるので、この2つが唯一の組み合わせというわけではありません。必要な権限がどのロール経由でも付いていなければ、エージェントを入れても Cloud Logging に届きません。

Terraformが推論できない順序依存
#

startup scriptはGCSを読みます。ところがインスタンスの定義はバケットオブジェクトを参照していません。Terraformはこの依存を推論できません。

resource "google_compute_instance" "web" {
  # ...
  depends_on = [
    google_storage_bucket_object.ansible,
    google_storage_bucket_iam_member.vm_read,
    google_compute_router_nat.nat,
  ]
}

明示しないと、VMが起動したときバケットが空という状態が起きます。

playbookはfilesetで回してアップロードします。roleファイルを足してもTerraformの変更は要りません。

resource "google_storage_bucket_object" "ansible" {
  for_each = fileset("${path.module}/ansible", "**")

  name           = "ansible/${each.value}"
  bucket         = google_storage_bucket.ansible.name
  source         = "${path.module}/ansible/${each.value}"
  detect_md5hash = filemd5("${path.module}/ansible/${each.value}")
}

detect_md5hashがあるので、playbookを直してterraform applyすれば配れます。

startup scriptは毎回のbootで走る
#

「初回bootのみ」という説明を見かけますが、そうではありませんでした。

sudo wc -l < /var/log/startup-ansible.log   # 再起動前
209

reset はゲストOSの正常な終了処理を伴わない強制リセットです。手元から実行します。

gcloud compute instances reset tf-adv-gce-ans-web --zone=asia-northeast1-a

起動を待って入り直し、VM内で数えます。

gcloud compute ssh tf-adv-gce-ans-web --zone=asia-northeast1-a --tunnel-through-iap
sudo wc -l < /var/log/startup-ansible.log   # 再起動後
257
sudo grep -c "startup-ansible: BEGIN" /var/log/startup-ansible.log
4

BEGINが4回。startup scriptは起動のたびに実行されるという仕様とは整合しますが、この出力だけでは各bootとの対応までは取れていません。 確かめるなら、再起動の前後でBEGINの件数と時刻、/proc/sys/kernel/random/boot_idを記録します。

運用上はありがたい挙動です。GCSのplaybookを更新してVMを再起動すれば設定が反映され、VMを作り直す必要がありません。

更新するものによって扱いが変わります。GCS上の資材だけを変えるなら、VMは触りません。

一方metadata_startup_scriptそのものを変えると、インスタンスのリソース定義が変わります。providerは条件付きで再作成を選びますが、どちらになるかは今回試していません。 変えるならterraform planで確かめます。

ただし毎回apt-get install ansibleが走るのでboot時間は延びます。本番ならAnsibleが入ったカスタムイメージを使うか、条件分岐を入れます。

terraform applyの成功は中身を保証しない
#

ここが今回いちばん重要な点で、検証の途中に実際に起きました。

terraform apply
Apply complete! Resources: 35 added, 0 changed, 0 destroyed.

VMの中では失敗していました。

sudo tail /var/log/startup-ansible.log
ERROR! the role 'common' was not found in /opt/ansible/playbooks/roles:...

原因はAnsibleのrole探索です。playbookと同じ階層のroles/や、設定済みのroles_pathなどを探します。playbooks/site.ymlから見るとplaybooks/roles/ですが、roleはroles/に置いていました。

# ansible.cfg
[defaults]
roles_path = ./roles

ansible.cfgはカレントディレクトリのものが読まれます。roles_pathの./rolesもカレントからの相対です。startup scriptは/opt/ansibleへcdしてから実行しており、別のディレクトリから実行すると同じエラーに戻ります。

問題は、この失敗がTerraform側にまったく現れないことです。terraform state listは35件のまま、terraform planも差分なしです。

startup scriptの終了コードはVMの状態に影響しません。 設定が終わったかどうかは、VM内のログやシリアルポート出力で別途確認します。

terraform applyが通ったことを構築完了の合図にすると、この区間を見落とします。

template の validate には %s が要る
#

nginxの設定を書く前に構文検査したくなります。templateモジュールにvalidateがあります。

validate: nginx -t -c /etc/nginx/nginx.conf
fatal: [localhost]: FAILED! => {"msg": "validate must contain %s: nginx -t -c ..."}

%sに一時ファイルのパスが入ります。ただしnginx -t -c %sにフラグメントをそのまま渡すことはできません。 nginx -t -cは完全なnginx.confを期待するので、server { ... }だけのファイルでは失敗します。

validateには任意のコマンドを指定できるので、フラグメントをhttpコンテキストに読み込む検証用スクリプトを呼べば、配備前の検査もできます。今回はそこまでせず、配備後に検査して失敗したらバックアップから戻す方式にしました。

以下は処理の流れを示す抜粋です。site.conf.j2 と reload nginx ハンドラは別に定義してあります。

- name: Deploy the site configuration
  ansible.builtin.template:
    src: site.conf.j2
    dest: /etc/nginx/sites-available/default
    backup: true
  register: nginx_site
  notify: reload nginx

- name: Verify the configuration parses, restoring the backup if it does not
  block:
    - ansible.builtin.command: nginx -t
      changed_when: false
  rescue:
    - ansible.builtin.copy:
        src: "{{ nginx_site.backup_file }}"
        dest: /etc/nginx/sites-available/default
        remote_src: true
      when: nginx_site.backup_file is defined
    - ansible.builtin.fail:
        msg: >-
          nginx の設定が不正だった。
          {{ '直前のバックアップに戻した。'
             if nginx_site.backup_file is defined
             else 'バックアップが無く、自動では戻していない。' }}

復元をスキップした場合も「戻した」と報告すると、直っていない設定を直ったと読ませます。backup は変更があったときだけ作られるので、backup_file が未定義になる経路があります。

タスクが失敗すると、既定ではそのホストのハンドラは走らず、壊れた設定がreloadされることもありません。ただしforce_handlersを有効にすると失敗後もハンドラが走るので、これを唯一の防御にはできません。

冪等性
#

2回目は何も変えません。

localhost : ok=22  changed=0  unreachable=0  failed=0  skipped=4  rescued=0  ignored=0

インストーラはcommandで実行しています。commandは実行しただけでchangedを報告するので、statで導入済みを判定してスキップしています。

この結果から言えるのは、スキップによって2回目がchanged=0になったところまでです。インストーラ自体が冪等かどうかは分かりません。

動いていることと正しいことは別
#

サービスの確認は3つ見ます。

sudo nginx -t
for s in nginx google-cloud-ops-agent; do
  echo "$s: enabled=$(systemctl is-enabled $s) active=$(systemctl is-active $s)"
done
nginx: configuration file /etc/nginx/nginx.conf test is successful
nginx: enabled=enabled active=active
google-cloud-ops-agent: enabled=enabled active=active

is-activeだけでは足りません。今回のnginxとOps Agentは明示的に自動起動させる設計なので、is-enabledも検査します。

playbookでも同じことを見て、満たさなければ失敗します。ただし許可する出力は揃えていません。 nginxはenabledのみ、Ops Agentはenabledとgeneratedを許容しています。

google-cloud-ops-agentは親ユニットです。 これがactiveでも、実際に収集するgoogle-cloud-ops-agent-fluent-bitや-opentelemetry-collectorが動いているかは別に見ます。

後述の再起動後の確認も親ユニットしか見ていないので、収集が再開したことまでは確かめていません。

ただしsystemdにはstaticのように明示的な有効化を要さないユニットもあるので、この条件をすべてのサービスに当てはめることはできません。

curlは200だけでなく中身も見る
#

2経路で確かめます。

playbook側の検査も同じで、ステータスと本文の両方を見ます。

failed_when: >-
  nginx_local.status != 200
  or nginx_marker not in (nginx_local.content | default(''))

failed_whenはモジュール自身のステータス判定を置き換えます。 前半が無いと、マーカーを含むエラーページが素通りします。後半のdefault('')は、接続できずcontentが未定義のときに式ごと落ちるのを防ぐためです。

VM内から。

curl -s http://127.0.0.1/ | grep -o "tf-adv-ansible-nginx"
curl -s -w " (%{http_code})\n" http://127.0.0.1/healthz
tf-adv-ansible-nginx
ok (200)

200が返るだけでは、配置した内容が反映されているとは限りません。実際、設定の配布に失敗していたとき、nginxはDebianの既定ページで200を返していました。

次にIAPトンネル経由。VMに外部IPはありません。

gcloud compute start-iap-tunnel tf-adv-gce-ans-web 80 \
  --local-host-port=localhost:18080 --zone=asia-northeast1-a &

curl -s -o /dev/null -w "index: %{http_code}\n" http://localhost:18080/
curl -s http://localhost:18080/healthz
curl -s http://localhost:18080/ | grep -o "configured by Ansible"
index: 200
ok
configured by Ansible

ファイアウォールとネットワーク経路まで通っていることが分かります。nginx をインターネットへ公開していないという意味で、外向きの通信が無いわけではありません。パッケージの取得は Cloud NAT を通ります。

再起動後もサービスが上がる
#

1行目は手元、残りは入り直したあとVM内で実行します。sudo reboot による通常の再起動は測っていません。

gcloud compute instances reset tf-adv-gce-ans-web --zone=asia-northeast1-a
# 80秒待って入り直す
for s in nginx google-cloud-ops-agent; do echo "$s: $(systemctl is-active $s)"; done
curl -s -w " healthz(%{http_code})\n" http://127.0.0.1/healthz
nginx: active
google-cloud-ops-agent: active
ok healthz(200)

HTMLの変更は再起動なしで反映される
#

ローカルのansible/roles/nginx/defaults/main.ymlでnginx_bodyを変え、terraform applyでGCSの資材を更新します。次にterraform output -raw rerun_playbook_exampleが表示するコマンドで、既存VMへの同期とplaybookの再実行を行います。VMは再起動しません。

この変数を参照しているのはindex.html.j2だけで、notify: reload nginxが付いているのはサイト設定の配備タスクのほうです。 この変更ではハンドラは走りません。

localhost : ok=22  changed=1  ...

MainPID before=2038 after=2038
curl -s http://127.0.0.1/ | grep -o "reloaded without restart"
reloaded without restart

MainPIDが変わっていません。この回で確認できたのは、masterプロセスが入れ替わらなかったことだけです。 workerが入れ替わったかも、reloadが走ったかどうかも、この値からは判定できません。

サイト設定を変えた場合はreloadハンドラが走ります。nginxのreloadはmasterプロセスを残したまま、新しいworkerを起動する仕組みです。古いworkerは処理中のリクエストを終えてから終わります。

その挙動はこの検証では切り分けていません。

検査の前にハンドラを流しておく必要があります。 ハンドラは既定でrole/tasksの実行後にまとめて走るので、そのままではHTTP検査がreloadより前に実行され、変更前の設定を検査してしまいます。 nginx_portを変えるとさらに悪く、新しいポートへの検査がreload前に失敗し、失敗したホストではハンドラも走りません。

- name: Apply any pending reload before verifying
  ansible.builtin.meta: flush_handlers

ハンドラをrestartにするとPIDが変わります。ただし通信断の差は測っていません。 比べるなら、連続リクエストと長いリクエストを流しながら両方を実行し、失敗件数と応答時間を記録します。

GCEはOps Agentを入れるまでOS・アプリケーションのログが来なかった
#

GKEのログがCloud Loggingにどう届くかでは、収集エージェントがコンテナの標準出力を自動で拾っていました。GCEは違います。

今回の構成では、Ops Agentを入れる前に、ゲストOSやnginxのログを1件も確認できませんでした。 対象VMも時間範囲も絞らない検索なので、「届いていない」と言い切れるだけの条件では引いていません。

VMの作成やresetを記録するCloud Audit Logsはこれとは別で、Ops Agentが無くても残ります。ここで言っているのはOS・アプリケーション側のログです。

ただし Ops Agent が唯一の経路ではありません。2つあります。

シリアルポート出力を Cloud Logging へ送る機能は serial-port-logging-enable メタデータで有効にできます(既定は無効)。

Guest Agent 自身にも送信経路があります。 /etc/default/instance_configs.cfg の Core.cloud_logging_enabled で切り替えられ、既定は有効です。startup script の実行状況と出力もここを通ります。ただしリリースノートによると、この経路には不具合がありました。

Version 20251107.01 includes a fix for the Startup script runner component that prevented it from writing status logs and script output to Cloud Logging.

今回は Guest Agent のバージョンと cloud_logging_enabled の実効値を記録していません。 後述の0件を切り分けるなら、まずこの2つを見ます。

導入後に確認します。

syslog                   5件
nginx_access             5件
nginx_error              1件
ops-agent-fluent-bit     5件

この数字は件数の比較に使えません。--limit=5の上限に当たっており、実際にいくつ届いたかは分かりません。言えるのは「導入後は0件ではなかった」ところまでです。

ログ クエリ
syslog logName="projects/YOUR_PROJECT_ID/logs/syslog"
nginxアクセスログ logName="projects/YOUR_PROJECT_ID/logs/nginx_access"
nginxエラーログ logName="projects/YOUR_PROJECT_ID/logs/nginx_error"

logNameのログID部分がreceiver IDになります。filesレシーバならprojects/PROJECT_ID/logs/RECEIVER_IDで、nginx_accessならprojects/PROJECT_ID/logs/nginx_accessです。レシーバの型によっては入力タグが後ろに付くので、この形がすべてではありません。

以下は receiver ID を示すための抜粋です。収集を始めるには service.pipelines の receivers にも同じ名前を並べます。

logging:
  receivers:
    nginx_access:          # ← この名前が logName になる
      type: files
      include_paths:
        - /var/log/nginx/access.log
  service:
    pipelines:
      nginx:
        receivers: [nginx_access]

filesレシーバが読んだ行はjsonPayload.messageに入ります。textPayloadではありません。

このクエリではstartup scriptのログを確認できなかった
#

gcloud logging read 'resource.type="gce_instance" AND logName=~"startupscript"' --limit=5
(0件)

logNameにstartupscriptを含むログは0件でした。ただしこの検索は条件が緩すぎます。 対象VMを絞らず、時間範囲も既定(直近1日)のまま、上限5件で引いています。

導入前後を比べるなら、resource.labels.instance_id と開始・終了時刻を明示し、上限に当たらない件数で両方を引きます。

この検索では、syslog やシリアルポート出力、Guest Agent 経由のログに含まれる可能性も否定できません。

今回の失敗はこの区間で起きました。 Terraformにも返らず、Cloud Loggingにも出ないので、気づきにくい場所です。シリアルコンソールと、VM内の/var/log/startup-ansible.logで追いました。

後片付け
#

terraform destroy
Destroy complete! Resources: 35 destroyed.

バケットはforce_destroy = trueにしてあります。オブジェクトが残っていても中身ごと消せます。資材のアップロードは Terraform が行い、startup script はバケットから読むだけです。

まとめ
#

  • startup scriptは毎回のbootで実行される。 playbookを更新してVMを再起動すれば反映される
  • terraform applyの成功は中の設定を保証しない。 Ansibleが失敗してもterraform planは差分なしのまま
  • Terraformが推論できない順序依存がある。 startup scriptがGCSを読むことはdepends_onで明示する
  • Ansibleのrole探索はplaybookと同じ階層のroles/が既定。今回の配置ではroles_pathの追加が要った
  • templateのvalidateは%sが必須。フラグメントをnginx -t -c %sへ直接は渡せないが、完全な設定として読み込ませる検証スクリプトを呼べば検査できる
  • 動いていることと正しいことは別。 is-activeだけでなくis-enabledと構文検査も見る
  • curlは200だけでなく中身も見る。 外部IPなしならIAPトンネルで外からも確かめられる
  • HTMLの差し替えでmasterプロセスは入れ替わらなかった。 MainPIDが一致しただけで、workerの入れ替わりやreloadの有無までは判定していない
  • GCEは、今回の構成ではOps Agentを入れるまでゲストOSとnginxのログを確認できなかった。 VMの管理操作を記録する監査ログはこれとは別で、Ops Agent が無くても残る。シリアルポート出力と Guest Agent にも送信経路がある

参考資料
#

Terraform-GoogleCloud - この記事は連載の一部です
パート 38: この記事

関連記事

標準出力に1行JSONを書くだけなら、GKEではFluentdサイドカーが要らなかった
2 分
Terraform GoogleCloud GKE CloudLogging Fluentd
GKEのdefault_compute_class_enabledを有効にしても何も起きなかったので調べた
3 分
Terraform GoogleCloud GKE
GKEノードプールのSURGEアップグレードをBlue/Greenと同じ条件で測って比べてみた
3 分
Terraform GoogleCloud GKE
GKEノードプールをBlue/Greenでアップグレードして、soak期間中にロールバックしてみた
5 分
Terraform GoogleCloud GKE CloudKMS
GKEノードのブートディスクをCMEKで暗号化して鍵をローテーションしてみた
6 分
Terraform GoogleCloud GKE CloudKMS CMEK
TerraformでGKEのPodにSecret Managerの値をファイルとしてマウントしてみた
3 分
Terraform GoogleCloud GKE SecretManager