Add stackTrace property to fiber

[mode777]

I was writing a small test runner and noticed that after calling fiber.try, you can only obtain the error text but not the location where the error occured, which makes debugging very cumbersome.

I added fiber.stackTrace in addition to fiber.error. The stack trace is formated on the fly, which means there is no additional performance overhead if you don't use the property.

This also works for fibers which are yielded. It will return null if the fiber hasn't run yet or returned already.

I added two additional tests to show how it works.

var fiber = Fiber.new {
  "s".unknown
}

System.print(fiber.stackTrace) // expect: null
System.print(fiber.try()) // expect: String does not implement 'unknown'.
System.print(fiber.stackTrace) // expect: at new(_) block argument:(main) line 2\n

EDIT: Looks like some commits show up here that should be in main already. Basically, I only want e3f1774 and ad05671. Anyone knows some git magic on how to fix that?

[ChayimFriedman2]

If this is a bug, don't try(): let the fiber kill your program and the stack trace will be printed.

[ruby0x1]

often you want resilience as well as information, which this PR aims for.

[ChayimFriedman2]

Logging and so?

[ruby0x1]

This is not resilient:

let the fiber kill your program

[mode777]

I think there are valid use cases, where you want a detailed error report without killing the vm.

• A test runner that should continue when a test fails
• A scheduler which runs several fibers in parallel
• A web server that will report an error if one request fails

[ChayimFriedman2]

A web server that will report an error if one request fails

Logging and so?

Anyway, remove what I said 😄 You're right.

[mhermier]

Incidentally, doest it work on new fiber and yield fiber? And does it out something useful?

[mhermier]

It would be good to try to compress the stack trace in case of infinite direct recursion. Since the trace as limited output, it possible to not see where the error started.

In addition if the stack trace get trunckated there should be an indication of the situation, so the user does not get confused.

[mode777]

@mhermier It returns null for a new Fiber and works correctly on a yielded Fiber. The current implementation will stop walking the stack after the 16kb buffer was filled.

[mhermier]

(sorry for the noise) Maybe a better solution would be to allow to iterate on stack frames entries, and let wren make the string. It is suboptimal, may have memory implications, but it should be easier to let the user customize the stack trace output.

[ChayimFriedman2]

Maybe a better solution would be to allow to iterate on stack frames

They meant for debugging and not for text processing, IMO. You can process the stack trace and find the function names etc., that reminds me what angularjs used to do... :P

[mode777]

(sorry for the noise) Maybe a better solution would be to allow to iterate on stack frames entries, and let wren make the string. It is suboptimal, may have memory implications, but it should be easier to let the user customize the stack trace output.

I thought about that but felt that the additional complexity was not worth it

[mhermier]

Yes but that info can be used in plain text, viewed inside a debugger and displayed in columns in a table, the user can make a stack trace formatter more to it's liking, or whatever.

And more importantly, we have access to the whole trace, and not possibly a truncated version of it.

[mode777]

Yes but that info can be used in plain text, viewed inside a debugger and displayed in columns in a table, the user can make a stack trace formatter more to it's liking, or whatever. And more importantly, we have access to the whole trace, and not possibly a truncated version of it.

I see the benefits too, I just don't see a simple way of doing it. This means we would need to make some kind of "StackIterator" available that let's you iterate "StackFrame" objects both exposed to wren. Right?

[mhermier]

A simple solution is to do like string does with StringByteSequence. Do something like:

class Fiber {
  foreign iterateStackFrames_(iterator)
  foreign moduleToStringAt_(iterator)
  foreign functionToStringAt_(iterator)
  foreign lineAt_(iterator)

  stackTrace { StackStrace.new(this) }
}

// Lazy implementation example
class StackFrame {
  construct new_(fiber, iterator) {
    _fiber = fiber
    _iterator = iterator
  }

  module  { _fiber.moduleToStringAt_(_iterator) }
  function { _fiber.functionToStringAt_(_iterator) }
  line        { _fiber.lineAt_(_iterator) }

  toString { "at %(module):%(function ) line %( line )" }
}

class StackTrace is Sequence {
  construct new(fiber) {
    _fiber = fiber
  }

  iterate(iterator) { _fiber.iterateStackFrames_(iterator) }
  iteratorValue(iterator) { StackFrame.new_(_fiber, iterator) }

  toString { joint("\n") }
}

The implementation can be lazy or not. Going not lazy has the advantage of being able to compare stacks/make them easy to compare trivially, and could be helpfull in case of implementing a debugger that allows to trace instructions. But it is not an absolute requirement, since if we have access to the data we can make a copy of it.

[mhermier]

If we don't want to bloat core, another possibility is to move this to an extra module and move the foreign functions to StackFrame and change arguments to (fiber, iterator) in the signature.

[mode777]

A simple solution is to do like string does with StringByteSequence. Do something like:

class Fiber {
  foreign iterateStackFrames_(iterator)
  foreign moduleToStringAt_(iterator)
  foreign functionToStringAt_(iterator)
  foreign lineAt_(iterator)

  stackTrace { StackStrace.new(this) }
}

// Lazy implementation example
class StackFrame {
  construct new_(fiber, iterator) {
    _fiber = fiber
    _iterator = iterator
  }

  module  { _fiber.moduleToStringAt_(_iterator) }
  function { _fiber.functionToStringAt_(_iterator) }
  line        { _fiber.lineAt_(_iterator) }

  toString { "at %(module):%(function ) line %( line )" }
}

class StackTrace is Sequence {
  construct new(fiber) {
    _fiber = fiber
  }

  iterate(iterator) { _fiber.iterateStackFrames_(iterator) }
  iteratorValue(iterator) { StackFrame.new_(_fiber, iterator) }

  toString { joint("\n") }
}

The implementation can be lazy or not. Going not lazy has the advantage of being able to compare stacks/make them easy to compare trivially, and could be helpfull in case of implementing a debugger that allows to trace instructions. But it is not an absolute requirement, since if we have access to the data we can make a copy of it.

Thats also what I was thinking of. I think C# does a similar thing. I have a few concerns about this. Bloating core and the overall code base is one of them, I also think we will need to exchange the iterator with a pre-filled list. Otherwise we would be able to run the fiber between iterations, which sounds like a recipe for disaster.

I would definitely be willing to give such an implementation a try but I would like to hear some more opinions on that before putting any more work in it.

[mhermier]

One solution to mitigate the bload is to lazy import StackTrace by doing:

class Fiber {
  stacktrace {
    import "what_ever_module_name" for StackTrace
    return StackTrace.new(this)
  }
}

[mode777]

One solution to mitigate the bload is to lazy import StackTrace by doing:

class Fiber {
  stacktrace {
    import "what_ever_module_name" for StackTrace
    return StackTrace.new(this)
  }
}

Possible but using a module external of core for accessing Wren internals seems a little odd. It might be possible to expose stack-walking functionality to the public C Api and let people implement the functionality themselves - but this seems overly complex to me

[mhermier]

Just thought about a simpler implementation that don't need a separated module:

class Fiber {
  foreign iterateStackFrames_(iterator)
  foreign moduleAt_(iterator)
  foreign functionAt_(iterator)
  foreign lineAt_(iterator)

  stackTrace {
    var trace = []
    stackTrace {|module, function, line|
       trace.append("at %( module ):%( function ) line %( line )")
    }
    return trace.join("\n")
  }

  stackTrace(cb) {
    var iterator = null
    while (iterateStackFrames_(iterator)) {
      cb.call(moduleAt_(iterator), functionAt_(iterator), lineAt_(iterator))
    }
    return cb
  }
}

[mode777]

@mhermier looks good. I'll have a look into it.

[mhermier]

For implementation of the primitives make the things simple. Iterator is the index on the array, and make iterate skip the unwanted indexes. That way a count primitive can be added so we can also visit the full stack indexes.

[ChayimFriedman2]

I now thought about another use-case, inspired by JS and DOME: DOME has deprecated methods, Color.new(_,_,_) and Color.new(_,_,_,_). Like good deprecated methods, they print a warning. However, it can be hard to track the source, esp. if for example it's inside an external library you use. This would be a nice benefit if they would print the stack trace. In JS (although non-standard) developers usually create a new Error and print its stack property:

var Color = {
  new(r, g, b) {
    console.warn('Color.new(_,_,_) is deprecated. Please use Color.rgb(_,_,_) instead.');
    console.warn(new Error().stack);
    // ...
  },
};

If we have the stackTrace property, we could copy this idiom to Wren:

class Color {
  construct new(r, g, b) {
    System.print("Color.new(_,_,_) is deprecated. Please use Color.rgb(_,_,_) instead.")
    System.print(Fiber.new {}.stackTrace);
    // ...
  }
}

[mhermier]

This raise an interesting question/problem. Since we can get the current fiber, we can get the current stack trace doing Fiber.current.stackTrace. But the implementation I proposed does not have a stabilised output since the thread is in flight. There are ways to solve this issue, but it does requires to have access to the stack frame count to ignore anything after (including) the call to stackTrace.

[ChayimFriedman2]

@mhermier I haven't reviewed your implementation in-depth, just took a glance, so sorry if this is a noob question: why doesn't it allow getting the stack trace of the current fiber?

[mhermier]

It is not that it doesn't allow, the problem is that iterator stack is not stable. While it is not truly a problem in practice with the implementation, it will expose the fact that stackTrace is a function call.

[mhermier]

And to make things a little bit problematic, the behavior depends if it the active Fiber or a stale one.

[mode777]

My current implementation seems to handles this case just fine. I'm not sure about the implications of your proposed implementations.

[joshgoebel]

Anyone know the status of this? Really need it for test runners... Some errors are impossible to debug without a working stack trace with a line number (such as method [] doesn't exist on null, or some such, etc)... Right now I'm considering having to wrap each individual test inside it's own shell process just to get a stack trace (when the VM/CLI dies)... workable I think, but far from optimal - and means I need yet another language to wrap Wren since we also don't have Process.exec in CLI yet.

[mhermier]

I still have the patch on my branch, but I'm not really happy how it turns out. Thinking at it today, maybe it should be part of the mirror API with a FiberMirror.