snapJob Part II : Managing application logs using LogStash

Part I of this project ("Creating a simple RESTFull API that rocks! REST in peace!") can be found here.

How does logstash works ?!?

Log stash takes one or several inputs as a streams of incoming messages, and produces an output to display or store messages.

We could specify the stdin as an input, which means that stuff typed in our console will be catched by logstash. But this ain't the best solution.

We could specify Apache Kafka (a messaging system) to be our input, which could be very efficient, but a little bit more complex to configure and implement.

So, as a first try, we will specify a tcp input on port 28777, and just use a npm API, winston-logstash.

The output should be elasticsearch, but as we want a firt try, lets output to the console.

In this example, we will use logstash 1.4.2, installed in the directory "/opt".

1. Configuring LogStash
   We will create a simple json configuration file called snapJob.conf in the "/opt/logstash-1.4.2" directory, containing the following text :
   

   input {
    tcp { port => 28777 type=>"log" }
   }
   output {
    stdout { codec => rubydebug }
   }
   
   filter {
    json {
     source => "message"
    }
   }
   

   
   
   
2. Running LogStash
   Realy simple. Just run these commands :
   

   cd /opt/logstash-1.4.2
   bin/logstash -f snapJobLogs.conf
   

   
   
   
3. Modifying our node.js application
   Let's start by adding a new dependency to our project by adding a dependency in our package.json file :

   "winston-logstash":"*"
   

   
   Next, create a new "log.js" file, located in a subdirectory in our application called "util" :
   

   var winston = require('winston');
   
   // Requiring `winston-logstash` will expose `winston.transports.Logstash`
   require('winston-logstash');
   
   var Logger = function Logger() {
       this.logger = new (winston.Logger)({
           transports: [
               new (winston.transports.Logstash)({
                   port: 28777,
                   node_name: 'snapJob',
                   localhost: 'localhost',
                   pid: 12345 ,
                   ssl_enable: false,
                   ca: undefined
               })
           ]
       });
   
       this.cleanRequest = function(req, callback){
           if(callback) callback(
               req === undefined ?
                   undefined :
                   {ip: req.ip, url: req.url});
       }
   
       // Logs an info message
       this.logInfo = function(message, req, callback) {
           var _this = this;
           this.cleanRequest(req, function(cleanedRequest, callback){
               _this.logger.log('info', {message: message, req: cleanedRequest}, {stream: 'log'}, callback);
           });
       }
   };
   
   Logger.instance = null;
   
   /**
    * Singleton getInstance definition
    * @return singleton class
    */
   Logger.getInstance = function(){
       if(this.instance === null)
           this.instance = new Logger();
       return this.instance;
   };
   
   module.exports = Logger.getInstance();
   

   
   
   This will create a singleton class that will be used to handle logging.
   This is a good idea to wrap this in a new class, containing the dependency to "winston" in a single file, because if later on we want to produce messages to kafka and set the logstash input as a kafka topic, we will have only one file to update.
   
   
   
4. Produce a new log from our application
   To do that, we just have to add a few lines in our app.js file :
   
   

   var express = require("express")
       , swagger = require("swagger-node-express")
       , path = require('path')
       , argv = require('minimist')(process.argv.slice(2))
       , test = require("./models/test")
       , models = require("./models/models")
       , logger = require("./util/log")
       , app = express();
   
   
   // [...]
   // File truncated for reading purposes
   // [...]
   
   // Log application start
   logger.logInfo('snapJob API running on ' + applicationUrl);
   
   // Start the web server
   app.listen(port);
   

   
   
   Let's also update our models/test.js to add informational logs :

   var logger = require("./../util/log");
   
   exports.dummyTestMethod = {
       'spec': {
           description : "Test method",
           path : "/test/",
           method: "GET",
           summary : "This is a dummy test method",
           type : "void",
           nickname : "dummyTestMethod",
           produces : ["application/json"]
       },
       'action': function (req, res) {
           logger.logInfo('dummyTestMethod called', req);
           res.send(JSON.stringify("test is ok"));
       }
   };
   

5. Run the application
   First, we need to update our npm dependencies because we added a new dependency to our node.js app :

   npm install
   

   
   Then we need to run the application :
   

   node app.js
   

6. Application outputs
   At launch, in the console where you previously launched logstash, you should see something like this (logstash should have been launched before you started the node.js application) :

   yoann@LYnux:/opt/logstash-1.4.2$ bin/logstash -f snapJobLogs.conf 
   Using milestone 2 input plugin 'tcp'. This plugin should be stable, but if you see strange behavior, please let us know! For more information on plugin milestones, see http://logstash.net/docs/1.4.2/plugin-milestones {:level=>:warn}
   Using milestone 2 filter plugin 'json'. This plugin should be stable, but if you see strange behavior, please let us know! For more information on plugin milestones, see http://logstash.net/docs/1.4.2/plugin-milestones {:level=>:warn}
   {
          "message" => "{ message: 'snapJob API running on http://localhost:8080',\n  req: undefined } { stream: 'log' } undefined",
         "@version" => "1",
       "@timestamp" => "2014-07-08T21:39:00.160Z",
             "host" => "127.0.0.1:34602",
             "type" => "log",
            "level" => "info"
   }
   

   
   
   Now, if you click on the "Try it out!" button, located here (see previous article) http://localhost:8080/#!/test/dummyTestMethod, you should see a new log line in the logstash console :

   {
          "message" => "{ message: 'dummyTestMethod called',\n  req: { ip: '127.0.0.1', url: '/test/' } } { stream: 'log' } undefined",
         "@version" => "1",
       "@timestamp" => "2014-07-08T21:41:14.092Z",
             "host" => "127.0.0.1:34602",
             "type" => "log",
            "level" => "info"
   }
   

   
   
   Yeay ! \o/
   We did it !
   Next step ? Output to elasticsearch instead of the console !



7. Install elasticsearch
   On Ubuntu, pretty easy step : just download and install the debian package !
   If you're lucky, you should be able to test your installation by browsing the following url : http://localhost:9200/
   ...and get the following json string displayed in your browser :
   

   {
     "ok" : true,
     "status" : 200,
     "name" : "Slyde",
     "version" : {
       "number" : "0.90.10",
       "build_hash" : "0a5781f44876e8d1c30b6360628d59cb2a7a2bbb",
       "build_timestamp" : "2014-01-10T10:18:37Z",
       "build_snapshot" : false,
       "lucene_version" : "4.6"
     },
     "tagline" : "You Know, for Search"
   }

   
   
   
8. Reconfigure logstash
   Let's update our /opt/logstash-1.4.2/snapJobLogs.conf file to something like this:

   input {
    tcp { port => 28777 type=>"log" }
   }
   output {
    elasticsearch { host => localhost }
   }
   
   filter {
    json {
     source => "message"
    }
   }
   

9. View logs with Kibana
   Kibana is embeded with logstash. To run it, just change the way you launch logstash :
   

   bin/logstash -f snapJobLogs.conf web
   

   
   Now browse http://localhost:9292 to see this :
   
   

Pretty nice, huh ? That wasn't so hard after all...

Presentation of the project can be found here.
Source code for this application can be downloaded from here.

Next part : snapJob Part III : Storing and loading data with Apache CouchDB and node.js