How can I add a field to all logs in the same request?

[gnarea]

You have already researched for similar issues?

Yes

What are you trying to achieve or the steps to reproduce?

I want all the logs in any given request to have some fields that originates in a request header. That includes the logs that Fastify writes when the request starts and ends.

The reason why I want to do this is so that I can map log entries to traces on Google Cloud Trace. I basically want to parse the X-Cloud-Trace-Context request header, to extract two fields that I'll then add to all logs.

In other words, I'd like to do something like request.log.child({field1, field2}), but changing request.log in place in the context of the current request only -- I don't want to introduce any side effects.

What was the result you received?

I don't know how to do what I'm trying to do.

What did you expect?

Context

• node version: 12
• fastify version: 3.11
• os: Linux
• any other relevant information:

[mcollina]

Take a look at https://www.fastify.io/docs/latest/Logging/. You can use the logs serializers to add custom fields from req.

[gnarea]

Thanks for the pointer @mcollina, but I'm not sure I can use serializers or formatters to achieve what I want:

• The incoming request message logged by Fastify does include a req field, so I could set a req serializer to extract the fields I need, but those fields would be under req -- And Google Cloud Trace requires them to be top-level fields.
• I could get around the issue above by using a formatter instead. However, the tracing fields won't be populated for any other logs, unless I create a child logger to add the request. Yet this still won't work with Fastify's own request completed log.

The solution I'm currently considering involves replacing req.log from a hook, but mutating things like this make me uncomfortable:

const [trace, spanId] = req.id.split(';')[0].split('/');
req.log = req.log.child({trace, spanId})

Can you think of a better way to achieve what I want?

[mcollina]

That's it, yes. I think you should set it on reply as well.

[gnarea]

Thanks @mcollina! I'm making progress with the hook below, but unfortunately is seems to be run after the incoming request log, so I can't annotate those logs yet. Any thoughts on how to achieve that?

  await server.addHook('onRequest', (request, reply, done) => {
    if (typeof request.id === 'string') {
      const [trace, spanId] = request.id.split(';')[0].split('/');
      const bindings = { trace: `projects/relaycorp-cloud-gateway/traces/${trace}`, spanId };
      request.log = request.log.child(bindings);
      reply.log = reply.log.child(bindings);
    }
    done();
  });

[mcollina]

You can use https://www.fastify.io/docs/latest/Server/#disablerequestlogging and disable all native logging... and then implement your own in hooks.

[gnarea]

Thanks! I'll do that. I'll close this issue now, since the rest of the work seems straightforward.

[mcollina]

It would be good if you'd like to contribute a little guide or a plugin to do that, as it's a question that pops up very often!

[gnarea]

Indeed, that's what I'm planning to do once I get it all to work. I'm planning to create a cloud-agnostic plugin, so that other folks can add support for AWS and others. I'll keep you posted!