CoffeeScript

CoffeeScript

Le 23 juin 2014
Créer un middleware de log des requêtes HTTP entrantes pour Express

Créer un middleware de log des requêtes HTTP entrantes pour Express

Vous souhaitez pouvoir logger les connections HTTP rentrantes avec Node.js et Express ? Rien de plus simple! Il suffit de déclarer un middleware de la façon suivante:

util = require 'util'

module.exports = (req, res, next) ->
    console.log  """---------------------------------------------------------
                    Http Request - Pid process: [#{process.pid}]
                    Http Request - Url: #{req.url}
                    Http Request - Query: #{util.inspect(req.query)}
                    Http Request - Method: #{req.method}
                    Http Request - Headers: #{util.inspect(req.headers)}
                    Http Request - Body: #{util.inspect(req.body)}
                    ---------------------------------------------------------"""

    next()

Comme vous pouvez le voir, aucun module externe n’est nécessaire. Il suffit ensuite d’intégrer votre nouveau middleware dans le code de configuration de votre serveur Express, comme suit:

express = require 'express'
requestLogger = require './lib/requestLogger'

app = express()

app.configure ->
    console.log "Environment: #{app.get('env')}"
    app.set 'port', 8000

    ...

    app.use requestLogger

    ...

    app.use app.router

app.listen app.get('port')

Le log résultant d’une requête HTTP prendra la forme suivante:

---------------------------------------------------------
Http Request - Pid process: [26074]
Http Request - Url: /
Http Request - Query: {}
Http Request - Method: GET
Http Request - Headers: { host: 'localhost:9000',
  connection: 'keep-alive',
  accept: 'text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8',
  'user-agent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/35.0.1916.153 Safari/537.36',
  'accept-encoding': 'gzip,deflate,sdch',
  'accept-language': 'fr-FR,fr;q=0.8,en-US;q=0.6,en;q=0.4',
  cookie: '...' }
Http Request - Body: undefined
---------------------------------------------------------
Le 16 juin 2014
Logger le contenu de vos objets avec Node.js

Logger le contenu de vos objets avec Node.js

Le contenu des logs est un élément essentiel de votre programme, bien souvent laissé de côté, il peut s’avérer précieux en cas problème.

En particulier, il arrive de vouloir logger le contenu d’un objet ou bien une de ses propriétés. Bien souvent, le premier réflexe sera d’en afficher le contenu en concaténant son contenu dans une chaine de caractère comme suit:

foobar = foo: "bar"
console.log "Contenu de la variable foobar: '#{foobar}'"

Malheureusement, le résultat ne correspond pas toujours à ce qu’on imagine:

Contenu de la variable foobar: '[object Object]'

Vu comme ça, on n’en fera pas grand chose si on met le nez dans les logs. Bien sûr, il est possible d’afficher la valeur de la propriété ‘foobar’ de l’objet:

console.log "Contenu de la variable foobar: '#{foobar.foo}'"

Le résultat sera un peu meilleur car on sera en mesure de logger la valeur de foo:

Contenu de la variable foobar: 'bar'

Dans notre cas, nous avons de la chance, car la variable ‘foo’ est de type String. Mais si la variable en question est un objet ou bien un tableau, nous tomberons sur le même problème.

JavaScript et Node.js nous proposent au moins deux solutions pour nous aider à produire un log convenable: La fonction ‘JSON.stringify’, et la fonction ‘inspect’ du module ‘util’.

JSON.stringify()

Bien connu dans le mode du JavaScript côté browser pour sérialiser le contenu d’une requête AJAX par exemple, on ne pense pas toujours à utiliser cette méthode pour sérialiser un objet ou bien un tableau JavaScript dans le but d’en logger son contenu:

console.log "Contenu de la variable foobar: '#{JSON.stringify(foobar})'"

On obtient déjà quelque chose de bien plus intéressant, c’est à dire un log avec un descriptif complet de l’objet au format JSON:

Contenu de la variable foobar: '{"foo":"bar"}'

Des objets plus complexes peuvent néanmoins devenir difficile à relire dans les logs, il ne faut donc pas hésiter à renseigner les informations de formatage du JSON lors de l’appel de la méthode ‘stringify’, qui permettent d’obtenir un log plus lisible avec un contenu bien indenté:

console.log "Contenu de la variable foobar: '#{JSON.stringify(foobar, undefined, 2})'"

ce qui donne:

Contenu de la variable foobar: '{
  "foo": "bar"
}'

Le dernier paramètre permet de spécifier l’indentation souhaitée.

La documentation complète de la méthode stringify peut être consulté sur le site de Mozilla: https://developer.mozilla.org/fr/docs/JavaScript/Reference/Objets_globaux/JSON/stringify

La méthode JSON.stringify peut être utilisée également avec des tableaux:

foo = [ "foo", "bar" ]
console.log "Contenu de la variable foobar: '#{JSON.stringify(foo, undefined, 2)}'"

ce qui donne:

Contenu de la variable foobar: '[
  "foo",
  "bar"
]'

Malheureusement, cela ne fonctionne pas avec les fonctions qui ne font pas partie du standard JSON:

bar = (foo, bar) -> "#{foo}-#{bar}"
console.log "Contenu de la variable foobar: '#{JSON.stringify(bar, undefined, 2)}'"

ce qui donne:

Contenu de la variable foobar: 'undefined'

Il ne faut pas oublier que nous détournons une fonctionnalité qui n’est pas spécialement faite pour le log au départ… Heureusement notre bonne vieille méthode toString() appelée sur la fonction nous sortira d’affaire:

console.log "Contenu de la variable foobar: '#{bar.toString()}'"

ou tout simplement:

console.log "Contenu de la variable foobar: '#{bar}'"

donne:

Contenu de la variable foobar: 'function (foo, bar) {
    return "" + foo + "-" + bar;
  }

util.inspect()

Le module util de Node.js fournit quelques fonctions intéressantes, dont la fonction: inspect. Elle permet de formatter un contenu de la façon que le réalise la fonction JSON.stringify que ce soit un objet ou bien un tableau. Elle a l’avantage d’être plus souple en proposant différentes options de sérialisation telles qu’une profondeur limite d’inspection ou bien encore la capacité d’appeler la méthode inspect() sur les sous-objets de l’arbre, lorsqu’ils la propose, afin de produire un contenu sérialisé spécifique.

Par exemple, les appels suivants:

util = require 'util'

console.log "Contenu de la variable foobar: '#{util.inspect(foobar)}'"
console.log "Contenu de la variable foobar: '#{util.inspect(foo)}'"
console.log "Contenu de la variable foobar: '#{util.inspect(bar)}'"

donneront:

Contenu de la variable foobar: '{ foo: 'bar' }'
Contenu de la variable foobar: '[ 'foo', 'bar' ]'
Contenu de la variable foobar: '[Function]'

Et la customisation de la sérialisation comme suit:

qix = { foo:"bar", foobar: { inspect: () -> "Some custom representation of foobar" } }
console.log "Contenu de la variable foobar: '#{util.inspect(qix)}'"

donnera:

Contenu de la variable foobar: '{ foo: 'bar', foobar: Some custom representation of foobar }'

On notera avec ce dernier exemple que la fonction util.inspect() n’a pas vocation à produire un JSON valide, mais elle produira par défaut une notation proche du JSON.

Il est possible entre autre d’afficher les propriétés non-enumerables d’un objet, de coloriser le résultat de l’appel ou bien encore de désactiver l’appel des inspections customisées sur les objets.

Pour approfondir: http://nodejs.org/api/util.html#util_util_inspect_object_options

Pour aller plus loin …

Sachez qu’il existe des modules Node.js dédiés à la sérialisation d’objets à des fins d’analyse. Par exemple, le module nodedump permet de logger dans une sortie HTML un tableau qui détaille le contenu de l’objet:

nodedump

Bien entendu, vous pourrez toujours préférer le debugger de votre IDE favori, son côté interactif apporte de nombreux bénéfices, et l’évaluation d’expressions se révèle être d’une grande aide:

debugger