fractal-analytics-platform / fractal-web

Web client for Fractal
https://fractal-analytics-platform.github.io/fractal-web/
BSD 3-Clause "New" or "Revised" License
6 stars 0 forks source link

Review server logging (possibly via third-party library) #489

Closed tcompa closed 4 months ago

tcompa commented 5 months ago

console.log is fine, but AFAIK it doesn't offer easy format customization, logging levels, or redirection to file. Let's see whether we find an appropriate 3rd-party library.

The basic criteria are something like

  1. Lightweight (in terms of dependencies and configuration effort).
  2. Widespread and maintained (and not necessarily a svelte-specific one)
  3. Required feature: log record format (e.g. we want to include timestamps)
  4. Required feature: logging levels
  5. Useful feature: logging to file
  6. Anything else?

I don't have an opinion (or even a clear understanding) on whether the same logging strategy should be adopted for browser logging as well.

zonia3000 commented 5 months ago

I had a look at this article https://betterstack.com/community/guides/logging/best-nodejs-logging-libraries/ and then I've done some tests with Pino, Winston and Log4js. All these logging frameworks provide what we need, so we can choose any of them.

Pino and Winston by default create logs using the JSON format. This can be useful in production environments where logs are collected by automatic tools in order to analyze them (e.g. Logstash and similar). If we don't plan to set up such kind of log analysis I would avoid the JSON format, since it makes the logs less human-readable. Moreover, I think that if we set up JSON logs on fractal-web we should do the same on fractal-server.

Personally I would go for Log4js or Pino.

Pros of Pino:

Pros if Log4js:

Here some examples of configurations done with the various loggers. I've also configured the output format to add the context of the logger (e.g. the name of the file/service that is generating the log - in these examples "hooks", since I've tested the logger replacing the console.log calls inside the file hooks.server.js).

Pino

import { pino } from 'pino';

const transport = pino.transport({
  targets: [
    // this writes to file in JSON format using the asynchronous mode
    {
      level: 'debug',
      target: 'pino/file',
      options: {
        destination: './fractal-web.log',
        sync: false
      }
    },
    // pino-pretty disable the JSON output and adds colors
    // it has to be installed as a separate module: https://github.com/pinojs/pino-pretty
    {
      level: 'debug',
      target: 'pino-pretty',
      options: {
        destination: 1, // writes to STDOUT
        // service is the logger context ("hooks" in the example)
        messageFormat: `({service}) {msg}`,
        // we need to ignore the service key, otherwise the service value will be treated
        // as an additional property and will be put inside a new line;
        // we want to ignore program pid and hostname too
        ignore: 'service,pid,hostname'
      }
    }
  ]
});

// We define a parent logger
const parentLogger = pino({ level: 'debug' }, transport);

// And then a global function that create our custom logger with our custom property:
function getLogger(context) {
  return parentLogger.child({ service: context });
}

Inside hooks.server.js we create our logger and use it:

const logger = getLogger('hooks');

Console output:

pino

File output:

{"level":30,"time":1716197674293,"pid":19969,"hostname":"pjem","service":"hooks","msg":"[GET] - /"}
{"level":20,"time":1716197674293,"pid":19969,"hostname":"pjem","service":"hooks","msg":"Public page - No auth required"}
{"level":20,"time":1716197674308,"pid":19969,"hostname":"pjem","service":"hooks","msg":"Including cookie into request to http://localhost:8000/api/alive/, via handleFetch"}
{"level":20,"time":1716197674326,"pid":19969,"hostname":"pjem","service":"hooks","msg":"Including cookie into request to http://localhost:8000/auth/current-user/, via handleFetch"}

Log4js

log4js.configure({
  appenders: {
    // this will log to console
    console: {
      type: 'console'
    },
    // this will log to file
    file: {
      type: 'file',
      filename: 'fractal-web.log'
    }
  },
  categories: {
    default: {
      // we enable both console and file output
      appenders: ['console', 'file'],
      // log level can be specified also in the single appender
      level: 'debug'
    }
  }
});

Inside hooks.server.js we create our logger and use it (log4js supports the logger context by default):

const logger = log4js.getLogger('hooks');

Console output:

log4js

File output:

[2024-05-21T12:28:34.957] [INFO] hooks - [GET] - /
[2024-05-21T12:28:34.958] [DEBUG] hooks - Public page - No auth required
[2024-05-21T12:28:34.974] [DEBUG] hooks - Including cookie into request to http://localhost:8000/api/alive/, via handleFetch

Winston

// Defining our custom format
const logFormat = winston.format.printf(function (info) {
  return `[${new Date().toISOString()}] ${info.level} (${info.context}): ${info.message}`;
});

function getLogger(context) {
  return winston.createLogger({
    level: 'debug',
    format: winston.format.simple(),
    defaultMeta: { context },
    transports: [
      // writes to console
      new winston.transports.Console({
        // add colors to our custom format
        format: winston.format.combine(winston.format.colorize(), logFormat)
      }),
      // writes to file
      new winston.transports.File({ filename: 'fractal-web.log', level: 'debug' })
    ]
  });
}

Inside hooks.server.js we create our logger and use it:

const logger = getLogger('hooks');

Console output:

winston

File output using winston.format.json():

{"context":"hooks","level":"info","message":"[GET] - /"}
{"context":"hooks","level":"debug","message":"Public page - No auth required"}
{"context":"hooks","level":"debug","message":"Including cookie into request to http://localhost:8000/api/alive/, via handleFetch"}

File output using winston.format.simple():

info: [GET] - / {"context":"hooks"}
debug: Public page - No auth required {"context":"hooks"}
debug: Including cookie into request to http://localhost:8000/api/alive/, via handleFetch {"context":"hooks"}