Re: Emacs 23.0 is much slower starting than Emacs 22.3

["Lennart Borgman" <lennart.borgman@gmail.com>]

On Fri, Oct 24, 2008 at 11:51 AM, Eli Zaretskii <eliz@gnu.org> wrote:
>> Date: Fri, 24 Oct 2008 01:54:06 +0200
>> From: "Lennart Borgman" <lennart.borgman@gmail.com>
>> Cc: "Eli Zaretskii" <eliz@gnu.org>, acm@muc.de, monnier@iro.umontreal.ca,
>>       emacs-devel@gnu.org
>>
>>   Timing insert-file-contents-literally:
>>   Elapsed time: 8.375000s (0.187000s in 1 GCs)
>>   Timing insert-file-contents:
>>   Elapsed time: 14.297000s (0.312000s in 2 GCs)
>>   Timing file-attributes:
>>   Elapsed time: 5.890000s (0.156000s in 1 GCs)
>>   Timing file-exists-p:
>>   Elapsed time: 6.672000s (0.125000s in 1 GCs)
>>   Timing file-modes:
>>   Elapsed time: 5.609000s (0.188000s in 1 GCs)
>
> Thanks, but what does this mean?  What is behind a line such as

Here is the code again, a little bit enhanced:

(defun test-insert-dir (dir how)
  (let ((files (directory-files dir t)))
    (dolist (file files)
      (unless (file-directory-p file)
        (with-temp-buffer
          (cond
           ((eq how 'literally)
            (insert-file-contents-literally file))
           ((eq how 'normal-insert)
            (insert-file-contents file))
           ((eq how 'attributes)
            (file-attributes file))
           ((eq how 'exists)
            (file-exists-p file))
           ((eq how 'file-modes)
            (file-exists-p file))
           ((eq how 'normal-mode)
            (setq buffer-file-name file)
            (emacs-lisp-mode)
            (setq buffer-file-name nil)
            (set-buffer-modified-p nil))
           (t
            (error "How=%s" how))
           ))))))

(defun test-insert-emacs-lisp-dir ()
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'literally))
  (message "======================= After cache warm up")
  (message "Timing insert-file-contents-literally:")
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'literally))
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'literally))
  (message "Timing insert-file-contents:")
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/"
'normal-insert))
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/"
'normal-insert))
  (message "Timing file-attributes:")
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'attributes))
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'attributes))
  (message "Timing file-exists-p:")
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'exists))
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'exists))
  (message "Timing file-modes:")
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'file-modes))
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'file-modes))
  (message "Timing normal-mode:")
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'normal-mode))
  (benchmark 1 '(test-insert-dir "c:/emacs/u/070103/emacs/lisp/" 'normal-mode))
  (message "Ready"))

> Also, please compare that with Emacs 22, since this whole thread is
> about comparative performance.

In Emacs 22 I get in *Messages* buffer:

  ======================= After cache warm up
  Timing insert-file-contents-literally:
  Elapsed time: 3.172000s (0.031000s in 1 GCs)
  Elapsed time: 3.141000s (0.032000s in 1 GCs)
  Timing insert-file-contents:
  Elapsed time: 4.609000s (0.125000s in 4 GCs)
  Elapsed time: 4.610000s (0.125000s in 4 GCs)
  Timing file-attributes:
  Elapsed time: 1.859000s (0.031000s in 1 GCs)
  Elapsed time: 1.891000s (0.015000s in 1 GCs)
  Timing file-exists-p:
  Elapsed time: 1.875000s (0.016000s in 1 GCs)
  Elapsed time: 1.968000s (0.016000s in 1 GCs)
  Timing file-modes:
  Elapsed time: 2.063000s (0.031000s in 1 GCs)
  Elapsed time: 1.859000s (0.031000s in 1 GCs)
  Timing normal-mode:
  Elapsed time: 1.235000s (0.048000s in 2 GCs)
  Elapsed time: 1.437000s (0.016000s in 1 GCs)

and in Emacs 23:

  ======================= After cache warm up
  Timing insert-file-contents-literally:
  Elapsed time: 4.844000s
  Elapsed time: 4.828000s (0.109000s in 1 GCs)
  Timing insert-file-contents:
  Elapsed time: 8.094000s (0.109000s in 1 GCs)
  Elapsed time: 8.063000s (0.219000s in 2 GCs)
  Timing file-attributes:
  Elapsed time: 3.796000s
  Elapsed time: 3.579000s (0.094000s in 1 GCs)
  Timing file-exists-p:
  Elapsed time: 3.515000s
  Elapsed time: 3.578000s (0.109000s in 1 GCs)
  Timing file-modes:
  Elapsed time: 3.625000s
  Elapsed time: 3.953000s (0.109000s in 1 GCs)
  Timing normal-mode:
  Mark set [553 times]
  Elapsed time: 3.985000s (0.891000s in 9 GCs)
  Mark set [553 times]
  Elapsed time: 6.031000s (1.810000s in 18 GCs)

The system calls (file-attributes, file-exists-p and file-modes) takes
nearly twice as long time in Emacs 23 (on w32). For normal-mode the
factor is even bigger, 3-4 times longer time.