2017-03-03 18:26:30 +09:00
|
|
|
;;; benchmark.el --- support for benchmarking code -*- lexical-binding: t -*-
|
2003-02-03 15:00:57 +00:00
|
|
|
|
2022-01-01 02:45:51 -05:00
|
|
|
;; Copyright (C) 2003-2022 Free Software Foundation, Inc.
|
2003-02-03 15:00:57 +00:00
|
|
|
|
2019-05-26 00:58:28 -07:00
|
|
|
;; Author: Dave Love <fx@gnu.org>
|
2003-02-03 15:00:57 +00:00
|
|
|
;; Keywords: lisp, extensions
|
|
|
|
|
2008-05-06 03:21:21 +00:00
|
|
|
;; This file is part of GNU Emacs.
|
|
|
|
|
|
|
|
;; GNU Emacs is free software: you can redistribute it and/or modify
|
2003-02-03 15:00:57 +00:00
|
|
|
;; it under the terms of the GNU General Public License as published by
|
2008-05-06 03:21:21 +00:00
|
|
|
;; the Free Software Foundation, either version 3 of the License, or
|
|
|
|
;; (at your option) any later version.
|
2003-02-03 15:00:57 +00:00
|
|
|
|
2008-05-06 03:21:21 +00:00
|
|
|
;; GNU Emacs is distributed in the hope that it will be useful,
|
2003-02-03 15:00:57 +00:00
|
|
|
;; but WITHOUT ANY WARRANTY; without even the implied warranty of
|
|
|
|
;; MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
|
|
|
;; GNU General Public License for more details.
|
|
|
|
|
|
|
|
;; You should have received a copy of the GNU General Public License
|
2017-09-13 15:52:52 -07:00
|
|
|
;; along with GNU Emacs. If not, see <https://www.gnu.org/licenses/>.
|
2003-02-03 15:00:57 +00:00
|
|
|
|
|
|
|
;;; Commentary:
|
|
|
|
|
|
|
|
;; Utilities for timing the execution of forms, including the time
|
|
|
|
;; taken for GC. Note that prior to timing code you may want to
|
|
|
|
;; ensure things like: there has just been a GC, the relevant code is
|
|
|
|
;; already loaded (so that there's no overhead from autoloading etc.),
|
|
|
|
;; and the code is compiled if appropriate (but see
|
|
|
|
;; `benchmark-run-compiled').
|
|
|
|
|
|
|
|
;;; Code:
|
|
|
|
|
2021-03-17 19:04:28 -04:00
|
|
|
(eval-when-compile (require 'subr-x)) ;For `named-let'.
|
|
|
|
|
2003-02-03 15:00:57 +00:00
|
|
|
(defmacro benchmark-elapse (&rest forms)
|
|
|
|
"Return the time in seconds elapsed for execution of FORMS."
|
2017-03-03 18:26:30 +09:00
|
|
|
(declare (indent 0) (debug t))
|
Prefer nil to (current-time) when either works
* doc/misc/gnus.texi (Category Syntax):
* lisp/allout-widgets.el (allout-widgets-post-command-business):
* lisp/cedet/ede/detect.el (ede-detect-qtest):
* lisp/cedet/pulse.el (pulse-momentary-highlight-overlay)
(pulse-tick):
* lisp/cedet/semantic.el (bovinate):
* lisp/cedet/semantic/analyze.el:
(semantic-analyze-current-symbol-default, semantic-adebug-analyze):
* lisp/cedet/semantic/analyze/refs.el (semantic-analyze-current-tag):
* lisp/cedet/semantic/lex.el (semantic-lex-test):
* lisp/cedet/semantic/symref/filter.el:
(semantic-symref-test-count-hits-in-tag):
* lisp/cedet/srecode/dictionary.el (srecode-adebug-dictionary):
* lisp/cedet/srecode/map.el (srecode-adebug-maps):
* lisp/desktop.el (desktop-create-buffer):
* lisp/emacs-lisp/benchmark.el (benchmark-elapse):
* lisp/emacs-lisp/elp.el (elp--make-wrapper):
* lisp/epa.el (epa--show-key):
* lisp/erc/erc.el (erc-lurker-cleanup, erc-lurker-p):
* lisp/gnus/gnus-agent.el (gnus-agent-fetch-articles)
(gnus-agent-expire-group-1, gnus-agent-store-article):
* lisp/gnus/gnus-art.el (article-lapsed-string):
* lisp/gnus/gnus-cloud.el (gnus-cloud-update-newsrc-data)
(gnus-cloud-collect-full-newsrc):
* lisp/gnus/gnus-group.el (gnus-group-timestamp-delta):
* lisp/gnus/gnus-html.el (gnus-html-cache-expired):
* lisp/gnus/gnus-score.el (gnus-score-load-file)
(gnus-decay-scores):
* lisp/gnus/nndiary.el (nndiary-expired-article-p):
* lisp/gnus/nnmail.el (nnmail-expired-article-p):
* lisp/gnus/nnmaildir.el (nnmaildir--scan):
* lisp/gnus/score-mode.el (gnus-score-edit-insert-date):
* lisp/image/gravatar.el (gravatar-cache-expired):
* lisp/net/newst-backend.el (newsticker--image-get)
(newsticker--cache-mark-expired):
* lisp/nxml/rng-maint.el (rng-time-function):
* lisp/org/org-agenda.el (org-agenda-to-appt):
* lisp/org/org-clock.el (org-clock-resolve-clock)
(org-clock-resolve, org-resolve-clocks-if-idle):
* lisp/org/org-colview.el (org-columns-edit-value, org-columns)
(org-columns-compute-all, org-agenda-columns):
* lisp/org/org-element.el (org-element--cache-interrupt-p)
(org-element--cache-sync):
* lisp/org/org-habit.el (org-habit-get-faces)
(org-habit-insert-consistency-graphs):
* lisp/org/org-indent.el (org-indent-add-properties):
* lisp/org/org-timer.el (org-timer-start)
(org-timer-pause-or-continue, org-timer-seconds)
(org-timer-show-remaining-time, org-timer-set-timer):
* lisp/org/org.el (org-babel-load-file, org-current-time)
(org-today, org-auto-repeat-maybe, org-read-date-analyze)
(org-small-year-to-year, org-goto-calendar):
* lisp/org/ox.el (org-export-insert-default-template):
* lisp/time.el (emacs-uptime):
* lisp/type-break.el (type-break-mode, type-break)
(type-break-time-warning-schedule, type-break-check):
* lisp/url/url-cache.el (url-cache-expired):
* lisp/url/url.el (url-retrieve-synchronously):
* test/lisp/char-fold-tests.el (char-fold--speed-test):
* test/manual/cedet/semantic-ia-utest.el:
(semantic-symref-test-count-hits-in-tag):
* test/manual/cedet/semantic-tests.el (semantic-idle-pnf-test)
(semantic-lex-test-full-depth):
Use nil instead of (current-time) where either will do, as nil is
a bit more efficient and should have less timing error.
2017-10-20 19:40:09 -07:00
|
|
|
(let ((t1 (make-symbol "t1")))
|
2021-06-11 14:06:29 -04:00
|
|
|
`(let ((,t1 (current-time)))
|
2003-02-03 15:00:57 +00:00
|
|
|
,@forms
|
Avoid some double-rounding of Lisp timestamps
Also, simplify some time-related Lisp timestamp code
while we’re in the neighborhood.
* lisp/battery.el (battery-linux-proc-acpi)
(battery-linux-sysfs, battery-upower, battery-bsd-apm):
* lisp/calendar/timeclock.el (timeclock-seconds-to-string)
(timeclock-log, timeclock-last-period)
(timeclock-entry-length, timeclock-entry-list-span)
(timeclock-find-discrep, timeclock-generate-report):
* lisp/cedet/ede/detect.el (ede-detect-qtest):
* lisp/completion.el (cmpl-hours-since-origin):
* lisp/ecomplete.el (ecomplete-decay-1):
* lisp/emacs-lisp/ert.el (ert--results-update-stats-display)
(ert--results-update-stats-display-maybe):
* lisp/emacs-lisp/timer-list.el (list-timers):
* lisp/emacs-lisp/timer.el (timer-until)
(timer-event-handler):
* lisp/erc/erc-backend.el (erc-server-send-ping)
(erc-server-send-queue, erc-handle-parsed-server-response)
(erc-handle-unknown-server-response):
* lisp/erc/erc-track.el (erc-buffer-visible):
* lisp/erc/erc.el (erc-lurker-cleanup, erc-lurker-p)
(erc-cmd-PING, erc-send-current-line):
* lisp/eshell/em-pred.el (eshell-pred-file-time):
* lisp/eshell/em-unix.el (eshell-show-elapsed-time):
* lisp/gnus/gnus-icalendar.el (gnus-icalendar-event:org-timestamp):
* lisp/gnus/gnus-int.el (gnus-backend-trace):
* lisp/gnus/gnus-sum.el (gnus-user-date):
* lisp/gnus/mail-source.el (mail-source-delete-crash-box):
* lisp/gnus/nnmaildir.el (nnmaildir--scan):
* lisp/ibuf-ext.el (ibuffer-mark-old-buffers):
* lisp/gnus/nnmaildir.el (nnmaildir--scan):
* lisp/mouse.el (mouse--down-1-maybe-follows-link)
(mouse--click-1-maybe-follows-link):
* lisp/mpc.el (mpc--faster-toggle):
* lisp/net/rcirc.el (rcirc-handler-ctcp-KEEPALIVE)
(rcirc-sentinel):
* lisp/net/tramp-cache.el (tramp-get-file-property):
* lisp/net/tramp-sh.el (tramp-sh-handle-file-newer-than-file-p)
(tramp-maybe-open-connection):
* lisp/net/tramp-smb.el (tramp-smb-maybe-open-connection):
* lisp/org/org-clock.el (org-clock-resolve):
(org-resolve-clocks, org-clock-in, org-clock-out, org-clock-sum):
* lisp/org/org-timer.el (org-timer-start)
(org-timer-pause-or-continue, org-timer-seconds):
* lisp/org/org.el (org-evaluate-time-range):
* lisp/org/ox-publish.el (org-publish-cache-ctime-of-src):
* lisp/pixel-scroll.el (pixel-scroll-in-rush-p):
* lisp/play/hanoi.el (hanoi-move-ring):
* lisp/proced.el (proced-format-time):
* lisp/progmodes/cpp.el (cpp-progress-message):
* lisp/progmodes/flymake.el (flymake--handle-report):
* lisp/progmodes/js.el (js--wait-for-matching-output):
* lisp/subr.el (progress-reporter-do-update):
* lisp/term/xterm.el (xterm--read-event-for-query):
* lisp/time.el (display-time-update, emacs-uptime):
* lisp/tooltip.el (tooltip-delay):
* lisp/url/url-cookie.el (url-cookie-parse-file-netscape):
* lisp/url/url-queue.el (url-queue-prune-old-entries):
* lisp/url/url.el (url-retrieve-synchronously):
* lisp/xt-mouse.el (xterm-mouse-event):
Avoid double-rounding of time-related values. Simplify.
* lisp/calendar/icalendar.el (icalendar--decode-isodatetime):
When hoping for the best (unlikely), use a better decoded time.
(icalendar--convert-sexp-to-ical): Avoid unnecessary encode-time.
* lisp/calendar/timeclock.el (timeclock-when-to-leave):
* lisp/cedet/ede/detect.el (ede-detect-qtest):
* lisp/desktop.el (desktop-create-buffer):
* lisp/emacs-lisp/benchmark.el (benchmark-elapse):
* lisp/gnus/gnus-art.el (article-lapsed-string):
* lisp/gnus/gnus-group.el (gnus-group-timestamp-delta):
* lisp/gnus/nnmail.el (nnmail-expired-article-p):
* lisp/gnus/nnmaildir.el (nnmaildir-request-expire-articles):
* lisp/nxml/rng-maint.el (rng-time-function):
* lisp/org/org-clock.el (org-clock-get-clocked-time)
(org-clock-resolve, org-resolve-clocks, org-resolve-clocks-if-idle):
* lisp/org/org-habit.el (org-habit-insert-consistency-graphs):
* lisp/progmodes/vhdl-mode.el (vhdl-update-progress-info)
(vhdl-fix-case-region-1):
Use time-since instead of open-coding most of it.
* lisp/erc/erc-dcc.el (erc-dcc-get-sentinel):
* lisp/erc/erc.el (erc-string-to-emacs-time, erc-time-gt):
Now obsolete. All uses changed.
(erc-time-diff): Accept all Lisp time values.
All uses changed.
* lisp/gnus/gnus-demon.el (gnus-demon-idle-since):
* lisp/gnus/gnus-score.el (gnus-score-headers):
* lisp/gnus/nneething.el (nneething-make-head):
* lisp/gnus/nnheader.el (nnheader-message-maybe):
* lisp/gnus/nnimap.el (nnimap-keepalive):
* lisp/image.el (image-animate-timeout):
* lisp/mail/feedmail.el (feedmail-rfc822-date):
* lisp/net/imap.el (imap-wait-for-tag):
* lisp/net/newst-backend.el (newsticker--image-get):
* lisp/net/rcirc.el (rcirc-handler-317, rcirc-handler-333):
* lisp/obsolete/xesam.el (xesam-refresh-entry):
* lisp/org/org-agenda.el (org-agenda-show-clocking-issues)
(org-agenda-check-clock-gap, org-agenda-to-appt):
* lisp/org/org-capture.el (org-capture-set-target-location):
* lisp/org/org-clock.el (org-clock-resolve-clock)
(org-clocktable-steps):
* lisp/org/org-colview.el (org-columns-edit-value)
(org-columns, org-agenda-columns):
* lisp/org/org-duration.el (org-duration-from-minutes):
* lisp/org/org-element.el (org-element-cache-sync-duration)
(org-element-cache-sync-break)
(org-element--cache-interrupt-p, org-element--cache-sync):
* lisp/org/org-habit.el (org-habit-get-faces)
* lisp/org/org-indent.el (org-indent-add-properties):
* lisp/org/org-table.el (org-table-sum):
* lisp/org/org-timer.el (org-timer-show-remaining-time)
(org-timer-set-timer):
* lisp/org/org.el (org-babel-load-file, org-today)
(org-auto-repeat-maybe, org-2ft, org-time-stamp)
(org-read-date-analyze, org-time-stamp-to-now)
(org-small-year-to-year, org-goto-calendar):
* lisp/org/ox.el (org-export-insert-default-template):
* lisp/ses.el (ses--time-check):
* lisp/type-break.el (type-break-time-warning)
(type-break-statistics, type-break-demo-boring):
* lisp/url/url-cache.el (url-cache-expired)
(url-cache-prune-cache):
* lisp/vc/vc-git.el (vc-git-stash-snapshot):
* lisp/erc/erc-match.el (erc-log-matches-come-back):
Simplify.
2019-02-22 18:32:31 -08:00
|
|
|
(float-time (time-since ,t1)))))
|
2011-06-30 17:27:45 -07:00
|
|
|
|
2021-03-17 19:04:28 -04:00
|
|
|
;;;###autoload
|
|
|
|
(defun benchmark-call (func &optional repetitions)
|
|
|
|
"Measure the run time of calling FUNC a number REPETITIONS of times.
|
|
|
|
The result is a list (TIME GC GCTIME)
|
|
|
|
where TIME is the total time it took, in seconds.
|
|
|
|
GCTIME is the amount of time that was spent in the GC
|
|
|
|
and GC is the number of times the GC was called.
|
|
|
|
|
|
|
|
REPETITIONS can also be a floating point number, in which case it
|
|
|
|
specifies a minimum number of seconds that the benchmark execution
|
|
|
|
should take. In that case the return value is prepended with the
|
|
|
|
number of repetitions actually used."
|
|
|
|
(if (floatp repetitions)
|
|
|
|
(benchmark--adaptive func repetitions)
|
|
|
|
(unless repetitions (setq repetitions 1))
|
|
|
|
(let ((gc gc-elapsed)
|
|
|
|
(gcs gcs-done)
|
|
|
|
(empty-func (lambda () 'empty-func)))
|
|
|
|
(list
|
|
|
|
(if (> repetitions 1)
|
|
|
|
(- (benchmark-elapse (dotimes (_ repetitions) (funcall func)))
|
|
|
|
(benchmark-elapse (dotimes (_ repetitions) (funcall empty-func))))
|
|
|
|
(- (benchmark-elapse (funcall func))
|
|
|
|
(benchmark-elapse (funcall empty-func))))
|
|
|
|
(- gcs-done gcs)
|
|
|
|
(- gc-elapsed gc)))))
|
|
|
|
|
|
|
|
(defun benchmark--adaptive (func time)
|
|
|
|
"Measure the run time of FUNC, calling it enough times to last TIME seconds.
|
|
|
|
Result is (REPETITIONS . DATA) where DATA is as returned by `branchmark-call'."
|
|
|
|
(named-let loop ((repetitions 1)
|
|
|
|
(data (let ((x (list 0))) (setcdr x x) x)))
|
|
|
|
;; (message "Running %d iteration" repetitions)
|
|
|
|
(let ((newdata (benchmark-call func repetitions)))
|
|
|
|
(if (<= (car newdata) 0)
|
|
|
|
;; This can happen if we're unlucky, e.g. the process got preempted
|
|
|
|
;; (or the GC ran) just during the empty-func loop.
|
|
|
|
;; Just try again, hopefully this won't repeat itself.
|
|
|
|
(progn
|
|
|
|
;; (message "Ignoring the %d iterations" repetitions)
|
|
|
|
(loop (* 2 repetitions) data))
|
|
|
|
(let* ((sum (cl-mapcar #'+ data (cons repetitions newdata)))
|
|
|
|
(totaltime (nth 1 sum)))
|
|
|
|
(if (>= totaltime time)
|
|
|
|
sum
|
|
|
|
(let* ((iter-time (/ totaltime (car sum)))
|
|
|
|
(missing-time (- time totaltime))
|
|
|
|
(missing-iter (/ missing-time iter-time)))
|
|
|
|
;; `iter-time' is approximate because of effects like the GC,
|
|
|
|
;; so multiply at most by 10, in case we are wildly off the mark.
|
|
|
|
(loop (max repetitions
|
|
|
|
(min (ceiling missing-iter)
|
|
|
|
(* 10 repetitions)))
|
|
|
|
sum))))))))
|
|
|
|
|
2003-02-03 15:00:57 +00:00
|
|
|
;;;###autoload
|
|
|
|
(defmacro benchmark-run (&optional repetitions &rest forms)
|
|
|
|
"Time execution of FORMS.
|
2020-11-16 12:48:54 +01:00
|
|
|
If REPETITIONS is supplied as a number, run FORMS that many times,
|
2003-02-03 15:00:57 +00:00
|
|
|
accounting for the overhead of the resulting loop. Otherwise run
|
|
|
|
FORMS once.
|
|
|
|
Return a list of the total elapsed time for execution, the number of
|
|
|
|
garbage collections that ran, and the time taken by garbage collection.
|
|
|
|
See also `benchmark-run-compiled'."
|
2012-09-09 21:16:13 -04:00
|
|
|
(declare (indent 1) (debug t))
|
2018-03-27 16:19:40 -04:00
|
|
|
(unless (or (natnump repetitions) (and repetitions (symbolp repetitions)))
|
2003-02-03 15:00:57 +00:00
|
|
|
(setq forms (cons repetitions forms)
|
|
|
|
repetitions 1))
|
2021-03-17 19:04:28 -04:00
|
|
|
`(benchmark-call (lambda () ,@forms) ,repetitions))
|
2003-02-03 15:00:57 +00:00
|
|
|
|
|
|
|
;;;###autoload
|
|
|
|
(defmacro benchmark-run-compiled (&optional repetitions &rest forms)
|
|
|
|
"Time execution of compiled version of FORMS.
|
|
|
|
This is like `benchmark-run', but what is timed is a funcall of the
|
|
|
|
byte code obtained by wrapping FORMS in a `lambda' and compiling the
|
|
|
|
result. The overhead of the `lambda's is accounted for."
|
2012-09-09 21:16:13 -04:00
|
|
|
(declare (indent 1) (debug t))
|
2018-03-27 16:19:40 -04:00
|
|
|
(unless (or (natnump repetitions) (and repetitions (symbolp repetitions)))
|
2003-02-03 15:00:57 +00:00
|
|
|
(setq forms (cons repetitions forms)
|
|
|
|
repetitions 1))
|
2021-03-17 19:04:28 -04:00
|
|
|
`(benchmark-call (byte-compile '(lambda () ,@forms)) ,repetitions))
|
2003-02-03 15:00:57 +00:00
|
|
|
|
|
|
|
;;;###autoload
|
|
|
|
(defun benchmark (repetitions form)
|
|
|
|
"Print the time taken for REPETITIONS executions of FORM.
|
2018-02-17 11:59:36 +02:00
|
|
|
Interactively, REPETITIONS is taken from the prefix arg, and
|
|
|
|
the command prompts for the form to benchmark.
|
2009-03-17 10:32:20 +00:00
|
|
|
For non-interactive use see also `benchmark-run' and
|
2021-03-17 19:04:28 -04:00
|
|
|
`benchmark-run-compiled'.
|
|
|
|
FORM can also be a function in which case we measure the time it takes
|
|
|
|
to call it without any argument."
|
2003-02-03 15:00:57 +00:00
|
|
|
(interactive "p\nxForm: ")
|
2021-03-17 19:04:28 -04:00
|
|
|
(let ((result (benchmark-call (eval (pcase form
|
|
|
|
((or `#',_ `(lambda . ,_)) form)
|
|
|
|
(_ `(lambda () ,form)))
|
|
|
|
t)
|
|
|
|
repetitions)))
|
2003-02-03 15:00:57 +00:00
|
|
|
(if (zerop (nth 1 result))
|
|
|
|
(message "Elapsed time: %fs" (car result))
|
|
|
|
(message "Elapsed time: %fs (%fs in %d GCs)" (car result)
|
|
|
|
(nth 2 result) (nth 1 result)))))
|
|
|
|
|
2019-10-15 08:19:08 +02:00
|
|
|
;;;###autoload
|
|
|
|
(defmacro benchmark-progn (&rest body)
|
|
|
|
"Evaluate BODY and message the time taken.
|
|
|
|
The return value is the value of the final form in BODY."
|
|
|
|
(declare (debug body) (indent 0))
|
|
|
|
(let ((value (make-symbol "value"))
|
|
|
|
(start (make-symbol "start"))
|
|
|
|
(gcs (make-symbol "gcs"))
|
|
|
|
(gc (make-symbol "gc")))
|
|
|
|
`(let ((,gc gc-elapsed)
|
|
|
|
(,gcs gcs-done)
|
|
|
|
(,start (current-time))
|
|
|
|
(,value (progn
|
|
|
|
,@body)))
|
|
|
|
(message "Elapsed time: %fs%s"
|
|
|
|
(float-time (time-since ,start))
|
|
|
|
(if (> (- gcs-done ,gcs) 0)
|
|
|
|
(format " (%fs in %d GCs)"
|
|
|
|
(- gc-elapsed ,gc)
|
|
|
|
(- gcs-done ,gcs))
|
|
|
|
""))
|
|
|
|
;; Return the value of the body.
|
|
|
|
,value)))
|
|
|
|
|
2003-02-03 15:00:57 +00:00
|
|
|
(provide 'benchmark)
|
2003-09-01 15:45:59 +00:00
|
|
|
|
2003-02-03 15:00:57 +00:00
|
|
|
;;; benchmark.el ends here
|