Tips for profiling misbehaving Emacs Lisp?

问题:

I customize Emacs a lot. Recently, I added something to my .emacs configuration that sporadically pegs my CPU at 100%, but I really don't know what it is.

If I press C-g a bunch of times, eventually I'll get a message below the minibuffer asking me if I want to auto save my files and then if I want to abort emacs entirely. If I keep saying no and keeping pressing C-g, eventually I can get back to running emacs as normal. An hour or so later it will happen again.

I could keep going about like I am, commenting out various things I've added recently, restarting emacs, trying to narrow down the culprit, but it's slow going.

Is there a way I can profile emacs directly to figure out what lisp function is hogging the CPU?

回答1:

The suggestion of setting debug-on-quit to t so that you can find out what Emacs is up to is a good one. You can think of this as being a form of sampling profiling with a single sample: often a single sample is all you need.

---

Update: Starting with version 24.3, Emacs contains two profilers. There's a (new) sampling profiler in profiler.el, and an (old) instrumenting profiler in elp.el.

The sampling profiler is documented here. It's pretty straightforward to use:

To begin profiling, type M-x profiler-start. You can choose to profile by processor usage, memory usage, or both. After doing some work, type M-x profiler-report to display a summary buffer for each resource that you chose to profile. When you have finished profiling, type M-x profiler-stop.

Here's some example output from a cpu+mem profiler session with the Perforce/Emacs integration that I maintain. I've expanded the topmost function (progn) in order to find out where the CPU time and memory use is coming from.

Function                                            Bytes    %
- progn                                        26,715,850  29%
  - let                                        26,715,850  29%
    - while                                    26,715,850  29%
      - let                                    26,715,850  29%
        - cond                                 26,715,850  29%
          - insert                             26,715,850  29%
            + c-after-change                   26,713,770  29%
            + p4-file-revision-annotate-links       2,080   0%
+ let                                          20,431,797  22%
+ call-interactively                           12,767,261  14%
+ save-current-buffer                          10,005,836  11%
+ while                                         8,337,166   9%
+ p4-annotate-internal                          5,964,974   6%
+ p4-annotate                                   2,821,034   3%
+ let*                                          2,089,810   2%

You can see that the culprit is c-after-change, so it looks as though I could save a lot of CPU time and memory by locally binding inhibit-modification-hooks to t around this code.

---

You can also use the Emacs Lisp Profiler. This is rather under-documented: you'll have to read the comments in elp.el for the details, but basically you run elp-instrument-package to turn on profiling for all the functions with a given prefix, and then elp-results to see the results.

Here's some typical output after typing M-x elp-instrument-package RET c- RET, fontifying 4,000 lines of C, and then running elp-results (and using elp-sort-by-function to sort by call count):

Function Name                  Call Count  Elapsed Time  Average Time
=============================  ==========  ============  ============
c-skip-comments-and-strings    107         0.0           0.0
c-valid-offset                 78          0.0           0.0
c-set-offset                   68          0.031         0.0004558823
c-end-of-macro                 52          0.0           0.0
c-neutralize-CPP-line          52          0.0           0.0
c-font-lock-invalid-string     20          0.0           0.0
c-set-style-1                  19          0.031         0.0016315789
...

In your particular case the profiler doesn't help immediately, because you don't know which package is at fault. But if you can make a guess (or use debug-on-quit to find it for sure) then the profiler can help you diagnose the problem in detail.

回答2:

Have you tried: Options->Enter debugger on Quit/C-g? (this is on emacs22)

If you need to debug start-up of emacs: use emacs -q --no-site-file, visit your .emacs (or site-start.el or whatever), activate the menu item Options->Enter debugger on Quit/C-g, and then menu item Emacs-Lisp->Evaluate buffer and C-g when it appears to freeze. There may be a easier way of doing this.........

回答3:

With dope.el you can profile entire .emacs or multiple elisp files loaded at startup. Download it from www.gnufans.net/~deego/pub/emacspub/lisp-mine/dope/

M-x dope-quick-start will show a little introduction tutorial.

Edit: The original URL is now defunct, but there is a working mirror on Git Hub:
https://raw.github.com/emacsmirror/dope/master/dope.el

回答4:

This is not, strictly speaking, an answer to your question, but rather than doing the comment-out-and-restart thing, you can start emacs with the -q option, load your .emacs into a buffer and evaluate each sexpr yourself with C-x C-e to track down the offending one.