chore(sitelaunch): better error message

[kishore03109]

Problem

The existing statements does not print the error (since errors are not serializable) as mentioned here

In addition, we have not been using the child loggers as effectively as possible to provide the context needed to debug efficiently when errors arise. A obvious example is our constant noise of Github API call made, but we have no context surrounding that particular call being made.

To fix this issue, this pr introduces a small introduction of using child loggers, which has already been declared in our codebase by @seaerchin. A child logger is used to create a new logger instance that inherits all of its parent's metadata (e.g. logger name) and attach new metadata for all logs written by that child logger. This way we avoid having to keep repeating our context in the multiple calls that are needed.

Help needed, but not a blocker to this particular PR.

Moving forward, my stance is that we would want to inject the logger directly onto the child functions in different modules.

eg in this trace in the happy path, we can see that the trace for all the calls are not instantiated with the meta that I would like it to have.

The reason for this is because the other logs are done in seperate modules, and if we were to pass the child logger over, this means that for every call, we would need to pass in the logger with bindings as needed. But, I see how this could lead to verbose code.

To me, it seems like there is a balance to be strived for. I personally think using child loggers just the module is not very helpful. What I found more useful is the ability to view the context around the call useful. Ie, with what set of inputs did this module behave in the manner that we see here. I think this can help with debugging, rather than just the module name. But I am not too sure where to draw the line between passing the context form the parent service vs depending on the child service to log the relevant meta as needed during debugging. Happy to hear your thoughts on this. Note that regardless of the direction that we chose, this pr should still go in as it is only scoped to one module + it is an incremental improvement to introducing the usage of child loggers in our codebase.

Solution

use pino to serialize the errors instead + use child loggers with relevant context so that subsequent loggers do not need to keep repeating the context over and over again.

[kishore03109]

• chore(sitelaunch): better error message #1358 👈
• develop

This stack of pull requests is managed by Graphite. Learn more about stacking.

Join @kishore03109 and the rest of your teammates on Graphite

[timotheeg]

Thanks @kishore03109 🙏

My recommendation when updating logging in a given file (as part of "clean up your neighbourhood" activities) is:

• update ALL the log call sites in the file (not just error() calls, info()/warn() calls as well)
• remove message interpolation in favour of data fields at all call sites
• create a child logger for the file / module to specify the module

[kishore03109]

Thanks @kishore03109 🙏
My recommendation when updating logging in a given file (as part of "clean up your neighbourhood" activities) is:

• update ALL the log call sites in the file (not just error() calls, info()/warn() calls as well)
• remove message interpolation in favour of data fields at all call sites
• create a child logger for the file / module to specify the module

@timotheeg, apologies, have done changes to address points one and two.

i am unclear of the third point, wondering if this pattern is used anywhere in the current codebase that i can reference the pattern from!

[timotheeg]

i am unclear of the third point, wondering if this pattern is used anywhere in the current codebase that i can reference the pattern from!

Ah yes, the intention to use child loggers was there ever since the new logger was merged, but I don’t think any module was updated to make use of it yet (@seaerchin intended to do it) Apologies for dumping that on you as a “little surprise” 😅

So it’s a very minor stuff, but it’s something every dev should be aware of, so we can multiply the effects of doing incremental cleanup whenever we touch code.

The idea is that log entries have broad contextual info (e.g. which module is doing the logging), and very specific info for the call sites (code flows, error condition, etc.)

Rather than pollute the call sites with the broad context everywhere, child loggers are a way to encapsulate the context in a new logger instance. Like so:

import logger as baseLogger from "@root/logger/logger"

const logger = baseLogger.child({ module: 'SiteService' })

// later in the file
logger.info({message: 'foo', /* etc... */})

This means that in the file, your log entries will automatically have some additional information added to them, but your call sites will be as lean as possible.

It’s the same principle as DD adding the service name and environment transparently to log entries, but in this case, the base loggers and child loggers are explicitly controlled by us.

You are able to dump put more info into the child logger when you instantiate it btw (if you so wish), and/or you can have child’s child loggers (if that is useful for whatever reason).

Note that having the “module” as broad context doesn’t necessarily have a lot of value... APM is our killer tool to know the true context of a log call, BUT APM traces expire and we might need to revisit log entries in the future (e.g. police summon). So, having the log entries self-contained with context is useful. The context is also helpful for cases where we have duplicated log message in different places of the code base (e.g. “Record updated”), which is terrible because we can’t know where a given log line is from, and so the extra context help disambiguating.

[timotheeg]

Hey Kishore, I added a comment. I might be misunderstanding, but I see a potential red flags. Please check :)

[timotheeg]

LGTM