scylla-operator icon indicating copy to clipboard operation
scylla-operator copied to clipboard

[Flake] ScyllaCluster [It] should support scaling

Open tnozicka opened this issue 1 year ago • 1 comments

Link to the job that flaked.

https://prow.scylla-operator.scylladb.com/view/gs/scylla-operator-prow/pr-logs/pull/scylladb_scylla-operator/1758/pull-scylla-operator-master-e2e-gke-parallel/1762798835807031296#1:test-build-log.txt%3A1485

Snippet of what failed.

 • [FAILED] [660.567 seconds]
ScyllaCluster [It] should support scaling
github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllacluster_scaling.go:26
  Timeline >>
  STEP: Creating a new namespace @ 02/28/24 11:38:43.035
  Feb 28 11:38:43.150: INFO: Created namespace "e2e-test-scyllacluster-hzhsb-jzntd".
  STEP: Waiting for service account token Secret "e2e-user-token" in namespace "e2e-test-scyllacluster-hzhsb-jzntd". @ 02/28/24 11:38:43.403
  STEP: Waiting for default ServiceAccount in namespace "e2e-test-scyllacluster-hzhsb-jzntd". @ 02/28/24 11:38:43.714
  STEP: Waiting for kube-root-ca.crt in namespace "e2e-test-scyllacluster-hzhsb-jzntd". @ 02/28/24 11:38:43.94
  STEP: Creating a ScyllaCluster with 1 member @ 02/28/24 11:38:44.116
  STEP: Waiting for the ScyllaCluster to rollout (RV=8353) @ 02/28/24 11:38:44.356
  Feb 28 11:42:28.729: INFO: ScyllaCluster e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl (RV=13321) is rolled out
  STEP: Verifying the ScyllaCluster @ 02/28/24 11:42:28.73
  Feb 28 11:42:28.884: INFO: Found 1 pvc(s) in namespace "e2e-test-scyllacluster-hzhsb-jzntd"
  Feb 28 11:42:28.884: INFO: Found 1 pvc(s) for ScyllaCluster "e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl"
  STEP: Waiting for the ScyllaCluster(s) to reach consistency ALL @ 02/28/24 11:42:29.013
  Feb 28 11:42:29.170: INFO: ScyllaDB nodes have reached status consistency.
  STEP: Inserting data @ 02/28/24 11:42:29.244
  Feb 28 11:42:29.244: INFO: Creating CQL session (hosts="10.120.1.39")
  STEP: Inserting data @ 02/28/24 11:42:29.246
  Feb 28 11:42:29.246: INFO: Creating keyspace "hp7jmvtx" with RF "'replication_factor': 1"
  Feb 28 11:42:29.254: INFO: Creating table "hp7jmvtx"."test"
  Feb 28 11:42:29.331: INFO: Inserting data into table "hp7jmvtx"."test"
  Feb 28 11:42:29.345: INFO: Awaiting schema agreement
  Feb 28 11:42:29.345: INFO: Schema agreement reached
  STEP: Verifying the data @ 02/28/24 11:42:29.345
  Feb 28 11:42:29.345: INFO: Reading data from table "hp7jmvtx"."test"
  STEP: Scaling the ScyllaCluster to 3 replicas @ 02/28/24 11:42:29.348
  STEP: Waiting for the ScyllaCluster to rollout (RV=13356) @ 02/28/24 11:42:29.395
  Feb 28 11:46:29.249: INFO: ScyllaCluster e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl (RV=19322) is rolled out
  STEP: Verifying the ScyllaCluster @ 02/28/24 11:46:29.25
  Feb 28 11:46:29.288: INFO: Found 3 pvc(s) in namespace "e2e-test-scyllacluster-hzhsb-jzntd"
  Feb 28 11:46:29.288: INFO: Found 3 pvc(s) for ScyllaCluster "e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl"
  STEP: Waiting for the ScyllaCluster(s) to reach consistency ALL @ 02/28/24 11:46:29.407
  Feb 28 11:46:29.563: INFO: ScyllaDB nodes have reached status consistency.
  Feb 28 11:46:29.667: INFO: Awaiting schema agreement
  Feb 28 11:46:29.668: INFO: Schema agreement reached
  STEP: Verifying the data @ 02/28/24 11:46:29.668
  Feb 28 11:46:29.668: INFO: Reading data from table "hp7jmvtx"."test"
  STEP: Inserting data @ 02/28/24 11:46:29.676
  Feb 28 11:46:29.676: INFO: Creating CQL session (hosts="10.120.1.39, 10.120.1.72")
  STEP: Inserting data @ 02/28/24 11:46:29.685
  Feb 28 11:46:29.685: INFO: Creating keyspace "6hq4pgbx" with RF "'replication_factor': 2"
  Feb 28 11:46:30.158: INFO: Creating table "6hq4pgbx"."test"
  Feb 28 11:46:31.190: INFO: Inserting data into table "6hq4pgbx"."test"
  Feb 28 11:46:31.209: INFO: Awaiting schema agreement
  Feb 28 11:46:31.209: INFO: Schema agreement reached
  STEP: Verifying the data @ 02/28/24 11:46:31.209
  Feb 28 11:46:31.209: INFO: Reading data from table "6hq4pgbx"."test"
  STEP: Inserting data @ 02/28/24 11:46:31.218
  Feb 28 11:46:31.218: INFO: Creating CQL session (hosts="10.120.1.39, 10.120.1.72, 10.120.1.90")
  STEP: Inserting data @ 02/28/24 11:46:31.221
  Feb 28 11:46:31.221: INFO: Creating keyspace "dwh97zfc" with RF "'replication_factor': 3"
  Feb 28 11:46:32.286: INFO: Creating table "dwh97zfc"."test"
  Feb 28 11:46:32.965: INFO: Inserting data into table "dwh97zfc"."test"
  Feb 28 11:46:32.987: INFO: Awaiting schema agreement
  Feb 28 11:46:32.987: INFO: Schema agreement reached
  STEP: Verifying the data @ 02/28/24 11:46:32.987
  Feb 28 11:46:32.987: INFO: Reading data from table "dwh97zfc"."test"
  STEP: Scaling the ScyllaCluster down to 2 replicas @ 02/28/24 11:46:32.993
  STEP: Waiting for the ScyllaCluster to rollout (RV=19424) @ 02/28/24 11:46:33.053
  Feb 28 11:48:19.929: INFO: ScyllaCluster e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl (RV=21975) is rolled out
  STEP: Verifying the ScyllaCluster @ 02/28/24 11:48:19.929
  Feb 28 11:48:19.970: INFO: Found 2 pvc(s) in namespace "e2e-test-scyllacluster-hzhsb-jzntd"
  Feb 28 11:48:19.970: INFO: Found 2 pvc(s) for ScyllaCluster "e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl"
  STEP: Waiting for the ScyllaCluster(s) to reach consistency ALL @ 02/28/24 11:48:20.069
  Feb 28 11:48:20.188: INFO: ScyllaDB nodes have reached status consistency.
  Feb 28 11:48:20.245: INFO: Awaiting schema agreement
  Feb 28 11:48:20.245: INFO: Schema agreement reached
  STEP: Verifying the data @ 02/28/24 11:48:20.245
  Feb 28 11:48:20.245: INFO: Reading data from table "hp7jmvtx"."test"
  Feb 28 11:48:20.251: INFO: Creating CQL session (hosts="10.120.1.39, 10.120.1.72")
  Feb 28 11:48:20.253: INFO: Awaiting schema agreement
  Feb 28 11:48:20.254: INFO: Schema agreement reached
  STEP: Verifying the data @ 02/28/24 11:48:20.254
  Feb 28 11:48:20.254: INFO: Reading data from table "6hq4pgbx"."test"
  STEP: Marking ScyllaCluster node #2 (basic-pn2sl-us-east-1-us-east-1a-1) for maintenance @ 02/28/24 11:48:20.259
  STEP: Manually draining ScyllaCluster node #2 (basic-pn2sl-us-east-1-us-east-1a-1) @ 02/28/24 11:48:20.282
  Feb 28 11:48:20.622: INFO: Waiting for the ephemeral container "e2e-drain-scylla" in Pod "e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-1" to be created
  Feb 28 11:48:20.688: INFO: Waiting for the ephemeral container "e2e-drain-scylla" in Pod "e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-1" to start
  Feb 28 11:48:21.365: INFO: Waiting for the ephemeral container "e2e-drain-scylla" in Pod "e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-1" to start
  Feb 28 11:48:21.668: INFO: Waiting for the ephemeral container "e2e-drain-scylla" in Pod "e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-1" to finish
  [FAILED] in [It] - github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllacluster_scaling.go:169 @ 02/28/24 11:48:22.752
  STEP: Collecting events from namespace "e2e-test-scyllacluster-hzhsb-jzntd". @ 02/28/24 11:48:22.752
  STEP: Found 117 events. @ 02/28/24 11:48:22.827
  Feb 28 11:48:22.827: INFO: At 2024-02-28 11:38:46 +0000 UTC - event for basic-pn2sl-member: {scyllacluster-controller } RoleBindingCreated: RoleBinding e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-member created
  Feb 28 11:48:22.827: INFO: At 2024-02-28 11:38:46 +0000 UTC - event for basic-pn2sl-member: {scyllacluster-controller } ServiceAccountCreated: ServiceAccount e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-member created
  Feb 28 11:48:22.827: INFO: At 2024-02-28 11:38:47 +0000 UTC - event for basic-pn2sl-auth-token: {scyllacluster-controller } SecretCreated: Secret e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-auth-token created
  Feb 28 11:48:22.827: INFO: At 2024-02-28 11:41:21 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-0: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Pulled: Container image "docker.io/scylladb/scylla-manager-agent:3.2.5" already present on machine
  Feb 28 11:48:22.827: INFO: At 2024-02-28 11:41:21 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-0: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Started: Started container scylla
  Feb 28 11:48:22.827: INFO: At 2024-02-28 11:41:21 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-0: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Created: Created container scylla
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:41:22 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-0: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Started: Started container scylla-manager-agent
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:41:22 +0000 UTC - event for nodeconfig-podinfo-bc8d476a-4c0b-46b8-b5ba-d79cba65e61a: {NodeConfigCM-controller } ConfigMapUpdated: ConfigMap e2e-test-scyllacluster-hzhsb-jzntd/nodeconfig-podinfo-bc8d476a-4c0b-46b8-b5ba-d79cba65e61a updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:41:26 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-0: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Unhealthy: Startup probe failed: HTTP probe failed with statuscode: 503
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:41:38 +0000 UTC - event for basic-pn2sl-local-serving-certs: {scyllacluster-controller } SecretUpdated: Secret e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-local-serving-certs updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:41:39 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-0: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Unhealthy: Readiness probe failed: HTTP probe failed with statuscode: 503
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:41:58 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-0: {scyllacluster-controller } ServiceUpdated: Service e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-0 updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:29 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a: {statefulset-controller } SuccessfulCreate: create Claim data-basic-pn2sl-us-east-1-us-east-1a-1 Pod basic-pn2sl-us-east-1-us-east-1a-1 in StatefulSet basic-pn2sl-us-east-1-us-east-1a success
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:29 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a: {statefulset-controller } SuccessfulCreate: create Pod basic-pn2sl-us-east-1-us-east-1a-1 in StatefulSet basic-pn2sl-us-east-1-us-east-1a successful
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:29 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-1: {scyllacluster-controller } ServiceCreated: Service e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-1 created
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:29 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-2: {scyllacluster-controller } ServiceCreated: Service e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-2 created
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:44 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-1: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Started: Started container scylla
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:44 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-1: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Created: Created container scylla
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:44 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-1: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Pulled: Container image "docker.io/scylladb/scylla:5.4.0" already present on machine
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:45 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-1: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Started: Started container scylla-manager-agent
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:45 +0000 UTC - event for nodeconfig-podinfo-bbf24a07-e1d2-49b0-bc5d-2d38cea0ece3: {NodeConfigCM-controller } ConfigMapUpdated: ConfigMap e2e-test-scyllacluster-hzhsb-jzntd/nodeconfig-podinfo-bbf24a07-e1d2-49b0-bc5d-2d38cea0ece3 updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:42:51 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-1: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Unhealthy: Readiness probe failed: HTTP probe failed with statuscode: 503
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:43:57 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-1: {scyllacluster-controller } ServiceUpdated: Service e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-1 updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:19 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a: {statefulset-controller } SuccessfulCreate: create Claim data-basic-pn2sl-us-east-1-us-east-1a-2 Pod basic-pn2sl-us-east-1-us-east-1a-2 in StatefulSet basic-pn2sl-us-east-1-us-east-1a success
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:19 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a: {statefulset-controller } SuccessfulCreate: create Pod basic-pn2sl-us-east-1-us-east-1a-2 in StatefulSet basic-pn2sl-us-east-1-us-east-1a successful
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:19 +0000 UTC - event for data-basic-pn2sl-us-east-1-us-east-1a-2: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:20 +0000 UTC - event for data-basic-pn2sl-us-east-1-us-east-1a-2: {local.csi.scylladb.com_local-csi-driver-wcnms_44a22cfd-fc62-4b94-9f95-33827e144ccf } ProvisioningSucceeded: Successfully provisioned volume pvc-6bcb79cb-e94c-4c9e-80c2-cadb98ffcb31
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:31 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-2: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Pulled: Container image "docker.io/scylladb/scylla-manager-agent:3.2.5" already present on machine
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:31 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-2: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Started: Started container scylla-manager-agent
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:31 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-2: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Created: Created container scylla
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:31 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-2: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Started: Started container scylla
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:32 +0000 UTC - event for nodeconfig-podinfo-c0611bb6-88a6-4acf-b059-e3c62c764fd2: {NodeConfigCM-controller } ConfigMapUpdated: ConfigMap e2e-test-scyllacluster-hzhsb-jzntd/nodeconfig-podinfo-c0611bb6-88a6-4acf-b059-e3c62c764fd2 updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:44:42 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-2: {kubelet gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh} Unhealthy: Readiness probe failed: HTTP probe failed with statuscode: 503
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:45:43 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a-2: {scyllacluster-controller } ServiceUpdated: Service e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a-2 updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:46:13 +0000 UTC - event for basic-pn2sl-us-east-1-us-east-1a: {scyllacluster-controller } StatefulSetUpdated: StatefulSet e2e-test-scyllacluster-hzhsb-jzntd/basic-pn2sl-us-east-1-us-east-1a updated
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:46:23 +0000 UTC - event for cleanup-basic-pn2sl-us-east-1-us-east-1a-0: {job-controller } SuccessfulCreate: Created pod: cleanup-basic-pn2sl-us-east-1-us-east-1a-0-6wprr
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:46:23 +0000 UTC - event for cleanup-basic-pn2sl-us-east-1-us-east-1a-0: {scyllacluster-controller } JobCreated: Job e2e-test-scyllacluster-hzhsb-jzntd/cleanup-basic-pn2sl-us-east-1-us-east-1a-0 created
  Feb 28 11:48:22.828: INFO: At 2024-02-28 11:46:23 +0000 UTC - event for cleanup-basic-pn2sl-us-east-1-us-east-1a-0-6wprr: {default-scheduler } Scheduled: Successfully assigned e2e-test-scyllacluster-hzhsb-jzntd/cleanup-basic-pn2sl-us-east-1-us-east-1a-0-6wprr to gke-so-7e595d64-6162-4dd1-aa2-workers-c9067a81-knnh
  STEP: Collecting dumps from namespace "e2e-test-scyllacluster-hzhsb-jzntd". @ 02/28/24 11:48:22.828
  STEP: Destroying namespace "e2e-test-scyllacluster-hzhsb-jzntd". @ 02/28/24 11:48:24.128
  STEP: Waiting for namespace "e2e-test-scyllacluster-hzhsb-jzntd" to be removed. @ 02/28/24 11:48:24.154
  << Timeline
  [FAILED] Expected
      <int32>: 1
  to be equivalent to
      <int>: 0
  In [It] at: github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllacluster_scaling.go:169 @ 02/28/24 11:48:22.752
  Full Stack Trace
    github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster.glob..func12.1()
    	github.com/scylladb/scylla-operator/test/e2e/set/scyllacluster/scyllacluster_scaling.go:169 +0x23e8 

tnozicka avatar Feb 28 '24 12:02 tnozicka