JavaScript : console.log debugging pitfalls, rules of thumb for recognizing misleading printouts

Question

I just want to settle this longtime issue so that I can debug with a little bit more sanity.

Issue:

Maybe it's just me, and maybe I'm just having PTSD from console.log printouts screwing with me because of mutation issues.

But anyways, almost anytime I am debugging using printouts created by console.log I always have this little bit of doubt in the back of my head whether my printouts could be misleading because of other factors(i.e a multiplex of asynchronous code and nested scope, or maybe the platform of execution like the browser or terminal).

Just wanted to put a nail in the coffin of my nagging doubts I have anytime I'm trying to use printouts to examine the flow of code at run-time.

Question:

What are the gotchas with printouts with console.log?

Do you refer to [this behaviour](http://stackoverflow.com/a/23392650/1048572)? — Bergi, Feb 02 '16 at 07:44
possible duplicate of [console.log object at current state](http://stackoverflow.com/q/7389069/1048572) — Bergi, Feb 02 '16 at 07:45
@Bergi definitely not a duplicate. I'll update the question to make it even more apparent. — Nick Pineda, Feb 02 '16 at 07:58
I'm not sure why you refer to asynchronous code or nested scopes. They don't have anything to do with `console.log` behaviour. If you mean the [infamous "closure in a loop" issue](http://stackoverflow.com/q/750486/1048572), that's not specific to the console either. — Bergi, Feb 02 '16 at 08:03
Well @Bergi that is the point of the question - to rule out whether mutation was the only gotcha when it comes to console.log(). Sounds weird, but being suspicious of my printouts has been a constant nag when I'm debugging :) — Nick Pineda, Feb 02 '16 at 08:20

score 1 · Answer 1 · edited May 23 '17 at 12:01

Yes, there are some gotchas. The biggest one is that console.log(someObject) will print something that is a reference to that object, so if the value of the object changes it's possible the console.log might show the newer state of the object rather than the object at the moment you wanted.

I personally get around this by making a deep copy of any object I log out. That way I know the state of the object being logged is the state of the object when I logged it. By far the easiest way to make a deep copy of an object is:

var newObject = jQuery.extend(true, {}, oldObject);

So, for log statements just do:

console.log(jQuery.extend(true, {}, oldObject));

Or make it a function:

function deepCopy(oldObject) {
  return jQuery.extend(true, {}, oldObject);
}

console.log(deepCopy(someObject));

There are also things like circular references to worry about.

Moreover, some browsers don't even have a console to log to, so make sure to 1) never put debug code into production, and 2) shim the console.

Edit: Per your comment, here is an example of how to handle async logging with jQuery:

Let's say you are getting lots of messages, and you want to log which message you are getting responses from. If you do this, you'll get confused real quick because the value of messsageId in the function will be changing.

for(var i = 0; i < 10; ++i) {
  getMessage(i);
}

function getMessage(messageId) {
  $.ajax({
    url: 'myScript',
    success: function(data) { console.log('Got data for ' + messageId, data); }
  });
}

// This will most likely give you 10 log statements all with id = 9.

To get around this problem, we can create a closure. Understanding closures is outside the scope of this thread, but basically it will trap the value at the function level:

for(var i = 0; i < 10; ++i) {
  getMessage(i);
}

function onSuccess(messageId) {
  return function(data) {
    console.log('Got data for ' + messageId, data);
  }
} 

function getMessage(messageId) {
  $.ajax({
    url: 'myScript',
    success: onSuccess(messageId);
  });
}

// This will give 10 log statements each with the correct id

So does that mean the print out will always reflect the correct unless a reference issue is happening? Never because of scope or async code? — Nick Pineda, Feb 02 '16 at 07:15
@NickPineda scope and async code are unrelated to `console.log`. The scope of `console.log` will be the same as the function its called in. In terms of async code, see my edit to the answer. — Matthew Herbst, Feb 02 '16 at 07:23
Thanks Matthew! I really should of angled the question more towards that. I just couldn't find the right words when I was trying to ask. — Nick Pineda, Feb 02 '16 at 08:22
I'm going to update it now to make it more obvious for future readers. — Nick Pineda, Feb 02 '16 at 08:23
@vsync `console.debug` has the same pitfalls as `console.log` when it comes to (attempting to) log object states. I've observed it in both Firefox and Chrome. — faintsignal, Nov 29 '16 at 20:48

score 0 · Answer 2 · answered Feb 02 '16 at 07:02

This is an issue all JS developers face when debugging variables which behave as pointers to objects.. You can however clone it to store the then actual representation of the object.

var obj = {"a":0};
var objCloned = JSON.parse(JSON.stringify(obj)); // <---
obj.a = 1;
console.log(obj);
console.log(objCloned);

By the way, yes - using JSON.parse(JSON.stringify(someObject)) is faster than using jQuery's .clone() method, if anyone wonders :)

JavaScript : console.log debugging pitfalls, rules of thumb for recognizing misleading printouts

2 Answers2