Logging in Fastify

logging_in_fastify.md

Logging in Fastify

Fastify logging works differently from console.log(). It has a few gotchas.

TLDR

• If you want to log an error, it must be the first argument, and not a property inside an object. You may add your own string message as the second argument (optional but recommended).
• If you want to log an object, then put the object as the first argument, and again an optional message string as the second argument.
• But beware: If the "object" you are logging is actually a string, then do not put it as the first variable. Either wrap it inside an object, or concatenate it into your message.

Patterns which WORK

// Logging one string
fastify.log.info("message")
fastify.log.info("message: " + stringVariable)
fastify.log.info(`message: ${stringVariable}`)

// Puttting the error or context object first, and the log message second
fastify.log.info(error, "message")
fastify.log.info({ data, foo, bar, baz }, "message")

// You can also log two objects, although the second will be treated as the msg
fastify.log.debug({ foo: 'bar' }, { baz: 'qux' })
// Through pino, this will appear as: {baz: "qux"}, foo: "bar"

Patterns which surprisingly DO NOT WORK

// Providing a string as the first argument? Only the first argument gets logged!
// This will not log the data
fastify.log.info("message", { data })
// This will not log the variable
fastify.log.info("message", stringVariable)
// This will not log the message
fastify.log.info(stringVariable, "message")

// An error deep inside an object does not get serialized properly.
// This will only log: msg: "test_log", error: {}
fastify.log.info({ error }, "message")
// Unfortunately this means we cannot log both an error and some contextual data at the same time
// My solution to this is to send two logs, one with data, and one with the error
// Please correct me if there is a better way!

And one more surprising case:

// When logging a string property, it does not appear if I use the key 'msg', but it does with key 'message'
// I'm not sure if this is always true for Fastify.  It might just be in my current project.
fastify.log.info({ val, msg }, "only val will be logged")
fastify.log.info({ val, message }, "both val and message will be logged")