uqbar-project / wollok

Wollok Programming Language
GNU General Public License v3.0
60 stars 16 forks source link

Incorrect stack trace frames order when an error is thrown within a block #807

Closed flbulgarelli closed 8 years ago

flbulgarelli commented 8 years ago

Normally, when an exception is thrown inside a block, you expect to see that failure at the top of the stacktrace. E.g:

>  {2. 4} do: [ :x | self error: 'foo'  ]
Object: nil error: foo
Error(Exception)>>signal (ExcHandling.st:254)
Error(Exception)>>signal: (ExcHandling.st:264)
UndefinedObject(Object)>>error: (SysExcept.st:1415)
optimized [] in UndefinedObject>>executeStatements (a String:1)
Array(SequenceableCollection)>>do: (SeqCollect.st:827)
UndefinedObject>>executeStatements (a String:1)

Or:

irb(main):001:0> [1].each { raise 'foo'  }
RuntimeError: foo
    from (irb):1:in `block in irb_binding'
    from (irb):1:in `each'
    from (irb):1
    from /home/franco/.rbenv/versions/2.0.0-p481/bin/irb:12:in `<main>'

However, see what happens when you reproduce this situation in wollok:

program tests { 
 [1].forEach { throw new Exception("foo") }
}
wollok.lang.Exception: Error while calling native method 'WCollection.fold(WollokObject, WollokObject) with parameters: null, aClosure(acc, e)
  at wollok.lang.List.fold(initialValue,closure) [/wollok.wlk:485]
  at wollok.lang.Collection.forEach(closure) [/wollok.wlk:264]
  at [__synthetic0.wpgm]
  used by: wollok.lang.Exception: Error while calling native method 'Closure.doApply(WollokObject[]) with parameters: [Lorg.uqbar.project.wollok.interpreter.core.WollokObject;@2867adb7
  at wollok.lang.Closure.apply(parameters) [/wollok.wlk:722]
  at wollok.lang.Collection.forEach(closure) [/wollok.wlk:264]
  at wollok.lang.List.fold(initialValue,closure) [/wollok.wlk:485]
  at wollok.lang.Collection.forEach(closure) [/wollok.wlk:264]
  at [__synthetic0.wpgm]
  used by: wollok.lang.Exception: foo
  at [__synthetic0.wpgm]
  at wollok.lang.Closure.apply(parameters) [/wollok.wlk:722]
  at wollok.lang.Collection.forEach(closure) [/wollok.wlk:264]
  at wollok.lang.List.fold(initialValue,closure) [/wollok.wlk:485]
  at wollok.lang.Collection.forEach(closure) [/wollok.wlk:264]
  at [__synthetic0.wpgm]

The stacktrace is a mess, since the most important message is displayed at the bottom. Implementation details like Closure.doApplyand WCollection.fold get your attention instead of the actual problem wollok.lang.Exception: foo

fdodino commented 8 years ago

Ok, after debugging a while, I think issue is in wollok.lang.Closure (wollok.lib):

    @NativeMessage("apply") 
    def doApply(WollokObject... args) {
        val context = closure.createEvaluationContext(args).then(container)
        interpreter.performOnStack(closure, context) [|
            interpreter.eval(closure.expression)
        ]   
    }

Added a try/catching WollokProgramExceptionWrapper, since we are in Java but it is a Wollok Exception:

    @NativeMessage("apply") 
    def doApply(WollokObject... args) {
        val context = closure.createEvaluationContext(args).then(container)
        interpreter.performOnStack(closure, context) [|
            try {
                interpreter.eval(closure.expression)
            } catch (WollokProgramExceptionWrapper e) {
                throw new RuntimeException(e.wollokMessage)
            }

        ]   
    }

Resulting in

Wollok interactive console (type "quit" to quit):
>>> var bloque = { throw new Exception("quark") }
aClosure()
>>> bloque.apply()
wollok.lang.Exception: quark
    at wollok.lang.Closure.apply(parameters) [/lang.wlk:1536]
    at  [/__synthetic0.wpgm:3]
    at  [/__synthetic0.wpgm:3]
    at  [/wollokREPL.wlk:1]

>>> [1].forEach {throw new Exception("foo") }
wollok.lang.Exception: foo
    at wollok.lang.List.fold(initialValue,closure) [/lang.wlk:809]
    at wollok.lang.Collection.forEach(closure) [/lang.wlk:331]
    at  [/__synthetic0.wpgm:3]
    at  [/__synthetic0.wpgm:3]
    at  [/__synthetic0.wpgm:3]
    at  [/wollokREPL.wlk:1]

>>> 
javierfernandes commented 8 years ago

Yeap, but I think this must be abstracted away into a general issue of exceptions in native code.

The wollok interpreter when calls a native method is already handling exceptions. AFAIR it does something like this

  1. if the exception thrown was the Java wrapper for a wollok exception then it throws that same
  2. if it was another java exception then it converts it into a wollok exception and its corresponding java class.

The problem here is that the native code calls back wollok code (evaluates again using the interpreter)

So the flow goes like this

Wollok ---> Java -------------------> Wollok (interpreter)

Now lets see a normal flow without natives

Wollok ----------------------------------------------------------------------> Wollok (throw exception)

       <--- WrappedIntoASpecificJavaException(wollokException)

With "regular" natives

Wollok ----------------------------------------------------------------------> Native (throws a java exception)

       <--- WrappedIntoASpecificJavaException <-- wollok exception <---

java exec

                       convertion here

Wollok ----------------------------------------------------------------------> Native (throws a java exception)

<------------------------------------------------------------------------- wrapperexception

If a wollok exception arises in the second wollok "world" then probably the interpreter is converting it into another exception which is not passed through.

This is my guess

Wollok ------------------------> Native ---------------------------------> Wollok

       <--------- treated as    <--------------------- ??? <-------

wrapped <--------- wexept a java execp not a wollok

We need to test different cases, for this scenario, besides collections and closures. It is an error handling + native issue.

My 2 cents

On Tue, Jul 12, 2016 at 3:19 PM, Fernando Dodino notifications@github.com wrote:

Ok, after debugging a while, I think issue is in wollok.lang.Closure (wollok.lib):

@NativeMessage("apply")
def doApply(WollokObject... args) {
    val context = closure.createEvaluationContext(args).then(container)
    interpreter.performOnStack(closure, context) [|
        interpreter.eval(closure.expression)
    ]
}

Added a try/catching WollokProgramExceptionWrapper, since we are in Java but it is a Wollok Exception:

@NativeMessage("apply")
def doApply(WollokObject... args) {
    val context = closure.createEvaluationContext(args).then(container)
    interpreter.performOnStack(closure, context) [|
        try {
            interpreter.eval(closure.expression)
        } catch (WollokProgramExceptionWrapper e) {
            throw new RuntimeException(e.wollokMessage)
        }

    ]
}

Resulting in

Wollok interactive console (type "quit" to quit):>>> var bloque = { throw new Exception("quark") } aClosure()>>> bloque.apply()wollok.lang.Exception: quark at wollok.lang.Closure.apply(parameters) [/lang.wlk:1536] at [/synthetic0.wpgm:3] at [/synthetic0.wpgm:3] at [/wollokREPL.wlk:1]

[1].forEach {throw new Exception("foo") }wollok.lang.Exception: foo at wollok.lang.List.fold(initialValue,closure) [/lang.wlk:809] at wollok.lang.Collection.forEach(closure) [/lang.wlk:331] at [/synthetic0.wpgm:3] at [/synthetic0.wpgm:3] at [/__synthetic0.wpgm:3] at [/wollokREPL.wlk:1]

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/uqbar-project/wollok/issues/807#issuecomment-232133672, or mute the thread https://github.com/notifications/unsubscribe/AEORWOREipVTThEVE2O5gf4xCbbd_jJPks5qU9qdgaJpZM4JJ3Y4 .

fdodino commented 8 years ago

@javierfernandes you are referring to this

    override eval(EObject e) {
        try {
            stack.peek.defineCurrentLocation = e
            debugger.aboutToEvaluate(e)
            evaluator.evaluate(e)
        } catch (ReturnValueException ex) {
            throw ex // a return
        } catch (WollokProgramExceptionWrapper ex) {
            throw ex // a user-level exception, fine !
        }
        catch (Exception ex) { // vm exception
            throw new WollokInterpreterException(e, ex)
        }
        finally {
            debugger.evaluated(e)
        }           
    }

But, we should separate

Moreover, how can I distinguish here between a native call and a Wollok call? Because I receive a WollokProgramExceptionWrapper, so I throw ex, but I should check whether I come from a native call...

fdodino commented 8 years ago

Left all in branch dev-#807-exception-in-closures

javierfernandes commented 8 years ago

Sample program testing without any change

Wollok side

class Repeater {
    method ntimes(n, closure) native
}

program natives {
    const repeater = new Repeater()

    const closure = { throw new Exception("SoundGarden") }
    repeater.ntimes(1, closure)
}

Java side

package natives

import org.uqbar.project.wollok.interpreter.core.WollokObject

import static extension org.uqbar.project.wollok.lib.WollokSDKExtensions.*

/**
 * @author jfernandes
 */
class Repeater {

    def ntimes(Integer n, WollokObject clos) {
        val closure = clos.asClosure
        closure.doApply()
    }

}

Output

wollok.lang.Exception: Error while calling native method 'Repeater.ntimes(Integer, WollokObject) with parameters: 1, aClosure()
    at natives.Repeater.ntimes(n,closure) [/natives.wpgm:4]
    at  [/natives.wpgm:11]
Caused by: wollok.lang.Exception: SoundGarden
    at  [/natives.wpgm:10]
    at natives.Repeater.ntimes(n,closure) [/natives.wpgm:4]
    at  [/natives.wpgm:11]

With Fer changes in Closure

wollok.lang.Exception: SoundGarden
    at natives.Repeater.ntimes(n,closure) [/natives.wpgm:4]
    at  [/natives.wpgm:11]

Notice that the stack only goes until the native call. Any other further deeper call to wollok code is lost. Only the message of the original exception remains.

Now with a new change on the core of the native method invocation

wollok.lang.Exception: SoundGarden
    at  [/natives.wpgm:10]
    at natives.Repeater.ntimes(n,closure) [/natives.wpgm:4]
    at  [/natives.wpgm:11]

There are two lines that look weird, without a method name. But that's another issue. That's because they are lines defined in a program.

Second item in stack, line 10 is the closure body. Last item, line 11 is the invocation to the native method from the program. Sounds good.

As a program doesn't have any method we are not logging anything there. But as a separated issue we can think if there's a way to add more data there, etc.

fdodino commented 8 years ago

:+1: !