Node fastify from Docker image produces 502 without anything in the logs

Questions / Help
1

Everything works fine in dev and when running the Docker image locally.

My fly.toml file looks like this

kill_signal = "SIGINT"
kill_timeout = 5
processes = []

[env]

[experimental]
  allowed_public_ports = []
  auto_rollback = true

[[services]]
  http_checks = []
  internal_port = 8080
  processes = ["app"]
  protocol = "tcp"
  script_checks = []
  [services.concurrency]
    hard_limit = 25
    soft_limit = 20
    type = "connections"

  [[services.ports]]
    force_https = true
    handlers = ["http"]
    port = 80

  [[services.ports]]
    handlers = ["tls", "http"]
    port = 443

  [[services.tcp_checks]]
    grace_period = "1s"
    interval = "15s"
    restart_limit = 0
    timeout = "2s"

Are there any ways to see more logs than I can see with fly logs or in the monitoring tab?

I even added console logs in the method that fails, and it works all the way until it returns

        console.log("trying to redirect");
        return reply.redirect(finalRedirectUri);

So it looks like the server just crashes without any error in the logs.

2

Hi,

Strange :thinking:. The fly.toml looks ok to me. So I’d guess maybe reply and/or finalRedirectUri isn’t defined? It may be worth wrapping that in a try/catch if it’s that particular line where it fails.

The fly logs is normally the place to look, but you may be able to see more info via fly status --all -a <app-name>. That will list all the app’s vms/instances. Armed with the id of one vm (perhaps you only have one), you can then get the events for that vm. If its id is abcdefg then fly vm status abcdefg -a <app-name>. That may reveal additional info/events. Can’t hurt to look.

If not … I made a hello-world Fastify app a while ago that worked. So you could compare to that, if it helps:

3

So I made a clean route that redirects, and it seems to work.
I was then able to track it down to the following call

 instance.get("/redirect", async (request, reply) => {
    request.session.set("userId", "my-user-id");
    return reply.redirect(instance.appCtx.config.CLIENT_URL);
});

so it seeems that when it tries to redirect after having set a session, it somehow crashes the system?
But like I said earlier, there’s no errors in the logs. Do I have to add anything special for it to be able to reply with cookies?

4

It even logs that it sets the session correctly and saves it to the redis store

2022-11-26T16:51:14.011 app[d73edbdf] ams [info] {"level":20,"time":1669481474009,"pid":523,"hostname":"d73edbdf","reqId":"req-8","plugin":"fastify-session","hook":"onSend","sessionId":"redacted","msg":"About to save a created session, saving ..."}

2022-11-26T16:51:14.013 app[d73edbdf] ams [info] {"level":30,"time":1669481474013,"pid":523,"hostname":"d73edbdf","reqId":"req-8","plugin":"fastify-session","hook":"onSend","sessionId":"bBSHsTAkNFSn0Lgwy8a9A","msg":"Created session successfully saved"}
5

Also, my app never sends 502.
My “catch all” is a 500 code, so this is probably coming from something fly.io internal stuff.

6

Ah, yes, a 502 is returned by Fly’s proxy. So that is an internal Fly thing. However it would only return a 502 response if it can’t get a valid response from your app (which is of course what it is proxying the request for). So while it could be a Fly issue (proxy, network etc) the odds favour it being an issue with the response the app is sending.

Personally I’d comment out line by line, or adjust to see what breaks. Like it seems request.session.set is working (else Redis would not be being called) so that would suggest it’s that next line that is the issue. I’d experiment with that e.g

fastify.get('/', (request, reply) => {
  request.session.set('data', 'hello')
  reply.send('hello world')
})

… returning a static string (no async either). If that works (and you get a hello world back) next try redirecting to a static URL e.g ‘https://fly.io’. If that works, then try a variable URL (as you have now). If it only starts to fail using a variable, I would suspect the variable is either not defined or not a valid URL.

7

The value is a valid url.

I have two endpoints

/api/health/redirect
/api/health/redirect-session

and the only thing that differs betweeen them is:

request.session.set("userId", "my-user-id");

If I don’t call request.session.set, it redirects without a problem.
Checking that the redirectUri was defined was part of my initial debugging just to be sure :stuck_out_tongue:

I just don’t get why it works locally, both when running the docker image and when just running in dev mode, but it doesn’t work on fly.io.

It would be really interesting to see more logs from that part of the system, because there’s no delay or anything, the request seems to finish and then it just moves to the 502 error from Fly’s proxy instantly. So it seems there’s something that Fly’s proxy doesn’t like about the response that I send.

8

That is odd! :thinking:

One thing to say is that the environment is going to be different, because while you use a Dockerfile to build the image, Fly doesn’t actually use Docker to run it. That’s a whole other story. And so just because it runs locally (using Docker) would not guarantee it runs on Fly. Though it should. Normally.

Ok, so now you know the request.session.set is breaking it (rather than an undefined variable etc), the question is why … And that’s going to be a guess without a line in the log for an error handler. So given the default session plugin @fastify/session - npm (which I assume you are using) requires the cookie plugin, I’d next wonder if that’s the issue. :thinking: Only cookie behaviour will certainly change/break depending on where the code is run. The domain will definitely be different (are you using a specific domain for your cookie?). The ‘secure’ setting will likely be different too. If you specify secure-only, the cookie wouldn’t be set if the code does not think it safely can. And often when you run code behind a proxy (which you probably aren’t locally, but are when it’s run on Fly), the connection between the proxy and app is encrypted (Fly magic) but the app may not think it is. And then if you are using a signed cookie, is the secret it is using defined? It may be locally (e.g in env) but not be on Fly (needing it as a secret, set via fly secrets).

May be nothing to do with cookies of course! Just wondering what else would differ, and following that trail.

9

My app doesn’t boot if not all environment variables are set and validated via a zod schema.

I’m using another library called @mgcrea/fastify-session, but you make some valid points so I can try refactoring to use @fastify/session instead, and keep it simple with an in-memory store just to see if it helps.

10

I see we returned a few 502s for your app and they’re all due to your app closing the connection prematurely before sending the whole http response w/ body.

They appear to coincide with “invalid grant” errors in your logs. Would that close the connection before sending a full HTTP response?

1 Like
11

No, the invalid grant errors come from when I tried refreshing the 502 page (which included the token callback from my google auth), so it tried getting a token based on a code that was already used.

They’re not related. But the 502’s happening because I close the connection before the sending the whole response at least gets me closer to figuring out what’s wrong

12

Well, now I refactored to use @fastify/session, and everything seems to work.
I have no idea what the root cause was, but thanks @greg for pointing me in the right direction!

1 Like