208 lines
No EOL
14 KiB
HTML
208 lines
No EOL
14 KiB
HTML
<!DOCTYPE html>
|
|
<html lang='en'><head><meta charset='utf-8' /><meta name='pinterest' content='nopin' /><link href='../../../../static/css/style.css' rel='stylesheet' type='text/css' /><link href='../../../../static/css/print.css' rel='stylesheet' type='text/css' media='print' /><title>Customizing Common Lisp's Iterate: Timing / Steve Losh</title></head><body><header><a id='logo' href='https://stevelosh.com/'>Steve Losh</a><nav><a href='../../../index.html'>Blog</a> - <a href='https://stevelosh.com/projects/'>Projects</a> - <a href='https://stevelosh.com/photography/'>Photography</a> - <a href='https://stevelosh.com/links/'>Links</a> - <a href='https://stevelosh.com/rss.xml'>Feed</a></nav></header><hr class='main-separator' /><main id='page-blog-entry'><article><h1><a href='index.html'>Customizing Common Lisp's Iterate: Timing</a></h1><p class='date'>Posted on October 10th, 2016.</p><p>This entry is the second in a series about customizing Common Lisp's <a href="https://common-lisp.net/project/iterate/">iterate</a>
|
|
library. The full series:</p>
|
|
|
|
<ul>
|
|
<li><a href="../../09/iterate-averaging/index.html">Averaging</a></li>
|
|
<li><a href="index.html">Timing</a></li>
|
|
</ul>
|
|
|
|
<p>This post will show how to make a <code>timing</code> clause that keeps track of how much
|
|
time has elapsed between iterations (and across the entire loop). I've found it
|
|
handy when doing rough benchmarks for things like <a href="http://www.amazon.com/dp/1680500554/?tag=stelos-20">maze generation</a>.</p>
|
|
|
|
<ol class="table-of-contents"><li><a href="index.html#s1-end-result">End Result</a></li><li><a href="index.html#s2-code">Code</a><ol><li><a href="index.html#s3-argument-pairing">Argument Pairing</a></li><li><a href="index.html#s4-symbols-keywords">Symbols & Keywords</a></li><li><a href="index.html#s5-variables">Variables</a></li><li><a href="index.html#s6-splicing">Splicing</a></li></ol></li><li><a href="index.html#s7-composing">Composing</a></li></ol>
|
|
|
|
<h2 id="s1-end-result"><a href="index.html#s1-end-result">End Result</a></h2>
|
|
|
|
<p>Before we look at the code, let's look at what we're aiming for:</p>
|
|
|
|
<pre><code><span class="code"><span class="paren1">(<span class="code"><i><span class="symbol">defun</span></i> to-seconds <span class="paren2">(<span class="code">internal-time-units</span>)</span>
|
|
<span class="paren2">(<span class="code">/ internal-time-units internal-time-units-per-second 1.0</span>)</span></span>)</span>
|
|
|
|
<span class="paren1">(<span class="code">iterate
|
|
<span class="paren2">(<span class="code">repeat 5</span>)</span>
|
|
<span class="paren2">(<span class="code">sleep <span class="paren3">(<span class="code">random 3.0</span>)</span></span>)</span>
|
|
<span class="paren2">(<span class="code">timing real-time <span class="keyword">:since-start-into</span> total-time
|
|
<span class="keyword">:per-iteration-into</span> loop-time</span>)</span>
|
|
<span class="paren2">(<span class="code">collect loop-time <span class="keyword">:into</span> loop-times</span>)</span>
|
|
<span class="paren2">(<span class="code">finally
|
|
<span class="paren3">(<span class="code">format t <span class="string">"Individual times: ~S~%Total time: ~F seconds~%"</span>
|
|
<span class="paren4">(<span class="code">mapcar #'to-seconds loop-times</span>)</span>
|
|
<span class="paren4">(<span class="code">to-seconds total-time</span>)</span></span>)</span></span>)</span></span>)</span>
|
|
<span class="comment">; =>
|
|
</span>Individual times: <span class="paren1">(<span class="code">0.948 1.359 2.828 2.891 2.744</span>)</span>
|
|
Total time: 10.77 seconds</span></code></pre>
|
|
|
|
<p>The <code>timing</code> clause is what we'll be implementing.</p>
|
|
|
|
<h2 id="s2-code"><a href="index.html#s2-code">Code</a></h2>
|
|
|
|
<p>The code for <code>timing</code> is fairly short but does have a few interesting things to
|
|
talk about. I've omitted the docstring so it'll fit on one screen:</p>
|
|
|
|
<pre><code><span class="code"><span class="paren1">(<span class="code"><i><span class="symbol">defmacro-clause</span></i> <span class="paren2">(<span class="code">TIMING time-type &optional
|
|
SINCE-START-INTO since-var
|
|
PER-ITERATION-INTO per-var</span>)</span>
|
|
<span class="paren2">(<span class="code"><i><span class="symbol">let</span></i> <span class="paren3">(<span class="code"><span class="paren4">(<span class="code">timing-function <span class="paren5">(<span class="code">ecase time-type
|
|
<span class="paren6">(<span class="code"><span class="paren1">(<span class="code">real-time</span>)</span> #'get-internal-real-time</span>)</span>
|
|
<span class="paren6">(<span class="code"><span class="paren1">(<span class="code">run-time</span>)</span> #'get-internal-run-time</span>)</span></span>)</span></span>)</span>
|
|
<span class="paren4">(<span class="code">since-var <span class="paren5">(<span class="code">or since-var
|
|
<span class="paren6">(<span class="code">when <span class="paren1">(<span class="code">null per-var</span>)</span>
|
|
<span class="special">iterate::*result-var*</span></span>)</span></span>)</span></span>)</span></span>)</span>
|
|
<span class="paren3">(<span class="code"><i><span class="symbol">with-gensyms</span></i> <span class="paren4">(<span class="code">start-time current-time previous-time</span>)</span>
|
|
`<span class="paren4">(<span class="code"><i><span class="symbol">progn</span></i>
|
|
<span class="paren5">(<span class="code">with ,start-time = <span class="paren6">(<span class="code">funcall ,timing-function</span>)</span></span>)</span>
|
|
<span class="paren5">(<span class="code">for ,current-time = <span class="paren6">(<span class="code">funcall ,timing-function</span>)</span></span>)</span>
|
|
,@<span class="paren5">(<span class="code">when since-var
|
|
`<span class="paren6">(<span class="code"><span class="paren1">(<span class="code">for ,since-var = <span class="paren2">(<span class="code">- ,current-time ,start-time</span>)</span></span>)</span></span>)</span></span>)</span>
|
|
,@<span class="paren5">(<span class="code">when per-var
|
|
`<span class="paren6">(<span class="code"><span class="paren1">(<span class="code">for ,previous-time <span class="keyword">:previous</span> ,current-time
|
|
<span class="keyword">:initially</span> ,start-time</span>)</span>
|
|
<span class="paren1">(<span class="code">for ,per-var = <span class="paren2">(<span class="code">- ,current-time ,previous-time</span>)</span></span>)</span></span>)</span></span>)</span></span>)</span></span>)</span></span>)</span></span>)</span></span></code></pre>
|
|
|
|
<p>Times are recorded in "internal time units" to be consistent with other Common
|
|
Lisp functions like <a href="http://www.lispworks.com/documentation/HyperSpec/Body/f_get_in.htm#get-internal-real-time">get-internal-real-time</a>. Some implementations will be
|
|
more precise than others.</p>
|
|
|
|
<h3 id="s3-argument-pairing"><a href="index.html#s3-argument-pairing">Argument Pairing</a></h3>
|
|
|
|
<p>One thing that I sometimes find annoying about <code>iterate</code> clauses is that they
|
|
must contain <em>pairs</em> of arguments. You can't have an odd number of arguments,
|
|
like:</p>
|
|
|
|
<pre><code>(TIMING &optional SINCE-START since-var PER-ITERATION per-var).</code></pre>
|
|
|
|
<p>Often, however, you can make the best of this restriction and come up with
|
|
something at least <em>moderately</em> useful to use as an extra argument to pad things
|
|
out. For the <code>timing</code> clause I decided to make the second argument define which
|
|
type of time to measure (process run time or wall clock time).</p>
|
|
|
|
<h3 id="s4-symbols-keywords"><a href="index.html#s4-symbols-keywords">Symbols & Keywords</a></h3>
|
|
|
|
<p>In this implementation the type of time to record is given as a symbol in this
|
|
package's namespace. This means that you'll want to export the <code>real-time</code> and
|
|
<code>run-time</code> symbols from this package, not just the <code>timing</code> symbol. This is
|
|
a little annoying, but I like how it looks when used.</p>
|
|
|
|
<p>Another option would be to change these to keyword symbols, so you would say
|
|
<code>(timing :real-time ...)</code> instead. Or you could just support both (<code>ecase</code>
|
|
makes this easy).</p>
|
|
|
|
<p>Note the use of <code>ecase</code> when checking the time type to signal an error at
|
|
macroexpansion time with a helpful message if the user passed something
|
|
incorrect:</p>
|
|
|
|
<pre><code>(iterate (timing foo :since-start-into some-var))
|
|
; =>
|
|
debugger invoked on a SB-KERNEL:CASE-FAILURE in thread
|
|
#<THREAD "main thread" RUNNING {10028F7473}>:
|
|
FOO fell through ECASE expression. Wanted one of (REAL-TIME RUN-TIME).
|
|
|
|
...</code></pre>
|
|
|
|
<h3 id="s5-variables"><a href="index.html#s5-variables">Variables</a></h3>
|
|
|
|
<p>To fit with the general pattern of <code>iterate</code> clauses, we try to do something
|
|
intelligent with the variables depending on what the user says they want. If
|
|
the user doesn't specify any variable names, we return the total loop time as
|
|
the result of the loop:</p>
|
|
|
|
<pre><code>(macroexpand-iterate '(timing real-time))
|
|
; =>
|
|
(PROGN
|
|
(WITH #:START-TIME516 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
(FOR #:CURRENT-TIME517 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
(FOR ITERATE::*RESULT-VAR* = (- #:CURRENT-TIME517 #:START-TIME516)))
|
|
|
|
(iterate (repeat 1) (sleep 2.0) (timing real-time))
|
|
; =>
|
|
2003</code></pre>
|
|
|
|
<p>There's a bit of inefficiency here, because we're recalculating the time on
|
|
every iteration even though we really only need to do it once at the very end.
|
|
But I suppose someone could be accessing <code>iterate::*result-var*</code> in their loop
|
|
body like any other variable, so this will do the right thing in that case (even
|
|
if that case <em>is</em> horrifying).</p>
|
|
|
|
<p>If the user does specify a variable for either measurement, we assume they know
|
|
what they're doing and don't touch the loop result variable:</p>
|
|
|
|
<pre><code>(macroexpand-iterate
|
|
'(timing real-time :since-start-into x))
|
|
; =>
|
|
(PROGN
|
|
(WITH #:START-TIME525 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
(FOR #:CURRENT-TIME526 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
(FOR X = (- #:CURRENT-TIME526 #:START-TIME525)))
|
|
|
|
(macroexpand-iterate
|
|
'(timing real-time :per-iteration-into x))
|
|
; =>
|
|
(PROGN
|
|
(WITH #:START-TIME528 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
(FOR #:CURRENT-TIME529 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
(FOR #:PREVIOUS-TIME530 :PREVIOUS #:CURRENT-TIME529 :INITIALLY
|
|
#:START-TIME528)
|
|
(FOR X = (- #:CURRENT-TIME529 #:PREVIOUS-TIME530)))</code></pre>
|
|
|
|
<h3 id="s6-splicing"><a href="index.html#s6-splicing">Splicing</a></h3>
|
|
|
|
<p>Another thing to note is the use of <code>,@</code> to splice the appropriate clauses into
|
|
the final <code>progn</code>:</p>
|
|
|
|
<pre><code><span class="code"><span class="comment">; ...
|
|
</span> ,@<span class="paren1">(<span class="code">when since-var
|
|
`<span class="paren2">(<span class="code"><span class="paren3">(<span class="code">for ,since-var = <span class="paren4">(<span class="code">- ,current-time ,start-time</span>)</span></span>)</span></span>)</span></span>)</span>
|
|
,@<span class="paren1">(<span class="code">when per-var
|
|
`<span class="paren2">(<span class="code"><span class="paren3">(<span class="code">for ,previous-time <span class="keyword">:previous</span> ,current-time
|
|
<span class="keyword">:initially</span> ,start-time</span>)</span>
|
|
<span class="paren3">(<span class="code">for ,per-var = <span class="paren4">(<span class="code">- ,current-time ,previous-time</span>)</span></span>)</span></span>)</span></span>)</span>
|
|
<span class="comment">; ...</span></span></code></pre>
|
|
|
|
<p>For the <code>since-var</code> clause we could have gotten away with just using a plain <code>,</code>
|
|
and returning the <code>for</code> clause itself:</p>
|
|
|
|
<pre><code><span class="code"><span class="comment">; ...
|
|
</span> ,<span class="paren1">(<span class="code">when since-var
|
|
`<span class="paren2">(<span class="code">for ,since-var = <span class="paren3">(<span class="code">- ,current-time ,start-time</span>)</span></span>)</span></span>)</span>
|
|
<span class="comment">; ...</span></span></code></pre>
|
|
|
|
<p>This would work, but when <code>since-var</code> is null (when the user wants only the
|
|
per-iteration time) the <code>when</code> statement would evaluate to <code>nil</code>, and would
|
|
leave a stray <code>nil</code> in the <code>progn</code>:</p>
|
|
|
|
<pre><code>(macroexpand-iterate
|
|
'(timing real-time :per-iteration-into x))
|
|
; =>
|
|
(PROGN
|
|
(WITH #:START-TIME531 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
(FOR #:CURRENT-TIME532 = (FUNCALL #<CLOSURE GET-INTERNAL-REAL-TIME>))
|
|
NIL
|
|
(FOR #:PREVIOUS-TIME533 :PREVIOUS #:CURRENT-TIME532 :INITIALLY
|
|
#:START-TIME531)
|
|
(FOR X = (- #:CURRENT-TIME532 #:PREVIOUS-TIME533)))</code></pre>
|
|
|
|
<p>Any decent compiler will optimize this away, but it's ugly to read during
|
|
macroexpansion. If we're going to write this thing let's do it <em>right</em> and not
|
|
be lazy.</p>
|
|
|
|
<p>Also notice that we don't define the <code>previous-time</code> clause at all unless the
|
|
user wants per-iteration time, because the since-start time doesn't need it at
|
|
all. No reason to waste cycles calculating an extra value on every iteration if
|
|
we don't have to.</p>
|
|
|
|
<h2 id="s7-composing"><a href="index.html#s7-composing">Composing</a></h2>
|
|
|
|
<p>One of the great things about <code>iterate</code> is that the extensions you make can use
|
|
each other. For example, we can use last post's <code>averaging</code> clause with the one
|
|
we just made to calculate the average time per loop iteration:</p>
|
|
|
|
<pre><code><span class="code"><span class="paren1">(<span class="code">iterate
|
|
<span class="paren2">(<span class="code">repeat 20</span>)</span>
|
|
<span class="paren2">(<span class="code">sleep <span class="paren3">(<span class="code">random 1.0</span>)</span></span>)</span>
|
|
<span class="paren2">(<span class="code">timing real-time <span class="keyword">:per-iteration-into</span> time</span>)</span>
|
|
<span class="paren2">(<span class="code">averaging <span class="paren3">(<span class="code">to-seconds time</span>)</span></span>)</span></span>)</span>
|
|
<span class="comment">; =>
|
|
</span>0.51555</span></code></pre>
|
|
</article></main><hr class='main-separator' /><footer><nav><a href='https://github.com/sjl/'>GitHub</a> ・ <a href='https://twitter.com/stevelosh/'>Twitter</a> ・ <a href='https://instagram.com/thirtytwobirds/'>Instagram</a> ・ <a href='https://hg.stevelosh.com/.plan/'>.plan</a></nav></footer></body></html> |