JavaScript to server logging using AJAX (JQuery+Rails)

Recently I decided to investigate some of issues which users were experiencing with my current KurierPlikow.pl upload app. The problem was purely client side thus there was a need of client side logging. I write one using JQuery and Ruby on Rails Metal as back-end, but it can be easily ported to any other framework.

Below is JavaScript part which passes log messages as AJAX calls. Don't forget to load JQuery before.

var  Logger = {
  sid: '------------',   //logging scope ID - e.g. unique page visit ID
  counter: 0,
  log: function log(level, sid, message) {
    ct = ++this.counter; //ASAP - avoid races
    $.post('/logger',{level:level,sid:this.sid, counter:ct, message:message});
  },
  e: function(message) { this.log('E',this.sid,message) },  //error
  w: function(message) { this.log('W',this.sid,message) }, //warn
  i: function(message) { this.log('I',this.sid,message) },  //info
  d: function(message) { this.log('D',this.sid,message) }  //debug
}

Here is example call of above logger:

Logger.sid = "AbCd12345678";
Logger.e("Error occurred");
Logger.w("Warning .... ");
Logger.i("Starting process");
Logger.d("entering method foo");

The AJAX request posts parameters:

• level - first letter of log importance level
• sid - unique scope ID to identify client - site visitor ID, page visitor ID, flow ID etc.
• counter - message sequence number in relation to sid
• message - log message

Now, for a server side receiving part I used Rails 2.3 Metal layer to get best performance available. I created the receiver class as app/metal/client_logger.rb.

require(File.dirname(__FILE__) + "/../../config/environment") unless defined?(Rails)
require 'rack/utils'

class ClientLogger
  LOG_PATH = File.dirname(__FILE__) + "/../../log/client.log"
  def self.call(env)
    if env["PATH_INFO"] =~ /^\/logger/
      begin
        req = Rack::Request.new(env)
        params = req.params
        item = "#{Time.now.strftime("%m-%d %H:%M:%S")} "+
            "(#{params['level']}) [#{params['sid']}:#{"%2d" % params['counter']}] "+
             "#{params['message'].gsub('\r?\n','\\n')}"
        File.open(LOG_PATH, 'a+') {|f| f.write("#{item}\n") }   //TODO optimize
        [200, {}, [params['test'] ? item : "OK"]]
      rescue
        [200, {}, ["ERR"]] #ignore all errors
      end
    else
      [404]
    end
  end
end

Above code receives /logger request and assembles log entry from request parameter and then saves it to log file. As we don't want any other issues caused by logger, all errors are ignored. Important: File access part in above code definitely needs optimization - a buffer or a permanently opened file should be used.

This is fragment of one of my client logs generated by all above code:

12-16 23:46:06 (I) [Fj5EuXxpgaFf: 7] start(id=file0,.....jpg,size=33575), fileQueue.length=6
12-16 23:48:36 (I) [Fj5EuXxpgaFf: 8] onbeforeunload
12-16 23:54:20 (I) [xPjo9bznEo7f: 1] start session
12-16 23:54:20 (I) [xPjo9bznEo7f: 2] yui:contentReady
12-16 23:54:20 (D) [xPjo9bznEo7f: 3] yui:contentReady2
12-16 23:54:33 (I) [xPjo9bznEo7f: 4] yui:fileSelect(evt.fileList.length=undefined
12-16 23:54:38 (I) [xPjo9bznEo7f: 5] data:start(...)
12-16 23:54:39 (I) [xPjo9bznEo7f: 6] data:success(data=...)
12-16 23:54:39 (I) [xPjo9bznEo7f: 7] start(id=file0,name=....pdf,size=795612), fileQueue.length=4
12-16 23:54:41 (I) [xPjo9bznEo7f: 8] yui:uploadStart(id=file0)

You can see that using fixed length IDs gives nicely readable log entries. Enjoy!