text ZSH调试技术

Posted 2021-04-29

https://github.com/robbyrussell/oh-my-zsh/issues/5327

A Debugging Technique
I didn't read every post here, but I'm gonna post a technique for debugging slow startup just in case no one else has posted a good one yet.

If you install the moreutils package, you'll have a timestamp command called ts. You can use it to print sub second resolution timestamps of all of the debug output from zsh that tell you how long since the last line of output. Then you can search that file for timestamps that are "long". Here's the command:

zsh -xv 2>&1 | ts -i "%.s" > zsh_startup.log

Just hit 'ctrl-d' when the prompt pops up to exit the debug shell, and you can then read 'zsh_startup.log' with whatever you want. It'll be a long file, so find a good way to search it with regex. Keep in mind that zsh debug prints a line before running it, so the timestamps really tell you how long it took for the previous line to run, not the line the timestamp is currently on.

I used this search string in Vim to look for any command that took longer than a thousandth of a second: \M^\(0.000\)\@!. You can vary the number of zeros to search for the longest running lines first. E.g. To see which lines took longer than a second \M^\(0\)\@!.

Searching for lines taking longer than a second only found 1 line in my file, but that line took nearly one and a half seconds! Fixing that saved half the startup time that I was seeing.

Checking Your Progress
You may want to check your progress by looking for how many lines take longer than a given amount of time. If you're a Vim user, you can use the substitution command in count only mode. E.g. :%s/\M^\(0.0\)\@!//n found that I had 7 lines that took longer than a tenth of a second to complete. Addressing just these 7 lines brought my zsh init time down from 4.13 sec to 0.87 sec!

That's long compared to my bash which is 0.08 sec, but my zsh does so much more cool stuff, and I plan to look into some of the 26 lines that take more than a hundredth of a second at a later date.

Also, you may just want to see how long it's taking to load without having to add up all those timestamps in the log file. I think I got this command from a post on this thread, but I'll put it here for completeness:

/usr/bin/time /bin/zsh -i -c exit # reminder of last change