Flake: Scylla Manager integration [It] should discover cluster and sync tasks

[tnozicka]

https://github.com/scylladb/scylla-operator/actions/runs/3067025626/jobs/4954445399#step:12:441 https://github.com/scylladb/scylla-operator/suites/8323775595/artifacts/365955898

• [FAILED] [462.877 seconds]
Scylla Manager integration
github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllamanager.go:18
  [It] should discover cluster and sync tasks
  github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllamanager.go:23

  Begin Captured StdOut/StdErr Output >>
    I0916 12:29:55.912346     159 framework/framework.go:249] "Namespace removed." Namespace="e2e-test-scyllacluster-7t8gg-mxsmm"
  << End Captured StdOut/StdErr Output

  Begin Captured GinkgoWriter Output >>
    [BeforeEach] Scylla Manager integration
      github.com/scylladb/scylla-operator/test/e2e/framework/framework.go:57
    STEP: Creating a new namespace 09/16/22 12:22:13.035
    Sep 16 12:22:13.121: INFO: Created namespace "e2e-test-scyllacluster-7t8gg-mxsmm".
    STEP: Waiting for ServiceAccount "e2e-user" in namespace "e2e-test-scyllacluster-7t8gg-mxsmm". 09/16/22 12:22:13.216
    STEP: Waiting for default ServiceAccount in namespace "e2e-test-scyllacluster-7t8gg-mxsmm". 09/16/22 12:22:15.18
    [It] should discover cluster and sync tasks
      github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllamanager.go:23
    STEP: Creating a ScyllaCluster 09/16/22 12:22:15.184
    STEP: Waiting for the ScyllaCluster to deploy 09/16/22 12:22:15.199
    Sep 16 12:24:25.070: INFO: ScyllaCluster e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8 (RV=3430) is rolled out
    STEP: Inserting data with RF=1 09/16/22 12:24:30.151
    STEP: Verifying the ScyllaCluster 09/16/22 12:24:30.729
    Sep 16 12:24:30.751: INFO: Found 1 pvc(s) in namespace "e2e-test-scyllacluster-7t8gg-mxsmm"
    Sep 16 12:24:30.751: INFO: Found 1 pvc(s) for ScyllaCluster "e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8"
    STEP: Reading data with RF=1 09/16/22 12:24:30.807
    STEP: Verifying data consistency 09/16/22 12:24:30.812
    STEP: Waiting for the cluster sync with Scylla Manager 09/16/22 12:24:30.812
    [AfterEach] Scylla Manager integration
      github.com/scylladb/scylla-operator/test/e2e/framework/framework.go:58
    STEP: Collecting events from namespace "e2e-test-scyllacluster-7t8gg-mxsmm". 09/16/22 12:28:30.817
    STEP: Found 30 events. 09/16/22 12:28:30.852
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:41 +0000 UTC - event for basic-sxvd8-auth-token: {scyllacluster-controller } SecretCreated: Secret e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8-auth-token created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:41 +0000 UTC - event for basic-sxvd8-member: {scyllacluster-controller } ServiceAccountCreated: ServiceAccount e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8-member created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:41 +0000 UTC - event for basic-sxvd8-member: {scyllacluster-controller } RoleBindingCreated: RoleBinding e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8-member created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:41 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a: {scyllacluster-controller } StatefulSetCreated: StatefulSet e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8-us-east-1-us-east-1a created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:42 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a: {statefulset-controller } SuccessfulCreate: create Claim data-basic-sxvd8-us-east-1-us-east-1a-0 Pod basic-sxvd8-us-east-1-us-east-1a-0 in StatefulSet basic-sxvd8-us-east-1-us-east-1a success
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:42 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a: {statefulset-controller } SuccessfulCreate: create Pod basic-sxvd8-us-east-1-us-east-1a-0 in StatefulSet basic-sxvd8-us-east-1-us-east-1a successful
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:42 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {default-scheduler } FailedScheduling: 0/1 nodes are available: 1 pod has unbound immediate PersistentVolumeClaims.
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:42 +0000 UTC - event for data-basic-sxvd8-us-east-1-us-east-1a-0: {k8s.io/minikube-hostpath_fv-az136-60_065a1f85-feac-4ea1-b55a-0bda0d957ed6 } ProvisioningSucceeded: Successfully provisioned volume pvc-0e5f40ca-[443](https://github.com/scylladb/scylla-operator/actions/runs/3067025626/jobs/4954445399#step:12:444)e-49ed-bc13-c26[451](https://github.com/scylladb/scylla-operator/actions/runs/3067025626/jobs/4954445399#step:12:452)46d07a
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:42 +0000 UTC - event for data-basic-sxvd8-us-east-1-us-east-1a-0: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "k8s.io/minikube-hostpath" or manually created by system administrator
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:42 +0000 UTC - event for data-basic-sxvd8-us-east-1-us-east-1a-0: {k8s.io/minikube-hostpath_fv-az136-60_065a1f85-feac-4ea1-b55a-0bda0d957ed6 } Provisioning: External provisioner is provisioning volume for claim "e2e-test-scyllacluster-7t8gg-mxsmm/data-basic-sxvd8-us-east-1-us-east-1a-0"
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:43 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {default-scheduler } Scheduled: Successfully assigned e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8-us-east-1-us-east-1a-0 to fv-az136-60
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:52 +0000 UTC - event for basic-sxvd8: {scyllacluster-controller } PodDisruptionBudgetCreated: PodDisruptionBudget e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8 created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:52 +0000 UTC - event for basic-sxvd8-client: {scyllacluster-controller } ServiceCreated: Service e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8-client created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:52 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {scyllacluster-controller } ServiceCreated: Service e2e-test-scyllacluster-7t8gg-mxsmm/basic-sxvd8-us-east-1-us-east-1a-0 created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:58 +0000 UTC - event for nodeconfig-podinfo-70cb9e73-afd9-44ec-bbbf-cc8e41fdb038: {NodeConfigCM-controller } ConfigMapCreated: ConfigMap e2e-test-scyllacluster-7t8gg-mxsmm/nodeconfig-podinfo-70cb9e73-afd9-44ec-bbbf-cc8e41fdb038 created
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:22:59 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} FailedMount: MountVolume.SetUp failed for volume "scylla-client-config-volume" : failed to sync secret cache: timed out waiting for the condition
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:00 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} FailedMount: MountVolume.SetUp failed for volume "kube-api-access-bm7g6" : failed to sync configmap cache: timed out waiting for the condition
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:03 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Started: Started container sidecar-injection
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:03 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Pulled: Container image "docker.io/scylladb/scylla-operator:ci" already present on machine
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:03 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Created: Created container sidecar-injection
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:13 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Started: Started container scylla
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:13 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Pulled: Container image "docker.io/scylladb/scylla-manager-agent:2.6.3" already present on machine
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:13 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Created: Created container scylla-manager-agent
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:13 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Created: Created container scylla
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:13 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Pulled: Container image "docker.io/scylladb/scylla:4.6.3" already present on machine
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:14 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Started: Started container scylla-manager-agent
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:18 +0000 UTC - event for nodeconfig-podinfo-70cb9e73-afd9-44ec-bbbf-cc8e41fdb038: {NodeConfigCM-controller } ConfigMapUpdated: ConfigMap e2e-test-scyllacluster-7t8gg-mxsmm/nodeconfig-podinfo-70cb9e73-afd9-44ec-bbbf-cc8e41fdb038 updated
    Sep 16 12:28:30.853: INFO: At 2022-09-16 12:23:23 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Unhealthy: Startup probe failed: HTTP probe failed with statuscode: 503
    Sep 16 12:28:30.854: INFO: At 2022-09-16 12:23:33 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Unhealthy: Readiness probe failed: HTTP probe failed with statuscode: 500
    Sep 16 12:28:30.854: INFO: At 2022-09-16 12:23:43 +0000 UTC - event for basic-sxvd8-us-east-1-us-east-1a-0: {kubelet fv-az136-60} Unhealthy: Readiness probe failed: HTTP probe failed with statuscode: 503
    STEP: Collecting dumps from namespace "e2e-test-scyllacluster-7t8gg-mxsmm". 09/16/22 12:28:30.854
    STEP: Destroying namespace "e2e-test-scyllacluster-7t8gg-mxsmm". 09/16/22 12:28:31.094
    STEP: Waiting for namespace "e2e-test-scyllacluster-7t8gg-mxsmm" to be removed. 09/16/22 12:28:31.106
  << End Captured GinkgoWriter Output

  Unexpected error:
      <*errors.errorString | 0xc0002530b0>: {
          s: "timed out waiting for the condition",
      }
      timed out waiting for the condition
  occurred
  In [It] at: github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllamanager.go:96

  Full Stack Trace
    github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster.glob..func15.1()
    	github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllamanager.go:96 +0x813

[tnozicka]

flaking a lot, last one in https://github.com/scylladb/scylla-operator/actions/runs/3086220438/jobs/4990391763#step:12:559 https://github.com/scylladb/scylla-operator/suites/8367743162/artifacts/369018669

[tnozicka]

I saw this flake quite often today, one of them was https://github.com/scylladb/scylla-operator/actions/runs/3204391810/jobs/5235672421#step:3:1650

[Choraden]

It looks like https://github.com/scylladb/scylla-operator/commit/d516b107bfe7a7b6395ef7a7fcd0f535bab8f2a6 has no effect. The log level in artifacts for manager controller is 2!

[Choraden]

Please let me know if you encounter any flake, now that #1062 is merged

[tnozicka]

https://github.com/scylladb/scylla-operator/actions/runs/3220293020/jobs/5266866588#step:3:1595