Aufgezeichnet: Protokollieren mit Node.js

Inhaltsverzeichnis

Ein eigener Logger ist schnell geschrieben: In der einfachsten Variante genügt ein gekapselter Aufruf der Funktion console.log, der die zu protokollierende Nachricht um Datum und Uhrzeit ergänzt. Dieser Ansatz ist jedoch in der Regel nicht von Dauer.

Stattdessen kommt nämlich häufig der Wunsch nach weiteren Funktionen auf. Hierzu zählen unter anderem das dauerhafte Speichern des Protokolls, beispielsweise in eine Datei oder Datenbank, und das Kategorisieren einzelner Nachrichten, um diese gezielt auswerten zu können.

Ein derartiges Framework selbst zu entwickeln, liegt zwar nahe, ist aber zugleich wenig effizient. Weitaus zielführender ist die Auswahl eines bestehenden Werkzeugs und dessen anschließende Anpassung an die eigenen Bedürfnisse.

winston als Basis

Unter Node.js bietet sich das Framework winston als Basis an, da es zum einen die erforderliche Flexibilität für die gewünschten Änderungen bietet, und zum anderen bereits eine große Auswahl an Protokollzielen unterstützt.

Um winston einzubinden, muss man es zunächst auf dem üblichen Weg mit Hilfe von npm in den lokalen Kontext der Anwendung installieren:

$ npm install winston

Anschließend kann man die require-Funktion verwenden, um winston in die eigene Anwendung zu integrieren:

var winston = require('winston');

Um Anpassungen vornehmen zu können, instanziiert man als nächstes eine neue Instanz eines winston-Loggers. Dazu dient der Konstruktor winston.Logger. Diesem übergibt man beim Aufruf ein Parameterobjekt, um die gewünschten Protokollierungsstufen zu konfigurieren:

var logger = new winston.Logger({
  levels: {
    fatal: 4,
    error: 3,
    info: 2,
    warn: 1,
    debug: 0
  }
});

Da es auf der Konsole durchaus wünschenswert ist, unterschiedliche Protokollierungsstufen verschiedenfarbig zu kennzeichnen, teilt man winston anschließend die Zuordnung der gewünschten Farben mit:

winston.config.addColors({
  fatal: 'blue',
  error: 'red',
  info: 'green',
  warn: 'yellow',
  debug: 'grey'
});

Im Unterschied zum Produktivbetrieb verfügt man während der Entwicklungszeit in der Regel über eine Konsole. Daher ist es sinnvoll, diese standardmäßig als Protokollierungsziel zu aktivieren. Dies geschieht, indem man dem logger-Objekt eine Instanz des Console-Typs mitsamt der gewünschten Konfiguration übergibt:

if (!process.env.NODE_ENV ||
    (process.env.NODE_ENV === 'development')) {
  logger.add(winston.transports.Console, { level: 'debug' });
  logger.transports.console.colorize = true;
}

Die API definieren

Im nächsten Schritt muss man eine Funktion definieren, die das logger-Objekt aufruft und dem Protokoll die gewünschten Metadaten hinzufügt. Zu diesen zählen eine fortlaufende numerische ID, ein Zeitstempel, der Name des protokollierenden Moduls und eine eindeutige UUID:

var id = 0;
var log = function (module, level, uuid, message, metadata) {
  logger.log(level, JSON.stringify({
    id: id,
    timestamp: new Date(),
    module: module,
    uuid: uuid,
    level: level,
    message: message,
    metadata: metadata
  }));
  id += 1;
};

Während die numerische ID dazu dient, die Protokolleinträge sortieren zu können, ermöglicht die übergebene UUID eine eindeutige Zuordnung vom Protokolleintrag zum Quellcode: Dies vereinfacht die Suche nach der Quelle eines Eintrag deutlich.

Zu guter Letzt muss man die API noch für andere Module zur Verfügung stellen, wobei man für die verschiedenen Protokollierungsstufen jeweils Komfortfunktionen zur Verfügung stellen kann. Zudem lässt sich der Name des Moduls an dieser Stelle global festlegen:

module.exports = {
  add: function (transport, options) {
    logger.add(transport, options);
  },

  remove: function (transport) {
    logger.remove(transport);
  },

  getLogger: function (options) {
    return {
      fatal: function (uuid, message, metadata) {
        log(options.module, 'fatal', uuid, message, metadata);
      },
      error: function (uuid, message, metadata) {
        log(options.module, 'error', uuid, message, metadata);
      },
      info: function (uuid, message, metadata) {
        log(options.module, 'info', uuid, message, metadata);
      },
      warn: function (uuid, message, metadata) {
        log(options.module, 'warn', uuid, message, metadata);
      },
      debug: function (uuid, message, metadata) {
        log(options.module, 'debug', uuid, message, metadata);
      }
    };
  }
};

Den Logger verwenden

Fasst man all diesen Code in einem eigenständigen Modul zusammen, fällt die Verwendung danach ausgesprochen leicht: Es genügt, das Modul zu referenzieren und danach die Funktion getLogger aufzurufen, wobei man ihr den Namen des protokollierenden Moduls übergeben muss:

var log = require('./log'),
    logger = log.getLogger({ module: 'foo/bar' });

Anschließend kann man mit dem zurückgegebenen logger-Objekt die Funktionen fatal, error, info, warn und debug verwenden, um Protokolleinträge zu schreiben. Bei Bedarf könnte man außerdem ein zusätzliches Parameterobjekt mit Metadaten übergeben, das an den Protokolleintrag angehängt wird:

logger.info('b96d2ce1-7957-4fd1-86ee-477668cabfdb', 'started…');

Beginnt man die Protokollnachricht mit einem Verb, ergibt sich in Verbindung mit dem Modulnamen die eigentliche Meldung als vollständiger, grammatikalisch korrekter Satz: 'foo/bar started…'

tl;dr: Einen eigenen Logger zu schreiben ist zwar prinzipiell nicht sonderlich schwierig, ergibt aber nur bedingt Sinn. Weitaus effizienter ist es, auf ein vorhandenes Werkzeug aufzusetzen. Das Framework winston bietet alles, was man hierfür benötigt. ()