crossplane-contrib / provider-jet-gcp

GCP Provider for Crossplane generated using Terrajet
Apache License 2.0
12 stars 21 forks source link

Provisioning GCP projects with billing enabled fails around 2 minutes 40-50 seconds #52

Closed mol-george closed 2 years ago

mol-george commented 2 years ago

What happened?

Apply fails on GCP projects with billing enabled consistently around 2 minutes 40-50 seconds - see jet-gcp provider logs below:

gcp-jet-d39a1c5ba7e7-f4c6cf59d-t8wrg provider-jet-gcp 2022-03-18T12:48:30.017Z DEBUG provider-jet-gcp Reconciling {"controller": "managed/cloudplatform.gcp.jet.crossplane.io/v1alpha2, kind=project", "request": "/david-1647607708"}

gcp-jet-d39a1c5ba7e7-f4c6cf59d-t8wrg provider-jet-gcp 2022-03-18T12:48:32.261Z DEBUG provider-jet-gcp refresh ended {"workspace": "/tmp/a88721a1-5bc7-4fe3-ab46-48092004b4bc", "out": "{\"@level\":\"info\",\"@message\":\"Terraform 1.1.4\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:30.663463Z\",\"terraform\":\"1.1.4\",\"type\":\"version\",\"ui\":\"1.0\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Refreshing state...\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:32.247978Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"id_key\":\"id\"},\"type\":\"refresh_start\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Refresh complete\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:32.249178Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null}},\"type\":\"refresh_complete\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Drift detected (delete)\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:32.252979Z\",\"change\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"delete\"},\"type\":\"resource_drift\"}\n{\"@level\":\"info\",\"@message\":\"Plan: 0 to add, 0 to change, 0 to destroy.\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:32.253064Z\",\"changes\":{\"add\":0,\"change\":0,\"remove\":0,\"operation\":\"plan\"},\"type\":\"change_summary\"}\n{\"@level\":\"info\",\"@message\":\"Apply complete! Resources: 0 added, 0 changed, 0 destroyed.\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:32.257308Z\",\"changes\":{\"add\":0,\"change\":0,\"remove\":0,\"operation\":\"apply\"},\"type\":\"change_summary\"}\n{\"@level\":\"info\",\"@message\":\"Outputs: 0\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:32.257433Z\",\"outputs\":{},\"type\":\"outputs\"}\n"}

gcp-jet-d39a1c5ba7e7-f4c6cf59d-t8wrg provider-jet-gcp 2022-03-18T12:51:30.021Z DEBUG provider-jet-gcp apply ended {"workspace": "/tmp/a88721a1-5bc7-4fe3-ab46-48092004b4bc", "out": "{\"@level\":\"info\",\"@message\":\"Terraform 1.1.4\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:32.324076Z\",\"terraform\":\"1.1.4\",\"type\":\"version\",\"ui\":\"1.0\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Plan to create\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:33.599076Z\",\"change\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\"},\"type\":\"planned_change\"}\n{\"@level\":\"info\",\"@message\":\"Plan: 1 to add, 0 to change, 0 to destroy.\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:33.599238Z\",\"changes\":{\"add\":1,\"change\":0,\"remove\":0,\"operation\":\"plan\"},\"type\":\"change_summary\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Creating...\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:34.012480Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\"},\"type\":\"apply_start\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [10s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:44.012934Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":10},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [20s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:48:54.013295Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":20},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [30s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:49:04.014150Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":30},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [40s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:49:14.014322Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":40},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [50s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:49:24.015100Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":50},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [1m0s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:49:34.015758Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":60},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [1m10s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:49:44.016973Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":70},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [1m20s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:49:54.017821Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":80},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [1m30s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:50:04.018473Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":90},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [1m40s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:50:14.019676Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":100},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [1m50s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:50:24.020385Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":110},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [2m0s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:50:34.021506Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":120},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [2m10s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:50:44.021863Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":130},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [2m20s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:50:54.022180Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":140},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [2m30s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:51:04.022918Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":150},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [2m40s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:51:14.023179Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":160},\"type\":\"apply_progress\"}\n{\"@level\":\"info\",\"@message\":\"google_project.david-1647607708: Still creating... [2m50s elapsed]\",\"@module\":\"terraform.ui\",\"@timestamp\":\"2022-03-18T12:51:24.023492Z\",\"hook\":{\"resource\":{\"addr\":\"google_project.david-1647607708\",\"module\":\"\",\"resource\":\"google_project.david-1647607708\",\"implied_provider\":\"google\",\"resource_type\":\"google_project\",\"resource_name\":\"david-1647607708\",\"resource_key\":null},\"action\":\"create\",\"elapsed_seconds\":170},\"type\":\"apply_progress\"}\n"}

gcp-jet-d39a1c5ba7e7-f4c6cf59d-t8wrg provider-jet-gcp 2022-03-18T12:51:30.021Z DEBUG provider-jet-gcp Cannot create external resource {"controller": "managed/cloudplatform.gcp.jet.crossplane.io/v1alpha2, kind=project", "request": "/david-1647607708", "uid": "a88721a1-5bc7-4fe3-ab46-48092004b4bc", "version": "485696", "external-name": "", "error": "cannot apply: apply failed: ", "errorVerbose": "apply failed: \ncannot apply\ngithub.com/crossplane/terrajet/pkg/controller.(*external).Create\n\t/Users/dcollom/repos/github/davidcollom/provider-jet-gcp/.work/pkg/pkg/mod/github.com/crossplane/terrajet@v0.3.1/pkg/controller/external.go:205\ngithub.com/crossplane/crossplane-runtime/pkg/reconciler/managed.(*Reconciler).Reconcile\n\t/Users/dcollom/repos/github/davidcollom/provider-jet-gcp/.work/pkg/pkg/mod/github.com/crossplane/crossplane-runtime@v0.15.1-0.20211004150827-579c1833b513/pkg/reconciler/managed/reconciler.go:800\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\t/Users/dcollom/repos/github/davidcollom/provider-jet-gcp/.work/pkg/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.6/pkg/internal/controller/controller.go:298\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/Users/dcollom/repos/github/davidcollom/provider-jet-gcp/.work/pkg/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.6/pkg/internal/controller/controller.go:253\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/Users/dcollom/repos/github/davidcollom/provider-jet-gcp/.work/pkg/pkg/mod/sigs.k8s.io/controller-runtime@v0.9.6/pkg/internal/controller/controller.go:214\nruntime.goexit\n\t/usr/local/Cellar/go/1.17.3/libexec/src/runtime/asm_amd64.s:1581"}

gcp-jet-d39a1c5ba7e7-f4c6cf59d-t8wrg provider-jet-gcp 2022-03-18T12:51:30.023Z DEBUG controller-runtime.manager.events Warning {"object": {"kind":"Project","name":"david-1647607708","uid":"a88721a1-5bc7-4fe3-ab46-48092004b4bc","apiVersion":"cloudplatform.gcp.jet.crossplane.io/v1alpha2","resourceVersion":"485735"}, "reason": "CannotCreateExternalResource", "message": "cannot apply: apply failed: "}

The GCP Project gets created though but enabling billing fails:

$ kubectl get projects
NAME               READY   SYNCED   EXTERNAL-NAME   AGE
david-1647607708   False   False                    11m

How can we reproduce it?

Attempt to provision a Project resource using the

apiVersion: cloudplatform.gcp.jet.crossplane.io/v1alpha2
kind: Project
metadata:
  name: [...REDACTED...]
spec:
  forProvider:
    name: "[...REDACTED...]"
    projectId: "[...REDACTED...]"
    folderId: "[...REDACTED...]"
    autoCreateNetwork: false
    billingAccount: "[...REDACTED...]"

What environment did it happen in?

Crossplane version: v1.6.4 Provider version: provider-jet-gcp@v0.2.0-preview

Other things we tried

bash-5.1$ terraform apply
Terraform used the selected providers to generate the following execution plan. Resource actions are indicated with the following symbols:
  + create
Terraform will perform the following actions:
  # google_project.david-1647607708 will be created
  + resource "google_project" "david-1647607708" {
      + auto_create_network = false
      + billing_account     = "[...REDACTED...]"
      + folder_id           = "[...REDACTED...]"
      + id                  = (known after apply)
      + labels              = {
          + "cost_centre"    = "[...REDACTED...]"
          + "jetstack_owner" = "team-training_jetstack_io"
          + "training"       = "true"
        }
      + name                = "training-david-1647607709"
      + number              = (known after apply)
      + project_id          = "training-david-1647607709"
      + skip_delete         = (known after apply)
    }
Plan: 1 to add, 0 to change, 0 to destroy.
Do you want to perform these actions?
  Terraform will perform the actions described above.
  Only 'yes' will be accepted to approve.
  Enter a value: yes
google_project.david-1647607708: Creating...
google_project.david-1647607708: Still creating... [10s elapsed]
google_project.david-1647607708: Still creating... [20s elapsed]
google_project.david-1647607708: Still creating... [30s elapsed]
google_project.david-1647607708: Still creating... [40s elapsed]
google_project.david-1647607708: Still creating... [50s elapsed]
google_project.david-1647607708: Still creating... [1m0s elapsed]
google_project.david-1647607708: Still creating... [1m10s elapsed]
google_project.david-1647607708: Still creating... [1m20s elapsed]
google_project.david-1647607708: Still creating... [1m30s elapsed]
google_project.david-1647607708: Still creating... [1m40s elapsed]
google_project.david-1647607708: Still creating... [1m50s elapsed]
google_project.david-1647607708: Still creating... [2m0s elapsed]
google_project.david-1647607708: Still creating... [2m10s elapsed]
google_project.david-1647607708: Still creating... [2m20s elapsed]
google_project.david-1647607708: Still creating... [2m30s elapsed]
google_project.david-1647607708: Still creating... [2m40s elapsed]
google_project.david-1647607708: Still creating... [2m50s elapsed]
google_project.david-1647607708: Still creating... [3m0s elapsed]
google_project.david-1647607708: Still creating... [3m10s elapsed]
google_project.david-1647607708: Creation complete after 3m18s [id=projects/training-david-1647607709]
Apply complete! Resources: 1 added, 0 changed, 0 destroyed.
bash-5.1$ ls
main.tf.json       terraform.tfstate
davidcollom commented 2 years ago

I believe that this may also be related to issue #45 and the cause of a project never syncing