Function for examining structure of calls in debug output

Function for examining structure of calls in debug output

[Peter Stephenson]

In case this is useful to anyone, the function below is a very simple
(and easy to confuse) way of examining the structure of shell debug
output such as what you get from ^X? in completion.  For example (except
I keep changing my mind on the format) from some _complete_debug output:

_complete_debug:16
   _complete_debug:17 -> _main_complete
     _main_complete:25 -> (eval)
     _main_complete:82 -> _setup
     _main_complete:178 -> _oldlist
     _main_complete:178 -> _oldlist
     _main_complete:178 -> _expand
       _expand:81 -> (eval)
       _expand:89 -> (eval)
       _expand:106 -> (eval)
     _main_complete:178 -> _expand
     _main_complete:178 -> _user_expand
       _user_expand:39 -> (eval)
       _user_expand:48 -> _percent
     _main_complete:178 -> _user_expand
     _main_complete:178 -> _complete
       _complete:100 -> (eval)
       _complete:117 -> _normal
         _normal:38 -> _set_command
         _normal:40 -> _dispatch
           _dispatch:63 -> (eval)
             (eval):1 -> _mh
               _mh:44 -> _wanted
                 _wanted:7 -> _tags
                 _wanted:9 -> _tags
                 _wanted:10 -> _all_labels
                   _all_labels:37 -> _description
                     _description:18 -> _setup
                   _all_labels:39 -> _path_files
                     _path_files:17 -> _have_glob_qual
                     _path_files:201 -> _have_glob_qual
                     _path_files:202 -> _have_glob_qual
                     _path_files:725 -> _list_files
                 _wanted:10 -> _dispatch
                   _dispatch:64 -> _complete
                     _complete:144 -> _main_complete
                       _main_complete:380 -> _complete_debug


You'll notice it's already confused because the return from _dispatch
goes to _complete instead of _normal, since there are no further
non-trivial commands in _normal, and searching back up the stack for the
return function would mean there was no hope of it grokking recursive
structures.  I'm not sure how much effort I can be bothered to put into
this.  A better solution might be for a prompt escape that tracks the
nesting level (which is trivial apart from picking a new letter).


xtrace_trace() {
  # Trivial function to trace the strcture of zsh function calls
  # with xtrace output using a PS4 containing %N and %i (see prompt_match
  # below).
  #
  # Input is stderr from a shell with xtrace active and a suitable PS4.
  # The completion system's ^X? binding can produce such output.
  #
  # Because we can't be sure a change in execution is a new call
  # or a return to a previous function, we always assume the latter where
  # the names match.  This is the normal case but may be wrong for
  # certain recursive structures.

  emulate -L zsh
  setopt extendedglob

  # Match lines for PS4="+%N:%i> ".  Adapt as appropriate.
  local prompt_match="+(#b)([^>]##):([0-9]##)> *"
  # Function name in $match[1]
  integer func_match=1
  # Line number in $match[2]
  integer lineno_match=2
  # Padding to indent a line
  local pad="  "

  local line func indent last_line
  integer lineno
  local -a match mbegin mend funcs

  while read line; do
    [[ $line = ${~prompt_match} ]] || continue
    func=$match[$func_match]
    lineno=$match[$lineno_match]

    if (( ${#funcs} == 0 )); then
      print -r -- ${func}:${lineno}
      funcs+=($func)
    elif [[ $func != ${funcs[-1]} ]]; then
      if [[ $func = ${funcs[-2]} ]]; then
	funcs=(${funcs[1,-2]})
	indent=${indent%%$pad}
      else
	indent+=$pad
	print -r -- "$indent $last_line -> $func"
	funcs+=($func)
      fi
    fi

    last_line=${func}:${lineno}
  done <${1:-/dev/stdin}
}


-- 
Peter Stephenson <p.stephenson@samsung.com>  Principal Software Engineer
Tel: +44 (0)1223 434724                Samsung Cambridge Solution Centre
St John's House, St John's Innovation Park, Cowley Road,
Cambridge, CB4 0DS, UK

PATCH: evaluation depth in prompts

[Peter Stephenson]

On Tue, 26 Aug 2014 17:40:29 +0100
Peter Stephenson <p.stephenson@samsung.com> wrote:
> A better solution might be for a prompt escape that tracks the
> nesting level (which is trivial apart from picking a new letter).

%e for evaluation depth (%E is taken but %e isn't).

I won't commit this until the release now.  Probably Thursday is my next
chance for that while leaving enough time for people to moan.

diff --git a/Doc/Zsh/prompt.yo b/Doc/Zsh/prompt.yo
index 0ed52b5..183a93a 100644
--- a/Doc/Zsh/prompt.yo
+++ b/Doc/Zsh/prompt.yo
@@ -108,6 +108,12 @@ the full path;
 ifzman(see em(Dynamic) and em(Static named directories) in zmanref(zshexpn))\
 ifnzman(noderef(Filename Expansion)).
 )
+item(tt(%e))(
+Evaluation depth of the current sourced file, shell function, or tt(eval).
+This is incremented or decremented every time the value of tt(%N) is
+set or reverted to a previous value, respectively.  This is most useful
+for debugging as part of tt($PS4).
+)
 xitem(tt(%h))
 item(tt(%!))(
 Current history event number.
diff --git a/Src/prompt.c b/Src/prompt.c
index 328ae3c..4762535 100644
--- a/Src/prompt.c
+++ b/Src/prompt.c
@@ -786,6 +786,19 @@ putpromptchar(int doprint, int endchar, unsigned int *txtchangep)
 		if(bv->Rstring)
 		    stradd(bv->Rstring);
 		break;
+	    case 'e':
+	    {
+		int depth = 0;
+		Funcstack fsptr = funcstack;
+		while (fsptr) {
+		    depth++;
+		    fsptr = fsptr->prev;
+		}
+		addbufspc(DIGBUFSIZE);
+		sprintf(bv->bp, "%d", depth);
+		bv->bp += strlen(bv->bp);
+		break;
+	    }
 	    case 'I':
 		if (funcstack && funcstack->tp != FS_SOURCE &&
 		    !IN_EVAL_TRAP()) {


pws

Re: PATCH: evaluation depth in prompts

[Peter Stephenson]

On Tue, 26 Aug 2014 18:10:55 +0100
Peter Stephenson <p.stephenson@samsung.com> wrote:
> On Tue, 26 Aug 2014 17:40:29 +0100
> Peter Stephenson <p.stephenson@samsung.com> wrote:
> > A better solution might be for a prompt escape that tracks the
> > nesting level (which is trivial apart from picking a new letter).
> 
> %e for evaluation depth (%E is taken but %e isn't).

In case anyone's still following, here's the original script updated.
This now gives reliable tracing of who's calling whom, even for
functions calling themselves recursively, which I think was pretty much
impossible to automate reliably before by means of prompt tracing ---
you could hack it up or alternatively use debug traps and the functrace
stuff.

pws


# Trivial function to trace the strcture of zsh function calls
# with xtrace output using a PS4 containing %N and %i (see prompt_match
# below).
#
# Input is stderr from a shell with xtrace active and a suitable PS4.
# The completion system's ^X? binding can produce such output.
#
# For shells with %e (added in 5.0.7(?)): using PS4="+%e:%N:%i> "
# allows better tracing by outputting the execution depth of the
# construct being executed.
#
# If that's not available, the default PS4="+%N:%i> " is assumed. In
# this case, because we can't be sure a change in execution is a new
# call or a return to a previous function, we always assume the latter
# where the names match.  This is the normal case but may be wrong for
# certain recursive structures.

emulate -L zsh
setopt extendedglob

# Match lines for PS4="+%e:%N:%i> ".  Adapt as appropriate.
# With %e for evaluation depth.
local eprompt_match="+(#b)([0-9]##):([^>]##):([0-9]##)> *"
integer edepth_match=1
integer efunc_match=2
integer elineno_match=3

# Match lines for PS4="+%N:%i> ".  Adapt as appropriate.
# No evaluation depth.
local prompt_match="+(#b)([^>]##):([0-9]##)> *"
# Function name in $match[1]
integer func_match=1
# Line number in $match[2]
integer lineno_match=2
# Padding to indent a line
local pad="  "

local line func indent last_line
integer lineno depth last_depth=-1 diff
local -a match mbegin mend funcs

while read line; do
  if [[ $line = ${~eprompt_match} ]]; then
    depth=$match[$edepth_match]
    func=$match[$efunc_match]
    lineno=$match[$elineno_match]

    if (( last_depth == -1 )); then
      print -r -- ${func}:${lineno}
    elif (( depth < last_depth )); then
      (( diff = last_depth - depth ))
      while (( diff-- )); do
	indent=${indent%%$pad}
      done
    elif (( depth > last_depth )); then
      (( diff = depth - last_depth ))
      while (( diff-- )); do
	indent+=$pad
      done
      print -r -- "$indent$last_line -> $func"
    fi

    last_depth=$depth
    last_line=${func}:${lineno}
  elif [[ $line = ${~prompt_match} ]]; then
    depth=$match[$depth_match]
    func=$match[$func_match]
    lineno=$match[$lineno_match]

    if (( ${#funcs} == 0 )); then
      print -r -- ${func}:${lineno}
      funcs+=($func)
    elif [[ $func != ${funcs[-1]} ]]; then
      if [[ $func = ${funcs[-2]} ]]; then
	funcs=(${funcs[1,-2]})
	indent=${indent%%$pad}
      else
	indent+=$pad
	print -r -- "$indent$last_line -> $func"
	funcs+=($func)
      fi
    fi

    last_line=${func}:${lineno}
  fi
done <${1:-/dev/stdin}

Re: Function for examining structure of calls in debug output

[Bart Schaefer]

Hi, back from a few days on the road ...

On Aug 26,  5:40pm, Peter Stephenson wrote:
}
} You'll notice it's already confused because the return from _dispatch
} goes to _complete instead of _normal, since there are no further
} non-trivial commands in _normal, and searching back up the stack for the
} return function would mean there was no hope of it grokking recursive
} structures.  I'm not sure how much effort I can be bothered to put into
} this.  A better solution might be for a prompt escape that tracks the
} nesting level (which is trivial apart from picking a new letter).

I see you already implemented the latter idea.  An alternate / additional
idea would be to have xtrace output a "return N" expression any time a
function returns, whenever there is no explicit return statement in the
source.  The line number could be that of the closing curly brace, or
perhaps some flag value such as -1.

Re: PATCH: evaluation depth in prompts

[Bart Schaefer]

On Aug 26,  6:10pm, Peter Stephenson wrote:
} Subject: PATCH: evaluation depth in prompts
}
} On Tue, 26 Aug 2014 17:40:29 +0100
} Peter Stephenson <p.stephenson@samsung.com> wrote:
} > A better solution might be for a prompt escape that tracks the
} > nesting level (which is trivial apart from picking a new letter).
} 
} %e for evaluation depth (%E is taken but %e isn't).

Nifty, but it should also be added as %N(e.deep.shallow).


diff --git a/Doc/Zsh/prompt.yo b/Doc/Zsh/prompt.yo
index 183a93a..17af5b0 100644
--- a/Doc/Zsh/prompt.yo
+++ b/Doc/Zsh/prompt.yo
@@ -305,6 +305,7 @@ least var(n) elements relative to the root directory, hence tt(/) is
 counted as 0 elements.)
 sitem(tt(D))(True if the month is equal to var(n) (January = 0).)
 sitem(tt(d))(True if the day of the month is equal to var(n).)
+sitem(tt(e))(True if the evaluation depth is at least var(n).)
 sitem(tt(g))(True if the effective gid of the current process is var(n).)
 sitem(tt(j))(True if the number of jobs is at least var(n).)
 sitem(tt(L))(True if the tt(SHLVL) parameter is at least var(n).)
diff --git a/Src/prompt.c b/Src/prompt.c
index 4762535..9ed6c54 100644
--- a/Src/prompt.c
+++ b/Src/prompt.c
@@ -372,6 +372,17 @@ putpromptchar(int doprint, int endchar, unsigned int *txtchangep)
 		    if (t0 >= arg)
 			test = 1;
 		    break;
+		case 'e':
+		    {
+			Funcstack fsptr = funcstack;
+			test = arg;
+			while (fsptr && test > 0) {
+			    test--;
+			    fsptr = fsptr->prev;
+			}
+			test = !test;
+		    }
+		    break;
 		case 'L':
 		    if (shlvl >= arg)
 			test = 1;

Re: PATCH: evaluation depth in prompts

[Bart Schaefer]

On Aug 29,  5:16pm, Peter Stephenson wrote:
}
} In case anyone's still following, here's the original script updated.
} This now gives reliable tracing of who's calling whom

Here's a related idea/suggestion which adds indentation to the output
of _complete_debug.  There's no convenient way to produce ${(%):-%e}
spaces for arbitrary depths without turning on promptsubst, so this
generates a bunch of %N(e. .) expressions and glues them together.
If completion goes more than 20 function calls deep there's probably
something wrong anyway.

I couldn't decide whether to put the indentation after the leading "+"
or before it.  This has it before.

(This is another one I won't commit without positive feedback.)

diff --git a/Completion/Base/Widget/_complete_debug b/Completion/Base/Widget/_complete_debug
index eff0f8e..6c0d9a3 100644
--- a/Completion/Base/Widget/_complete_debug
+++ b/Completion/Base/Widget/_complete_debug
@@ -12,6 +12,8 @@ integer debug_fd=-1
     exec {debug_fd}>&2 2>| $tmp
   fi
 
+  local -a debug_indent; debug_indent=( '%'{3..20}'(e. .)' )
+  local PROMTP4 PS4="${(j::)debug_indent}+%N:%i> "
   setopt xtrace
   : $ZSH_NAME $ZSH_VERSION
   ${1:-_main_complete}

Re: PATCH: evaluation depth in prompts

[Peter Stephenson]

On Mon, 01 Sep 2014 14:02:02 -0700
Bart Schaefer <schaefer@brasslantern.com> wrote:
> On Aug 29,  5:16pm, Peter Stephenson wrote:
> }
> } In case anyone's still following, here's the original script updated.
> } This now gives reliable tracing of who's calling whom
> 
> Here's a related idea/suggestion which adds indentation to the output
> of _complete_debug.  There's no convenient way to produce ${(%):-%e}
> spaces for arbitrary depths without turning on promptsubst, so this
> generates a bunch of %N(e. .) expressions and glues them together.
> If completion goes more than 20 function calls deep there's probably
> something wrong anyway.

Seems reasonable --- it doesn't remove any of the existing information.
A visual cue for calls should make it a lot clearer.

> I couldn't decide whether to put the indentation after the leading "+"
> or before it.  This has it before.

That makes it easier to strip the spaces if you happen to prefer it
like that.

pws

Re: PATCH: evaluation depth in prompts

[Oliver Kiddle]

Bart wrote:

> Here's a related idea/suggestion which adds indentation to the output
> of _complete_debug.  There's no convenient way to produce ${(%):-%e}

Seems a useful idea and at worst, horizontally scrolling get used when
viewing the output.

> If completion goes more than 20 function calls deep there's probably
> something wrong anyway.

Or if it does, then it doesn't especially matter that indentation simply
stops at this limit: it's arguably a feature rather than a limitation.

> I couldn't decide whether to put the indentation after the leading "+"
> or before it.  This has it before.

When viewing _complete_debug output, I nearly always use the less
feature to filter lines using &pattern, often using a pattern such as
\+_expand to filter by a particular function. With that in mind,
indentation before is more helpful.

> +  local -a debug_indent; debug_indent=( '%'{3..20}'(e. .)' )
> +  local PROMTP4 PS4="${(j::)debug_indent}+%N:%i> "

Note the typo for PROMPT4.

Oliver

Re: PATCH: evaluation depth in prompts

[Bart Schaefer]

On Sep 3,  1:53am, Oliver Kiddle wrote:
}
} > +  local -a debug_indent; debug_indent=( '%'{3..20}'(e. .)' )
} > +  local PROMTP4 PS4="${(j::)debug_indent}+%N:%i> "
} 
} Note the typo for PROMPT4.

Thanks for noticing that.  I'm not sure PROMPT4 needs to be declared
there anyway, but given the alter ego I  it might be a good idea.