how can I log every method call in node.js without adding debug lines everywhere?

Question

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?

Possible duplicate of How do I debug Node.js applications?

Prageeth Liyanage
– Prageeth Liyanage

2016-06-27 16:54:23 +00:00
Commented Jun 27, 2016 at 16:54 — Prageeth Liyanage
– Prageeth Liyanage, Commented Jun 27, 2016 at 16:54

mthorley · Accepted Answer · 2015-02-24 23:57:09Z

9

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

answered Feb 24, 2015 at 23:57

mthorley

2,6502 gold badges21 silver badges8 bronze badges

Sign up to request clarification or add additional context in comments.

4 Comments

AturSams Over a year ago

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

Amit Kumar Gupta Over a year ago

Not getting the actual function name but

Function called:  Function called: addListener Function called: removeListener Function called: addListener Function called: removeListener Function called: addListener

John Smith Over a year ago

The problem here is this logs every single function call, including native ones. I'm getting huge logs full of "Function called: toString" and "Function called: hasOwnProperty". The output gets unusably long fast. I really just want to log my user-defined functions as they run, not every "toString".

John Smith Over a year ago

Update for anyone with the same problem... I (sort of) namespaced all my important functions (ie funcs={}; funcs.doThis = async function (args) {...;} funcs.doThat = async function (args2) {...;} and then used decorator functions to intercept & log calls to any function in funcs.

Peter Lyons · Accepted Answer · 2013-04-08 22:27:47Z

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
}

James Webster · Accepted Answer · 2015-01-10 23:49:31Z

3

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

edited Jan 10, 2015 at 23:49

James Webster

4,12433 silver badges41 bronze badges

answered Apr 9, 2013 at 4:15

phenomnomnominal

5,5161 gold badge32 silver badges48 bronze badges

1 Comment

Alex Lehmann Over a year ago

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

Collectives™ on Stack Overflow

how can I log every method call in node.js without adding debug lines everywhere?

3 Answers 3

4 Comments

Comments

1 Comment

Your Answer

Linked

Hot Network Questions

Collectives™ on Stack Overflow

3 Answers 3

4 Comments

Comments

1 Comment

Your Answer

Sign up or log in

Post as a guest

Linked

Related