GetCallStack reports wrong line numbers

[fatcerberus]

The GetCallStack debug command appears to suffer from the same issue as described for Duktape.act() in #143: The line number is for the instruction AFTER the call, rather than the call itself. I'm presuming it's the same root cause.

[svaarala]

Sounds probable, the 'PC' in the internal data structures is always for the next instuction to execute. I'll take a look at this in a bit.

[svaarala]

Yep, the issue is here: https://github.com/svaarala/duktape/blob/master/src/duk_debugger.c#L1154.

Line numbers are interesting: for the current PC/line people (me included) expect the debugger to point to the next instruction which is not yet executed. However, for the callstack below us it's usually expected that the line points to the current instruction because it's still conceptually in progress.

So when dumping the callstack, should the pc/line for the topmost activation reflect the next instruction and for others the current instruction?

[svaarala]

Error .stack will report "next pc/line" for all callstack levels too. That should be changed to match what the debugger shows.

[svaarala]

Ah, actually no. When the tracedata is collected, PCs are decremented by one so that in .stack they refer to the running opcodes. This applies to all callstack levels so that in a traceback the "line" will refer to the currently executing instruction, even for the topmost activation. For errors that actually does make sense, as the current instruction in the topmost activation is the offending one.

[svaarala]

Ok, so to summarize:

• Debugger current PC/line in Status notification should point to the next instruction to execute. This is intuitive for breakpoints because breakpoints pause execution before the relevant instruction is executed.
• Debugger current PC/line in GetCallStack for callstack levels below top should be for the current instruction being executed; this also matches .stack. Those calls are conceptually in progress.
• Debugger current PC/line in GetCallStack for the callstack top could have two plausible values. If it pointed to the next instruction to execute, it'd match Status. If it pointed to the current instruction being executed, it'd match .stack. Since it can't match both, I'd probably favor it matching Status. This seems intuitive because unlike for the other callstack levels the "current instruction" has already been completed and its results are visible in e.g. variable values. The executor is actually in-between instructions for the callstack top.

[fatcerberus]

Yes, for activations other than the topmost one the correct value isn't really in question: The only logical instruction to call out is the function call currently in progress.

For the callstack top while the debugger is paused, the bytecode executor is logically between instructions, however I wouldn't say either side is equally plausible: I would intuitively expect that clicking the current call in a stack view would highlight the exact same line highlighted when execution was first paused--i.e. the one which will be executed if a StepOver is performed. This matches, e.g. MSVC's behavior.

For .stack the current instruction makes sense, since you want a stack trace to show the line that generated the error. The next instruction is irrelevant in that context.

[fatcerberus]

Just to verify, I can fix this locally by simply subtracting 1 from curr_act->pc, right?

[svaarala]

Yes, but you need to check pc isn't zero (it can be for native functions and probably in some corner cases) before subtracting. And also value stack top may need different handling.

I'll work up a fix branch for this. Thanks for bringing this up, it was a clear oversight.

[svaarala]

Here's the branch: https://github.com/svaarala/duktape/compare/debugger-callstack-line-gh281

Here's a snapshot if you want to try it out: http://duktape.org/snapshots/duktape-1.2.99-20150815144710-v1.2.0-349-gb2b8784.tar.xz

[fatcerberus]

It looks like quite a bit was changed in the branch, so I'll try the snapshot out later today and let you know the results.

[svaarala]

I only changed the GetCallStack handling of PC/line and some comments.

[fatcerberus]

Okay, yeah, I see it now, you rewrote a few comments to make them more descriptive. That's one thing that's always impressed me with Duktape, how well documented the code is. :)

[fatcerberus]

Out of curiosity, when is the stack trace for errors created? When the Error is constructed, or when it is actually thrown? In most cases this is done in one statement, but sometimes the constructed error object might be manipulated first, in which case the construction and the throw could be on different lines.

[svaarala]

It's created when an Error instance is constructed, here: https://github.com/svaarala/duktape/blob/master/src/duk_api_call.c#L391-L399

It seems like a bit of an odd place (at least for my intuition) but augmenting an error at throw time would sometimes be incorrect - and an error can actually be thrown multiple times which would then be somewhat confusing.

[fatcerberus]

The snapshot works great, all lower stack entries report the line number of the function call-in-progress. :)

[svaarala]

Okay, merged to master. Thanks!

[fatcerberus]

No problem, always glad to help!

On a somewhat related note, how are native functions reported in a stack dump? If possible I'd like to be able to differentiate any non-JS calls when populating a callstack window.

[fatcerberus]

So it doesn't look like this was actually merged? Either that or just not pushed to GitHub yet...

[svaarala]

Forgot the push, it's now in.

[fatcerberus]

Regression: Latest master now reports previous instruction for top of callstack (it doesn't match Status)

[fatcerberus]

Okay, did some digging, and I'm thinking the bug is here:

if (i != curr_thr->callstack_top && pc > 0) {

Shouldn't that be callstack_top - 1?

[svaarala]

Yeah, that looks wrong. Fixed in master.

[svaarala]

Here's a snapshot from master with the fix: http://duktape.org/snapshots/duktape-1.2.99-20150822123309-v1.2.0-367-gc44072c.tar.xz

[fatcerberus]

That snapshot fixed it, thanks. I noticed this one right away because my debugger actually bases the line to highlight on the callstack now instead of the status notification (I have my reasons for this. 😉).