How to display or save stack information?

Question

Question

Eduard Lebedyuk · Mar 28, 2016

#Code Snippet #Debugging #Object Data Model #Caché

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?

Discussion (11)0

Log in or sign up to continue

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.

3 0

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

1 0

score 2 · Answer 1 · 2016-03-28T10:54:30-04:00

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

score 0 · Answer 2 · 2016-03-29T12:43:38-04:00

Eduard Lebedyuk · Mar 29, 2016

Thank you.

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

0 0

score 0 · Answer 3 · 2016-03-28T11:04:36-04:00

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=""

score 0 · Answer 4 · 2016-03-29T12:53:00-04:00

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.

score 2 · Answer 5 · 2016-03-29T15:14:00-04:00

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

score 0 · Answer 6 · 2016-03-30T07:09:11-04:00

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.

score 0 · Answer 7 · 2016-03-30T08:58:12-04:00

Eduard Lebedyuk · Mar 30, 2016

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

0 0

score 0 · Answer 8 · 2016-03-30T09:19:59-04:00

Alexey Maslov · Mar 30, 2016

Just noticed the following "reformatted" code fragment:

if zzz'["" { ... }

0 0

score 0 · Answer 9 · 2016-03-30T09:22:22-04:00

Eduard Lebedyuk · Mar 30, 2016

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

0 0