Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add zdebuglog for basic debug logging and profiling #1544

Open
wants to merge 3 commits into
base: master
Choose a base branch
from
Open

Add zdebuglog for basic debug logging and profiling #1544

Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
658ec4e
Add zdebuglog for basic debug logging and profiling
belak Feb 7, 2018
6ab2cc0
zdebuglog -> pdebuglog
belak Feb 12, 2018
3524cc2
Add comments for pdebuglog
belak Feb 12, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 18 additions & 0 deletions init.zsh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,20 @@ if ! autoload -Uz is-at-least || ! is-at-least "$min_zsh_version"; then
fi
unset min_zsh_version

# Change the resolution of the SECONDS variable to be more useful for debugging.
typeset -F SECONDS

# logging convenience, mostly meant for debugging performance issues.
function pdebuglog {
if ! zstyle -t ":prezto" debug; then
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I <3 zstyle we need more of those (python humor)

Nonetheless there is an zsh idiomatic way of achieving this. (perhaps the way it works makes other debugging features harder to implement? depends on your implementation details).

My suggestion is to use a TRAPNAL function or define a trap-list with the trap builtin. ether the TRAPNAL function or the builtin trap are set to be triggered upon SIGDEBUG emission, which happens before command execution by default. if you unsetopt DEBUG_BEFORE_COMMAND then SIGDEBUG is emitted after command execution. It's like a hook function, but awesome-er

the difference between a TRAPNAL function and a trap builtin-defned list is that functions are executed with their own context independent context while trap lists are "injected" to the calling command's context, so

        TRAPDEBUG { print $LINENO } #always prints 0
        trap 'print $LINENO' DEBUG #always prints the line it was called from

also, TRAPDEBUG functions have an internal parameter ZSH_DEBUG_CMD automagically available inside them, and it is set to the string representation of the next command to be executed vis a vis the one being debugged after all. This allows for interesting stuff happening in logs, for example via plain syslog and a more interesting zstyle set to an array of commands we are interested in profiling instead of just a boolean (overkill perhaps) it could look something like this:

zstyle -a ':prezto:funcs_to_debug' pmodload zmodload
TRAPDEBUG {
  zstyle -g funcs_to_debug
  if $ZSH_DEBUG_CMD in $funcs_to_debug; then
    logger.info($ZSH_DEBUG_CMD,$(date %S),"more_details")
}

You can go crazy there and do even counterintuitive stuff, such as skipping the execution o the next command when certain conditions are met, besides membership to the zstyle array. It' perhaps an elegant solution to instrumentate THE WHOLE SHELL in just a few lines of code.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In my initial experiments with TRAPDEBUG (and TRAP 'do_stuff' DEBUG, you don't get the function calls in ZSH_DEBUG_CMD, you get the function body, so while this would be much more flexible, it also doesn't quite do what I want.

return
fi

local format="$1"
shift
printf "[%f] $format\n" $SECONDS "$@"
}

# zprezto convenience updater
# The function is surrounded by ( ) instead of { } so it starts in a subshell
# and won't affect the environment of the calling shell
Expand Down Expand Up @@ -93,7 +107,9 @@ function pmodload {

# Load Prezto modules.
for pmodule in "$pmodules[@]"; do
pdebuglog "Started loading %q" $pmodule
if zstyle -t ":prezto:module:$pmodule" loaded 'yes' 'no'; then
pdebuglog "Module %q already loaded" $pmodule
continue
else
locations=(${pmodule_dirs:+${^pmodule_dirs}/$pmodule(-/FN)})
Expand Down Expand Up @@ -131,6 +147,7 @@ function pmodload {

if (( $? == 0 )); then
zstyle ":prezto:module:$pmodule" loaded 'yes'
pdebuglog "Module %q loaded" $pmodule
else
# Remove the $fpath entry.
fpath[(r)${pmodule_location}/functions]=()
Expand All @@ -148,6 +165,7 @@ function pmodload {
done
}

pdebuglog "Module %q failed to load" $pmodule
zstyle ":prezto:module:$pmodule" loaded 'no'
fi
fi
Expand Down