Stack Trace for ASH?

fronobulax

Developer
Staff member
When my debugger and imagination fail me I will often resort to (Java) Thread.dumpStack() so I can at least figure out how I got into the mess I am trying to fix. I am trying to debug and fix someone else's ASH script and there is just too much going on for grep and print to help me localize and confirm.

I know there is some tracing ability available in ash but my recollection is that it is execution tracing which is somewhat more information that I need or want to sort through.

So, is there something I am missing, that is already there?

If not, is anyone else besides me interested in a new ash function, dumpStack(boolean abort)?

Without digging into the code to verify what I think is possible is feasible, I'm hoping for something like

dumpStack() called by testMe() in script.ash at line 3
testMe() called by somethingElse() in script.ash at line 27
somethingElse() called in main() in bigOne.ash at line 7.

If abort is true then dumpStack prints and then aborts, otherwise it prints and continues (returns).

Good idea? More trouble than it is worth? Only needed because of my lack of imagination?

Thanks.
 

heeheehee

Developer
Staff member
I actually have a working prototype of stack traces on errors for ASH, although it's hacky, and I'm not sure how useful it'd actually be.
 

Attachments

  • stacktrace.patch
    9.6 KB · Views: 88

Veracity

Developer
Staff member
Doesn't seem all that hacky to me, unless you mean maintaining a call stack which is otherwise not needed for ASH execution. Other "interpreters" I've worked with maintained their own call stacks, but we just let Java do that for us. The advantage of the former is that it's easier to unwind to an arbitrary point - and to examine the call stack, as needed here - but we can do that via Java's catch/throw, as needed.

What I first thought when I read this was to request an actual Java stack trace and walk up it looking for function calls, but your solution is a lot simpler, at the expense of extra memory usage during normal execution, whether or not a stack trace will ever be needed.

Personally, I would not have STACK_LIMIT control how many frames we keep, but how many are printed out. Unless that is intended to not exhaust memory on infinite recursion, or something?
 

heeheehee

Developer
Staff member
Yeah, that was the idea, although you'll run into a stack overflow before then, It might throw a NPE if you go, say, STACK_LIMIT*2 frames deep, then try to return from all of them.
 

heeheehee

Developer
Staff member
Pretty straightforward change to make the change Veracity suggested.
Code:
	public void pushFrame( String name )
	{
		frameStack.push( new CallFrame( name, this.lineNumber, this.fileName ) );
	}

	private String getStackTrace()
	{
		...
		int stacks = 0;

		while ( frameStack.size() != 0 && stacks < STACK_LIMIT )
		{
			...
			stacks++;
		}
		return s.toString();
	}

I think it might potentially be useful to developers if there were a preference to set STACK_LIMIT, instead of having it be a hardcoded constant.
 

fronobulax

Developer
Staff member
I'm going to run with this. It is not quite what I was going to do but other than aesthetics there is no reason why editing a script to add "dumpStack(true)" is any better than "int i = 1/0" My quick test suggested a missing pop but I need to dig in some more. Thank you for the partial solution.
 

heeheehee

Developer
Staff member
Well, sometimes you want to just print out the stack trace without stopping execution. abort() doesn't currently trigger a stack trace, although maybe it should.

Pushes occur when entering a function call; pops occur when returning from a function. I suppose pushing the stack frame containing main is hardcoded, and it isn't popped off after the fact. But I don't think that should matter, since all top level commands are executed before main, and the interpreter should go away when main returns.

And no, this *shouldn't* affect calling a different function's main, since that should through the usual function lookup and execute. This case is special because Mafia needs to be able to prompt for unspecified parameters.

I can't see it pushing the frame if you're just importing a script, since then it shouldn't execute main. Although, if you want to be absolutely sure (seeing as all my speculation is just reasoning why it *shouldn't* happen),
Code:
	result = main.execute( this, values );
+	// returned from main; remove frame
+	this.popFrame();
in executeScope() of Interpreter.java should do the trick.
 

heeheehee

Developer
Staff member
Well, sometimes you want to just print out the stack trace without stopping execution. abort() doesn't currently trigger a stack trace, although maybe it should.

Pushes occur when entering a function call; pops occur when returning from a function. I suppose pushing the stack frame containing main is hardcoded, and it isn't popped off after the fact. But I don't think that should matter, since all top level commands are executed before main, and the interpreter should go away when main returns.

And no, this *shouldn't* affect calling a different function's main, since that should through the usual function lookup and execute. This case is special because Mafia needs to be able to prompt for unspecified parameters.

I can't see it pushing the frame if you're just importing a script, since then it shouldn't execute main. Although, if you want to be absolutely sure (seeing as all my speculation is just reasoning why it *shouldn't* happen),
Code:
	result = main.execute( this, values );
+	// returned from main; remove frame
+	this.popFrame();
in executeScope() of Interpreter.java should do the trick.

This change sometimes triggers an EmptyStackException which didn't exist before.
 

fronobulax

Developer
Staff member
This change sometimes triggers an EmptyStackException which didn't exist before.

Yeah. I was seeing that, didn't figure it out and got distracted because the Real World (i.e Work) required way too much attention. But this is on my list. Maybe Project #2 if I end up retiring next month, much sooner than planned :)
 

heeheehee

Developer
Staff member
Huh, this never got merged in; I'd just been assuming it did at some point. I guess, uh, bump for visibility?

It mostly applies out of the box (there was a tiny conflict in Operator.java), and I notice there's a typo in FunctionCall.java (I apparently misspelled this.target().getName() as "main". I didn't merge in the changes in #6.

I think if I were to make other changes, I'd also prefer to output the error as KoLConstants.LINE_BREAK + "\u00A0\u00A0" instead of the corresponding HTML ("<br>  "), since that renders just fine both in the gCLI as well as directly on the command line, and maybe also expose this to ASH somehow (e.g. string[] get_stacktrace(), or possibly a record with function / file / line number).
 

fronobulax

Developer
Staff member
I remember playing with this but don't recall whether I decided you were going to finish and commit or whether something did not work as I expected and I lacked the time to resolve that. In any event how shall we proceed?
 

heeheehee

Developer
Staff member
I remember playing with this but don't recall whether I decided you were going to finish and commit or whether something did not work as I expected and I lacked the time to resolve that. In any event how shall we proceed?

I guess part of this is a request for various script authors to provide input regarding what they want, e.g. how important is exposing get_stacktrace() to ASH? Is just printing the stack on error enough? Should abort() print a stacktrace (possibly controlled by preference)?

Part of the bump is also a request for various enterprising users to actually try out the patch (I guess I can spin out a new one; attached).
 

Attachments

  • stacktrace.patch
    10.7 KB · Views: 34

fronobulax

Developer
Staff member
So I installed the patch but did nothing to "test" it.

I ran Veracity's meat farm script using WHAM for combat. It brought my system to a point of unresponsiveness using 99% of the CPU and 50% of the memory. (That latter is often observed, the former is not). I went through the kill/restart process a couple of times and my impatience with the lack or response seemed to occur at about 83 adventures at least twice. I reverted the patch, re-ran and responsiveness returned to what I expected.

I'm thinking either the patch, or the patch in combination with WHAM, uses a lot of resource (memory?) and that inhibits performance. I'm mentioning this in case you get a chance to look at it before I have the time to dig.
 

heeheehee

Developer
Staff member
So, the change in #11 (that I incorporated into the most recent patch) obviously means we're tracking an additional object per call frame (whereas my original code had limited it to 10). Tracking the stack inherently also adds a few operations per function call (object creation, stack push, stack pop).

Thinking about it, I would not be surprised if a script with lots of function calls (even if it doesn't have a particularly deep stack) generates additional load for garbage collection. I suppose the obvious thing to do is reuse these CallFrame objects if possible, similar to the ObjectPool model we have elsewhere (except instead of internment we implement arena allocation).
 

heeheehee

Developer
Staff member
Inelegant implementation attached.
 

Attachments

  • stacktrace.patch
    11.2 KB · Views: 34
Last edited:

fronobulax

Developer
Staff member
Better but still a noticeable performance hit. I guess I need to remember how to use the profiler and save some turns to burn while doing so.
 

heeheehee

Developer
Staff member
Better but still a noticeable performance hit. I guess I need to remember how to use the profiler and save some turns to burn while doing so.

Hrm. I've additionally swapped out the LinkedLists for ArrayLists, since I suspect that the internal implementation (with Nodes and all that) might also create more GC pressure by adding / removing nodes.

Beyond that, I'm at a loss as to how this patch could be generating so much additional CPU load (I haven't seen significant impact on my end). If it's not too much effort for you, a dump of heap usage / growth (or just a typical CPU profile) would be valuable.
 

Attachments

  • stacktrace.patch
    11.1 KB · Views: 31

fronobulax

Developer
Staff member
Suffering from Monday Morning Brain Flatulence and ran out of time and turns before I accomplished what I hoped.

Running from a command line, which doesn't swallow some Java exceptions, the code definitely is running out of heap space and throwing the appropriate error.

I got a heap dump but none of the tools I have could read/display it. May have been too big or may have been because it was taken after the heap memory error, but in any event I need to try again.

I did get a snapshot with FlightRecorder but, other than seeing ....textui.parsetree.Value and ArrayLists taking up a lot of space I don't quite understand what I am seeing.

Tomorrow's another day :)
 
Top