[parse-speed-byte-compile] Investigating why I cannot reproduce results

[pkryger]

@errge Thank you for this report. I think it explains what the issue is and your conclusion pretty clearly.

I tried to apply your findings to file stdlib-changes from package package-lint. Since there was no exact example how to

[...] specify fixed utf-8 coding at the top of the saved data file

I went with a first line approach. Here's how my example data looks like:

$ diff --text stdlib-changes{,-coding}
0a1
> ;; -*- coding: utf-8-emacs -*-

Then I performed measurements. First with repeatedly loading data from file with no coding specified:

;; 2.24s on my machine
(let* ((gc-cons-threshold (* 500 1024 1024))
       (fname (expand-file-name "stdlib-changes"))
       (_gcbefore (garbage-collect))
       (measurement
        (benchmark-run 100
          (progn
            (setq my-data (with-temp-buffer (insert-file-contents fname) (read (current-buffer))))
	        (unless (assoc '(24 1) my-data) (error "wrong data")))))
       (_verify (cl-assert (eq 0 (cadr measurement))))
       )
  (car measurement))

Followed by loading data from file with specified coding:

;; 2.77 on my machine
(let* ((gc-cons-threshold (* 500 1024 1024))
       (fname (expand-file-name "stdlib-changes-coding"))
       (_gcbefore (garbage-collect))
       (measurement
        (benchmark-run 100
          (progn
            (setq my-data (with-temp-buffer (insert-file-contents fname) (read (current-buffer))))
	        (unless (assoc '(24 1) my-data) (error "wrong data")))))
       (_verify (cl-assert (eq 0 (cadr measurement))))
       )
  (car measurement))

As you can see, the results I got are exactly opposite what the finding in the report are: loading data from a file with coding specified takes longer than loading data from a file that doesn't specify coding. Would you mind helping me understanding why I am getting such a result?

Please let me know if you think that emacs-devel is a better place to have this discussion. I will move it.

Using Emacs MacPort 30.1.50 from this commit in jdsmith/emacs-mac.

FWIW: I've also repeated the experiment using my own implementation of Google Benchmark of interleaved samples methodology (to be found in my basic-stats package and got similar results, that is lloading file with coding specified is ~20% slower:

(use-package basic-stats
  :vc (:url "https://github.com/pkryger/basic-stats.el.git"
       :rev :newest))

(let ((default-directory "~/tmp"))
  (basic-stats-benchmark
      ((detect
        (package-lint--load-data "data/stdlib-changes"))
       (coding
        (package-lint--load-data "data/stdlib-changes-coding")))))

;; Sample results from my machine:
;; ((coding (repetitions . 36) (total-time . "662.592ms") (mean-time . "18.405ms")
;;          (gc . 0) (gc-time . "0.000s") (mean-time-sans-gc . "18.405ms")
;;          (times (min . "18.158ms") (q1 . "18.244ms") (med . "18.344ms")
;;                 (q3 . "18.555ms") (max . "18.798ms"))
;;          (times-sans-gc (min . "18.158ms") (q1 . "18.244ms") (med . "18.344ms")
;;                         (q3 . "18.555ms") (max . "18.798ms")))
;;  (detect (repetitions . 36) (total-time . "566.451ms") (mean-time . "15.735ms")
;;          (gc . 0) (gc-time . "0.000s") (mean-time-sans-gc . "15.735ms")
;;          (times (min . "15.378ms") (q1 . "15.527ms") (med . "15.703ms")
;;                 (q3 . "15.967ms") (max . "16.101ms"))
;;          (times-sans-gc (min . "15.378ms") (q1 . "15.527ms") (med . "15.703ms")
;;                         (q3 . "15.967ms") (max . "16.101ms"))))

[errge]

Hey @pkryger

Thank you for reading my report and trying to reproduce it to your use-case.

I'm testing on linux x64, if you want, I'm happy to run the measurements for you.

Can you please attach your test file to the bug-report?

You could also try ascii encoding.

Your results is even more interesting, because it's hard to understand how autodetection would save us time...

I'm happy to investigate if I get your data file to test with.

[errge]

@pkryger Regarding emacs-devel: I think it's enough if we investigate here, and then if we find something that is actually interesting for the maintainers, then we open bugs/discuss on emacs-devel.

[errge]

@pkryger Sorry for the spam, I just realized that the file you linked to is not a package name, but the actual file already (stdlib-changes sounded like a fancy package :D )

So I will try it on my machine and come back to you asap.

[pkryger]

@errge Thank you for looking at that. I have updated wording in the issue description in a hope to avoid confusion by a next person.

For completeness: I tested on M2 MacBook Air.

IIRC I tried with encoding: ascii but I don't think it's appropriate for this particular file and IIRC the results were even worse (I mean the reading was even slower). I can try to reproduce again and post actual numbers if you think it's useful.

Let me know what your findings are.

[errge]

@pkryger Sorry for the late reply.

For future reference, the file we are talking about is: https://raw.githubusercontent.com/purcell/package-lint/43012b41ac8d1a0ce6118c432c9b822c0f1a1981/data/stdlib-changes

Today, I had more time to look into this. First of all, thanks for your feedback and edits, I did small modifications to make my README more consistent and readable and/or easier to follow.

I find it funny, that core Emacs now has non-ascii variable and function names, thanks for pointing that out implicitly...

And apparently these are causing the issue.

I reproduced your measurements on my machine, and I can confirm your result, coding header at the top makes it slower, but specifying ;;; -*- coding: prefer-utf-8 -*- makes it fast again (which is the default for .el anyway).

So it looks like that if there are actually unicode chars in the buffer, then prefer-utf-8 is faster than utf-8, which is a very surprising result, and I don't yet know the explanation.

If I remove the unicode characters with cat stdlib-changes | recode -f utf-8..ascii >stdlib-changes-ascii, and then reproduce the whole testing with stdlib-changes-ascii, then we get my report's behavior back: utf-8 coding is fast, and prefer-utf-8 coding is slow.

So my current testing shows the following:

• my original report is only true if the file is ascii (no weird characters)
• if the file contains unicode characters and the file is utf-8 encoded, then prefer-utf-8 coding (with autodetection costs) is faster than utf-8 encoding (without autodetection)

The second result is very surprising, and needs further investigation. I'll try to spend time on this and dig deep, but can you please first confirm that you see the same?

[pkryger]

@errge, No problem at all! This is not my top priority either. That doesn't mean that I am not curious why the results are what they are.

I've done a liberty and wrote a tiny script to prepare test data. I hope it is clear what's going on and that its results are reproducible.

I've re-done the experiment, and I think there are three distinct timings in results I observe on my machine. That is:

• slow (more than 1.8s on my machine) when stdlib-changes contains UTF-8 characters and coding specification with either utf-8-emacs or utf-8,
• medium (circa 1.4 to circa 1.55s) when either:
  • stdlib-changes contains UTF-8 characters and no coding specification, or coding specification with prefer-utf-8,
  • stdlib-changes contains only ASCII characters and no coding specification, or coding specification with prefer-utf-8,
• fast (circa 1.3s on my machnie) when stdlib-changes contains only ASCII characters and coding specification with either utf-8-emacs or utf-8.

I yet know what to do with these findings. On the one hand coding specifcation prefer-utf-8 makes things faster for both ASCII only and UTF-8 data. On the other I struggle to recommend that, since coding specification of utf8-emacs (and utf8) yields even better results when file contains only ASCII data. Yet the latter coding specifications makes thing slower when data is actually UTF-8.

Experiment details

Prepare data to test (N.B., below uses gsed on macOS; on GNU Linux sed should be fine):

rm -rf ~/tmp/data-reading
mkdir -p ~/tmp/data-reading
cd ~/tmp/data-reading

curl --silent https://raw.githubusercontent.com/purcell/package-lint/43012b41ac8d1a0ce6118c432c9b822c0f1a1981/data/stdlib-changes > stdlib-changes

cat stdlib-changes | gsed -e '1i ;; -*- coding: utf-8-emacs -*-' > stdlib-changes-coding-utf-8-emacs
cat stdlib-changes | gsed -e '1i ;; -*- coding: utf-8 -*-' > stdlib-changes-coding-utf-8
cat stdlib-changes | gsed -e '1i ;; -*- coding: prefer-utf-8 -*-' > stdlib-changes-coding-prefer-utf-8

cat stdlib-changes{,-coding-prefer-utf8} | recode -f utf8..ascii > stdlib-changes-ascii

cat stdlib-changes-ascii | gsed -e '1i ;; -*- coding: utf-8-emacs -*-' > stdlib-changes-ascii-coding-utf-8-emacs
cat stdlib-changes-ascii | gsed -e '1i ;; -*- coding: utf-8 -*-' > stdlib-changes-ascii-coding-utf-8
cat stdlib-changes-ascii | gsed -e '1i ;; -*- coding: prefer-utf-8 -*-' > stdlib-changes-ascii-coding-prefer-utf-8

Run benchmarks:

(let ((gc-cons-threshold (* 500 1024 1024))
      (fill-column 60) ;; just to make `pp' below to spit one result per line
      (default-directory "~/tmp/data-reading")
      my-data)
  (pp
   (mapcar (lambda (file)
             (garbage-collect)
             (let* ((fname (expand-file-name file))
                    (measurement
                     (benchmark-run 100
                       (progn
                         (setq my-data (with-temp-buffer
                                         (insert-file-contents fname)
                                         (read (current-buffer))))))))
               (cl-assert (eq 0 (cadr measurement)))
               (unless (assoc '(24 1) my-data) (error "wrong data"))
               (setq my-data nil)
               (cons file
                     ;; round to two decimal places
                     (/ (fround (* 100.0 (car measurement))) 100.0))))
           '("stdlib-changes"
             "stdlib-changes-coding-utf-8-emacs"
             "stdlib-changes-coding-utf-8"
             "stdlib-changes-coding-prefer-utf-8"
             "stdlib-changes-ascii"
             "stdlib-changes-ascii-coding-utf-8-emacs"
             "stdlib-changes-ascii-coding-utf-8"
             "stdlib-changes-ascii-coding-prefer-utf-8"))))

Run 3:

(("stdlib-changes" . 1.51)
 ("stdlib-changes-coding-utf-8-emacs" . 1.8)
 ("stdlib-changes-coding-utf-8" . 1.8)
 ("stdlib-changes-coding-prefer-utf-8" . 1.47)
 ("stdlib-changes-ascii" . 1.43)
 ("stdlib-changes-ascii-coding-utf-8-emacs" . 1.33)
 ("stdlib-changes-ascii-coding-utf-8" . 1.33)
 ("stdlib-changes-ascii-coding-prefer-utf-8" . 1.56))

Run 2:

(("stdlib-changes" . 1.51)
 ("stdlib-changes-coding-utf-8-emacs" . 1.8)
 ("stdlib-changes-coding-utf-8" . 1.8)
 ("stdlib-changes-coding-prefer-utf-8" . 1.47)
 ("stdlib-changes-ascii" . 1.43)
 ("stdlib-changes-ascii-coding-utf-8-emacs" . 1.34)
 ("stdlib-changes-ascii-coding-utf-8" . 1.33)
 ("stdlib-changes-ascii-coding-prefer-utf-8" . 1.56))

Run 1:

(("stdlib-changes" . 1.52)
 ("stdlib-changes-coding-utf-8-emacs" . 1.82)
 ("stdlib-changes-coding-utf-8" . 1.83)
 ("stdlib-changes-coding-prefer-utf-8" . 1.47)
 ("stdlib-changes-ascii" . 1.44)
 ("stdlib-changes-ascii-coding-utf-8-emacs" . 1.33)
 ("stdlib-changes-ascii-coding-utf-8" . 1.33)
 ("stdlib-changes-ascii-coding-prefer-utf-8" . 1.56))

Setup info

I have been running these experiments on Emacs 30.1.50 (built from https://github.com/jdtsmith/emacs-mac/tree/4caf8199ea11305ce5f6ca0a380cf18d200d5039), on macOS Sequoia 15.4.1 on MacBook Air M2, 2022.

[errge]

@pkryger Hey, thanks for the very detailed testing and summary writing. If I understand your three cases correctly, it's the exact same result as mine, but much better organized, thanks for that.

Clarification request: "On the one hand coding specifcation prefer-utf-8 makes things faster for both ASCII only and UTF-8 data." Is this a typo or do I misunderstand something? For ascii-only data your run timings show slower prefer-utf-8 timings than utf-8 or no coding specified at all.

Reacting to your question: "what to recommend?" I think that's too early to say at this point.

At this point we have to answer the following question: how is utf-8 slower than prefer-utf-8 when non-ascii characters are present? That is absurd to the max, because after any kind of autodetection heuristics ("prefer"), the same reading has to be done with utf-8 decoding. If we manage to debug and fix this, and make it at least as fast as prefer-utf-8, then after that the recommendation would be clear: do the coding declaration, as it's equal or faster every case.

Is it clear why I'm surprised by this prefer-utf-8 vs utf-8 result on ascii data? Do you have a hunch? If I find the time, I will try to profile these cases somehow on the C level, but I'm not super confident in that, so it will take a while.

[pkryger]

[...] If I understand your three cases correctly, it's the exact same result as mine, but much better organized, thanks for that.

NW. I am glad you found that useful.

Clarification request: "On the one hand coding specifcation prefer-utf-8 makes things faster for both ASCII only and UTF-8 data." Is this a typo or do I misunderstand something? For ascii-only data your run timings show slower prefer-utf-8 timings than utf-8 or no coding specified at all.

I have been rearranging paragraphs multiple times and these are leftovers artefacts from earlier editions. Sorry for that. I think I meant: "On the one hand coding specifcation prefer-utf-8 makes things faster for UTF-8 data".

At this point we have to answer the following question: how is utf-8 slower than prefer-utf-8 when non-ascii characters are present? That is absurd to the max, because after any kind of autodetection heuristics ("prefer"), the same reading has to be done with utf-8 decoding. If we manage to debug and fix this, and make it at least as fast as prefer-utf-8, then after that the recommendation would be clear: do the coding declaration, as it's equal or faster every case.

That's the logical thing to do. As a pure speculation I could suggest that perhaps 'prefer' is not a prefer after all? Or some implementation detail (a performance bug perhaps?) makes things go awry.

Is it clear why I'm surprised by this prefer-utf-8 vs utf-8 result on ascii data? Do you have a hunch? If I find the time, I will try to profile these cases somehow on the C level, but I'm not super confident in that, so it will take a while.

Sorry, I have only a very superficial understanding of what's going on. Would need to dive into code to understand it better. I've done some performance profiling of C++/C code in the past, but that was some time ago, and I don't think many of the techniques I used back then would transfer to the Emacs code base. I will see how much spare time I will have and perhaps take a deep dive myself.