Error Handling & Logging Best Practice

Some context, when reviewing our code I feel some catch and throw actually useless\. Some logging are useless as well\. So here trying to figure out best practice\.

Catch - Throw Rules

Only use catch - throw (here only talking about re throw) when

  1. Change the business semantics. e.g. DB unique violation → ConflictError with 409

  2. HTTP status change. e.g. Turning a generic error into a specific status.

  3. Add additional info into error log.

Some anti-pattern:

1
2
3
4
5
6
7
8
9
10
11
12
// add no value, just noise. as correlationId can be found in logger already.
catch (error) {
this.logger.error('Something failed', { correlationId, error });
throw error;
}

// Some is throwing a new error type but actually no one cares about it.
// Also lose the error.cause.
catch (error) {
throw new XXXInternalError('UNIQUE_CODE');
}
// Question?: is a unique, greppable string worth the cost of a custom error class, a catch block, and lost error chain?

Logging Best Practice

1. Log at the boundary, not at every layer.

ClientService, ThirdParty. Should have logger already (with interceptor).
DB request and response logging is debug level off in prod.

2. Don’t log what’s already in the trace context

🙋‍♂️ But we can’t see it in Grafana logs.
But indeed, something has been logged automatically as rebind logger so it’s added in logger context: traceId, correlationId

3. Use the right log level

Seems very basic, but just realized I was actually using the wrong log level. I was abusing log\.info

info should be used only on Boundary. Or business outcome like card/account created

4. Log what the error does’t already tell you

N/A

5. Don’t log sensitive data

We’re using LOGGING\_MASKED\_SENSITIVE\_FIELDS to mask the PII

6. Prefer structured metadata over string interpolation

Bad:

1
this.logger.info(`Publish data for page: ${page}`);

Good:

1
this.logger.info('Publish data', { page });

7. Log the outcome, not the attempt

Verbose:

1
2
3
4
this.logger.info('Creating account in DA');
this.logger.info('Creating account in DB');
// do work
this.logger.info('Account created', { accountNumber });

Better:

1
2
3
// Optional this.logger.debug('Creating account in DA');
// Optional this.logger.debug('Creating account in DB');
this.logger.info('Account created', { accountNumber });

8. Catch - swallow must always log

N/A


I very often feel don’t have enough information for debugging. So tend to add noise into logger with info level.
Actually, if we have log on boundary and business outcome. It should be good. Other should be for debugging.

pino supports runtime level changes. We need to add endpoint, or listen to config, or request header for debug.

Comments