11

I would like to log the user_id of the person making a request and the method name of every method called for a javascript class. For example:

35 - log_in
35 - list_of_other_users
78 - log_in
35 - send_message_to_user
35 - connect_to_redis
78 - list_of_other_users

Since everything is async user 35 and 78 might be doing stuff at the same time. So I want to make sure each log line starts with their user_id so I can grep for it and only see one user's activity at a time.

Is there a super clever way to do this without adding logger statements to every method?

Andrew Arrow
  • 4,005
  • 8
  • 37
  • 69
  • Possible duplicate of [How do I debug Node.js applications?](http://stackoverflow.com/questions/1911015/how-do-i-debug-node-js-applications) – Prageeth Liyanage Jun 27 '16 at 16:54

3 Answers3

7

The answer is essentially correct, but here's how to avoid infinite recursion

Javascript

(function () {
  var oldCall = Function.prototype.call;
  var newCall = function(self) {
    Function.prototype.call = oldCall;
    console.log('Function called:', this.name);
    var args = Array.prototype.slice.call(arguments, 1);
    var res = this.apply(self, args);
    Function.prototype.call = newCall;
    return res
  }
  Function.prototype.call = newCall;
})();

Coffeescript

do ->
  oldCall = Function::call
  newCall = (self) ->
    Function::call = oldCall
    console.log "Function called: #{this.name}"
    args = Array.prototype.slice.call arguments, 1
    res = this.apply self, args
    Function::call = newCall
    res
  Function::call = newCall
mthorley
  • 2,372
  • 2
  • 17
  • 7
  • 2
    This is great but could you shed some light about how this works and maybe offer a usage example? It is pretty advance and SE is also for beginners / intermidiate users. :D – AturSams Apr 12 '17 at 07:57
4

This is one alternative, not entirely sure how reliable it is though, it feels a bit wrong:

(function () {
  var oldCall = Function.prototype.call;
  var newCall = function(self) {
    Function.prototype.call = oldCall;
    console.log('Function called:', this.name);
    var args = Array.prototype.slice.call(arguments, 1);
    Function.prototype.call = newCall;
    this.apply(self, args);
  }
  Function.prototype.call = newCall;
})();

As you can see, it overwrites the call function - this creates a slight problem when you try to call console.log() so you need to swap the function back. But it seems to work!

EDIT

Since this is tagged CoffeeScript:

do ->
  oldCall = Function::call
  newCall = (self) ->
    Function::call = oldCall
    console.log "Function called: #{this.name}"
    args = Array.prototype.slice.call arguments, 1
    Function::call = newCall
    this.apply self, args
  Function::call = newCall
James Webster
  • 3,887
  • 27
  • 41
phenomnomnominal
  • 5,246
  • 1
  • 26
  • 46
  • This is going into an infinite recursion for me since slice is called as a function. I had to move the slice call before setting newCall and pass the result as a variable below. Not sure if that works now – Alex Lehmann Feb 03 '14 at 14:19
3

I'm guessing this is a web app, in which case if you are using connect you can use a logger middleware that logs the user and the URL path, which is probably sufficient. Otherwise, you are going to have to do some metaprogramming along the lines of wrapping each function in a wrapper function to do the logging.

function logCall(realFunc, instance) {
    return function() {
      log.debug('User: ' + instance.user_id + ' method ' + realFunc.name);
      return realFunc.apply(instance, arguments);
    };
}

For this to work, your class method's must be named functions, not anonymous.

function sendMessage() {
    //code to send message
    //can use `this` to access instance properties
}
function MyClass(userId) {
    this.userId = userId; //or whatever
    this.sendMessage = logCall(sendMessage, this);
    //repeat above line for each instance method you want instrumented for logging
}
Peter Lyons
  • 131,697
  • 28
  • 263
  • 265