Question
Eduard Lebedyuk · Mar 28, 2016

How to display or save stack information?

Hello.

For debugging purposes I  sometimes need to display stack information to the current device or save it (to a global for example).

There is this snippet offered in documentation:

ClassMethod StackToDisplay()
{
    For loop = 0:1:$Stack(-1) {
        Write !, "Context level:", loop, ?25, "Context type: ", $Stack(loop)
        Write !, ?5, "Current place: ", $Stack(loop, "PLACE")
        Write !, ?5, "Current source: ", $Stack(loop, "MCODE")
        Write !
    }
}

And to save stack to a global there's always an exception method:

ClassMethod StackToGlobal()
{
    Set ex = ##class(%Exception.SystemException).%New()
    Do ex.StackAsArray(.arr)
    Set time = $ZDT($H)
    Merge ^StackInfo(time) = arr
}

But I'm interested if someone has a better code (more info) for this purpose? What's your approach to saving stack information?

#Code Snippet #Debugging #Object Data Model #Caché
00
1 0 11 1,004
Log in or sign up to continue
Evgeny Shvarov · Mar 28, 2016

In Catch block I usually execute Log method of Exception 

try {

                // App logic


}


 catch e
    {
                 d e.Log()


                 // Error handling logic


         }

And then find this in Application Error Log journal with all the stack.

E.g. link to the bugs in USER Namespace

http://localhost:57772/csp/sys/op/UtilSysAppErrorNamespaces.csp?$NAMESPACE=USER

20
Eduard Lebedyuk · Mar 29, 2016

Thank you.

Also note, that e.Log() calls LOG^%ETN.

00
Timothy Leavitt · Mar 28, 2016

An easier way to capture the stack and values of variables at all stack levels is:

Do LOG^%ETN

Then it's possible to view full information on stack and variables from terminal with:

Do ^%ER

Or in the management portal at System Operation > System Logs > Application Error Log.

If you're logging to globals to track more limited parts of the process state for debugging, it's helpful to use a ^CacheTemp* or ^mtemp* global so that the debugging information (a) isn't rolled back by TROLLBACK and (b) won't accumulate in an important database if the debugging code is accidentally left in.

31
Dmitry Maslennikov · Mar 28, 2016

LOG^%ETN it is very useful but in most cases overkill. And may take several seconds to gather full stack.
and maybe used for any logging, but should have filled $zerror
some time for logging I use such code.
set $ze="test",t=$$LOG^%ETN,$ze=""
 

00
Eduard Lebedyuk · Mar 29, 2016

You can fill $zerror by passing a name into LOG^%ETN:

Do LOG^%ETN("test")

It would record your current $zerror  value, replace it with "test", execute LOG captue, and at the end restore $zerror to what it was before the call.

00
Alexey Maslov · Mar 29, 2016

Somewhen I used the following function to save stacked calls and all variables defined. Variables are not separated by stack levels, that seems to be the reason of $$getst() quickness.

getst(zzzzgetvars,zzzzStBeg,zzzztemp) ; Save call stack in local or global array
 ; In:
 ; zzzzgetvars = 1 - save variables defined at the last stack level
 ; zzzzgetvars = 0 or omitted - don't save; default = 0
 ; zzzzStBeg - starting stack level for save; default: 1
 ; zzzztemp - where to save ($name).
 ; Out:
 ; zzzztemp    - number of stack levels saved 
 ; zzzztemp(1) - call at zzzzStBeg level
 ; zzzztemp(2) - call at zzzzStBeg+1 level
 ; ...
 ; zzzztemp(zzzztemp) - call at zzzzStBeg+zzzztemp-1 level
 ;
 ; Calls are saved in format:
 ; label+offset^rouname +CommandNumberInsideCodeLine~CodeLine w/o leading spaces"
 ; E.g.:
 ; zzzztemp(3) = First+2^%ZUtil +3~i x=""1stAarg"" s x=x+1 s c=$$Null(x,y)"
 ; Sample calls:
 ; d getst^%ZUtil(0,1,$name(temp)) ; save calls w/o variables in temp starting from level 1
 ; d getst^%ZUtil(1,4,$name(^zerr($i(^zerr)))) ; save calls with variables in ^zerr starting from level 4
 n zzzzloop,zzzzzzZ,zzzzStEnd
 s zzzzgetvars=$g(zzzzgetvars),zzzzStBeg=$g(zzzzStBeg,1) k @zzzztemp s @zzzztemp=0 s zzzzStEnd=$STACK(-1)-2
 for zzzzloop=zzzzStBeg:1:zzzzStEnd s @zzzztemp=@zzzztemp+1,@zzzztemp@(@zzzztemp)=$STACK(zzzzloop,"PLACE")_"~"_$zstrip($STACK(zzzzloop,"MCODE"),"<W") i zzzzgetvars,(zzzzloop=zzzzStEnd) d
 . s zzzzzzZ="" for  s zzzzzzZ=$o(@zzzzzzZ) q:zzzzzzZ=""  if zzzzzzZ'["zzzz" s @zzzztemp@(@zzzztemp,zzzzzzZ)=$g(@zzzzzzZ)
 . i $ze'="" s @zzzztemp@(@zzzztemp,"$ze")=$ze
 q 1
10
Eduard Lebedyuk · Mar 29, 2016

Formatted your code a little.

getst(getvars, StBeg, temp) ; Save call stack in local or global array
 ; In:
 ; getvars = 1 - save variables defined at the last stack level
 ; getvars = 0 or omitted - don't save; default = 0
 ; StBeg - starting stack level for save; default: 1
 ; temp - where to save ($name).
 ; Out:
 ; temp - number of stack levels saved 
 ; temp(1) - call at StBeg level
 ; temp(2) - call at StBeg+1 level
 ; ...
 ; temp(temp) - call at StBeg+temp-1 level
 ;
 ; Calls are saved in format:
 ; label+offset^rouname +CommandNumberInsideCodeLine~CodeLine w/o leading spaces"
 ; E.g.:
 ; temp(3) = First+2^%ZUtil +3~i x=""1stAarg"" s x=x+1 s c=$$Null(x,y)"
 ; Sample calls:
 ; d getst^%ZUtil(0,1,$name(temp)) ; save calls w/o variables in temp starting from level 1
 ; d getst^%ZUtil(1,4,$name(^zerr($i(^zerr)))) ; save calls with variables in ^zerr starting from level 4
    new loop,zzz,StEnd
    set getvars = $get(getvars)
    set StBeg = $get(StBeg, 1) 
    kill @temp 
    set @temp = 0 
    set StEnd = $STACK(-1)-2
    for loop = StBeg:1:StEnd {
        set @temp = @temp+1
        set @temp@(@temp) = $STACK(loop, "PLACE") _ "~" _ $zstrip($STACK(loop, "MCODE"), "<W") 
        if getvars,(loop=StEnd) {
            set zzz="" 
            for { 
                set zzz = $order(@zzz)
                quit:zzz=""  
                set @temp@(@temp,zzz) = $get(@zzz)
            }
            if $zerror'="" {
                set @temp@(@temp,"$ze") = $zerror
            }
         }
    }
     quit 1
20
Alexey Maslov · Mar 30, 2016

Well-well, Ed. The intention of following check up:

if zzzzzzZ'["zzzz" 

was to avoid logging my own variables which names were deliberately started with this nasty prefix. I agree that it's rather naive trick, but it worked.
As to original code, it was taken from the existing code base and complied our internal coding standards; I preferred to publish it "as is", having neither time nor will to re-test it.

00
Eduard Lebedyuk · Mar 30, 2016

I wondered actually, what for do you prefix all variable names with "zzzz". 

00
Alexey Maslov · Mar 30, 2016

Just noticed the following "reformatted" code fragment:

if zzz'["" { ... }
00
Eduard Lebedyuk · Mar 30, 2016

Thanks. Removed that as it's useless without zzzz variables.

00