Logging Development Guide
This guide gives an overview of using Mosaic Logger and the related logging features. The guide contains many code examples accompanied by the resulting log output. The guide starts with a simple example. The consecutive examples are based on the previous example(s) where possible. This makes it easier to understand the changes between them. This means that the examples get more complicated/intricate throughout the guide.
Logging Overview
The simplest use case of writing a log in Mosaic (not counting explicit console
calls)
is represented by the following code:
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log('This is a log message.');
When this piece of code is called, the following log is written to stdout
:
09:45:05.552Z INFO This is a log message. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
The JSON above is what would usually be seen in a console window during development.
This representation is dictated by the environment variable and value NODE_ENV=development
.
In production (NODE_ENV=production
or any other value other than dev
), the written
log would look like this:
{"logtime":"2024-07-09T09:53:42.221Z","loglevel":"INFO","retention":"medium","context":"DEFAULT","component":"media-service","message":"This is a log message.","details":{"tenantId":"000ada85-5bb5-4330-9ba2-44520c052f44","environmentId":"6230a977-de5c-4d8d-b699-7ccd8df5bee4"}}
The differences between the two JSON examples above are:
prod log | dev log |
---|---|
A proper JSON, with property names and values wrapped in double quotes. | A JSON-like object (similar to javascript objects), property names are not wrapped in quotes, and values are wrapped in single quotes. |
Logged as a single-line JSON string. | A pretty, printed, multiline colorized object. |
Has a component property. | The property is hidden to make the log more compact and show only relevant info for development, as during development it’s usually clear to which component the log belongs to. |
Has a retention property. | The property is hidden to make the log more compact and show only relevant info for development, as during development log retention is not applicable. |
Once the log is written to stdout
(or stderr
, depending on the used logger method),
it is the SE team’s responsibility to set up a mechanism to take the written log,
expand it with additional properties, and redirect it to appropriate storage.
Developers shouldn’t have to concern themselves too much with the transportation
topic. If such a log would have been written in a deployed environment and redirected
to Elastic, its would look similar to the screenshot below.
Elastic log representation
At this point, it is possible to search for specific logs based on the values of all properties listed in the log above.
Changing Context
The log context
property clarifies in which context the log was written. Usually,
it translates to some place in the code. There is no strict convention for this
string value. It can be a function name (e.g. bootstrap
), API endpoint name (e.g.
encodeVideo
), some conceptual name that represents multiple different functions
tied by the same theme (e.g. Migrations
) or any other value that might seem appropriate
from the perspective of searching for specific logs later.
If no context is explicitly specified, the context value is set to DEFAULT
. It
would probably be a good idea to set it to something more appropriate. You can do
this in two ways.
First option: pass context as a part of Logger constructor. This way, all logs produced by the said logger instance have passed context value.
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger({ context: 'documentation example' });
logger.log('This is a log message.');
10:01:57.503Z INFO This is a log message. [documentation example]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Second option: pass the context as a part of the log call. The context passed as a part of the method call has a higher priority over the constructor value.
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger({ context: 'documentation example' });
logger.log({
message: 'This is a log message.',
context: 'custom message context',
});
10:03:27.859Z INFO This is a log message. [custom message context]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
To pass a context with the log method call, you need to pass an object, which
contains both message and context. Also, the same result log would have been written
if a logger instance without context (new Logger();
) would have been used.
Changing loglevel
Log level indicates the importance of the message and is written to the loglevel
property. The following table briefly describes each log level.
Level | Number | Description |
---|---|---|
FATAL | 0 | Overall application or system failure that should be investigated immediately. |
ERROR | 1 | Definitely a problem that should be investigated, but not immediately. |
WARN | 2 | This MIGHT be a problem, or might not. For example, it could refer to parts of code where incorrect user input is expected. |
INFO | 3 | This is important information that should be logged under normal conditions, such as successful initialization, services starting and stopping, or the successful completion of significant transactions. |
DEBUG | 4 | Messages that help during development, but are usually disabled in a production environment, unless there is a pressing need to enable them to investigate isolated cases. |
TRACE | 5 | Most detailed logging ever. Using Trace logs is a good way to diagnose an issue in a live system. They can be very verbose and added for every line of code, if that makes sense. There is nothing wrong with having Trace logs in your code, as long as they are not enabled by default. Enabling and disabling them should be a conscious decision to either start or stop diagnosing an issue. |
Each log level has a numerical representation. It is only used internally by the Logger to compare log levels. Mosts of the time you will use either a string or an enum representation, e.g. ERROR
or LogLevel.ERROR
.
INFO example can already be observed in the section above, so it is omitted below. There is a dedicated logger method for each supported log level:
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.fatal('1. This is a fatal message.');
logger.error('2. This is an error message.');
logger.warn('3. This is a warn message.');
logger.debug('4. This is a debug message.');
logger.trace('5. This is a trace message.');
10:05:03.322Z ❗FATAL❗ 1. This is a fatal message. [DEFAULT]
{
logtime: '2024-07-09T10:05:03.322Z',
loglevel: 'FATAL',
retention: 'medium',
context: 'DEFAULT',
component: undefined,
message: '1. This is a fatal message.',
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: undefined
}10:05:03.323Z ❗ERROR❗ 2. This is an error message. [DEFAULT]
{
logtime: '2024-07-09T10:05:03.323Z',
loglevel: 'ERROR',
retention: 'medium',
context: 'DEFAULT',
component: undefined,
message: '2. This is an error message.',
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: undefined
}
10:05:03.324Z WARN 3. This is a warn message. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:05:03.325Z DEBUG 4. This is a debug message. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:09:20.987Z TRACE 5. This is a trace message. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
TRACE
logging is disabled by default both in dev and prod environments.
To enable TRACE
logs, set the environment variable LOG_LEVEL=TRACE
,
but only enable it temporarily!
Apart from these dedicated methods, there is a common write
method that can be
used to write logs of any level (might be useful for some generalized piece of logic
that can write logs of any level).
import { Logger, LogLevel } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.write('This is a write message', { level: LogLevel.WARN });
10:11:55.788Z WARN This is a write message [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
write
has slightly different parameters compared to other level-specific
methods (for instance, the error
objects are passed to it differently).
Changing logtime
Generally, you do not want to explicitly specify the logtime value, as it is
calculated automatically when a log is written. Still, it’s possible to overwrite
the auto-generated value with a specific datetime, e.g. the datetime
value is
generated by some other action and you want the same value in your log.
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log({
message: 'This is a log message with Date value',
logtime: new Date(),
});
logger.log({
message: 'This is a log message with ISO 8601 value',
logtime: '2020-09-08T10:20:48.314Z',
});
10:13:07.826Z INFO This is a log message with Date value [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:20:48.314Z INFO This is a log message with ISO 8601 value [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
About Empty Message
The message
, either as a string parameter or part of a LogMessage
object parameter,
should always be written. If a message is not written or is an empty or whitespace string,
the log shall be written with a default message no message
.
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
// All calls below will produce logs with the same message
logger.log(undefined as any);
logger.log(null as any);
logger.log('');
logger.log(' ');
logger.log({});
10:15:22.690Z INFO no message [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:15:22.690Z INFO no message [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:15:22.691Z INFO no message [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:15:22.691Z INFO no message [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:15:22.691Z INFO no message [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Logging Additional Details
When logging, simply a message is not always enough. Some additional information can also be logged:
the explicit details
sub-object can be used to pass any information.
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log({
message: 'This is a log message',
details: {
userId: 'some user id value',
totallyRandomProperty: 42,
subObjectWithArray: { array: [false, 1, '2', 'Three'] },
},
});
10:17:23.073Z INFO This is a log message [DEFAULT]
{
userId: 'some user id value',
totallyRandomProperty: 42,
subObjectWithArray: { array: [ false, 1, '2', 'Three' ] },
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Logging custom values into a dedicated sub-object is done, so that the reserved
root-level log properties would not be accidentally overwritten. When such a log
is processed and stored in Elastic, Elastic flattens the sub-objects into separate
properties, where each level of nesting is separated by an underscore. For example,
the following properties are available for the previously presented details example:
details_userId
, details_totallyRandomProperty
and details_subObjectWithArray_array
Logging Errors
When an error occurs and the code catches it, you might want to log it. Each logger method is able to log errors as-is:
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
try {
throw new Error('This is a thrown error message');
} catch (error) {
if (error instanceof Error) {
logger.error(error);
}
}
Starting from Typescript 4.4, when an error is caught and typescript is configured
to use the strict
mode, the type of caught error is set to unknown
, so an explicit
cast/type assertion is needed to pass it as a parameter without type errors.
More info here.
10:18:36.070Z ❗ERROR❗ This is a thrown error message [DEFAULT]
{
logtime: '2024-07-09T10:18:36.070Z',
loglevel: 'ERROR',
retention: 'medium',
context: 'DEFAULT',
component: undefined,
message: 'This is a thrown error message',
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
name: 'Error',
message: 'This is a thrown error message',
stack: 'Error: This is a thrown error message\n' +
' at bootstrap (/PathToService/dist/index.js:49:15)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:95:5)'
}
}
Error is logged into a separate error
property as a serialized error object. If
only an error object is passed, the root message value is set to the error message.
You can customize other property values as well as use other methods if you want
to log an error under specific log levels with custom values.
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
try {
throw new Error('This is a thrown error message');
} catch (error) {
if (error instanceof Error) {
logger.warn(error, '1. Custom message for thrown error');
logger.debug(error, {
message: '2. Custom message for thrown error',
context: 'Startup',
});
logger.write(
{
message: '3. Custom message for thrown error',
context: 'Startup',
},
{ level: LogLevel.INFO, error }, // write is a bit different
);
}
}
10:19:50.415Z WARN 1. Custom message for thrown error [DEFAULT]
{
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
name: 'Error',
message: 'This is a thrown error message',
stack: 'Same value as in original example, removed to save space'
}
}
10:19:50.417Z DEBUG 2. Custom message for thrown error [Startup]
{
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
name: 'Error',
message: 'This is a thrown error message',
stack: 'Same value as in original example, removed to save space'
}
}
10:19:50.418Z INFO 3. Custom message for thrown error [Startup]
{
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
name: 'Error',
message: 'This is a thrown error message',
stack: 'Same value as in original example, removed to save space'
}
}
Logger Config Overview
The logger instance relies on service configuration for some of its features to work. While it was not visible from the previous examples, multiple Logger instances in the example below use the same config values and produce the same logs:
import {
getBasicConfigDefinitions,
getConfig,
getValidatedConfig,
Logger,
} from '@axinom/mosaic-service-common';
import { getFullConfig } from './common';
①
const config1 = getConfig(getBasicConfigDefinitions()).values;
const logger1 = new Logger({ config: config1 });
②
const config2 = getValidatedConfig(getBasicConfigDefinitions());
const logger2 = new Logger({ config: config2 });
③
const config3 = getFullConfig();
const logger3 = new Logger({ config: config3 });
④
const logger4 = new Logger();
① Uses non-validated basic config values to create a logger instance.
If some values end up being invalid, the logger uses its own default values instead.
② Uses validated basic config values. The only difference is that
there is a chance for a validation error to be thrown in case of incorrect config values.
③ Uses validated full config object with all service-wide config
values, although the Logger instance uses only a certain set of basic values.
getFullConfig
is usually defined by the service itself to construct a specific
config object with both default and custom config definitions.
④ Is equivalent with the first example, as this is how the Logger
retrieves config values internally in case none are passed.
Usually, config is being validated on service startup. Since it is not expected for config values to change while the service is running, all the instantiation examples are totally valid. One case when you might want to pass a custom config object into Logger instance: if Logger is used in unit tests and you want to simulate different behavior based on the config values.
Environment Variables Overview
The table below gives an overview of all config properties that are used by the Logger instance:
Property name | Matching environment variable name | Description |
---|---|---|
logLevel | LOG_LEVEL | Used to decide whether the log should be written or skipped altogether because its level value is (numerically) higher than the configured value. (e.g. if ERROR (1) is configured, DEBUG (4) logs are skipped) |
serviceId | SERVICE_ID | Written only in non-dev mode and appears in the log as component . |
isProd | NODE_ENV | If logLevel/LOG_LEVEL is not defined for some reason or it is defined incorrectly, this value is used to determine the value of the logLevel above. If true - INFO , if false - DEBUG . The isProd value itself is true if the NODE_ENV value is production . Otherwise, it is false. |
isDev | NODE_ENV | If true, it skips writing the component property to Log objects. If false, it avoids formatting the log object and outputs it as a single-line JSON string. The isDev value itself is true if the NODE_ENV value is development . Otherwise, it is false. |
secureLoggingMode | SECURE_LOGGING_MODE | Can be one of these three values: SECRETS_HIDDEN , UNSAFE_SECRETS_NOT_HIDDEN_UNSAFE , UNSAFE_DEBUG_UNSAFE to decide if sensitive values in logs should be masked or not. These come from MaskMode enum. |
logMaskKeywords | LOG_MASK_KEYWORDS | This variable expects a comma-separated string of keywords, which are then used during log masking to determine if some values should be masked or not. |
See Log Masking for more info on SECURE_LOGGING_MODE
and LOG_MASK_KEYWORDS
.
Considering the table above, it is also not wrong to instantiate Logger like in the example below.
import { BasicConfig, Logger } from '@axinom/mosaic-service-common';
const config: Partial<BasicConfig> = {
logLevel: 'DEBUG',
serviceId: 'some service id',
secureLoggingMode: MaskMode.SECRETS_HIDDEN,
logMaskKeywords: [],
isDev: false,
isProd: true,
};
const logger = new Logger({ config });
logger.log('This is a log message.');
{"logtime":"2024-07-09T10:28:47.423Z","loglevel":"INFO","retention":"medium","context":"DEFAULT","component":"some service id","message":"This is a log message.","details":{"tenantId":"000ada85-5bb5-4330-9ba2-44520c052f44","environmentId":"6230a977-de5c-4d8d-b699-7ccd8df5bee4"}}
Example above should generally be avoided. Config object is readily available in most parts of the code. It is easy to construct with available functions and is not even required to be explicitly passed to Logger instance. All of these features and tools are there to provide consistent logging. Having a logger with a custom object instead of a dedicated config would make finding such logs in Elastic (or any other storage) troublesome when such a need actually arises. The example above is just an example of what kind of object the Logger actually expects from the config
parameter.
The logger is made to be flexible and produce logs even if the config is not defined, although such usage should be avoided if possible.
import { BasicConfig, Logger } from '@axinom/mosaic-service-common';
const config: Partial<BasicConfig> = {};
const logger = new Logger({ config });
logger.log('This is a log message.');
{"logtime":"2024-07-09T10:29:49.554Z","loglevel":"INFO","retention":"medium","context":"DEFAULT","component":"Undefined","message":"This is a log message.","details":{"tenantId":"000ada85-5bb5-4330-9ba2-44520c052f44","environmentId":"6230a977-de5c-4d8d-b699-7ccd8df5bee4"}}
Log Levels Configuration Examples
As already stated, the LOG_LEVEL
env variable controls which logs are written
to stdout/stderr
, and which are not. This section shows some examples of some
combinations of config, code, and output values (config values being referenced
as comments in code blocks and are not explicitly passed to the Logger):
//LOG_LEVEL=DEBUG
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log('This is a log message, which is written.');
logger.debug('This is a debug message, which is written.');
logger.trace('This is a trace message, which is skipped.');
10:31:20.458Z INFO This is a log message, which is written. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:31:20.458Z DEBUG This is a debug message, which is written. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
//LOG_LEVEL=FATAL
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.fatal('This is a fatal message, which is written.');
logger.error('This is a error message, which is skipped.');
logger.warn('This is a warn message, which is skipped.');
logger.log('This is a log message, which is skipped.');
logger.debug('This is a debug message, which is skipped.');
logger.trace('This is a trace message, which is skipped.');
10:32:27.570Z ❗FATAL❗ This is a fatal message, which is written. [DEFAULT]
{
logtime: '2024-07-09T10:32:27.570Z',
loglevel: 'FATAL',
retention: 'medium',
context: 'DEFAULT',
component: undefined,
message: 'This is a fatal message, which is written.',
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: undefined
}
If the LOG_LEVEL
is set to a not supported value, an additional warning is logged
as a part of config validation (but it does not stop the app execution). This log
is produced without relying on other config values, so it is always written as a
prod JSON string even if NODE_ENV=dev
. The value of NODE_ENV
influences which
LOG_LEVEL
value is used internally by the Logger instance (prod
- INFO
,
anything else - DEBUG
).
//NODE_ENV=dev
//LOG_LEVEL=CRITICAL
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.debug('This is a debug message, which is written.');
logger.trace('This is a trace message, which is skipped.');
{"logtime":"2024-07-09T10:34:51.239Z","loglevel":"WARN","retention":"medium","context":"asLogLevel","message":"LOG_LEVEL 'CRITICAL' is not valid. Please use one of the following values: FATAL, ERROR, WARN, INFO, DEBUG, TRACE","details":{"code":"STARTUP_ERROR"}}
10:34:56.345Z DEBUG This is a debug message, which is written. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
//NODE_ENV=prod
//LOG_LEVEL=CRITICAL
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log('This is a log message, which is written.');
logger.debug('This is a debug message, which is skipped.');
logger.trace('This is a trace message, which is skipped.');
{"logtime":"2024-07-09T10:36:36.516Z","loglevel":"WARN","retention":"medium","context":"asLogLevel","message":"LOG_LEVEL 'CRITICAL' is not valid. Please use one of the following values: FATAL, ERROR, WARN, INFO, DEBUG, TRACE","details":{"code":"STARTUP_ERROR"}}
{"logtime":"2024-07-09T10:36:42.085Z","loglevel":"INFO","retention":"medium","context":"DEFAULT","component":"media-service","message":"This is a log message, which is written.","details":{"tenantId":"000ada85-5bb5-4330-9ba2-44520c052f44","environmentId":"6230a977-de5c-4d8d-b699-7ccd8df5bee4"}}
Log Masking
When a log is written, there might be a chance that some sensitive data would be logged as well. This can happen when a whole error is logged as-is (e.g. HTTP error can contain header info with auth token) or perhaps some object (e.g. user) is logged in the details. It’s also not always clear if a log has the potential to include sensitive information or not. For this reason, the log masking mechanism is enabled by default in Mosaic services and there are multiple ways to control the masking behavior. However, this also means that the developer needs to provide some extra care when deciding what information should be written into a log.
When the NODE_ENV
variable is set to development
the unmasked value is shown
in the log message. This is done to help developers understand what is being masked.
Default Behavior
As previously stated, there are two environment variables that can affect masking:
LOG_MASK_KEYWORDS
and SECURE_LOGGING_MODE
. If none of them are specified,
SECURE_LOGGING_MODE
defaults to SECRETS_HIDDEN
, which basically means that
masking is enabled by default. LOG_MASK_KEYWORDS
defaults to a comma-separated
string like this, which means that the masking mechanism looks for the following
values in both log values and property names to decide whether masking should be
performed or not:
secret,credential,password,mail,authorization,connectionString,sig=,postgres://,postgresql://,amqp://,amqps://,AccountKey,SharedAccessKey,Tenant-Auth
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log('This message contains a Secret.');
10:53:09.745Z INFO T*i* *e*s*g* *o*t*i*s*a*S*c*e*.
[ORIGINAL UNMASKED DEBUG VALUE: This message contains a Secret.] [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
As the message value contains the word Secret
, the default masking is done where
every other character is masked. This is actually a last resort default behavior
because in this case, it’s impossible to say with 100% certainty whether or not
a message has a secret value. In addition to looking for secret keywords inside
the message, the default masking middleware also tries to look for values in quotes
inside the string, assuming that quoted values are the actual secrets.
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log("This message 'contains' a Secret.");
logger.log('A secret "might" be in this message.');
logger.log('This message \'potentially has\' two secrets "within".');
logger.log(
'No "keywords", but with quoted "values" will not mask the value.',
);
10:55:13.818Z INFO This message ****** a Secret.
[ORIGINAL UNMASKED DEBUG VALUE: This message 'contains' a Secret.] [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:55:13.821Z INFO A secret ****** be in this message.
[ORIGINAL UNMASKED DEBUG VALUE: A secret "might" be in this message.] [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:55:13.821Z INFO This message ****** two secrets ******.
[ORIGINAL UNMASKED DEBUG VALUE: This message 'potentially has' two secrets "within".] [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:55:13.821Z INFO No "keywords", but with quoted "values" will not mask the value. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
In this case, only quoted values are masked. One other notable default masking behavior
is to fully mask the whole value if a property name contains a keyword. This cannot
happen to a message property, but can for properties of details
or error
objects
(regular masking also applied for these objects and their properties and sub-properties).
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log({
message: 'There is a keyword in details property',
details: {
authorization: 'Any value',
},
});
logger.log(
new Error(
'Unable to connect to database using connection string "postgresql://credname:credpass@localhost"',
),
);
10:57:32.199Z INFO There is a keyword in details property [DEFAULT]
{
authorization: '******\n[ORIGINAL UNMASKED DEBUG VALUE: Any value]',
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:57:32.200Z INFO Unable to connect to database using connection string ******
[ORIGINAL UNMASKED DEBUG VALUE: Unable to connect to database using connection string "postgresql://credname:credpass@localhost"] [DEFAULT]
{
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
name: 'Error',
message: 'Unable to connect to database using connection string ******\n' +
'[ORIGINAL UNMASKED DEBUG VALUE: Unable to connect to database using connection string "postgresql://credname:credpass@localhost"]',
stack: 'Error: Unable to connect to database using connection string ******\n' +
' at bootstrap (/PathToService/dist/index.js:54:19)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n' +
'[ORIGINAL UNMASKED DEBUG VALUE: Error: Unable to connect to database using connection string "postgresql://credname:credpass@localhost"\n' +
' at bootstrap (/PathToService/dist/index.js:54:19)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:95:5)]'
}
}
Masking JWT values
One special default masking behavior is trying to recognize if a string value is a JSON Web Token (JWT) or if a string value contains it. If such a value is found - (only) the last section (the signature) of the JWT will be masked since the first part is only about the used encryption settings and the second part should not contain any secrets. But together with the signature part the JWT token could be used to call APIs in the name of the user. Example:
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log('eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ0ZW5hbnRJZCI6IjAwMDAwMDAwLTAwMDAtMDAwMC0wMDAwLTAwMDAwMDAwMDAwMCIsImVudmlyb25tZW50SWQiOiIwMDAwMDAwMC0wMDAwLTAwMDAtMDAwMC0wMDAwMDAwMDAwMDAiLCJuYW1lIjoiQXhpbm9tIE5hdnkiLCJlbWFpbCI6ImF4aW5vbW5hdnlAZ21haWwuY29tIiwicGVybWlzc2lvbnMiOnt9LCJzdWJqZWN0VHlwZSI6IlVzZXJBY2NvdW50IiwiaWF0IjoxNjM0MDE0NDI2LCJleHAiOjE2MzY2MDY0MjYsImF1ZCI6IioiLCJpc3MiOiJheC1pZC1zZXJ2aWNlIiwic3ViIjoiMDAwMDAwMDAtMDAwMC0wMDAwLTAwMDAtMDAwMDAwMDAwMDAwIn0.SflKxwRJSMeKKF2QT4fwpMeJf36POk6yJV_adQssw5c');
11:17:28.764Z INFO eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ0ZW5hbnRJZCI6IjAwMDAwMDAwLTAwMDAtMDAwMC0wMDAwLTAwMDAwMDAwMDAwMCIsImVudmlyb25tZW50SWQiOiIwMDAwMDAwMC0wMDAwLTAwMDAtMDAwMC0wMDAwMDAwMDAwMDAiLCJuYW1lIjoiQXhpbm9tIE5hdnkiLCJlbWFpbCI6IioqKioqKlxuW09SSUdJTkFMIFVOTUFTS0VEIERFQlVHIFZBTFVFOiBheGlub21uYXZ5QGdtYWlsLmNvbV0iLCJwZXJtaXNzaW9ucyI6e30sInN1YmplY3RUeXBlIjoiVXNlckFjY291bnQiLCJpYXQiOjE2MzQwMTQ0MjYsImV4cCI6MTYzNjYwNjQyNiwiYXVkIjoiKiIsImlzcyI6ImF4LWlkLXNlcnZpY2UiLCJzdWIiOiIwMDAwMDAwMC0wMDAwLTAwMDAtMDAwMC0wMDAwMDAwMDAwMDAifQ.***MASKED_JWT_SIGNATURE*** [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
The reason to have this behavior is because the alternative would be to
have a keyword like token
in the list of configured mask keywords. While such
an approach would potentially help in masking token values, it will also produce
a lot of false-positive masking results, e.g. a harmless message like Token has expired.
would be masked. Custom masking also adds additional security if the
keyword token is not included, but the token value itself is, e.g. "The JWT of
the user is xxx.xxx.xxx".
Changing SECURE_LOGGING_MODE
It’s always recommended to have masking enabled because even if the app code does
not produce logs with sensitive data by itself. However, the same cannot be said
about 3rd party libraries. Still, if there is a strong reason to disable masking
altogether, it can be done with SECURE_LOGGING_MODE=UNSAFE_SECRETS_NOT_HIDDEN_UNSAFE
.
//SECURE_LOGGING_MODE=UNSAFE_SECRETS_NOT_HIDDEN_UNSAFE
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log('This message contains a Secret.');
09:56:10.112Z INFO This message contains a Secret. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
You might also want to see both masked and unmasked values in the same log. This
can be helpful for debugging purposes in some deployed environment which can provide
you with examples of "real" logs. You can do this with SECURE_LOGGING_MODE=UNSAFE_DEBUG_UNSAFE
.
In this case, a debug suffix with unmasked value is attached to any value which was
fully or partially masked.
//SECURE_LOGGING_MODE=UNSAFE_DEBUG_UNSAFE
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log(
new Error(
'Unable to connect to database using connection string "postgresql://credname:credpass@localhost"',
),
{
message: 'Fallback masked secret value',
details: { password: 'some value' },
},
);
09:57:25.990Z INFO Fallback masked secret value [DEFAULT]
{
details: {
password: 'some value',
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
name: 'Error',
message: 'Unable to connect to database using connection string "postgresql://credname:credpass@localhost"',
stack: 'Error: Unable to connect to database using connection string "postgresql://credname:credpass@localhost"\n' +
' at bootstrap (/pathToService/dist/index.js:48:19)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:95:5)'
}
}
Changing LOG_MASK_KEYWORDS
LOG_MASK_KEYWORDS
defines a comma-separated string of keywords that are looked
up during masking to determine whether or not a value should be masked. It is possible
to modify the value if the default set of keywords is either too strict or not strict enough.
//LOG_MASK_KEYWORDS=platypus,credential,some-other-values
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log({
message: 'secret value',
details: {
password: 'some value',
randomFact: 'Scientists thought the first known Platypus was a hoax.',
},
});
10:03:23.117Z INFO secret value [DEFAULT]
{
password: 'some value',
randomFact: 'S*i*n*i*t* *h*u*h* *h* *i*s* *n*w* *l*t*p*s*w*s*a*h*a*.\n' +
'[ORIGINAL UNMASKED DEBUG VALUE: Scientists thought the first known Platypus was a hoax.]',
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Overriding Default Masking Behavior
Default masking behavior should be enough to handle most cases. Still, there might arise a need to either extend this behavior or change it altogether. For this reason, there are ways to change the way the masking of a value works by using a custom masking middleware. Masking middleware is a function that receives a value to check and a set of options that might help with making a decision whether the original value should be modified or not.
An example could look like this:
import { MaskMiddleware, MaskMode } from '@axinom/mosaic-service-common';
/*
* This middleware will always mask any other character in case a keyword is found inside the value.
* The character to mask the value is changed to `#` instead of `*`.
* The logic to mask value in quotes belongs to the default mask middleware and is not applied here.
*/
export const customMaskMiddleware: MaskMiddleware = (value, options) => {
if (options?.maskMode === MaskMode.DEBUG) {
return `DEBUG: [${value}]`;
}
const containsKey = options?.keywords?.some(
(keyword) =>
(value || '').toLocaleLowerCase().indexOf(keyword.toLocaleLowerCase()) >
-1,
);
if (containsKey) {
return value?.replace(/(.)./g, '$1#');
}
return value;
};
The value
parameter is the actual string value to be masked (or not masked). The
options
is an object with maskMode
enum property and a string array of keywords
,
both of which correspond to previously described environment variables. The function
must return a string (or null or undefined), which ideally should be either masked
or unmasked original value.
Once the middleware function is defined, it can be used to replace the default middleware. This can be done in two ways.
First option: pass this function to the Logger constructor. Then, all logs produced by the said logger instance perform masking using this custom middleware.
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger({ maskMiddleware: customMaskMiddleware });
logger.log('This message contains a "Secret".');
10:10:07.726Z INFO T#i# #e#s#g# #o#t#i#s#a#"#e#r#t#. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
It is worth noting that masking the entire value based on the property name (for
details
and error
log objects) is not affected by custom middleware and is a
part of the underlying masking mechanisms which cannot be overridden. See example below.
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger({ maskMiddleware: customMaskMiddleware });
logger.log({
message: 'This message contains a "Secret".',
details: { secret: 'test' },
});
10:15:59.712Z INFO T#i# #e#s#g# #o#t#i#s#a#"#e#r#t#. [DEFAULT]
{
secret: '******',
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Overriding masking middleware for a single Logger instance might not be good enough if we want to modify the default behavior for the whole service. For this reason, there is a way to set the custom middleware once (preferably on service startup) and it will then be used by every Logger instance.
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger, setupGlobalMaskMiddleware } from '@axinom/mosaic-service-common';
setupGlobalMaskMiddleware(customMaskMiddleware);
const logger = new Logger();
logger.log('This message contains a "Secret".');
10:17:50.606Z INFO T#i# #e#s#g# #o#t#i#s#a#"#e#r#t#. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Masking middleware is resolved at a time when a log is written, so middleware can be set up globally even after the Logger instance is created and custom masking is still applied:
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger, setupGlobalMaskMiddleware } from '@axinom/mosaic-service-common';
const logger = new Logger();
setupGlobalMaskMiddleware(customMaskMiddleware);
logger.log('This message contains a "Secret".');
10:17:50.606Z INFO T#i# #e#s#g# #o#t#i#s#a#"#e#r#t#. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Custom middleware passed to Logger constructor has a higher priority over the one that is set globally.
Extending Default Masking
@axinom/mosaic-service-common
exports both defaultMaskMiddleware
and defaultMaskKeywords
comma-separated string which can be used to extend default functionality.
An example could look like this:
import {
defaultMaskKeywords,
defaultMaskMiddleware,
MaskMiddleware,
MaskMode,
} from '@axinom/mosaic-service-common';
export const customMaskMiddleware: MaskMiddleware = (value, options) => {
if (value && value.toLowerCase().startsWith('platypus')) {
return value;
}
let keywords = options?.keywords;
if (!options?.keywords || options.keywords.length === 0) {
keywords = defaultMaskKeywords.split(',');
}
return defaultMaskMiddleware(value, {
maskMode: options?.maskMode ?? MaskMode.SECRETS_HIDDEN,
keywords,
});
};
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger({ maskMiddleware: customMaskMiddleware });
logger.log('This message with secret keyword is masked.');
logger.log(
"Platypuses don't have stomachs. This message with secret keyword is not masked.",
);
10:19:42.799Z INFO T*i* *e*s*g* *i*h*s*c*e* *e*w*r* *s*m*s*e*. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
10:19:42.801Z INFO Platypuses don't have stomachs. This message with secret keyword is not masked. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Whitelisting Masked Values
When generalized masking logic is used, it’s always possible for the log to be
masked incorrectly. For example, mail
is a commonly used word and is by
default included in default keywords comma-separated string. An example of a false-positive
masking case can look like this:
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log('The confirmation mail has been sent successfully.');
10:20:54.678Z INFO T*e*c*n*i*m*t*o* *a*l*h*s*b*e* *e*t*s*c*e*s*u*l*. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Such log obviously should not be masked. While such logs can be whitelisted using custom masking middleware, an explicit whitelisting functionality to help easily whitelist any log was also implemented, providing several approaches to do so.
Using skipMaskTag
@axinom/mosaic-service-common
exports a const string variable named skipMaskTag
,
which can be added to details of any log which then prevents the said log from being masked:
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger, skipMaskTag } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log({
message: 'The confirmation mail has been sent successfully.',
details: { skipMaskTag },
});
10:23:33.916Z INFO The confirmation mail has been sent successfully. [DEFAULT]
{
skipMaskTag: 'MASKING_SKIPPED',
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Although it adds an additional property to be logged, it’s also better to explicitly
have an indication that log masking was intentionally skipped. It is also enables
searching for such logs (e.g. in Elastic, using \_exists_:details_skipMaskTag
).
In addition, this tag can also be added to custom Error classes if there is a certainty that the thrown error of a specific type does not contain any sensitive information.
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger, skipMaskTag } from '@axinom/mosaic-service-common';
const logger = new Logger();
logger.log(
new MosaicError({
message: 'The provided email is not valid.',
code: 'EMAIL_NOT_VALID',
logInfo: { skipMaskTag },
}),
);
logger.log(
new MosaicError({
message: 'The provided email is not valid.',
code: 'EMAIL_NOT_VALID',
}),
);
10:32:13.269Z INFO The provided email is not valid. [DEFAULT]
{
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
message: 'The provided email is not valid.',
code: 'EMAIL_NOT_VALID',
details: undefined,
logInfo: { skipMaskTag: 'MASKING_SKIPPED' },
name: 'MosaicError',
stack: 'MosaicError: The provided email is not valid.\n' +
' at bootstrap (/pathToService/dist/index.js:62:19)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:95:5)'
}
}
10:32:13.270Z INFO T*e*p*o*i*e* *m*i* *s*n*t*v*l*d* [DEFAULT]
{
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
message: 'T*e*p*o*i*e* *m*i* *s*n*t*v*l*d*',
code: 'E*A*L*N*T*V*L*D',
details: undefined,
logInfo: undefined,
name: 'MosaicError',
stack: 'M*s*i*E*r*r* *h* *r*v*d*d*e*a*l*i* *o* *a*i*.\n' +
' * *a* *o*t*t*a* */*s*r*/*a*i*h*W*r*/*e*i*-*e*p*a*e*m*s*i*-*e*i*-*e*p*a*e*s*r*i*e*/*e*i*/*e*v*c*/*i*t*i*d*x*j*:*7*1*)\n' +
' * *a* *r*c*s*.*r*c*s*T*c*s*n*R*j*c*i*n* *n*d*:*n*e*n*l*p*o*e*s*t*s*_*u*u*s*9*:*)'
}
}
Default Cases of Masking Skips
The logic that checks for the existence of skipMaskTag
inside of the log or error
object belongs to defaultSkipMaskMiddleware
. Similar to mask middleware, it’s
a function that decides if log masking should be skipped or not. By default, it is
enabled. In addition to skipping logs with skipMaskTag
, it skips masking of some
other log types:
- PostGraphile development logs that are enabled/disabled using
disableQueryLog
postgraphile setting.- Only applies if
NODE_ENV=dev
- Only applies if
- RabbitMQ logs that contain
amqps
oramqp
connection strings produced byrascal
library, because they already have the values masked.- Only applies if string also contains
\***
to indicate already masked values.
- Only applies if string also contains
Creating a Custom Skip Mask Middleware
While skipMaskTag
should be able to cover a lot of false-positive cases, it’s also
possible to override defaultSkipMaskMiddleware
with a custom middleware to cover
specific cases. However, it is recommended to wrap the default middleware and add
additional checks in the custom middleware.
An example skipMaskMiddleware
could look like this:
import {
defaultMaskKeywordsArray,
defaultSkipMaskMiddleware,
isEmptyObject,
Log,
MaskMiddleware,
MaskMode,
MaskOptions,
SkipMaskMiddleware,
SkipMaskResult,
} from '@axinom/mosaic-service-common';
export const customSkipMaskMiddleware: SkipMaskMiddleware = (
log: Log,
maskMiddleware: MaskMiddleware = defaultMaskMiddleware,
maskOptions: MaskOptions = {
maskMode: MaskMode.SECRETS_HIDDEN,
keywords: defaultMaskKeywordsArray,
},
): SkipMaskResult => {
// Look for a `customFlag` property in log details, and if it's found and has a truthy value - remove it and skip masking for the log.
if (log.details?.customFlag) {
delete log.details?.customFlag;
if (isEmptyObject(log.details)) {
delete log.details;
}
return { skipMasking: true, modifiedLog: log };
}
return defaultSkipMaskMiddleware(log, maskMiddleware, maskOptions);
};
Compared to mask middleware, skip mask middleware gets the whole log object (before
the masking is applied) and the object itself can be used to decide if masking should
be skipped or not. Additionally, it is possible to change the input log object properties
(message
, details
and error
only, others cannot be changed) and return a modified
object to be logged.
maskMiddleware
and maskOptions
parameters are middleware and options that are used by Logger instance to perform masking. They are passed to SkipMaskMiddleware
as optional parameters to support partial masking. In the example above both parameters are needed because defaultSkipMaskMiddleware
uses them to mask log message and details for jwt expired
error (keeping error unmasked). If a completely custom skip mask middleware is created that is not performing any explicit masking, these parameters can be omitted.
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger } from '@axinom/mosaic-service-common';
const logger = new Logger({ skipMaskMiddleware: customSkipMaskMiddleware });
logger.log({
message: 'This message contains a Secret.',
details: { customFlag: true },
});
logger.log('This message contains a Secret.');
11:06:07.745Z INFO This message contains a Secret. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
11:06:07.745Z INFO T*i* *e*s*g* *o*t*i*s*a*S*c*e*. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
The way to override defaultSkipMaskMiddleware
is the same as for mask middleware.
Either by using the Logger constructor parameter (example above) or using a dedicated
setup function that should be called once and that applies custom middleware to all
Logger instances.
//SECURE_LOGGING_MODE and LOG_MASK_KEYWORDS are not explicitly defined
import { Logger, setupGlobalSkipMaskMiddleware } from '@axinom/mosaic-service-common';
setupGlobalSkipMaskMiddleware(customSkipMaskMiddleware);
const logger = new Logger();
logger.log({
message: 'This message contains a Secret.',
details: { customFlag: true },
});
logger.log('This message contains a Secret.');
11:07:38.111Z INFO This message contains a Secret. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
11:07:38.111Z INFO T*i* *e*s*g* *o*t*i*s*a*S*c*e*. [DEFAULT]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
Same as with setupGlobalMaskMiddleware
, using the skip mask middleware
is decided when log methods are called. So, setupGlobalSkipMaskMiddleware
can
be called after the Logger instance is created and it still applies custom middleware.
Handling Huge Errors
In some cases, the thrown errors can contain an enormous amount of information,
which is not worth logging in its entirety. Usually, such errors happen during HTTP
request and contain the request
and response
properties. Each of them can contain
numerous sub-properties. To prevent logging all this information, an explicit skipMask
middleware function trimErrorsSkipMaskMiddleware
is exported explicitly. If there
is an error object in the log, it is trimmed and only some dedicated properties are
logged.
This is a specific case where skip mask middleware can be used to modify output logs:
import {
Logger,
setupGlobalSkipMaskMiddleware,
trimErrorsSkipMaskMiddleware,
} from '@axinom/mosaic-service-common';
import * as request from 'superagent';
const logger = new Logger();
setupGlobalSkipMaskMiddleware(trimErrorsSkipMaskMiddleware);
try {
await request.post('www.google.com').send({});
} catch (error) {
logger.error(error as Error);
}
11:42:33.188Z ❗FATAL❗ Method Not Allowed [bootstrap]
{
logtime: '2024-07-15T11:42:33.188Z',
loglevel: 'FATAL',
retention: 'medium',
context: 'bootstrap',
component: undefined,
message: 'Method Not Allowed',
details: {
code: 'STARTUP_ERROR',
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
status: 405,
name: 'Error',
message: 'Method Not Allowed',
stack: 'Error: Method Not Allowed\n' +
' at Request.callback (/pathToNodeModules/superagent/lib/node/index.js:825:17)\n' +
' at IncomingMessage.<anonymous> (/pathToNodeModulessuperagent/lib/node/index.js:1078:18)\n' +
' at IncomingMessage.emit (node:events:525:35)\n' +
' at endReadableNT (node:internal/streams/readable:1359:12)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:82:21)',
requestUrl: 'www.google.com',
responseError: {
status: 405,
text: '<!DOCTYPE html>\n' +
'<html lang=en>\n' +
' <meta charset=utf-8>\n' +
' <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">\n' +
' <title>Error 405 (Method Not Allowed)!!1</title>\n' +
' <style>\n' +
' *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}\n' +
' </style>\n' +
' <a href=//www.google.com/><span id=logo aria-label=Google></span></a>\n' +
' <p><b>405.</b> <ins>That’s an error.</ins>\n' +
' <p>The request method <code>POST</code> is inappropriate for the URL <code>/</code>. <ins>That’s all we know.</ins>\n',
method: 'POST',
path: '/',
name: 'Error',
message: 'cannot POST / (405)',
stack: 'Error: cannot POST / (405)\n' +
' at Response.toError (/pathToNodeModules/superagent/lib/node/response.js:116:17)\n' +
' at ResponseBase._setStatusProperties (/pathToNodeModules/superagent/lib/response-base.js:107:48)\n' +
' at new Response (/pathToNodeModules/superagent/lib/node/response.js:47:8)\n' +
' at Request._emitResponse (/pathToNodeModules/superagent/lib/node/index.js:871:20)\n' +
' at IncomingMessage.<anonymous> (/pathToNodeModules/superagent/lib/node/index.js:1078:38)\n' +
' at IncomingMessage.emit (node:events:525:35)\n' +
' at endReadableNT (node:internal/streams/readable:1359:12)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:82:21)'
},
responseStatus: 405
}
}
npm packages like superagent
, axios
, and @azure/storage-blob
are able
to produce huge errors like the one above, so it is recommended to trim such errors
and not log them completely. While the example log seems large, it is very compact
compared to the original error object with all properties.
Overriding Console Logs
Logger produces logs in the JSON format, so it would be easier to process by Elastic (or other) storage engines. However, simply using the Logger does not prevent regular text console logs from appearing. It can be some leftover debug logs or logs produced by 3rd party libraries. To handle such logs, there is a way to intercept them and pass the message with parameters through the Mosaic Logger to produce JSON logs in the same format.
import {
Logger,
setupGlobalConsoleOverride,
} from '@axinom/mosaic-service-common';
const logger = new Logger();
console.log('This is a console message.');
setupGlobalConsoleOverride(logger);
console.log('This is an overridden console message.');
This is a console message.
12:00:55.424Z INFO This is an overridden console message. [console]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
The context of such logs is always console
and the loglevel
is set depending
on the console method that is called. The override function overrides the following
console methods with custom implementation: log
, info
, debug
, warn
, and
error
. It also tries to process different data types and additional properties,
so that JSON logs would have a proper representation.
import {
Logger,
setupGlobalConsoleOverride,
} from '@axinom/mosaic-service-common';
const logger = new Logger();
setupGlobalConsoleOverride(logger);
console.debug('This is a console message.', 'param 1', `param 2`);
console.warn({
message: 'This is a warn object',
randomParam: 'this is a random param',
});
console.error(new Error('An error has occurred'));
12:02:57.690Z DEBUG This is a console message. [console]
{
params: [ 'param 1', 'param 2' ],
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
12:02:57.691Z WARN This is a warn object [console]
{
params: [
{
message: 'This is a warn object',
randomParam: 'this is a random param'
}
],
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
12:02:57.691Z ❗ERROR❗ An error has occurred [console]
{
logtime: '2024-07-15T12:02:57.691Z',
loglevel: 'ERROR',
retention: 'medium',
context: 'console',
component: undefined,
message: 'An error has occurred',
details: {
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
},
error: {
name: 'Error',
message: 'An error has occurred',
stack: 'Error: An error has occurred\n' +
' at bootstrap (/pathToService/dist/index.js:54:19)\n' +
' at process.processTicksAndRejections (node:internal/process/task_queues:95:5)'
}
}
This behavior is achieved by overriding default methods of the Node console’s global
instance, but also by storing original console instance copy in a dedicated global variable.
In the end, one needs to use default console methods to print JSON logs to stderr/stdout
anyway. It might happen that you would need to have console override enabled, but
also to produce regular console logs. To achieve this, register a custom type in
the globals.d.ts
file (usually located in the service root folder):
declare namespace NodeJS {
interface Global {
mosaicConsole?: Console;
}
}
import {
Logger,
setupGlobalConsoleOverride,
} from '@axinom/mosaic-service-common';
const logger = new Logger();
setupGlobalConsoleOverride(logger);
console.log('This is a log message.');
(global.mosaicConsole ?? console).log('This is a console message.');
12:00:55.424Z INFO This is a log message. [console]
{
tenantId: '000ada85-5bb5-4330-9ba2-44520c052f44',
environmentId: '6230a977-de5c-4d8d-b699-7ccd8df5bee4'
}
This is a console message.
The nullish coalescing operator is used in case override is removed at some
point. In that case, global.mosaicConsole
is no longer available and the default
console instance is used instead.
Additional Notes
Logger, Console, and Stream Mapping Table
Log Level | Logger Method | Console Method | Output Stream |
---|---|---|---|
FATAL | fatal | error | stderr |
ERROR | error | error | stderr |
WARN | warn | warn | stderr |
INFO | log | log | stdout |
DEBUG | debug | debug | stdout |
TRACE | trace | debug | stdout |
Masking Outside of the Logs
The logic that is used to mask the whole log object is exported from @axinom/mosaic-service-common
and available to be used in other places. For example, if you want to save some arbitrary JSON
to the database and mask some values in it.
import {
defaultMaskMiddleware,
maskObject,
} from '@axinom/mosaic-service-common';
const original = {
unmasked: 'not masked',
propertyToMaskFully: 'fully masked value',
propertyToMaskPartially: 'Connection string "value to mask"',
propertyToMaskUsingFallback: 'Connection string value to mask',
};
const maskedResult = maskObject(original, defaultMaskMiddleware, {
keywords: ['propertyToMaskFully', 'connection string'],
});
console.log(maskedResult);
{
unmasked: 'not masked',
propertyToMaskFully: '******',
propertyToMaskPartially: 'Connection string ******',
propertyToMaskUsingFallback: 'C*n*e*t*o* *t*i*g*v*l*e*t* *a*k'
}