AppEngine nodejs app sporadically sends 502s and restarts

user_13769946 0
Viewed 339

We have a nodejs app that gets successfully deployed to a standard environment. Something happens after about two hours (or sooner depending on traffic): our downstream clients start receiving a bunch of 502 responses and then the service stabilizes. We think this has been happening for at least a few months.

When investigating the cause of the 502s, I see that:

  • There are no unhandled exception/promise rejection logs to indicate that the node app has crashed
  • I console.log when receiving SIGTERM and that, too, does not appear in the logs
  • The logs of the nginx sidecar include the following:
2020/06/16 23:11:11 [error] 35#35: *1149 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 169.254.1.1, server: _, request: "POST /api/redacted HTTP/1.1", upstream: "http://127.0.0.1:8081/api/redacted", host: "redacted.appspot.com""

I'm assuming that the 502s are coming from nginx because the upstream has disappeared. Are there other explanations I should explore?

If GAE is replacing my app containers intentionally, shouldn't that process prevent these types of 502s?

Should I expect something other than SIGTERM to be sent by the environment when the application/container is getting replaced?

Update #1 (2020-06-22)

I investigated and found evidence that we might be exceeding memory quota so I changed our instance_class from F1 to F2. As I write this our instances are sitting at ~200M of memory usage (F2s have 512M available). Additionally, I use the --max-old-space-size switch to set nodes memory usage to 496M.

The 502s are still happening.

I suspect that the 502s are happening as a result of the autoscaler terminating instances. Our app never receives SIGTERM (even during deployments). That means I can't close http keepalive connections gracefully and might explain why nginx raises Connection reset by peer.

Update #2 (2020-06-24)

Our service is just standard REST type stuff, no heavy loops.

I'll post another update with some memory graphs but I don't see any spikes. Perhaps a small memory leak.

Here's our app.yaml:

service: redacted
runtime: nodejs12
instance_class: F2
handlers:
  - url: /.*
    secure: always
    redirect_http_response_code: 301
    script: auto
node.js google-app-engine nginx
2 Answers

We had a very similar problem with our Node.js app deployed on App Engine Flexible.

In our case, we ultimately determined that we had memory pressure that was causing the Node.js garbage collector to sometimes delay the processing of a request for hundreds of milliseconds (sometimes more). This caused our health check URLs to sporadically timeout, prompting GAE to remove the instance from the active pool.

Because we typically had just two instances handling the steady traffic, removing one instance quickly overloaded the remaining instance, and it would soon suffer the same fate.

We were surprised to find that it could take two minutes or longer before App Engine assigned traffic to a newly-created instance. Between the time our original instances were declared unhealthy, and when new instance(s) were online, 502s would be returned (presumably by GAE's nginx) to the client.

We were able to stabilize the environment simply by adding:

automatic_scaling:
   min_num_instances: 4

To our app.yaml. Because two instances were generally sufficient for the traffic, ensuring we always had four running apparently kept our memory usage low enough to prevent the GC from stalling request handling, and even if it did, we had enough excess capacity to handle one instance being removed.

The scaling settings for GAE standard are slightly different.

In retrospect, we could see that our latency/response times would get a little "jittery" before the real problems started. Most responses had typical response times ~30ms, but increasingly we would see outlier requests in the x00ms range. You may want to check your request logs to see if you see something similar.

New Relic's Node.js VM data was helpful in detecting that garbage collection was taking an increasing amount of time.

user_9254780

Usually, 502 messages are errors on nginx side, as you have mentioned. The detailed logs related to this errors are not surfaced to Cloud Logging, yet.

According to your behavior, it seems a workload, so we can relate this case to an issue with running out of resources.

There are somethings that are well worth to take a look:

  • Check your metrics. The memory and CPU usage should be under healthy limits.
  • Check whether your scaling metrics are being enough to your workload.

Is there a chance to share these metrics near to the restart event? Also, i t would be goo if you share your resources and scaling in the app.yaml.

user_43759990
Related