bug#14966: 24.3.50; Char-displayable-p is a very long running function

["Sebastien Vauban" <sva-news-D0wtAvR13HarG/iDocfnWg@public.gmane.org>]

Eli Zaretskii wrote:
>> From: "Sebastien Vauban" <sva-news-D0wtAvR13HarG/iDocfnWg@public.gmane.org>
>> Date: Sat, 27 Jul 2013 11:47:30 +0200
>> 
>> When looking at the performance of my .emacs at startup time, I've noticed
>> that (char-displayable-p) takes around 400 ms (!) to execute itself...
>
> It calls the font driver to actually encode the character.  That could
> look up several fonts.  FWIW, I see 219 ms on my i7 Windows desktop.

FWIW, I can't reproduce it in a minimal Emacs file (and I remember that the
tests were, in fact, done on my wife's laptop, a recent i5).

Minimal Emacs file:

--8<---------------cut here---------------start------------->8---
(defconst em/emacs-load-time-start (float-time))

;; set default font for all frames
;; (modify-all-frames-parameters '((font . "Consolas-10")))              ;; 0.58 s (max 2.13 s on battery)
;; (modify-all-frames-parameters '((font . "Courier New-9")))            ;; 0.58 s (max 2.13 s on battery)
;; (modify-all-frames-parameters '((font . "DejaVu Sans Mono-9")))       ;; 0.07 s (max 0.25 s on battery)
;; (modify-all-frames-parameters '((font . "Lucida Sans Typewriter-9"))) ;; 0.13 s (max 0.48 s on battery)
;; (modify-all-frames-parameters '((font . "Lucida Console-9")))         ;; 0.57 s (max 2.09 s on battery)
;; default (i.e., nothing)                                               ;; 0.58 s (max 1.83 s on battery)

(defadvice message (before leuven-when-was-that activate)
  "Add timestamps to `message' output."
  (ad-set-arg 0 (concat (format-time-string "[%Y-%m-%d %T.")
                        (substring (format-time-string "%N") 0 3)
                        (format-time-string "] ")
                        (ad-get-arg 0))))

(dolist (i '(1 2 3 4 5 6 7 8 9 10))

  (setq org-ellipsis
         (if (char-displayable-p ?\u25B7) ;; white right-pointing triangle
             " \u25B7" ;; string
           'org-ellipsis))

  (message "Call nr %s" i))

(message "Loading Minimal Emacs... Done (in %.2f s)"
         (- (float-time) em/emacs-load-time-start))
--8<---------------cut here---------------end--------------->8---

Notice that the time spent depends a lot on the chosen font!!!  It is quite
constant (at 0.01 s diff when on mains) for one specific font. For another
font, it can be more than 8 x the time (from 0.07 to 0.58 s).

FWIW, I don't understand the timing in the *Messages* buffer:

--8<---------------cut here---------------start------------->8---
For information about GNU Emacs and the GNU system, type C-h C-a.
[2013-07-29 10:08:14.866] Call nr 1
[2013-07-29 10:08:14.869] Call nr 2
[2013-07-29 10:08:14.870] Call nr 3
[2013-07-29 10:08:14.870] Call nr 4
[2013-07-29 10:08:14.871] Call nr 5
[2013-07-29 10:08:14.872] Call nr 6
[2013-07-29 10:08:14.872] Call nr 7
[2013-07-29 10:08:14.873] Call nr 8
[2013-07-29 10:08:14.873] Call nr 9
[2013-07-29 10:08:14.874] Call nr 10
[2013-07-29 10:08:14.874] Loading Minimal Emacs... Done (in 0.58 s)
--8<---------------cut here---------------end--------------->8---

14.874 (after last call) - 14.866 (after first call) is 0.008 s, not really
0.580 s!???

Something really escapes me here.

> Unless char-displayable-p is called in an inner loop (is it?), this
> shouldn't really matter, should it?

I'm not sure to understand this sentence. What do you mean by inner loop?
As I said to Andreas, I'm looking (hard) to get a startup time of Emacs under
the second. So, for that purpose, yes, it does matter. Though, in general, it
certainly does not hurt that much.

Best regards,
  Seb

-- 
Sebastien Vauban