Emacs init performance analysis

I recently wanted to have some more information about which of the packages I am using contributes more time to the total (emacs-init-time) I use to keep my emacs init code in a single file and I manually divide the file into sections of related code. A section is opened by entering a carefully prepared comment string and ended by another one so that it looks like this:

;; [ an example section
(some emacs lisp)
(and some more)
;; ]

Starting from here I could alter my init file to write down time values from the stop-clock (And since I also need to know to which section the time value belongs – the section names). Therefore I invoked query-replace-regexp and query-replace to surround my sections with emacs lisp to collect the necessary information:

query replace regexp: ;; []] \(.*\) ➤ ;; [ \1[C-q C-j](add-to-list 'section-names "\1")
query replace: ;; ] ➤  (add-to-list 'init-runtime (get-internal-run-time))[C-q C-j];; ]

My example section would then look like this:

;; [ an example section
(add-to-list 'section-names "an example section")
(some emacs lisp)
(and some more)
(add-to-list 'init-runtime (get-internal-run-time))
;; ]

After the whole file is processed I end up with two lists (I called them section-names and init-runtime). These I then further-process. So I switched to an org-mode buffer and entered


#+NAME: perf_data_names
#+BEGIN_SRC emacs-lisp
(reverse section-names)
#+END_SRC

#+NAME: perf_data_times
#+BEGIN_SRC emacs-lisp
(progn
    (let ((bak-init-times init-runtime)
          (next nil)
          (result '()))
        (while bak-init-times
           (setq next (car bak-init-times))
           (setq bak-init-times (cdr bak-init-times))
           (add-to-list 'result (+ (nth 2 next)
                                   (* (nth 1 next) 1000000))))
      result))
#+END_SRC

#+BEGIN_SRC python :var sections=perf_data_names :var times=perf_data_times :results output
xtics="set xtics ("
numsections=len(sections)
for i, section in enumerate(sections):
    xtics = xtics +  "\"{0}\" {1}".format(section, i+1)
    if i<numsections-1:
      xtics = xtics + ", "
xtics+=")"      
print("set grid")
print(xtics)
print("plot \"-\" using 1:2 title "Stopclock times")
for i, time in enumerate(times):
    print("{0} {1}".format(i+1, time))
print("e")    
#+END_SRC

This results in a snippet of text that can be fed into gnuplot! Gnuplot kindly generates the following image:

It turns out that no one can really be blamed for beeing responsible and it must be taken into consideration that some of the loading may be deferred and is not subject to the analysis (No, I did not look up how exactly use-package is deferring package loading). Some sections take more time then others:

  • packages
  • s
  • global appearance
  • yasnippet
  • org mode
  • java mode
  • elpy python
  • magit

6 Kommentare

  1. You may also like using use-package itself to measure performance. You can do so by setting use-package-verbose to t, and optionally configuring use-package-minimum-reported-time as well. Have fun!

Schreibe einen Kommentar

Deine E-Mail-Adresse wird nicht veröffentlicht. Erforderliche Felder sind mit * markiert.