Preview environment takes too long to start, causing workspace integration tests to fail

[kylos101]

Bug description

Sometimes the preview envrionment takes too long to start, causing the initial workspace integration test job to fail.

Steps to reproduce

Refer to this internal conversation for context.

Workspace affected

No response

Expected behavior

Ideally we'd wait longer for the environment to start, allowing for the tests to run, or the environment would start up quicker.

Example repository

No response

Anything else?

No response

[mads-hartmann]

Some quick thoughts

1. We should update your job to be resilient to errors from Werft. From a quick glance it looks like it's just failing if we get at 503 when polling the state of the jobs. In that case we can just ignore the error and poll again ☺️ -> This is taken care of here tests: Stabilization of port-foward errors #12611
2. We should have better insights the Werft API - currently we have no monitoring for that AFAIK

[mads-hartmann]

And a quick clarification: The integration tests don't fail because the preview environments start too slowly, it's because we get an error when querying for the state of the Werft job for the preview environments. At least from looking at the logs from the job https://werft.gitpod-dev.com/job/gitpod-custom-to-stablization-test.19 mentioned in the thread ☺️

[build preview environment] Waiting for gitpod-build-wk-inte-test-20220901164435.0 to finish running. Current phase: PHASE_RUNNING. Sleeping 10 seconds.
Error: rpc error: code = Unavailable desc = Service Unavailable: HTTP status code 503; transport: received the unexpected content-type "text/html"
[slack notification and cleanup EXIT|PHASE] Slack notification and cleanup: EXIT
[slack notification] Sending Slack notificaition
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   507    0     2  100   505     10   2729 --:--:-- --:--:-- --:--:--  2740

[mads-hartmann]

It looks like Werft is restarting quite often:

 kubectl -n werft get pods werft-0
W0906 12:52:20.714506  119023 gcp.go:120] WARNING: the gcp auth plugin is deprecated in v1.22+, unavailable in v1.25+; use gcloud instead.
To learn more, consult https://cloud.google.com/blog/products/containers-kubernetes/kubectl-auth-changes-in-gke
NAME      READY   STATUS    RESTARTS   AGE
werft-0   1/1     Running   52         7d3h

Looking at the logs:

resource.type="k8s_pod"
resource.labels.cluster_name="core-dev"
resource.labels.location="europe-west1-b"
resource.labels.pod_name="werft-0"

We see quite a few readiness and liveness probes failing (source)

[kylos101]

Nice detective work, @mads-hartmann ! 🚀 Do we limit the CPU or memory for werft pods? In other words, is it possible they might need more resources?

[mads-hartmann]

Looking at the logs from the pod before it restarted using the following command

kubectl -n werft logs --previous --tail 10 werft-0

It looks like it might be the github-integration plugin which is getting data it doesn't know how to parse, and then decides to exit 1

time="2022-09-07T13:38:27Z" level=info msg="level=fatal msg=\"rpc error: code = Internal desc = grpc: failed to unmarshal the received message proto: cannot parse invalid wire-format data\"" plugin=github-integration-integration
time="2022-09-07T13:38:27Z" level=fatal msg="plugin error" error="exit status 1" plugin=github-integration

[mads-hartmann]

Looking at the last 30 days this has happened 120 times, so it isn't a regression in the latest version of Werft which was deployed 8 days ago.

Source

[mads-hartmann]

Quick update: There's a workaround in place so that Werft won't restart. Once a new Werft release has been cut I'll bump the version and see if the restarts stop. The reason why protobuf deserialization is sometimes failing is not clear, so even with the latest version we might still see some events being dropped (e.g. Werft not running a build when you push - but that's still the case today and at least with the workaround Werft wouldn't restart and return 503 to other users ☺️)