debugger fails to find location of calls to "error" in Core

[mahrud]

@mikestillman pointed out something which I had also observed and noted on other issues here, which is that the debugger often doesn't end up in the right place in the Core.

Here is how to reproduce: insert blah = x -> error "debug me" somewhere in Core, then run it with errorDepth one or less. Here is the result for me:

i1 : debug Core

i2 : code blah

o2 = ../../m2/debugging.m2:6:7-6:28: --source code:
     blah = x -> error "debug me"

i3 : errorDepth=1

o3 = 1

i4 : blah 12
../../m2/debugging.m2:20:13:(1): error: debug me
../../m2/debugging.m2:20:13:(1): --entering debugger (type help to see debugger commands)
../../m2/debugging.m2:20:5-20:30: --source code:
     olderror processArgs args)

ii5 : currentString

ii6 : code current

oo6 = ../../m2/debugging.m2:20:5-20:30: --source code:
           olderror processArgs args)

ii7 : locate current

oo7 = ../../m2/debugging.m2:20:5-20:30

oo7 : FilePosition

I don't seem to be able to get the original location in anyway.

ii8 : listLocalSymbols

oo8 = symbol  class  value  location of symbol
      ------  -----  -----  ------------------

ii9 : listUserSymbols

oo9 = symbol  class  value  location of symbol
      ------  -----  -----  ------------------

ii10 : x

oo10 = x

oo10 : Symbol

One interesting factor is that avoiding tail-end optimization of error leads to the symbols remaining accessible. If I instead add blah = x -> (error "debug me";) then I get:

i2 : code blah

o2 = ../../m2/debugging.m2:6:7-6:31: --source code:
     blah = x -> (error "debug me";)

i3 : errorDepth=1

o3 = 1

i4 : blah 12
../../m2/debugging.m2:20:13:(1):[1]: error: debug me
../../m2/debugging.m2:20:13:(1):[1]: --entering debugger (type help to see debugger commands)
../../m2/debugging.m2:20:5-20:30: --source code:
     olderror processArgs args)

So far identical, but:

ii8 : listLocalSymbols

oo8 = symbol              class             value                                                 location of symbol
      ------              -----             -----                                                 ------------------                
      x                   ZZ                12                                                    ../../m2/debugging.m2:6:7-6:8     
      ls                  FunctionClosure   FunctionClosure[../../m2/debugging.m2:165:6-165:63]   ../../m2/debugging.m2:165:0-165:2 
      show1               MethodFunction    MethodFunction[]                                      ../../m2/debugging.m2:128:0-128:5 
      processArgs         FunctionClosure   FunctionClosure[../../m2/debugging.m2:8:15-16:6]      ../../m2/debugging.m2:8:0-8:11    
      olderror            CompiledFunction  CompiledFunction[]                                    ../../m2/debugging.m2:17:0-17:8   
      callCount           MutableHashTable  MutableHashTable{}                                    ../../m2/debugging.m2:36:0-36:9   
      allThingsWithNames  FunctionClosure   FunctionClosure[../../m2/debugging.m2:126:22-126:96]  ../../m2/debugging.m2:126:0-126:18
      justTypes           FunctionClosure   FunctionClosure[../../m2/debugging.m2:125:13-125:71]  ../../m2/debugging.m2:125:0-125:9 
      select2             FunctionClosure   FunctionClosure[../../m2/debugging.m2:158:11-163:16]  ../../m2/debugging.m2:158:0-158:7 

ii10 : x

oo10 = 12

Note that if instead of error "debug me" I had put 1/0 then location would have worked fine.

Related to this, there are a number of tests for error messages here that weren't being tested manually. Perhaps they should be moved to a manual directory, with more documentation of expected behavior, or somehow made automatic.

[mahrud]

Other observation: if I comment out these lines:

M2/M2/Macaulay2/m2/debugging.m2

Lines 15 to 18 in ec9e9ac

	olderror := error
	error = args -> (
	-- this is the body of the "error" function, which prints out error messages
	olderror processArgs args)

then everything works fine:

i4 : blah 12
../../m2/debugging.m2:6:17:(1): error: debug me
../../m2/debugging.m2:6:17:(1): --entering debugger (type help to see debugger commands)
../../m2/debugging.m2:6:12-6:28: --source code:
blah = x -> error "debug me"

So maybe a naive solution is to move that segment to the interpreter.

Playing around with setting loadDepth to something lower before that section and resetting it after doesn't seem to help either.

@pzinn my best guess is that the FilePosition of the error code is somehow involved, but I don't know where to look for more clues.

[mahrud]

In #3431 I'm adding a new keyword breakpoint which can be used to start the debugger in the correct location. e.g. instead of adding error "debug me" you could add:

kernel Matrix := Module => opts -> (cacheValue symbol kernel) ((m) -> (
	  N := source m;
	  if m == 0 then return N;
	  P := target m;
	  if m.?RingMap then (
	       f := m.RingMap;
	       n := map(target m,f source m,raw m);
-	       p := pushNonLinear(options pushForward, f, coimage n);
+	       p := breakpoint pushNonLinear(options pushForward, f, coimage n);
	       image p)
	  else (
	       m = matrix m;
	       if P.?generators then m = P.generators * m;
	       h := modulo(m, if P.?relations then P.relations);
	       if N.?generators then h = N.generators * h;
	       subquotient( h, if N.?relations then N.relations))))

[pzinn]

Other observation: if I comment out these lines:

M2/M2/Macaulay2/m2/debugging.m2

Lines 15 to 18 in ec9e9ac

	olderror := error
	error = args -> (
	-- this is the body of the "error" function, which prints out error messages
	olderror processArgs args)

then everything works fine:

i4 : blah 12
../../m2/debugging.m2:6:17:(1): error: debug me
../../m2/debugging.m2:6:17:(1): --entering debugger (type help to see debugger commands)
../../m2/debugging.m2:6:12-6:28: --source code:
blah = x -> error "debug me"

So maybe a naive solution is to move that segment to the interpreter.

Playing around with setting loadDepth to something lower before that section and resetting it after doesn't seem to help either.

@pzinn my best guess is that the FilePosition of the error code is somehow involved, but I don't know where to look for more clues.

definitely these lines should go at some point (and be moved to the interpreter).

[pzinn]

Interestingly, the same test you propose at the top produces a quite different result on Macaulay2Web, which incorporates some major changes I made to the error workflow. I'll try to analyse where the difference is.
Also, the interaction between TCO and debugging is messy, cf possibly related #3371 (on which I'm stuck).

[mahrud]

Interestingly, the same test you propose at the top produces a quite different result on Macaulay2Web, which incorporates some major changes I made to the error workflow.

On the other hand, it used to work as late as version 1.21:

Macaulay2, version 1.21

i1 : debug Core

i2 : errorDepth=1

o2 = 1

i3 : blah()
M2/Macaulay2/m2/debugging.m2:6:13:(1):[1]: error: debug me
M2/Macaulay2/m2/debugging.m2:6:13:(1):[1]: --entering debugger (type help to see debugger commands)
M2/Macaulay2/m2/debugging.m2:6:13-6:13: --source code:
blah = x -> error "debug me"

So analyzing the differences since then could also work.

[mahrud]

Very exiting realization: the breakpoint keyword that I added in #3431 allows you to drop into a thread for debugging! This is currently not possible using error, at least as far as I can tell.

[mahrud]

@pzinn this error was introduced after 1.24.05. Did you have any luck isolating when it started?

[mahrud]

Okay, found the commit that broke this: 94ac762. Going to submit a pull request to revert this for now. Later we can figure out how to fix error location in tail calls without breaking the debugger.

[pzinn]

All I can add (a bit late) is that I think I'd effectively solved the problem on my branch (without any need to revert #3544), see attached screenshot. But as I mentioned in the other thread, will need more time to investigate.