Print assertion to the console before erroring out?

[samreid]

When running with ?ea and the console open, it takes me longer than necessary to find the assertion message. How do others get around (or not have) this problem?

Should we print the assertion error to the console before throwing error?

Adding this line to assert.js looks like it will make my life much easier:

console.log( 'Assertion failed: ' + message );

Assigned to @jonathanolson for discussion, but @pixelzoom @jbphet @jessegreenberg and @phetsims/aadish may want to discuss as well.

[samreid]

Marking for developer meeting in case we haven't closed the issue by then.

[pixelzoom]

Turn off "Pause for exceptions" and the assertion will immediately be printed to the console.

[samreid]

Is there a way to get the best of both worlds? A nice error message I can immediately see, and also pausing so I can inspect stack trace? @pixelzoom do you normally leave "Pause for exceptions" checked or unchecked?

[samreid]

@jbphet said:

I generally just hover over the 'message' variable, and it tells you what the error is. Sometimes I just type 'message' at the console.

[samreid]

Sometimes my chrome debugger doesn’t show the paused line on the screen, perhaps I have too small of a screen, or a buggy Chrome, but I have to scroll up and down a few lines to find the line it is paused on.

Any problems with always printing the message to the console?

Or if this is objectionable, then perhaps another query parameter ?eaconsole

[samreid]

@jbphet said:

No objections, as long as it doesn't end up printing twice when the console is closed (and then opened).

[samreid]

I think that would print twice. I took a screenshot (assertion hit with console closed):

[pixelzoom]

@samreid asked:

@pixelzoom do you normally leave "Pause for exceptions" checked or unchecked?

I usually leave "Pause for exceptions" checked. If I hit an exception, I press the "Paused in debugger" button. If I need to iterate on debugging an exception, then I'll turn "Pause for exceptions" off so that I see the message without having to press the "Paused in debugger" button. Doesn't seem like a big deal, but perhaps I'm not clear on how this is impacting your work flow.

Imo, I don't think we should print the message twice. And the message should be passed to (and handled by) the Error instance rather than printed directly to the console.

[pixelzoom]

@samreid said:

When running with ?ea and the console open, it takes me longer than necessary to find the assertion message. How do others get around (or not have) this problem?

To clarify... Does "longer than necessary" mean that you have "Pause for exceptions" enabled, and that you don't want to have to push the "Paused in debugger" button when you hit an exception? If that's the case then I suggest that you run with "Pause for exceptions" disabled, and only enable it when you need to do so.

[samreid]

I usually leave "Pause for exceptions" checked.

OK so you normally have it pause on exceptions.

If I hit an exception, I press the "Paused in debugger" button.

So now that you have hit an exception, you uncheck the "paused in debugger" option in order to see the error message. But then you lose your stack trace, right?

[pixelzoom]

So now that you have hit an exception, you uncheck the "paused in debugger" option in order to see the error message. But then you lose your stack trace, right?

The "Paused in debugger" button appears at the top-center of the browser window. It's not something you "uncheck". Pressing it merely causes executing to continue, and the Error message is printed to the console. Double-clicking on the filename to the right of the Error message (typically assert.js) displays the stack trace.

[samreid]

Thanks! I'll try that.

[pixelzoom]

Here's the "Paused in debugger" button for a startup exception in function-builder:

[jonathanolson]

Mini-guide to how I would use Chrome's debugger for this:

Depending on your screen resolution, you'll have the 'compact' debugger or 'wide' debugger (no clue what terms they use, but the layout significantly changes).

In general, I typically don't care about the exact message, but for assertions I'll go 1 stack frame up to where the assertion statement actually exists, as I can immediately inspect any local variables (most helpful). I'll also show how to get the actual logged message in both cases.

Compact form:

I've found it quick to double-click on the message, copy it, and paste it wherever I like (sometimes in console) if I really need the message itself. Usually don't bother.

Going up one level in the stack gives me more information:

Wide form:

It's more inconvenient to get the message here. Need to collapse the call stack usually to view the message, OR just go up one level to view the assertion directly:

With call stack collapsed to view the message (same double-click to copy):

And the place in the stack the assertion was caused:

Also, I almost always leave "pause on unhandled exception" on. If I don't want errors to lock things up, I'll typically close the dev tools until I get the sim in the state I would need.

[samreid]

Thanks @jonathanolson and @pixelzoom for helping me understand how you deal with this in practice--it is something I (and I suspect everyone) deal with many times per day during PhET development.

@pixelzoom Pressing that button with the mouse seems like it has the desirable behavior of (a) keeping an equivalent current stack frame so that stack vars can be inspected and (b) printing the error message to the console.

Is there a way to do this without having to mouse? The popup for the button says F8 does the same thing, but when I try F8 it instead loses the stack frame and goes to the next error.

@jonathanolson I find it interesting that you rarely need to know the text of the assertion--usually this is very important for me. I think your way of navigating the stacks is useful and similar to what I have done.

I have tried printing a console.log from assert.js, and leaving "pause on exceptions" checked, and I am getting the best of both worlds--seeing the error immediately and having the stack paused in the right frame with no additional thinking, reflexive mousework, etc. If others want to give this a try, feel free, otherwise if you have a pattern that already works perfectly for you, then no need to change :)

[pixelzoom]

Is there a way to do this without having to mouse? The popup for the button says F8 does the same thing, but when I try F8 it instead loses the stack frame and goes to the next error.

F8 works fine for me on Mac OS 10.11.1. Here's how I have function keys configured (System Preferences > Keyboard), in case that matters:

[samreid]

I'm using OS X 10.11.1 as well, with newly updated Chrome 47.0.2526.80 (64-bit). Here's what I see with a single artificial assert in acid-base-solutions-main.js when clicking that button, now I lose the stack:

[samreid]

By contrast, here is what happens with console.log in assert.js:

This seems extremely convenient because you can see the name of the error and use the stack variables immediately. The only price we pay is that it prints the assertion message twice when the console is closed then opened. Is that such a terrible price to pay? I'm having trouble understanding why this change wouldn't immediately benefit all PhET developers.

[jonathanolson]

I'm not really against console logging of the error. This is particularly helpful if you have newlines in your error message (say GLSL shader complication fails and prints out the entire shader). In that case, reading the error message with newlines is important, and somewhat of a hassle.

Logging to the console has the potential to cause the console log to take up a lot of memory (say Chrome previously collapsed 1,000,000 consecutive error statements into one line, now you'll have 1,000,000 console lines and 1,000,000 error lines), but I can't really come up with a reason why this would be a problem.

The duplication doesn't particularly annoy me, although if we conceptually treat console output like stdout and errors as stderr, you wouldn't typically want errors on stdout. Since I don't see the console log output in the browser being used for many things besides debugging, I'm fine with adding the console.log (but please check for window.console and window.console.log existence).

[pixelzoom]

In https://github.com/phetsims/assert/issues/1#issuecomment-163369379, @samreid wrote:

Here's what I see with a single artificial assert in acid-base-solutions-main.js when clicking that button, now I lose the stack:

You have not lost the stack. As described in https://github.com/phetsims/assert/issues/1#issuecomment-163331137... Double-clock on the file name (in this case assert.js) that is to the right of the error message, and the stack trace will expand below the error message.

[pixelzoom]

I'm having trouble understanding why this change wouldn't immediately benefit all PhET developers.

I'm having trouble understanding why we need this, because I have no problem accessing error messages or stack traces with the current implementation of assert.js. Let's figure out why this is a problem for @samreid before doing something that makes it more difficult for others.

[samreid]

Consensus from Dec 10 meeting: we will add the console.log message and leave the door open to rediscuss this next week, in case opinions have changed.

[samreid]

@jonathanolson is this an appropriate way to check for the existence of console.log?

console && console.log && console.log( 'Assertion failed: ' + message );

[samreid]

Committed above, @jonathanolson or @pixelzoom or others please reopen if you see any problems here.