Hasura Build Failure with GCP Cloud Build and GKE

[markerdmann]

Hi, we're having a mysterious issue with our production Hasura instance. It's running on Google Kubernetes Engine with 3 replicas, and we manage deployment with GCP Cloud Build. Starting this week, the Hasura build sometimes fails, timing out after waiting 5 minutes for the container to be ready. In GKE, it usually shows that 1 or more of the Hasura pods has warnings, but the warning message just says that the container is not ready. While this is happening, all requests to Hasura are failing in production. I'm not seeing anything in the Hasura logs that would explain it.

So far the fix has been to try rebuilding once or twice in Cloud Build, and eventually a build succeeds. I can't think of anything that changed in the past week that would have triggered this. We've had about three or four incidents in the past week, and each one has caused about 5-20 minutes of downtime in production.

One interesting clue is that the Active Connections to our postgres db spike up to 100 when these outages occur. Normal deployments show no impact on Active Connections. There's a 1:1 correlation between these spikes and the outages.

[shahidhk]

Hi @markerdmann, it looks like when the new build is rolled out, multiple replicas are updated at the same time and all are trying to apply migrations together. This could result in Postgres issues.

If you use the following update strategy for the k8s deployment, only 1 container will be updated at a time:

replicas: 3  
strategy:
    type: RollingUpdate
    rollingUpdate:
      maxSurge: 1
      maxUnavailable: 0

This will do the following update:

Let me know if this strategy helps.

[markerdmann]

Hi @shahidhk,

Thanks for the tip! I made the suggested change to our Kubernetes config, but unfortunately still experienced the same downtime on the second or third deployment after we made this change.

There's another interesting clue in the logs. Normally, during Hasura startup, I see the following sequence of log messages:

1. "Applying migrations"
2. "nothing to apply" or applied
3. "Applying metadata"
4. "Metadata applied"

So if I search for `("Applying migrations" OR "Metadata applied") in the logs, I usually always see the pair, and that tells me how long it took for the complete sequence to finish. Normally it takes about 4-5 seconds.

In the case of the build that caused today's downtime, I'm not seeing the "Metadata applied" message. It seems as though the Hasura instance never completes the sequence, but so far I'm not seeing an obvious failure or error message in the logs.

In the screenshot below, you can see the problematic build at the 1:08:58 timestamp.

[markerdmann]

Perhaps even more useful, here's the outage from the point of view of our slow query log in Postgres. The slow queries go from 1s to 50s to 900s. 01:25:01 is the time when the site came back up. It looks like the queries are getting backed up while Hasura is applying metadata, and for some reason it's stalling on that step for 15 minutes.

These recently reported issues look similar: #5997 #6052

[tirumaraiselvan]

We are investigating this, might be better to move this to Issues but can't see an automatic way to do that. Anyway, is it possible to see locks acquired when you are experience this issue:

SELECT
    activity.pid,
    activity.usename,
    activity.query,
    blocking.pid AS blocking_id,
    blocking.query AS blocking_query
FROM pg_stat_activity AS activity
JOIN pg_stat_activity AS blocking ON blocking.pid = ANY(pg_blocking_pids(activity.pid));

[tirumaraiselvan]

Also, how big would you say your hasura metadata is? How long does it take to get applied on a dev instance (i.e. no connected clients).

[markerdmann]

Answered the questions above in #6052