#2054 Problem of Reduced Stack Trace

Akcelisto Sat 10 Nov 2012

Info loss in stack trace make many pain when I try to found err in my code because almost my code is called via actors. Please, fix Fantom or give me workaround.

Early I try to explain this problem but without success #1933. Now I make next try with maximum of details.

Problem of Reduced Stack Trace:

  1. Stack trace is reduced. This make debug hard.
  2. Reducing appears when code is called via send(msg).get.
  3. There is two kinds of errs: good and evil. Good kind have proper stack, evil kind have reduced stack.
  4. This problem not have revelations with disappearing of trace when code called via send without get.

Actual:

There is evil kind of err with reduced stack trace.

Expected:

All of errs have full stack trace as good kind of errs.

Code:

using concurrent

class TraceTest{
  static Void main(){
    try{
      Complicated().methodA
    }catch(Err e){
      echo("standard stack for methodA (this is call without actors)")
      e.trace
    }
    echo

    try{
      Complicated().methodB
    }catch(Err e){
      echo("standard stack for methodB (this is call without actors)")
      e.trace
    }
    echo

    try{
      ComplicatedActor().methodA
    }catch(Err e){
      echo("reduced stack of evil err (this is call via actors)")
      e.trace
    }
    echo

    try{
      ComplicatedActor().methodB
    }catch(Err e){
      echo("proper stack of good err (this is call via actors)")
      e.trace
    }
  }
}

class Complicated{
  Void methodA(){
    methodAA
  }

  Void methodAA(){
    methodWithNpe
  }

  // method with evil kind of err
  Void methodWithNpe(){
    Str? str
    str.capitalize
  }

  Void methodB(){
    methodBB
  }

  Void methodBB(){
    methodWithNullErr
  }

  // method with good kind of err
  Obj methodWithNullErr(){
    Str? str
    return str
  }
}

const class ComplicatedActor : Actor{
  new make():super(ActorPool()){
    send(null)
  }

  override Obj? receive(Obj? msg){
    if(msg==null){
      Actor.locals["complicated"] = Complicated()
    }else{
      Complicated complicated := Actor.locals["complicated"]
      if(msg=="a"){
        complicated.methodA
      }else if(msg=="b"){
        complicated.methodB
      }else{
        throw Err("Unknown msg")
      }
    }
    return null
  }

  Void methodA(){
    send("a").get
  }

  Void methodB(){
    send("b").get
  }
}

Ouput:

standard stack for methodA (this is call without actors)
sys::NullErr: java.lang.NullPointerException
  fan.sys.FanStr.capitalize (FanStr.java:448)
  rateResearch::Complicated.methodWithNpe (ReducedStack.fan:50)
  rateResearch::Complicated.methodAA (ReducedStack.fan:44)
  rateResearch::Complicated.methodA (ReducedStack.fan:40)
  rateResearch::TraceTest.main (ReducedStack.fan:6)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)

standard stack for methodB (this is call without actors)
sys::NullErr: Coerce to non-null
  fan.sys.NullErr.makeCoerce (NullErr.java:38)
  rateResearch::Complicated.methodWithNullErr (ReducedStack.fan:64)
  rateResearch::Complicated.methodBB (ReducedStack.fan:58)
  rateResearch::Complicated.methodB (ReducedStack.fan:54)
  rateResearch::TraceTest.main (ReducedStack.fan:14)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)

reduced stack of evil err (this is call via actors)
sys::NullErr: java.lang.NullPointerException
  concurrent::Future.get (Future.java:100)
  concurrent::Future.get (Future.java:57)
  rateResearch::ComplicatedActor.methodA (ReducedStack.fan:90)
  rateResearch::TraceTest.main (ReducedStack.fan:22)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)
  sys::NullErr: java.lang.NullPointerException
    concurrent::Actor._dispatch (Actor.java:236)
    concurrent::Actor._work (Actor.java:199)
    concurrent::ThreadPool$Worker.run (ThreadPool.java:255)

proper stack of good err (this is call via actors)
sys::NullErr: Coerce to non-null
  concurrent::Future.get (Future.java:100)
  concurrent::Future.get (Future.java:57)
  rateResearch::ComplicatedActor.methodB (ReducedStack.fan:94)
  rateResearch::TraceTest.main (ReducedStack.fan:30)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)
  sys::NullErr: Coerce to non-null
    fan.sys.NullErr.makeCoerce (NullErr.java:38)
    rateResearch::Complicated.methodWithNullErr (ReducedStack.fan:64)
    rateResearch::Complicated.methodBB (ReducedStack.fan:58)
    rateResearch::Complicated.methodB (ReducedStack.fan:54)
    rateResearch::ComplicatedActor.receive (ReducedStack.fan:81)
    concurrent::Actor._dispatch (Actor.java:228)
    concurrent::Actor._work (Actor.java:199)
    concurrent::ThreadPool$Worker.run (ThreadPool.java:255)

brian Sat 10 Nov 2012

The max depth reported defaults to 20, but you can override with options like this:

trace(Env.cur.out, ["maxDepth":100])

Would everyone like to increase depth? Or get rid of it?

Akcelisto Sun 11 Nov 2012

No. No. Plz, look at my examples. None of these are not exceeds max depth.

Look at this trace of evil err. This trace not contains names of methods where errs was raised.

reduced stack of evil err (this is call via actors)
sys::NullErr: java.lang.NullPointerException
  concurrent::Future.get (Future.java:100)
  concurrent::Future.get (Future.java:57)
  rateResearch::ComplicatedActor.methodA (ReducedStack.fan:90)
  rateResearch::TraceTest.main (ReducedStack.fan:22)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)
  sys::NullErr: java.lang.NullPointerException
    concurrent::Actor._dispatch (Actor.java:236)
    concurrent::Actor._work (Actor.java:199)
    concurrent::ThreadPool$Worker.run (ThreadPool.java:255)

Compare with trace of good err. This trace contains names of methods where errs was raised.

proper stack of good err (this is call via actors)
sys::NullErr: Coerce to non-null
  concurrent::Future.get (Future.java:100)
  concurrent::Future.get (Future.java:57)
  rateResearch::ComplicatedActor.methodB (ReducedStack.fan:94)
  rateResearch::TraceTest.main (ReducedStack.fan:30)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)
  sys::NullErr: Coerce to non-null
    fan.sys.NullErr.makeCoerce (NullErr.java:38)
    rateResearch::Complicated.methodWithNullErr (ReducedStack.fan:64)
    rateResearch::Complicated.methodBB (ReducedStack.fan:58)
    rateResearch::Complicated.methodB (ReducedStack.fan:54)
    rateResearch::ComplicatedActor.receive (ReducedStack.fan:81)
    concurrent::Actor._dispatch (Actor.java:228)
    concurrent::Actor._work (Actor.java:199)
    concurrent::ThreadPool$Worker.run (ThreadPool.java:255) 

Problem in existence of good and evil errs. All errs must be good.

All errs must have proper stack with names of methods where errs was raised.

Akcelisto Mon 12 Nov 2012

I try to explain the Problem with other words.

There is bug. Look at code, actual output and expected output.

Code:

using concurrent

class TraceTest{
  static Void main(){
    try{
      ComplicatedActor().methodA
    }catch(Err e){
      e.trace(Env.cur.out, ["maxDepth":100])
    }
  }
}

class Complicated{
  Void methodA(){
    methodAA
  }

  Void methodAA(){
    methodWithNpe
  }

  // method with evil kind of err
  Void methodWithNpe(){
    Str? str
    str.capitalize
  }    
}

const class ComplicatedActor : Actor{
  new make():super(ActorPool()){
    send(null)
  }

  override Obj? receive(Obj? msg){
    if(msg==null){
      Actor.locals["complicated"] = Complicated()
    }else{
      Complicated complicated := Actor.locals["complicated"]
      if(msg=="a"){
        complicated.methodA
      }else{
        throw Err("Unknown msg")
      }
    }
    return null
  }

  Void methodA(){
    send("a").get
  }
}

Actual output:

sys::NullErr: java.lang.NullPointerException
  concurrent::Future.get (Future.java:100)
  concurrent::Future.get (Future.java:57)
  rateResearch::ComplicatedActor.methodA (ReducedStack.fan:90)
  rateResearch::TraceTest.main (ReducedStack.fan:22)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)
  sys::NullErr: java.lang.NullPointerException
    concurrent::Actor._dispatch (Actor.java:236)
    concurrent::Actor._work (Actor.java:199)
    concurrent::ThreadPool$Worker.run (ThreadPool.java:255)

Expected output:

sys::NullErr: java.lang.NullPointerException
  concurrent::Future.get (Future.java:100)
  concurrent::Future.get (Future.java:57)
  rateResearch::ComplicatedActor.methodA (ReducedStack.fan:90)
  rateResearch::TraceTest.main (ReducedStack.fan:30)
  java.lang.reflect.Method.invoke (Unknown)
  fan.sys.Method.invoke (Method.java:559)
  fan.sys.Method$MethodFunc.callList (Method.java:198)
  fan.sys.Method.callList (Method.java:138)
  fanx.tools.Fan.callMain (Fan.java:173)
  fanx.tools.Fan.executeType (Fan.java:140)
  fanx.tools.Fan.execute (Fan.java:41)
  fanx.tools.Fan.run (Fan.java:298)
  fanx.tools.Fan.main (Fan.java:336)
  sys::NullErr: java.lang.NullPointerException
    fan.sys.FanStr.capitalize (FanStr.java:448)
    rateResearch::Complicated.methodWithNpe(ReducedStack.fan:50)
    rateResearch::Complicated.methodAA (ReducedStack.fan:44)
    rateResearch::Complicated.methodA (ReducedStack.fan:40)
    rateResearch::ComplicatedActor.receive (ReducedStack.fan:81)
    concurrent::Actor._dispatch (Actor.java:228)
    concurrent::Actor._work (Actor.java:199)
    concurrent::ThreadPool$Worker.run (ThreadPool.java:255)

brian Mon 12 Nov 2012

I started looking at it this morning, but not finished investigation. Yes I agree it is a probably bug, but want to dig into it some more

brian Wed 14 Nov 2012

Promoted to ticket #2054 and assigned to brian

Yes there is some problem in Err.rebase which causes the exception's original actual stack trace to be overwritten by RebaseException

Akcelisto Wed 14 Nov 2012

--dancing--

brian Mon 20 May 2013

Ticket resolved in 1.0.65

Was sort of a tricky problem b/w how I did exception rebase for actors and how I was storing the actual native exception for things like NPE. But think I have a new design worked out that looks like it works much better.

Login or Signup to reply.