Debugging Terraform

Es kann vorkommen, dass Infrastruktur, die mit Terraform ausgerollt wird, durchaus länger, unverändert läuft.

Dieser Umstand kann dazu führen, daß die Infrastruktur "unter" der Infrastruktur (aka "the cloud") sich (unbemerkt) verändert. Neulich wollte ich unsere dnsdist-Loadbalancer aktualisieren und neu ausrollen. Da begrüßte Terraform mich so:

09:02:26 toens@NB-46261 terraform ±|master ✗|→ terraform plan 
openstack_compute_keypair_v2.user_keypair: Refreshing state... [id=tf_dnsdist]
openstack_networking_floatingip_v2.float_ip[1]: Refreshing state... [id=dddaba56-1ffc-4319-b58f-2435ff74bbff]
openstack_networking_secgroup_v2.sg_dnsdist: Refreshing state... [id=01345a91-ee9c-4de2-92bc-e7e017591fac]
openstack_networking_floatingip_v2.float_ip[0]: Refreshing state... [id=d932503a-7952-4f5a-8337-82693b2a03dd]
data.template_file.user_data: Reading...
openstack_compute_keypair_v2.user_keypairhire: Refreshing state... [id=tf_dnsdisthire]
data.template_file.user_data: Read complete after 0s [id=e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855]
openstack_networking_secgroup_v2.sg_dnsdisthire: Refreshing state... [id=cdb2b283-bb12-4b45-b03e-15ee3728383e]
openstack_networking_floatingip_v2.float_iphire[0]: Refreshing state... [id=44eacd54-e50d-42c0-a679-5e07d1de6285]
openstack_networking_floatingip_v2.float_iphire[1]: Refreshing state... [id=1e170ae6-6bcc-4c34-b5a5-08f01076df28]
openstack_networking_secgroup_v2.sg_dnsdistprod1: Refreshing state... [id=824df8ee-0e73-45e3-adec-a72bec0a3d5b]
openstack_networking_floatingip_v2.float_ipprod1[0]: Refreshing state... [id=b9df5f66-6742-4751-b50f-60d476d92231]
openstack_networking_floatingip_v2.float_ipprod1[1]: Refreshing state... [id=7894a583-a94d-4e24-8338-b6d99f69b06f]
openstack_compute_keypair_v2.user_keypairprod1: Refreshing state... [id=tf_dnsdistprod1]
openstack_networking_secgroup_rule_v2.sr_dd_ssprod1: Refreshing state... [id=d456a00d-a7ce-4792-9b84-672bccf2c14e]
openstack_networking_secgroup_rule_v2.sr_dd_dns1prod1: Refreshing state... [id=360d0844-2283-413c-a025-254a3729e9e7]
openstack_networking_secgroup_rule_v2.sr_dd_dns2prod1: Refreshing state... [id=9e9854bb-9783-4985-a64f-9a543db88d40]
openstack_networking_secgroup_rule_v2.sr_dd_dns1: Refreshing state... [id=6aa7f06e-0ca0-49e0-8a57-0df85e9f7a95]
openstack_networking_secgroup_rule_v2.sr_dd_dns2: Refreshing state... [id=5412cfa4-726e-4e99-9244-8cabf79f3196]
openstack_networking_secgroup_rule_v2.sr_dd_ssh: Refreshing state... [id=dc6337a0-7fab-4493-8929-8a9b1ad3b292]
openstack_compute_instance_v2.dnsdist[0]: Refreshing state... [id=56551ca0-dde2-40e0-8448-213ed5a3f39b]
openstack_compute_instance_v2.dnsdist[1]: Refreshing state... [id=065f4f65-6c53-4bc8-b410-9fbd7def714e]
openstack_compute_instance_v2.dnsdistprod1[0]: Refreshing state... [id=b2bb1935-d39a-4f21-9f22-1f7c704093cb]
openstack_compute_instance_v2.dnsdistprod1[1]: Refreshing state... [id=faae17ed-aa03-4f24-ab8e-15d1df980401]
openstack_compute_floatingip_associate_v2.float_ip[0]: Refreshing state... [id=213.131.230.226/56551ca0-dde2-40e0-8448-213ed5a3f39b/]
openstack_compute_floatingip_associate_v2.float_ip[1]: Refreshing state... [id=213.131.230.31/065f4f65-6c53-4bc8-b410-9fbd7def714e/]
2022-12-14T09:09:38.882+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdistprod1[0]" error: Resource not found
2022-12-14T09:09:38.898+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdistprod1[1]" error: Resource not found
2022-12-14T09:09:38.898+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdistprod1" error: Resource not found
2022-12-14T09:09:38.898+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdistprod1" error: Resource not found
2022-12-14T09:09:38.898+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdistprod1 (expand)" error: Resource not found
2022-12-14T09:09:38.898+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdistprod1 (expand)" error: Resource not found
openstack_compute_instance_v2.dnsdisthire[0]: Refreshing state... [id=aef6c75d-5be0-43f7-ab1f-9a34a6f1fe4e]
openstack_compute_instance_v2.dnsdisthire[1]: Refreshing state... [id=1c2ce381-735e-4a07-a319-9c51f0347534]
openstack_networking_secgroup_rule_v2.sr_dd_dns2hire: Refreshing state... [id=23598c55-4979-49f3-b3bb-19bb0568f1b2]
openstack_networking_secgroup_rule_v2.sr_dd_sshhire: Refreshing state... [id=86f3ebe8-9c37-4d36-bb8a-088c48f81251]
openstack_networking_secgroup_rule_v2.sr_dd_dns1hire: Refreshing state... [id=68203cfa-6c09-45b4-bb6a-797fe6db9678]
2022-12-14T09:09:39.419+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdisthire[0]" error: Resource not found
2022-12-14T09:09:39.438+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdisthire[1]" error: Resource not found
2022-12-14T09:09:39.438+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdisthire" error: Resource not found
2022-12-14T09:09:39.438+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdisthire" error: Resource not found
2022-12-14T09:09:39.438+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdisthire (expand)" error: Resource not found
2022-12-14T09:09:39.438+0100 [ERROR] vertex "openstack_compute_instance_v2.dnsdisthire (expand)" error: Resource not found
╷
│ Error: Resource not found
│ 
│   with openstack_compute_instance_v2.dnsdisthire[0],
│   on compute.tf line 19, in resource "openstack_compute_instance_v2" "dnsdisthire":
│   19: resource "openstack_compute_instance_v2" "dnsdisthire" {
│ 
╵
╷
│ Error: Resource not found
│ 
│   with openstack_compute_instance_v2.dnsdisthire[1],
│   on compute.tf line 19, in resource "openstack_compute_instance_v2" "dnsdisthire":
│   19: resource "openstack_compute_instance_v2" "dnsdisthire" {
│ 
╵
╷
│ Error: Resource not found
│ 
│   with openstack_compute_instance_v2.dnsdistprod1[0],
│   on compute.tf line 34, in resource "openstack_compute_instance_v2" "dnsdistprod1":
│   34: resource "openstack_compute_instance_v2" "dnsdistprod1" {
│ 
╵
╷
│ Error: Resource not found
│ 
│   with openstack_compute_instance_v2.dnsdistprod1[1],
│   on compute.tf line 34, in resource "openstack_compute_instance_v2" "dnsdistprod1":
│   34: resource "openstack_compute_instance_v2" "dnsdistprod1" {
│ 

Das ist natürlich etwas unerfreulich. Insbesondere, da die Fehlermeldung nicht wirklich hilfreich ist: Die ausgerollten Instanzen waren ja ganz offensichtlich noch da. Die allwissende Müllhalde konnte mir schnell helfen. Damit ich das Ergebnis der Suche nicht vergesse, hier die Abhilfe:

Zunächst empfiehlt es sich, das Loglevel für das Debugging hochzusetzen:

  • TF_LOG=DEBUG
  • OS_DEBUG=1

Beim nächsten Aufruf wird terraform plan schon gesprächiger und liefert den gesamten Output der Kommunikation mit der API mit. Im ASCII-Wust entdecken wir:

2022-12-14T09:36:10.256+0100 [DEBUG] provider.terraform-provider-openstack_v1.39.0: 2022/12/14 09:36:10 [DEBUG] OpenStack Response Body: {
2022-12-14T09:36:10.256+0100 [DEBUG] provider.terraform-provider-openstack_v1.39.0:   "itemNotFound": {
2022-12-14T09:36:10.256+0100 [DEBUG] provider.terraform-provider-openstack_v1.39.0:     "code": 404,
2022-12-14T09:36:10.256+0100 [DEBUG] provider.terraform-provider-openstack_v1.39.0:     "message": "Flavor cb635210-085e-4659-a10e-d1dcddf897f9 could not be found."
2022-12-14T09:36:10.256+0100 [DEBUG] provider.terraform-provider-openstack_v1.39.0:   }
2022-12-14T09:36:10.256+0100 [DEBUG] provider.terraform-provider-openstack_v1.39.0: }

Klar. Wir hatten Flavors gelöscht und dabei waren offenbar auch die, mit denen diese dnsdist-Instanzen erzeugt worden sind. Terraform braucht den aktuellen Status, um ermitteln zu können, welche Komponenten der Infrastruktur ersetzt werden sollen. Das Problem kann man umgehen, in dem man Terraform beim Planen anweist, keinen Refresh der aktuellen Infrastruktur durchzuführen:

terraform plan -refresh=false

Damit sollte man auf den Pfad der Tugend zurückfinden und in der Lage sein, ein neues Deployment durchzuführen.