external-secrets: Sometimes multiple errors occur and secret files are not synchronized properly in GKE

Version / env

  • ESO v0.4.4
  • GKE v1.21.6-gke.1500
  • use Workload Identity
  • use SecretStore (don’t use ClusterSecretStore)
  • use Secret Manager

Problem

When I kubectl describe external-secret, I get the following error

Events:
Type Reason AgeFromMessage
---- ------ ---- -----------
Normal Updated56m (x415 over 7h56m)external-secretsUpdated Secret
WarningUpdateFailed 49m (x2 over 53m)external-secrets could not get secret data from provider: key "development-exsec-my-credential" from ExternalSecret "my-external-secrets-operator": unable to access Secret from SecretManager Client: rpc error: code = PermissionDenied desc = Permission 'secretmanager.versions.access' denied for resource 'projects/MY_PROJECT/secrets/development-exsec-my-credential/versions/latest' (or it may not exist).
WarningUpdateFailed 43m (x12 over 53m) external-secrets could not get secret data from provider: key "development-exsec-my-session-key" from ExternalSecret "my-external-secrets-operator": unable to access Secret from SecretManager Client: rpc error: code = Canceled desc = grpc: the client connection is closing
WarningUpdateFailed 38m external-secrets could not get secret data from provider: key "development-exsec-my-api-key" from ExternalSecret "my-external-secrets-operator": unable to access Secret from SecretManager Client: rpc error: code = Canceled desc = grpc: the client connection is closing
WarningUpdateFailed 24m (x19 over 53m) external-secrets could not get secret data from provider: key "development-exsec-my-credential" from ExternalSecret "my-external-secrets-operator": unable to access Secret from SecretManager Client: rpc error: code = Canceled desc = grpc: the client connection is closing
WarningInvalidProviderClientConfig17m (x33 over 54m) external-secrets failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing
Normal Updated12m (x14 over 45m) external-secretsUpdated Secret
WarningUpdateFailed 2m42s (x10 over 34m) external-secrets could not get secret data from provider: key "development-exsec-my-bugsnag-api-key" from ExternalSecret "my-external-secrets-operator": unable to access Secret from SecretManager Client: rpc error: code = Canceled desc = grpc: the client connection is closing

In summary, the following types of errors occur randomly.

msg: could not update Secret
err: could not get secret data from provider: key \\"development-exsec-admin-bugsnag-api-key-for-api\\" from ExternalSecret \\"admin-secrets\\": unable to access Secret from SecretManager Client: rpc error: code = Canceled desc = grpc: the client connection is closing

msg: could not update Secret
err: could not get secret data from provider: key "development-exsec-my-credential" from ExternalSecret "my-external-secrets-operator": unable to access Secret from SecretManager Client: rpc error: code = PermissionDenied desc = Permission 'secretmanager.versions.access' denied for resource 'projects/MY_PROJECT/secrets/development-exsec-my-credential/versions/latest' (or it may not exist).

msg: could not get provider client
err: failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing

msg: could not close provider client
err: failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing

Lack of authorization appears to be the problem, but the following are in place.

  • Workload Identity settings (NodePool/GKE) have been done.
  • GSA - KSA ties are in place.
  • IAM role (Workload Identity/TokenCreator) is granted.

I believe that the privileges granted are not wrong because "most of the time the Secret is created successfully, but sometimes it fails.

By the way, here is the ESO Pod log. (Ignore the fact that it does not correspond to the above error.)

ESO Pod log (Click me)
{"level":"error","ts":1646971718.1400776,"logger":"controllers.ExternalSecret","msg":"could not close provider client","ExternalSecret":"app-dev-test1/my-secrets","SecretStore":"app-dev-test1/my-external-secrets-operator","error":"unable to close SecretManager client: rpc error: code = Canceled desc = grpc: the client connection is closing (and 4 other errors)","stacktrace":"github.com/external-secrets/external-secrets/pkg/controllers/externalsecret.(*Reconciler).Reconcile\\n\\t/home/runner/work/external-secrets/external-secrets/pkg/controllers/externalsecret/externalsecret_controller.go:246\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}
{"level":"info","ts":1646971718.6454322,"logger":"controllers.ExternalSecret","msg":"reconciled secret","ExternalSecret":"app-dev-test1/my-secrets","SecretStore":"app-dev-test1/my-external-secrets-operator"}external-secrets-c4bc855d7-9wnlb {"level":"error","ts":1646971718.7890575,"logger":"controllers.ExternalSecret","msg":"could not get provider client","ExternalSecret":"app-dev-outgame-sandbox/admin-secrets","SecretStore":"app-dev-outgame-sandbox/admin-external-secrets-operator","error":"failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}
{"level":"error","ts":1646971721.8899071,"logger":"controllers.ExternalSecret","msg":"could not update Secret","ExternalSecret":"app-dev-test2/admin-secrets","SecretStore":"app-dev-test2/admin-external-secrets-operator","error":"could not get secret data from provider: key \\"development-exsec-admin-bugsnag-api-key-for-api\\" from ExternalSecret \\"admin-secrets\\": unable to access Secret from SecretManager Client: rpc error: code = Canceled desc = grpc: the client connection is closing","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}
{"level":"error","ts":1646971721.890896,"logger":"controllers.ExternalSecret","msg":"could not get provider client","ExternalSecret":"prometheus/prometheus-iap-client","SecretStore":"prometheus/external-secrets-operator","error":"failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}
{"level":"info","ts":1646971722.2506986,"logger":"controllers.ExternalSecret","msg":"reconciled secret","ExternalSecret":"prometheus/prometheus-iap-client","SecretStore":"prometheus/external-secrets-operator"}
{"level":"error","ts":1646971781.9834816,"logger":"controllers.ExternalSecret","msg":"could not update Secret","ExternalSecret":"app-dev-test3/admin-secrets","SecretStore":"app-dev-test3/admin-external-secrets-operator","error":"could not get secret data from provider: key \\"development-exsec-admin-bugsnag-api-key-for-frontend\\" from ExternalSecret \\"admin-secrets\\": unable to access Secret from SecretManager Client: rpc error: code = PermissionDenied desc = Permission 'secretmanager.versions.access' denied for resource 'projects/MY_PROJECT/secrets/development-exsec-admin-bugsnag-api-key-for-frontend/versions/latest' (or it may not exist).","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}
{"level":"error","ts":1646971810.505019,"logger":"controllers.ExternalSecret","msg":"could not update Secret","ExternalSecret":"app-dev-test4/admin-secrets","SecretStore":"app-dev-test4/admin-external-secrets-operator","error":"could not get secret data from provider: key \\"development-exsec-admin-bugsnag-api-key-for-frontend\\" from ExternalSecret \\"admin-secrets\\": unable to access Secret from SecretManager Client: rpc error: code = PermissionDenied desc = Permission 'secretmanager.versions.access' denied for resource 'projects/MY_PROJECT/secrets/development-exsec-admin-bugsnag-api-key-for-frontend/versions/latest' (or it may not exist).","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}

Concerns

We have two GKE clusters running on one GCP project, both running ESO. Tentatively named dev cluster / staging cluster, this problem only occurs in the dev cluster.

The ESO startup configuration for the dev cluster and staging cluster is exactly the same. The only difference is that the dev cluster has many external secrets and secret stores running because it is a development environment.

# dev cluster
❯ k get -A externalsecrets.external-secrets.io| wc -l
68
❯ k get -A secretstores.external-secrets.io | wc -l
47

# staging cluster
❯ k get -A externalsecrets.external-secrets.io| wc -l
 9
❯ k get -A secretstores.external-secrets.io | wc -l
 5

Our manifests

our manifests (Click me)
apiVersion: external-secrets.io/v1alpha1
kind: ExternalSecret
metadata:
  labels:
    app.kubernetes.io/component: admin-api
    app.kubernetes.io/name: admin-api
  name: admin-iap-client-secrets
  namespace: app-dev-test0
spec:
  data:
  - remoteRef:
      key: development-exsec-admin-iap-client
      property: client_id
      version: latest
    secretKey: client_id
  - remoteRef:
      key: development-exsec-admin-iap-client
      property: client_secret
      version: latest
    secretKey: client_secret
  refreshInterval: 1m
  secretStoreRef:
    kind: SecretStore
    name: admin-external-secrets-operator
---
apiVersion: external-secrets.io/v1alpha1
kind: ExternalSecret
metadata:
  labels:
    app.kubernetes.io/component: admin-api
    app.kubernetes.io/name: admin-api
  name: admin-secrets
  namespace: app-dev-test0
spec:
  data:
  - remoteRef:
      key: development-exsec-admin-bugsnag-api-key-for-api
      version: latest
    secretKey: bugsnag-api-key-for-api
  - remoteRef:
      key: development-exsec-admin-bugsnag-api-key-for-frontend
      version: latest
    secretKey: bugsnag-api-key-for-frontend
  refreshInterval: 1m
  secretStoreRef:
    kind: SecretStore
    name: admin-external-secrets-operator
  target:
    creationPolicy: Owner
    name: admin-secrets
---
apiVersion: external-secrets.io/v1alpha1
kind: ExternalSecret
metadata:
  labels:
    app.kubernetes.io/component: api
    app.kubernetes.io/name: my-api
  name: my-secrets
  namespace: app-dev-test0
spec:
  data:
  - remoteRef:
      key: development-exsec-my-credential
      version: latest
    secretKey: credentials.json
  - remoteRef:
      key: development-exsec-my-session-key
      version: latest
    secretKey: session-key
  - remoteRef:
      key: development-exsec-my-api-key
      version: latest
    secretKey: api-key
  - remoteRef:
      key: development-exsec-my-bugsnag-api-key
      version: latest
    secretKey: bugsnag-api-key
  refreshInterval: 1m
  secretStoreRef:
    kind: SecretStore
    name: my-external-secrets-operator
  target:
    creationPolicy: Owner
    name: my-secrets
apiVersion: external-secrets.io/v1alpha1
kind: SecretStore
metadata:
  labels:
    app.kubernetes.io/component: admin-api
    app.kubernetes.io/name: admin-api
  name: admin-external-secrets-operator
  namespace: app-dev-test0
spec:
  provider:
    gcpsm:
      auth:
        workloadIdentity:
          clusterLocation: asia-northeast1
          clusterName: development
          serviceAccountRef:
            name: admin-external-secrets-operator
      projectID: MY_PROJECT
---
apiVersion: external-secrets.io/v1alpha1
kind: SecretStore
metadata:
  labels:
    app.kubernetes.io/component: api
    app.kubernetes.io/name: my-api
  name: my-external-secrets-operator
  namespace: app-dev-test0
spec:
  provider:
    gcpsm:
      auth:
        workloadIdentity:
          clusterLocation: asia-northeast1
          clusterName: development
          serviceAccountRef:
            name: my-external-secrets-operator
      projectID: MY_PROJECT

What we tried

I tried and checked the following, but no improvement.

  • Set concurrent=10 to ESO in dev-cluster.
  • Set .spec.refreshInterval to 5m in externalsecrets used in dev-cluster (originally 1m)
  • Check GCP Quota for Secret Manager API / IAM API (staging-cluster is running in the same PJ so this should not be a problem)

I also took the debug log but it doesn’t seem to have any useful information.

debug log(Click me)
2022-03-11T06:41:03.937506827Z {"level":"debug","ts":1646980863.9366648,"logger":"controllers.ExternalSecret","msg":"reconciled secret","ExternalSecret":"app-dev-test0/admin-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator"}
2022-03-11T06:41:03.937595199Z {"level":"debug","ts":1646980863.9367306,"logger":"events","msg":"Normal","object":{"kind":"ExternalSecret","namespace":"app-dev-test0","name":"admin-secrets","uid":"5bdb1a3b-226b-41d3-b116-eaf5e55cc0c7","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370114762"},"reason":"Updated","message":"Updated Secret"}
2022-03-11T06:41:04.059129393Z {"level":"debug","ts":1646980864.0589173,"logger":"controllers.ExternalSecret","msg":"skipping refresh","ExternalSecret":"app-dev-test0/admin-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator","rv":"1-472f358594e87ba4678b952d5f0d02af"}
2022-03-11T06:41:30.059628782Z {"level":"error","ts":1646980890.059401,"logger":"controllers.ExternalSecret","msg":"could not get provider client","ExternalSecret":"app-dev-test0/admin-iap-client-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator","error":"failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}
2022-03-11T06:41:30.060736443Z {"level":"debug","ts":1646980890.0605001,"logger":"events","msg":"Warning","object":{"kind":"ExternalSecret","namespace":"app-dev-test0","name":"admin-iap-client-secrets","uid":"500f9d9f-8d68-4e18-804b-9df866414a54","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370112794"},"reason":"InvalidProviderClientConfig","message":"failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing"}
2022-03-11T06:41:30.385601122Z {"level":"info","ts":1646980890.3854601,"logger":"controllers.ExternalSecret","msg":"reconciled secret","ExternalSecret":"app-dev-test0/admin-iap-client-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator"}
2022-03-11T06:41:30.386757849Z {"level":"debug","ts":1646980890.3862054,"logger":"events","msg":"Normal","object":{"kind":"ExternalSecret","namespace":"app-dev-test0","name":"admin-iap-client-secrets","uid":"500f9d9f-8d68-4e18-804b-9df866414a54","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370115999"},"reason":"Updated","message":"Updated Secret"}
2022-03-11T06:41:30.494851945Z {"level":"debug","ts":1646980890.4946878,"logger":"controllers.ExternalSecret","msg":"skipping refresh","ExternalSecret":"app-dev-test0/admin-iap-client-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator","rv":"2-aa72504d829be8d0dc98bffd91af7175"}
2022-03-11T06:41:30.496088871Z {"level":"error","ts":1646980890.495925,"logger":"controllers.ExternalSecret","msg":"could not close provider client","ExternalSecret":"app-dev-test0/admin-iap-client-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator","error":"unable to close SecretManager client: rpc error: code = Canceled desc = grpc: the client connection is closing (and 4 other errors)","stacktrace":"github.com/external-secrets/external-secrets/pkg/controllers/externalsecret.(*Reconciler).Reconcile\\n\\t/home/runner/work/external-secrets/external-secrets/pkg/controllers/externalsecret/externalsecret_controller.go:189\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266\\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\\n\\t/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"}
2022-03-11T06:42:00.188171213Z {"level":"debug","ts":1646980920.1880045,"logger":"controllers.ExternalSecret","msg":"skipping refresh","ExternalSecret":"app-dev-test0/admin-iap-client-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator","rv":"2-aa72504d829be8d0dc98bffd91af7175"}
2022-03-11T06:42:03.827023557Z {"level":"debug","ts":1646980923.826863,"logger":"controllers.ExternalSecret","msg":"reconciled secret","ExternalSecret":"app-dev-test0/my-secrets","SecretStore":"app-dev-test0/my-external-secrets-operator"}
2022-03-11T06:42:03.829087766Z {"level":"debug","ts":1646980923.8288572,"logger":"events","msg":"Normal","object":{"kind":"ExternalSecret","namespace":"app-dev-test0","name":"my-secrets","uid":"78d5e757-064c-4214-981b-98889d1af799","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370113132"},"reason":"Updated","message":"Updated Secret"}
2022-03-11T06:42:03.946847552Z {"level":"debug","ts":1646980923.9466808,"logger":"controllers.ExternalSecret","msg":"skipping refresh","ExternalSecret":"app-dev-test0/my-secrets","SecretStore":"app-dev-test0/my-external-secrets-operator","rv":"2-b8c4fa48ab589f778dd09a8f2b0ea8e7"}
2022-03-11T06:42:04.268476009Z {"level":"debug","ts":1646980924.2669353,"logger":"controllers.ExternalSecret","msg":"reconciled secret","ExternalSecret":"app-dev-test0/admin-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator"}
2022-03-11T06:42:04.268531595Z {"level":"debug","ts":1646980924.2683086,"logger":"events","msg":"Normal","object":{"kind":"ExternalSecret","namespace":"app-dev-test0","name":"admin-secrets","uid":"5bdb1a3b-226b-41d3-b116-eaf5e55cc0c7","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370115711"},"reason":"Updated","message":"Updated Secret"}
2022-03-11T06:42:04.380377285Z {"level":"debug","ts":1646980924.3801599,"logger":"controllers.ExternalSecret","msg":"skipping refresh","ExternalSecret":"app-dev-test0/admin-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator","rv":"1-472f358594e87ba4678b952d5f0d02af"}
2022-03-11T06:43:03.803177998Z {"level":"debug","ts":1646980983.8029563,"logger":"controllers.SecretStore","msg":"validating","secretstore":"app-dev-test0/admin-external-secrets-operator"}
2022-03-11T06:43:03.901338841Z {"level":"debug","ts":1646980983.9011183,"logger":"events","msg":"Normal","object":{"kind":"SecretStore","namespace":"app-dev-test0","name":"admin-external-secrets-operator","uid":"c1e70348-046b-441d-9a25-1e49d9e113fb","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370107419"},"reason":"Valid","message":"store validated"}
2022-03-11T06:43:04.602448342Z {"level":"debug","ts":1646980984.6022263,"logger":"controllers.ExternalSecret","msg":"reconciled secret","ExternalSecret":"app-dev-test0/admin-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator"}
2022-03-11T06:43:04.604262051Z {"level":"debug","ts":1646980984.6022446,"logger":"events","msg":"Normal","object":{"kind":"ExternalSecret","namespace":"app-dev-test0","name":"admin-secrets","uid":"5bdb1a3b-226b-41d3-b116-eaf5e55cc0c7","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370116354"},"reason":"Updated","message":"Updated Secret"}
2022-03-11T06:43:04.716556753Z {"level":"debug","ts":1646980984.7163868,"logger":"controllers.ExternalSecret","msg":"skipping refresh","ExternalSecret":"app-dev-test0/admin-secrets","SecretStore":"app-dev-test0/admin-external-secrets-operator","rv":"1-472f358594e87ba4678b952d5f0d02af"}
2022-03-11T06:43:05.331476139Z {"level":"debug","ts":1646980985.3313165,"logger":"controllers.SecretStore","msg":"validating","secretstore":"app-dev-test0/my-external-secrets-operator"}
2022-03-11T06:43:05.439749825Z {"level":"debug","ts":1646980985.4394543,"logger":"events","msg":"Normal","object":{"kind":"SecretStore","namespace":"app-dev-test0","name":"my-external-secrets-operator","uid":"cff1fcff-67f6-4e43-b629-e24c86ae2c9b","apiVersion":"external-secrets.io/v1alpha1","resourceVersion":"370086544"},"reason":"Valid","message":"store validated"}

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Reactions: 1
  • Comments: 18 (10 by maintainers)

Commits related to this issue

Most upvoted comments

Hey @lirlia ! This can be a long shot, but can you try removing the version: latest field from your manifests? It seems to me that the issue is around this call on google grpc client. If you leave it empty, the latest version will be the one fetched.

Edit: Nevermind, I just found out a better way to debug it. I think I’m moving closer to the issue.

I took a deeper look but couldn’t find any obvious issue from reading the code. My guess is that it’s specific to workload identity because the issue originates from the iamcredentials.googleapis.com grpc target. For some reason a connection pool seems to be re-used after it has been disposed. Based on your information it seems that the issue happens in ~3% of cases.

Unfortunately i don’t have a GCP Account and can’t look deeper into that issue. @gusfcarvalho did you find some time to reproduce that issue?

I’ll debug this later today, and I’ll come back with any findings. It does seem to be a weird behavior, so my first guess would be that these messages show exactly while GCP is handling rotation (making latest version unavailable). I’ll take a further look into this, and if this is confirmed, I’ll come back to you as well. Probably there are ways to avoid this scenario within the provider code.

debug log in dev cluster

2022-03-14T08:58:34.817811269Z	"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"
2022-03-14T08:58:34.818977021Z	failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing
2022-03-14T08:58:34.819469741Z	INFO: [core] Channel Connectivity change to SHUTDOWN
full grpc-go debug log(Click me)
2022-03-14T08:58:34.171820968Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.171896531Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.171910435Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.172079983Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.172102493Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.172163983Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.172210937Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.172420183Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.172579068Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.172647031Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.172663957Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.172680668Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.172688483Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.172696243Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.172704043Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.172711451Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.172724577Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.172733655Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.172741807Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.172750037Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.172757355Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.172764048Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.172770495Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.172776671Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.172782485Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.172804452Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.172837552Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.172911977Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.173025929Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.173145969Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.173268902Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.173379067Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.173523514Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.173640971Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.173759349Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.173882531Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.173985172Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.174112232Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.174225692Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.174324711Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.175325397Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.175379170Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.175874702Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.176004430Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.176175860Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc0098fa4b0, {CONNECTING <nil>}
2022-03-14T08:58:34.176304957Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.176446447Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.176559385Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.176732790Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc0098fac20, {CONNECTING <nil>}
2022-03-14T08:58:34.176848237Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.176957440Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.177069151Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.177247950Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc0098fb380, {CONNECTING <nil>}
2022-03-14T08:58:34.177361840Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.177497680Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.177625930Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.177806151Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01c367e10, {CONNECTING <nil>}
2022-03-14T08:58:34.177910810Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.178064754Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01c3676a0, {CONNECTING <nil>}
2022-03-14T08:58:34.178176869Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.224097598Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.224179580Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01c367e10, {READY <nil>}
2022-03-14T08:58:34.224243310Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.224893798Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.224982664Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01c3676a0, {READY <nil>}
2022-03-14T08:58:34.224997452Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.225033604Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.225044182Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc0098fa4b0, {READY <nil>}
2022-03-14T08:58:34.225052414Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.225575142Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.225605276Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc0098fac20, {READY <nil>}
2022-03-14T08:58:34.225646514Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.226026104Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.226194324Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc0098fb380, {READY <nil>}
2022-03-14T08:58:34.226314819Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.285252877Z	INFO: [core] original dial target is: "secretmanager.googleapis.com:443"
2022-03-14T08:58:34.285463433Z	INFO: [core] parsed dial target is: {Scheme:secretmanager.googleapis.com Authority: Endpoint:443 URL:{Scheme:secretmanager.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.285538573Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.285677274Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:secretmanager.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/secretmanager.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.285822370Z	INFO: [core] Channel authority set to "secretmanager.googleapis.com:443"
2022-03-14T08:58:34.285982667Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{secretmanager.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.286114369Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.286242860Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.286568193Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.286717170Z	INFO: [core] Subchannel picks a new address "secretmanager.googleapis.com:443" to connect
2022-03-14T08:58:34.287205090Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc00755f410, {CONNECTING <nil>}
2022-03-14T08:58:34.287662328Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.327888133Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.328782027Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc00755f410, {READY <nil>}
2022-03-14T08:58:34.329207338Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.541940426Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.542463993Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.542824143Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.543106748Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.543436085Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.543724058Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.543995630Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.544243698Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.544633595Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.544666639Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.545020299Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.545129465Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.545274131Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.545638891Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.545668448Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.545690378Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.545702112Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.546419465Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.546784089Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.546818808Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.547726992Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.547759201Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.547854932Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.547896674Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.547906479Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.547915152Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.547939582Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.547997249Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.548014042Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.548022129Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.548066022Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.548139777Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.548154301Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.548192141Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.548233915Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.548311691Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.548330854Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.548396769Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.548531151Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.548649808Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.548783060Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.548907902Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.550015047Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc007511510, {CONNECTING <nil>}
2022-03-14T08:58:34.550169928Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.550302134Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.550447118Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.550658208Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc007511c00, {CONNECTING <nil>}
2022-03-14T08:58:34.550798794Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.550949148Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.551083250Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.551268918Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8ce260, {CONNECTING <nil>}
2022-03-14T08:58:34.551420042Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.551583968Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.551738756Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.551923321Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8ce810, {CONNECTING <nil>}
2022-03-14T08:58:34.552060918Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.552208066Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.552355733Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.552535056Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8ced60, {CONNECTING <nil>}
2022-03-14T08:58:34.552681379Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.592015283Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.592275104Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8ced60, {READY <nil>}
2022-03-14T08:58:34.592405977Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.592492949Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.592606993Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc007511c00, {READY <nil>}
2022-03-14T08:58:34.592755183Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.595712950Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.595816140Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8ce260, {READY <nil>}
2022-03-14T08:58:34.595831726Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.596303699Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.596349882Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8ce810, {READY <nil>}
2022-03-14T08:58:34.596392862Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.597449183Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.597543771Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc007511510, {READY <nil>}
2022-03-14T08:58:34.597919108Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.657348626Z	INFO: [core] original dial target is: "secretmanager.googleapis.com:443"
2022-03-14T08:58:34.657432640Z	INFO: [core] parsed dial target is: {Scheme:secretmanager.googleapis.com Authority: Endpoint:443 URL:{Scheme:secretmanager.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.657479560Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.657492760Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:secretmanager.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/secretmanager.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.657696114Z	INFO: [core] Channel authority set to "secretmanager.googleapis.com:443"
2022-03-14T08:58:34.657880004Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{secretmanager.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.657995317Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.658107584Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.658574634Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.658990443Z	INFO: [core] Subchannel picks a new address "secretmanager.googleapis.com:443" to connect
2022-03-14T08:58:34.659590039Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f690710, {CONNECTING <nil>}
2022-03-14T08:58:34.659988256Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.700950497Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.701055373Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f690710, {READY <nil>}
2022-03-14T08:58:34.701123068Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.739193106Z	reconciled secret
2022-03-14T08:58:34.739276113Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.739289672Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.739464405Z	Updated
2022-03-14T08:58:34.740176095Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.740255412Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.740412282Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.740572433Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.740719902Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.740924725Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.741060821Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.741215269Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.741365831Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.741529931Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.741981437Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.742426657Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.742654988Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.742813779Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.743178979Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.743534502Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.757732129Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.757798988Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.757811791Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.757821009Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.757894445Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.758667048Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.758722572Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.758737011Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.759099522Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.759128192Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.759642618Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f6eef00, {CONNECTING <nil>}
2022-03-14T08:58:34.759836671Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.760183258Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.760493842Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.760931934Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.761125365Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.761274417Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.761603152Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.761650823Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.761676400Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.761859858Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.762203438Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.762638777Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.762838190Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.763211479Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.763390825Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.763607535Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.763880547Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.764308395Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.764859764Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f6ef590, {CONNECTING <nil>}
2022-03-14T08:58:34.764990949Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.765154721Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.765313584Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.765469070Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.765637287Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.765782562Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.765932816Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.766068822Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.766204267Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.766388467Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.766540624Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.766692900Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.766865922Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.767014473Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.767201014Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.767337064Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.767482593Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.768169130Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.768195178Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.768768350Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.768794062Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f6efe70, {CONNECTING <nil>}
2022-03-14T08:58:34.768805480Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.768814233Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.768835569Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.769379913Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017cb6400, {CONNECTING <nil>}
2022-03-14T08:58:34.769404609Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.769415019Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.769475979Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.769939366Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017cb6980, {CONNECTING <nil>}
2022-03-14T08:58:34.769980349Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.810055727Z	"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"
2022-03-14T08:58:34.810924137Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.811324607Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.811709112Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.812154355Z	UpdateFailed
2022-03-14T08:58:34.812566515Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.812946467Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f6efe70, {READY <nil>}
2022-03-14T08:58:34.813312070Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.813866666Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.814246650Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.814273680Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017cb6400, {READY <nil>}
2022-03-14T08:58:34.814394596Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.814659152Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.814821456Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017cb6980, {READY <nil>}
2022-03-14T08:58:34.814970920Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.815314234Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.815338849Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.815375575Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.815423400Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.815940844Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.815978590Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.815992609Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.816495594Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.816928412Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.817811269Z	"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:114
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:311
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:266
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2
	/home/runner/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.11.1/pkg/internal/controller/controller.go:227"
2022-03-14T08:58:34.818977021Z	failed to create GCP secretmanager client: unable to generate gcp access token: rpc error: code = Canceled desc = grpc: the client connection is closing
2022-03-14T08:58:34.819469741Z	INFO: [core] Channel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.819498807Z	INFO: [core] Subchannel Connectivity change to SHUTDOWN
2022-03-14T08:58:34.820389071Z	INFO: [transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"
2022-03-14T08:58:34.831978869Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.832063679Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.832080148Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.832117978Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.832206679Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.832362872Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.832503241Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.832653239Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.832891208Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.833056121Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.833206317Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.833378135Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.833535582Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.833721520Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.833881984Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.834045521Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.834240094Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.834409717Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.834563178Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.834765452Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.834895741Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.835047564Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.835181430Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.835306976Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.835475286Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.835640018Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.835779570Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.835936717Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.836085333Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.836294976Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.836460106Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.836627050Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.836804990Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.836954250Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.837084711Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.837219961Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.837349209Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.837499269Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.837636680Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.837787671Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.839169735Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.840683733Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.840756932Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.840808505Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.840940043Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.841326626Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.841384938Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.841584202Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f812df0, {CONNECTING <nil>}
2022-03-14T08:58:34.841743245Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.841870083Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.842054218Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.842381555Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.842408390Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.842699805Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.843349261Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.843512693Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.843747778Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017d071c0, {CONNECTING <nil>}
2022-03-14T08:58:34.843883978Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.844008985Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.844180119Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.844334197Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.844548613Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f813930, {CONNECTING <nil>}
2022-03-14T08:58:34.844682858Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.844828172Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.845001468Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.845162863Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.845343022Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.845498578Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.845685522Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.845862892Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.845990701Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.846187280Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.846358517Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.846504591Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.846671330Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.846822776Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.846969098Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.847174090Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.847324176Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.847488431Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.847649038Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.847778811Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.847921500Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.848064604Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.848214096Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.848357363Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.848480703Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.848654174Z	INFO: [core] original dial target is: "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.848799710Z	INFO: [core] parsed dial target is: {Scheme:iamcredentials.googleapis.com Authority: Endpoint:443 URL:{Scheme:iamcredentials.googleapis.com Opaque:443 User: Host: Path: RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.848937250Z	INFO: [core] fallback to scheme "passthrough"
2022-03-14T08:58:34.849083383Z	INFO: [core] parsed dial target is: {Scheme:passthrough Authority: Endpoint:iamcredentials.googleapis.com:443 URL:{Scheme:passthrough Opaque: User: Host: Path:/iamcredentials.googleapis.com:443 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}
2022-03-14T08:58:34.849246213Z	INFO: [core] Channel authority set to "iamcredentials.googleapis.com:443"
2022-03-14T08:58:34.849422459Z	INFO: [core] ccResolverWrapper: sending update to cc: {[{iamcredentials.googleapis.com:443  <nil> <nil> 0 <nil>}] <nil> <nil>}
2022-03-14T08:58:34.849556796Z	INFO: [core] ClientConn switching balancer to "pick_first"
2022-03-14T08:58:34.849695731Z	INFO: [core] Channel switches to new LB policy "pick_first"
2022-03-14T08:58:34.850871433Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.850900059Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.851101966Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01444dd00, {CONNECTING <nil>}
2022-03-14T08:58:34.851119859Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.851272044Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.851411959Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.851608297Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa24980, {CONNECTING <nil>}
2022-03-14T08:58:34.851769181Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.852156123Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.852328726Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.852570374Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa24e90, {CONNECTING <nil>}
2022-03-14T08:58:34.852782783Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.852952974Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.853101642Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.853358869Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa25390, {CONNECTING <nil>}
2022-03-14T08:58:34.853492920Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.853662454Z	INFO: [core] Subchannel Connectivity change to CONNECTING
2022-03-14T08:58:34.853802686Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.854007533Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa258d0, {CONNECTING <nil>}
2022-03-14T08:58:34.854139713Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.854271798Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8133e0, {CONNECTING <nil>}
2022-03-14T08:58:34.854402088Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.855653363Z	INFO: [core] Subchannel picks a new address "iamcredentials.googleapis.com:443" to connect
2022-03-14T08:58:34.855821769Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017d06650, {CONNECTING <nil>}
2022-03-14T08:58:34.855954205Z	INFO: [core] Channel Connectivity change to CONNECTING
2022-03-14T08:58:34.896565344Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.896645224Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa24e90, {READY <nil>}
2022-03-14T08:58:34.896665508Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.898768962Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.898806876Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017d06650, {READY <nil>}
2022-03-14T08:58:34.904377764Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.904440792Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.904460023Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa24980, {READY <nil>}
2022-03-14T08:58:34.904555306Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.904994723Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.905175687Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01444dd00, {READY <nil>}
2022-03-14T08:58:34.905295082Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.905397138Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.905538187Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa25390, {READY <nil>}
2022-03-14T08:58:34.905667742Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.905779977Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.905908907Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f813930, {READY <nil>}
2022-03-14T08:58:34.906021543Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.907230450Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.907319387Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc017d071c0, {READY <nil>}
2022-03-14T08:58:34.907335142Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.907931540Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.908015477Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f8133e0, {READY <nil>}
2022-03-14T08:58:34.908029583Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.908642656Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.908748029Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01fa258d0, {READY <nil>}
2022-03-14T08:58:34.908763747Z	INFO: [core] Channel Connectivity change to READY
2022-03-14T08:58:34.909242845Z	INFO: [core] Subchannel Connectivity change to READY
2022-03-14T08:58:34.909271877Z	INFO: [core] pickfirstBalancer: UpdateSubConnState: 0xc01f812df0, {READY <nil>}
2022-03-14T08:58:34.909287267Z	INFO: [core] Channel Connectivity change to READY