Logging with std/log

Why not using console.*()?

Avoid to use console.log(), console.error(), console.info(), console.debug() and console.warn() for logging in scripts. Logging everything to console.*() is hard to control (enable/disable) and problematic to redirect. With a logging library it is possible to specify the output destination (stdout, stderr and/or to files) and a output format. The output size and log rotation can be controlled and configured.

Configure log rotation to avoid huge logging files which can slow down logging dramatically which can have a huge impact to the whole application performance. Huge logfiles also waste diskspace and can increase the costs to run the application dramatically. Remove all console.log() statements from the code.

Using deno.land/std/log for Logging

In deno.land/std/log a logging messages is called LogRecord. A LogRecord is written to a Logger. A Logger uses one or more Handler to output the LogRecord.

The ConsoleHandler writes a LogRecord to console.log / stdout. The FileHandler writes LogRecord to a file. The RotatingFileHandler writes a LogRecord to a file which is rotated when a maximum file size is reached and keeps a maximum number of previous logging files.

It is possible to specify a custom output format for your logging messages in a Handler. It is also possible to write complete own Handler. For more details, see deno.land/std/log ↱.

Using the Default ConsoleHandler/console Logger

The default logger is set to the INFO level and logs all output to the console / stdout. This is the reason why the log.debug() message (Line 5) is not seen in the console output in this example.

1
2
3
4
5
6
7

import * as log from "https://deno.land/std/log/mod.ts";

log.debug("this is an debug message");
log.info("this is an info message");
log.warning("this is a warning message");
log.error("this is an error message");
log.critical("this is a critical message");

Run the example and see that all logging message except the DEBUG message appear on screen.

$ deno run example-0001.ts
INFO this is an info message
WARNING this is a warning message
ERROR this is an error message
CRITICAL this is a critical message

Logging to a ConsoleHandler/console and a FileHandler/logging file

Initialize a handler console with a ConsoleHandler, logging from DEBUG level. Also add a handler file, a FileHandler handler logging from DEBUG level to the file application.log. Set the default logger log level to DEBUG and add the handlers console and file.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26

import * as log from "https://deno.land/std/log/mod.ts";

await log.setup({
    handlers: {
        console: new log.handlers.ConsoleHandler("DEBUG"),

        file: new log.handlers.FileHandler("DEBUG", {
            filename: "./application.log",
        }),
    },

    loggers: {
        default: {
            level: "DEBUG",
            handlers: ["console", "file"],
        },
    },
});

// get default logger.
const logger = log.getLogger();
logger.debug("this is an debug message");
logger.info("this is an info message");
logger.warning("this is a warning message");
logger.error("this is an error message");
logger.critical("this is a critical message");

Run the example and see that all logging messages appear on screen and in the logfile.

$ deno run --allow-write example-0002.ts
DEBUG this is an debug message
INFO this is an info message
WARNING this is a warning message
ERROR this is an error message
CRITICAL this is a critical message
$ cat application.log 
DEBUG this is an debug message
INFO this is an info message
WARNING this is a warning message
ERROR this is an error message
CRITICAL this is a critical message

Log to ConsoleHandler/console and a RotatingFileHandler/logging files and control the LogLevel with an Environment Variable

Create a automatically rotating logging file, log messages to console and in the logging file.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46

import * as log from "https://deno.land/std/log/mod.ts";
import type { LevelName } from "https://deno.land/std/log/mod.ts";

const env = Deno.env.toObject();
const LOGLEVEL:LevelName = env.LOGLEVEL as LevelName ?? "INFO";

await log.setup({

    handlers: {
        console: new log.handlers.ConsoleHandler("DEBUG"),

        defaultLog: new log.handlers. RotatingFileHandler("DEBUG", {
            maxBytes: 1024000,
            maxBackupCount: 5,
            filename: "./application.log",
            formatter: "{levelName} {msg}",
            mode: "a",
        }),
    },

    loggers: {
        default: {
            // to console and logfile
            level: LOGLEVEL,
            handlers: ["console", "defaultLog"],
        },
    },
});

let logger;
logger = log.getLogger();
logger.debug("this is an debug message");
logger.info("this is an info message");
logger.warning("this is a warning message");
logger.error("this is an error message");
logger.critical("this is a critical message");

for (let i = 0; i < 1_000_000; i++) {
    logger.debug(`this is an debug message i:${i}`);
    if(i % 2) {
        logger.info(`this is an info message i:${i}`);
    }
    if(i % 5) {
        logger.warning(`this is an warning message i:${i}`);
    }
}

Lines 4 - 5

Set the variable LOGLEVEL to the value of the environment variable LOGLEVEL if exists, otherwise set to variable to the default log level INFO.

Line 10

Create a console handler which logs everything from DEBUG level on.

Lines 12 - 18

Create a RotatingFileHandler handler which logs everything from DEBUG level on in a logging file named application.log. The logging file keeps a maximum of 1Mb, maxBytes: 1024000. Is the maximum capacity of the logging file is reached, the file is rotated. A maximum of 5 backup files is kept, maxBackupCount: 5, older files get deleted.

Lines 22 - 26

Create a logger which logs everything from the specified logging level LOGLEVEL to the console handler and the RotatingFileHandler handler.

Lines 39 - 41

Create a lot of logging messages.

Run the example and see that up to five logging files are created and rotated. All ‘INFO’ and ‘WARNING’ messages are written to the logging files and screen.

$ deno run --allow-env --allow-read --allow-write example-0004.ts

Delete created logging files.

rm application.log*

Set the log level to ‘WARNING’ and run the example. The ‘INFO’ records are not kept in the logging files and screen.

$ LOGLEVEL=WARNING deno run --allow-env --allow-read --allow-write example-0004.ts

Delete created logging files.

rm application.log*

Set the log level to DEBUG and run the example. All messages ‘INFO’, ‘WARNING’ and ‘DEBUG’ are kept in logging files and screen.

$ LOGLEVEL=DEBUG deno run --allow-env --allow-read --allow-write example-0004.ts

Lazy evaluation only if log level avail

To save your application from using unnecessary computing time, use a lambda which is only evaluated if the requested log level is avail and logs output.

In this example the JSON.stringify is only evaluated when the ‘DEBUG’ level is avail.

1

log.debug(() => `getProperty property: ${JSON.stringify(property)}`);

Requires

Tool Version See
deno > 1.17.1 Tools

See also