1 ;;;; benchmark-suite/lib.scm --- generic support for benchmarking
2 ;;;; Copyright (C) 2002, 2006, 2011 Free Software Foundation, Inc.
4 ;;;; This program is free software; you can redistribute it and/or
5 ;;;; modify it under the terms of the GNU Lesser General Public
6 ;;;; License as published by the Free Software Foundation; either
7 ;;;; version 3, or (at your option) any later version.
9 ;;;; This program is distributed in the hope that it will be useful,
10 ;;;; but WITHOUT ANY WARRANTY; without even the implied warranty of
11 ;;;; MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
12 ;;;; GNU Lesser General Public License for more details.
14 ;;;; You should have received a copy of the GNU Lesser General Public
15 ;;;; License along with this software; see the file COPYING.LESSER.
16 ;;;; If not, write to the Free Software Foundation, Inc., 51 Franklin
17 ;;;; Street, Fifth Floor, Boston, MA 02110-1301 USA
19 (define-module (benchmark-suite lib)
22 ;; Controlling the execution.
26 ;; Running benchmarks.
30 ;; Naming groups of benchmarks in a regular fashion.
31 with-benchmark-prefix with-benchmark-prefix* current-benchmark-prefix
34 ;; Computing timing results
36 benchmark-total-time benchmark-user-time benchmark-system-time
37 benchmark-frame-time benchmark-core-time
38 benchmark-user-time\interpreter benchmark-core-time\interpreter
40 ;; Reporting results in various ways.
41 register-reporter unregister-reporter reporter-registered?
47 ;;;; If you're using Emacs's Scheme mode:
48 ;;;; (put 'with-benchmark-prefix 'scheme-indent-function 1)
49 ;;;; (put 'benchmark 'scheme-indent-function 1)
54 ;;;; The function (run-benchmark name iterations thunk) is the heart of the
55 ;;;; benchmarking environment. The first parameter NAME is a unique name for
56 ;;;; the benchmark to be executed (for an explanation of this parameter see
57 ;;;; below under ;;;; NAMES. The second parameter ITERATIONS is a positive
58 ;;;; integer value that indicates how often the thunk shall be executed (for
59 ;;;; an explanation of how iteration counts should be used, see below under
60 ;;;; ;;;; ITERATION COUNTS). For example:
62 ;;;; (run-benchmark "small integer addition" 100000 (lambda () (+ 1 1)))
64 ;;;; This will run the function (lambda () (+ 1 1)) a 100000 times (the
65 ;;;; iteration count can, however be scaled. See below for details). Some
66 ;;;; different time data for running the thunk for the given number of
67 ;;;; iterations is measured and reported.
69 ;;;; Convenience macro
71 ;;;; * (benchmark name iterations body) is a short form for
72 ;;;; (run-benchmark name iterations (lambda () body))
77 ;;;; Every benchmark in the benchmark suite has a unique name to be able to
78 ;;;; compare the results of individual benchmarks across several runs of the
81 ;;;; A benchmark name is a list of printable objects. For example:
82 ;;;; ("ports.scm" "file" "read and write back list of strings")
83 ;;;; ("ports.scm" "pipe" "read")
85 ;;;; Benchmark names may contain arbitrary objects, but they always have
86 ;;;; the following properties:
87 ;;;; - Benchmark names can be compared with EQUAL?.
88 ;;;; - Benchmark names can be reliably stored and retrieved with the standard
89 ;;;; WRITE and READ procedures; doing so preserves their identity.
93 ;;;; (benchmark "simple addition" 100000 (+ 2 2))
95 ;;;; In that case, the benchmark name is the list ("simple addition").
97 ;;;; The WITH-BENCHMARK-PREFIX syntax and WITH-BENCHMARK-PREFIX* procedure
98 ;;;; establish a prefix for the names of all benchmarks whose results are
99 ;;;; reported within their dynamic scope. For example:
102 ;;;; (with-benchmark-prefix "basic arithmetic"
103 ;;;; (benchmark "addition" 100000 (+ 2 2))
104 ;;;; (benchmark "subtraction" 100000 (- 4 2)))
105 ;;;; (benchmark "multiplication" 100000 (* 2 2))))
107 ;;;; In that example, the three benchmark names are:
108 ;;;; ("basic arithmetic" "addition"),
109 ;;;; ("basic arithmetic" "subtraction"), and
110 ;;;; ("multiplication").
112 ;;;; WITH-BENCHMARK-PREFIX can be nested. Each WITH-BENCHMARK-PREFIX
113 ;;;; appends a new element to the current prefix:
115 ;;;; (with-benchmark-prefix "arithmetic"
116 ;;;; (with-benchmark-prefix "addition"
117 ;;;; (benchmark "integer" 100000 (+ 2 2))
118 ;;;; (benchmark "complex" 100000 (+ 2+3i 4+5i)))
119 ;;;; (with-benchmark-prefix "subtraction"
120 ;;;; (benchmark "integer" 100000 (- 2 2))
121 ;;;; (benchmark "complex" 100000 (- 2+3i 1+2i))))
123 ;;;; The four benchmark names here are:
124 ;;;; ("arithmetic" "addition" "integer")
125 ;;;; ("arithmetic" "addition" "complex")
126 ;;;; ("arithmetic" "subtraction" "integer")
127 ;;;; ("arithmetic" "subtraction" "complex")
129 ;;;; To print a name for a human reader, we DISPLAY its elements,
130 ;;;; separated by ": ". So, the last set of benchmark names would be
133 ;;;; arithmetic: addition: integer
134 ;;;; arithmetic: addition: complex
135 ;;;; arithmetic: subtraction: integer
136 ;;;; arithmetic: subtraction: complex
138 ;;;; The Guile benchmarks use with-benchmark-prefix to include the name of
139 ;;;; the source file containing the benchmark in the benchmark name, to
140 ;;;; provide each file with its own namespace.
143 ;;;; ITERATION COUNTS
145 ;;;; Every benchmark has to be given an iteration count that indicates how
146 ;;;; often it should be executed. The reason is, that in most cases a single
147 ;;;; execution of the benchmark code would not deliver usable timing results:
148 ;;;; The resolution of the system time is not arbitrarily fine. Thus, some
149 ;;;; benchmarks would be executed too quickly to be measured at all. A rule
150 ;;;; of thumb is, that the longer a benchmark runs, the more exact is the
151 ;;;; information about the execution time.
153 ;;;; However, execution time depends on several influences: First, the
154 ;;;; machine you are running the benchmark on. Second, the compiler you use.
155 ;;;; Third, which compiler options you use. Fourth, which version of guile
156 ;;;; you are using. Fifth, which guile options you are using (for example if
157 ;;;; you are using the debugging evaluator or not). There are even more
160 ;;;; For this reason, the same number of iterations for a single benchmark may
161 ;;;; lead to completely different execution times in different
162 ;;;; constellations. For someone working on a slow machine, the default
163 ;;;; execution counts may lead to an inacceptable execution time of the
164 ;;;; benchmark suite. For someone on a very fast machine, however, it may be
165 ;;;; desireable to increase the number of iterations in order to increase the
166 ;;;; accuracy of the time data.
168 ;;;; For this reason, the benchmark suite allows to scale the number of
169 ;;;; executions by a global factor, stored in the exported variable
170 ;;;; iteration-factor. The default for iteration-factor is 1. A number of 2
171 ;;;; means, that all benchmarks are executed twice as often, which will also
172 ;;;; roughly double the execution time for the benchmark suite. Similarly, if
173 ;;;; iteration-factor holds a value of 0.5, only about half the execution time
174 ;;;; will be required.
176 ;;;; It is probably a good idea to choose the iteration count for each
177 ;;;; benchmark such that all benchmarks will take about the same time, for
178 ;;;; example one second. To achieve this, the benchmark suite holds an empty
179 ;;;; benchmark in the file 0-reference.bm named "reference benchmark for
180 ;;;; iteration counts". It's iteration count is calibrated to make the
181 ;;;; benchmark run about one second on Dirk's laptop :-) If you are adding
182 ;;;; benchmarks to the suite, it would be nice if you could calibrate the
183 ;;;; number of iterations such that each of your added benchmarks takes about
184 ;;;; as long to run as the reference benchmark. But: Don't be too accurate
185 ;;;; to figure out the correct iteration count.
190 ;;;; A reporter is a function which we apply to each benchmark outcome.
191 ;;;; Reporters can log results, print interesting results to the standard
192 ;;;; output, collect statistics, etc.
194 ;;;; A reporter function takes the following arguments: NAME ITERATIONS
195 ;;;; BEFORE AFTER GC-TIME. The argument NAME holds the name of the benchmark,
196 ;;;; ITERATIONS holds the actual number of iterations that were performed.
197 ;;;; BEFORE holds the result of the function (times) at the very beginning of
198 ;;;; the excution of the benchmark, AFTER holds the result of the function
199 ;;;; (times) after the execution of the benchmark. GC-TIME, finally, holds
200 ;;;; the difference of calls to (gc-run-time) before and after the execution
201 ;;;; of the benchmark.
203 ;;;; This library provides some standard reporters for logging results
204 ;;;; to a file, reporting interesting results to the user, (FIXME: and
205 ;;;; collecting totals).
207 ;;;; You can use the REGISTER-REPORTER function and friends to add whatever
208 ;;;; reporting functions you like. See under ;;;; TIMING DATA to see how the
209 ;;;; library helps you to extract relevant timing information from the values
210 ;;;; ITERATIONS, BEFORE, AFTER and GC-TIME. If you don't register any
211 ;;;; reporters, the library uses USER-REPORTER, which writes the most
212 ;;;; interesting results to the standard output.
215 ;;;; TIME CALCULATION
217 ;;;; The library uses the guile functions (times) and (gc-run-time) to
218 ;;;; determine the execution time for a single benchmark. Based on these
219 ;;;; functions, the values of BEFORE, AFTER and GC-TIME are computed, which
220 ;;;; are then passed to the reporter functions. All three values BEFORE,
221 ;;;; AFTER and GC-TIME include the time needed to executed the benchmark code
222 ;;;; itself, but also the surrounding code that implements the loop to run the
223 ;;;; benchmark code for the given number of times. This is undesirable, since
224 ;;;; one would prefer to only get the timing data for the benchmarking code.
226 ;;;; To cope with this, the benchmarking framework uses a trick: During
227 ;;;; initialization of the library, the time for executing an empty benchmark
228 ;;;; is measured and stored. This is an estimate for the time needed by the
229 ;;;; benchmarking framework itself. For later benchmarks, this time can then
230 ;;;; be subtracted from the measured execution times.
232 ;;;; In order to simplify the time calculation for users who want to write
233 ;;;; their own reporters, benchmarking framework provides the following
236 ;;;; benchmark-time-base : This variable holds the number of time units that
237 ;;;; make up a second. By deviding the results of each of the functions
238 ;;;; below by this value, you get the corresponding time in seconds. For
239 ;;;; example (/ (benchmark-total-time before after) benchmark-time-base)
240 ;;;; will give you the total time in seconds.
241 ;;;; benchmark-total-time : this function takes two arguments BEFORE and AFTER
242 ;;;; and computes the total time between the two timestamps. The result
243 ;;;; of this function is what the time command of the unix command line
244 ;;;; would report as real time.
245 ;;;; benchmark-user-time : this function takes two arguments BEFORE and AFTER
246 ;;;; and computes the time spent in the benchmarking process between the
247 ;;;; two timestamps. That means, the time consumed by other processes
248 ;;;; running on the same machine is not part of the resulting time,
249 ;;;; neither is time spent within the operating system. The result of
250 ;;;; this function is what the time command of the unix command line would
251 ;;;; report as user time.
252 ;;;; benchmark-system-time : similar to benchmark-user-time, but here the time
253 ;;;; spent within the operating system is given. The result of this
254 ;;;; function is what the time command of the unix command line would
255 ;;;; report as system time.
256 ;;;; benchmark-frame-time : this function takes the argument ITERATIONS. It
257 ;;;; reports the part of the user time that is consumed by the
258 ;;;; benchmarking framework itself to run some benchmark for the given
259 ;;;; number of iterations. You can think of this as the time that would
260 ;;;; still be consumed, even if the benchmarking code itself was empty.
261 ;;;; This value does not include any time for garbage collection, even if
262 ;;;; it is the benchmarking framework which is responsible for causing a
263 ;;;; garbage collection.
264 ;;;; benchmark-core-time : this function takes three arguments ITERATIONS,
265 ;;;; BEFORE and AFTER. It reports the part of the user time that is
266 ;;;; actually spent within the benchmarking code. That is, the time
267 ;;;; needed for the benchmarking framework is subtracted from the user
268 ;;;; time. This value, however, includes all garbage collection times,
269 ;;;; even if some part of the gc-time had actually to be attributed to the
270 ;;;; benchmarking framework.
271 ;;;; benchmark-user-time\interpreter : this function takes three arguments
272 ;;;; BEFORE AFTER and GC-TIME. It reports the part of the user time that
273 ;;;; is spent in the interpreter (and not in garbage collection).
274 ;;;; benchmark-core-time\interpreter : this function takes four arguments
275 ;;;; ITERATIONS, BEFORE, AFTER. and GC-TIME. It reports the part of the
276 ;;;; benchmark-core-time that is spent in the interpreter (and not in
277 ;;;; garbage collection). This value is most probably the one you are
278 ;;;; interested in, except if you are doing some garbage collection
281 ;;;; There is no function to calculate the garbage-collection time, since the
282 ;;;; garbage collection time is already passed as an argument GC-TIME to the
283 ;;;; reporter functions.
289 ;;; Perform a division and convert the result to inexact.
291 (exact->inexact (/ a b)))
293 ;;; Scale the number of iterations according to the given scaling factor.
294 (define iteration-factor 1)
295 (define (scale-iterations iterations)
296 (let* ((i (inexact->exact (round (* iterations iteration-factor)))))
303 ;;; The central routine for executing benchmarks.
304 ;;; The idea is taken from Greg, the GNUstep regression test environment.
305 (define run-benchmark #f)
306 (let ((benchmark-running #f))
307 (define (local-run-benchmark name iterations thunk)
308 (if benchmark-running
309 (error "Nested calls to run-benchmark are not permitted.")
310 (let ((benchmark-name (full-name name))
311 (iterations (scale-iterations iterations)))
312 (set! benchmark-running #t)
313 (let ((before #f) (after #f) (gc-time #f))
315 (set! gc-time (gc-run-time))
316 (set! before (times))
321 (set! gc-time (- (gc-run-time) gc-time))
322 (report benchmark-name iterations before after gc-time))
323 (set! benchmark-running #f))))
324 (set! run-benchmark local-run-benchmark))
326 ;;; A short form for benchmarks.
327 (defmacro benchmark (name iterations body . rest)
328 `(run-benchmark ,name ,iterations (lambda () ,body ,@rest)))
334 ;;;; Turn a benchmark name into a nice human-readable string.
335 (define (format-benchmark-name name)
336 (call-with-output-string
338 (let loop ((name name)
342 (display separator port)
343 (display (car name) port)
344 (loop (cdr name) ": ")))))))
346 ;;;; For a given benchmark-name, deliver the full name including all prefixes.
347 (define (full-name name)
348 (append (current-benchmark-prefix) (list name)))
350 ;;; A fluid containing the current benchmark prefix, as a list.
351 (define prefix-fluid (make-fluid '()))
352 (define (current-benchmark-prefix)
353 (fluid-ref prefix-fluid))
355 ;;; Postpend PREFIX to the current name prefix while evaluting THUNK.
356 ;;; The name prefix is only changed within the dynamic scope of the
357 ;;; call to with-benchmark-prefix*. Return the value returned by THUNK.
358 (define (with-benchmark-prefix* prefix thunk)
359 (with-fluids ((prefix-fluid
360 (append (fluid-ref prefix-fluid) (list prefix))))
363 ;;; (with-benchmark-prefix PREFIX BODY ...)
364 ;;; Postpend PREFIX to the current name prefix while evaluating BODY ...
365 ;;; The name prefix is only changed within the dynamic scope of the
366 ;;; with-benchmark-prefix expression. Return the value returned by the last
368 (defmacro with-benchmark-prefix (prefix . body)
369 `(with-benchmark-prefix* ,prefix (lambda () ,@body)))
372 ;;;; TIME CALCULATION
375 (define benchmark-time-base
376 internal-time-units-per-second)
378 (define time-base ;; short-cut, not exported
381 (define frame-time/iteration
382 "<will be set during initialization>")
384 (define (benchmark-total-time before after)
385 (- (tms:clock after) (tms:clock before)))
387 (define (benchmark-user-time before after)
388 (- (tms:utime after) (tms:utime before)))
390 (define (benchmark-system-time before after)
391 (- (tms:stime after) (tms:stime before)))
393 (define (benchmark-frame-time iterations)
394 (* iterations frame-time/iteration))
396 (define (benchmark-core-time iterations before after)
397 (- (benchmark-user-time before after) (benchmark-frame-time iterations)))
399 (define (benchmark-user-time\interpreter before after gc-time)
400 (- (benchmark-user-time before after) gc-time))
402 (define (benchmark-core-time\interpreter iterations before after gc-time)
403 (- (benchmark-core-time iterations before after) gc-time))
409 ;;; The global list of reporters.
410 (define reporters '())
412 ;;; The default reporter, to be used only if no others exist.
413 (define default-reporter #f)
415 ;;; Add the procedure REPORTER to the current set of reporter functions.
416 ;;; Signal an error if that reporter procedure object is already registered.
417 (define (register-reporter reporter)
418 (if (memq reporter reporters)
419 (error "register-reporter: reporter already registered: " reporter))
420 (set! reporters (cons reporter reporters)))
422 ;;; Remove the procedure REPORTER from the current set of reporter
423 ;;; functions. Signal an error if REPORTER is not currently registered.
424 (define (unregister-reporter reporter)
425 (if (memq reporter reporters)
426 (set! reporters (delq! reporter reporters))
427 (error "unregister-reporter: reporter not registered: " reporter)))
429 ;;; Return true iff REPORTER is in the current set of reporter functions.
430 (define (reporter-registered? reporter)
431 (if (memq reporter reporters) #t #f))
433 ;;; Send RESULT to all currently registered reporter functions.
434 (define (report . args)
435 (if (pair? reporters)
436 (for-each (lambda (reporter) (apply reporter args))
438 (apply default-reporter args)))
441 ;;;; Some useful standard reporters:
442 ;;;; Log reporters write all benchmark results to a given log file.
443 ;;;; Full reporters write all benchmark results to the standard output.
444 ;;;; User reporters write some interesting results to the standard output.
446 ;;; Display a single benchmark result to the given port
447 (define (print-result port name iterations before after gc-time)
448 (let* ((name (format-benchmark-name name))
449 (total-time (benchmark-total-time before after))
450 (user-time (benchmark-user-time before after))
451 (system-time (benchmark-system-time before after))
452 (frame-time (benchmark-frame-time iterations))
453 (benchmark-time (benchmark-core-time iterations before after))
454 (user-time\interpreter
455 (benchmark-user-time\interpreter before after gc-time))
456 (benchmark-core-time\interpreter
457 (benchmark-core-time\interpreter iterations before after gc-time)))
458 (write (list name iterations
459 'total (i/ total-time time-base)
460 'user (i/ user-time time-base)
461 'system (i/ system-time time-base)
462 'frame (i/ frame-time time-base)
463 'benchmark (i/ benchmark-time time-base)
464 'user/interp (i/ user-time\interpreter time-base)
465 'bench/interp (i/ benchmark-core-time\interpreter time-base)
466 'gc (i/ gc-time time-base))
470 ;;; Return a reporter procedure which prints all results to the file
471 ;;; FILE, in human-readable form. FILE may be a filename, or a port.
472 (define (make-log-reporter file)
473 (let ((port (if (output-port? file) file
474 (open-output-file file))))
476 (apply print-result port args)
477 (force-output port))))
479 ;;; A reporter that reports all results to the user.
480 (define (full-reporter . args)
481 (apply print-result (current-output-port) args))
483 ;;; Display interesting results of a single benchmark to the given port
484 (define (print-user-result port name iterations before after gc-time)
485 (let* ((name (format-benchmark-name name))
486 (user-time (benchmark-user-time before after))
487 (benchmark-time (benchmark-core-time iterations before after))
488 (benchmark-core-time\interpreter
489 (benchmark-core-time\interpreter iterations before after gc-time)))
490 (write (list name iterations
491 'user (i/ user-time time-base)
492 'benchmark (i/ benchmark-time time-base)
493 'bench/interp (i/ benchmark-core-time\interpreter time-base)
494 'gc (i/ gc-time time-base))
498 ;;; A reporter that reports interesting results to the user.
499 (define (user-reporter . args)
500 (apply print-user-result (current-output-port) args))
503 ;;;; Initialize the benchmarking system:
506 ;;; First, display version information
507 (display ";; running guile version " (current-output-port))
508 (display (version) (current-output-port))
509 (newline (current-output-port))
511 ;;; Second, make sure the benchmarking routines are compiled.
512 (define (null-reporter . args) #t)
513 (set! default-reporter null-reporter)
514 (benchmark "empty initialization benchmark" 2 #t)
516 ;;; Third, initialize the system constants
517 (display ";; calibrating the benchmarking framework..." (current-output-port))
518 (newline (current-output-port))
519 (define (initialization-reporter name iterations before after gc-time)
520 (let* ((frame-time (- (tms:utime after) (tms:utime before) gc-time 3)))
521 (set! frame-time/iteration (/ frame-time iterations))
522 (display ";; framework time per iteration: " (current-output-port))
523 (display (i/ frame-time/iteration time-base) (current-output-port))
524 (newline (current-output-port))))
525 (set! default-reporter initialization-reporter)
526 (benchmark "empty initialization benchmark" 524288 #t)
528 ;;; Finally, set the default reporter
529 (set! default-reporter user-reporter)