Woodman

Faisez des logs !

http://joshfire.github.io/woodman/

ParisJS – le 29 janvier 2014
François Daoust / @tidoust
(logo by @mauriz)

Il était une fois…

un moteur de recherche

pour les opérateurs WAP

Implémentation en C++

Neo holds a Nokia 8110 in Matrix

Trouver la meilleure réponse ?

Règles de filtrage

  • ET logique sur les mots-clés entrés
  • Position dans le dictionnaire opérateur
  • Popularité du service
  • Période d’activation
  • Liens sponsorisés
  • Aléatoire

Questions récurrentes

  • “0 réponse pour une recherche sur "paris js", pourquoi ?”
  • Hier, 0 réponse, aujourd’hui 1 réponse, pourquoi ?”
  • “Le serveur en prod vient juste de planter, pourquoi ?”
  • “Ca marche pas…”

Logs !

Retour vers le futur…

2014 – 100% JavaScript

console.log

Pas de console.log

Besoins

  • Facile à utiliser
  • Filtrage en fonction du niveau
  • Filtrage en fonction du module
  • Formattage flexible des messages (layout)
  • Différentes cibles possibles (console, fichier, serveur, etc.)
  • Suppression des logs avant mise en prod possible
  • Utilisable partout, côté client comme côté serveur
  • Facilement extensible

Déjà vu…

log4j

http://logging.apache.org/log4j/2.x/

Woodman

Une implémentation de log4j en JavaScript

http://joshfire.github.io/woodman/

Installation


# Pour les fans de npm
npm install woodman

# Si votre truc, c’est Bower
bower install woodman

# Si vous êtes plutôt brut de décoffrage
wget https://raw.github.com/joshfire/woodman/master/dist/woodman.js
          

Facile à utiliser


// Démarrer Woodman avec une configuration de base
// (à faire une fois pour toutes au chargement de l’application)
woodman.load('console');

// Récupérer un logger pour le module ou le scope courant
// (par module/scope à identifier dans les logs)
var logger = woodman.getLogger('slides');

// Ecrire des messages
logger.log('Salut Woodman');
logger.info('Ceci n’est pas une pipe');
logger.warn('Résultat étonnant', { result: 42, operation: '6x7' });
logger.error('Oh non !', 'J’ai tout cassé !');
logger.log('Ceci est {} {}', 'une', 'substitution');
          

Et puis c’est tout.

Tout est dans la config


woodman.load({
  "loggers": [ … ],   // What to log depending on provenance
  "appenders": [ … ], // Where to log and how
  "filters": [ … ]    // Additional filters, if needed
});
            

Le raccourci "console"


woodman.load({
  loggers: [{
    root: true,
    level: 'log',
    appenders: [ 'theconsole' ]
  }],
  appenders: [{
    name: 'theconsole',
    type: 'Console',
    appendStrings: false,
    layout: {
      type: 'PatternLayout',
      pattern: '%date{yyyy-MM-dd HH:mm:ss} [%logger] %message%n'
    }
  }]
});
            

Changer le niveau


woodman.load({
  loggers: [{
    root: true,
    level: 'warn',
    appenders: [ 'theconsole' ]
  }],
  appenders: [ … ]
});
            

var logger = woodman.getLogger('slides');
logger.log('Un log filtré');
logger.info('Une info filtrée');
logger.warn('Une alerte affichée');
logger.error('Une erreur affichée');
            

Faire taire un module


woodman.load({
  loggers: [
    { level: 'log',  root: true, appenders: [ 'theconsole' ] },
    { level: 'off',  name: 'slides' },
    { level: 'warn', name: 'slides.shout' }
  ],
  appenders: [ … ]
});
            

var logger = woodman.getLogger('slides');
var sublogger = woodman.getLogger('slides.sub');
var shoutlogger = woodman.getLogger('slides.shout');
logger.warn('Cette alerte est filtrée');
sublogger.warn('Cette alerte d’un sous-module est filtrée');
shoutlogger.warn('Cette alerte du sous-module "shout" n’est pas filtrée');
            

Envoyer les traces avec Socket.IO


woodman.load({
  loggers: [{
    level: 'log', root: true,
    appenders: [ 'theconsole', 'remoteserver' ] }
  ],
  appenders: [
    { name: 'theconsole', … },
    { name: 'remoteserver',
      type: 'SocketAppender',
      url: 'http://localhost:40031',
      layout: {
        type: 'PatternLayout',
        pattern: '%date{ISO8601} [%level] %logger - %message'
      }
    }
  ]
});
            

(sous réserve d’avoir un serveur Socket.IO qui tourne !)

Tout est possible

Les paramètres peuvent se combiner.

On peut s’y perdre…

mais la configuration change rarement.

Et surtout…

le code de l’application ne change pas !

Supprimer les logs avant mise en prod

Le précompilateur de Woodman supprime tout ou une partie des appels à Woodman présents dans du code javascript.


npm install woodman
node woodman/precompile/precompiler.js {JSFILE}
node woodman/precompile/precompiler.js {JSFOLDER} {OUTPUTFOLDER}
node woodman/precompile/precompiler.js {JSFILE} {OUTPUTFILE} --verbose
node woodman/precompile/precompiler.js {JSFILE} --keep warn,error
            

Usage


Usage: node precompiler.js [options] <input> [output]

  Description:
    Removes calls to Woodman from a JavaScript file or folder.

  Parameters:
    input   Full path to the JS file or folder to update.
    output  Full path to the JS file or folder to create.
            Precompiler outputs the result to the console otherwise.

  Options:
    -h, --help          Outputs usage information.
    -k, --keep <levels> Keeps specified trace levels in updated file(s).
                        Comma-separated values.
                        Possible values: "log", "info", "warn", "error". 
                        Defaults to an empty list.
    -v, --verbose       Trace precompiler execution.
            

Le précompilateur gère correctement…

  • les arborescences de fichiers
  • les modules AMD
  • les modules Node.js
  • les appels aux fonctions de Woodman
  • les conditions d’utilisation "normales" de la librairie

En interne

  • Esprima pour générer l’arbre AST
  • Falafel pour ré-écrire le code
  • 5 passes sont nécessaires
  • ~10 secondes sur un fichier conséquent
  • … peut casser le code dans certaines conditions

Tracer l’exécution d’une requête ?

Un serveur HTTP traite plusieurs requêtes en parallèle.
Comment séparer les logs ?

But

  • Assigner un ID à une requête HTTP
  • accessible partout dans le code
  • sans devoir trimballer cet ID partout


Facile sous Apache, IIS via le local thread storage.
Equivalent sous Node.js ?

Les domaines dans Node.js


// Create two domains with an ID
var domain = require('domain');
var firstDomain = domain.create();
var secondDomain = domain.create();
firstDomain.id = 'first';
secondDomain.id = 'second';

// Some function to execute
var func = function () { … };

// Run function in both domains
firstDomain.run(func);
secondDomain.run(func);
            

Pattern %domain dans Woodman


// Tell Woodman to log the message with the domain ID to the console.
var woodman = require('woodman');
var logger = woodman.getLogger();
woodman.load('console Got "%message" from %domain domain.%n');

// Async function that logs two messages using Woodman.
// The function does not know anything about its underlying domain.
var func = function () {
  logger.log('sync message');
  setTimeout(function () {
    logger.log('async message');
  }, 0);
};
            

Pattern %domain dans Woodman


Got "sync message" from first domain.
Got "sync message" from second domain.
Got "async message" from first domain.
Got "async message" from second domain.
            

Exemple de serveur HTTP


var connect = require('connect');
var domain = require('domain');
var woodman = require('woodman');
var logger = woodman.getLogger();
var requestID = 1;

var app = connect()
  .use(function (req, res, next) {
    // Code below extends connect-domain (MIT license)
    // https://github.com/baryshev/connect-domain
    var reqDomain = domain.create();
    reqDomain.id = requestID++;
    reqDomain.bind(res);
    res.on('finish', function () {
      reqDomain.dispose();
    });
    reqDomain.on('error', function (err) {
      reqDomain.dispose();
      next(err);
    });
    reqDomain.run(next);
  })
  .use(function (req, res) {
    logger.log('start request processing');
    setTimeout(function () {
      logger.log('end request processing');
      res.end('Hello, see console');
    }, 2000);
  })
  .use(function (err, req, res, next) {
    res.end(err.message);
  });

woodman.load('console request %domain - %message%n');
app.listen(3000);
            

Evolutions possibles

  • SyslogAppender
    BSD, RFC 5424
  • DBAppender
    Mongo, MySQL, etc.
  • Intégration avec des plateformes d’agglomération de logs
    Sentry, Airbrake, Papertrail
  • Précompileur en mode full AST

logger.log('Merci !');

http://joshfire.github.io/woodman/talks/20140129-parisjs/
http://joshfire.github.io/woodman/