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.

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

Conversation

belak
Copy link
Collaborator

@belak belak commented Feb 7, 2018

Proposed Changes

  • Add a zdebuglog function which only prints if :prezto:debug is enabled.
  • Add some basic startup logging to zmodload

Reason

This came about so I could work on debugging slow startup times of some modules. There may be a better way - I'm open to improvements or suggestions.

Notes

I'd like comments from the other maintainers on this, since I feel like there's got to be a better way... but if we like this, we can merge it in and start using it elsewhere, since it lets us provide more useful debugging info, rather than just using set +x.

typeset -F SECONDS

function zdebuglog {
if ! zstyle -t ":prezto" debug; then

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.

init.zsh Outdated
@@ -93,7 +106,9 @@ function pmodload {

# Load Prezto modules.
for pmodule in "$pmodules[@]"; do
zdebuglog "Started loading %q" $pmodule
Copy link

@hlecuanda hlecuanda Feb 9, 2018

Choose a reason for hiding this comment

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

See my detailed comment above about the possibility of avoiding this and instead do automatic debug instrumentation for any command, scripted or interactive via TRAPNAL functions 😃

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants