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!