I now feel like Homer Simpson..... Doh!
Alan
On Sat, Apr 11, 2020 at 2:34 AM Paul Stadig <p...@stadig.name> wrote:
> The output of `time` is in milliseconds and the output of
> `with-timer-print` is in seconds. So to make them comparable:
> `time` 0.01344 msec
> `time` with eval 0.922536 msec
>
> `with-timer-print` 0.048 msec
> `with-timer-print` with eval 1.041 msec
>
> The `with-timer-print` version is slower, and I suspect it is the use of
> `format` instead of `str`.
>
> Paul
>
> On Fri, Apr 10, 2020 at 8:46 PM Alan Thompson <clooj...@gmail.com> wrote:
>
>> I was doing some macro work and was curious about the cost of an inline
>> `eval` vs compiled code. I tried to time it with `clojure.core/time` and
>> got results I can't explain:
>>
>>
>> (println :eval-time)
>> (time
>> (do
>> (println (eval (quote (+ 40 0))))
>> (println (eval (quote (+ 40 1))))
>> (println (eval (quote (+ 40 2))))
>> (println (eval (quote (+ 40 3))))
>> (println (eval (quote (+ 40 4))))))
>>
>>
>> :eval-time
>> 40
>> 41
>> 42
>> 43
>> 44
>> "Elapsed time: 0.922536 msecs"
>>
>> On a modern computer, this is an insanely long amount of time. And yes,
>> it is approx 5x longer than doing just one line of the above. I also tried
>> it without the eval:
>>
>> (println :add-time)
>> (time
>> (do
>> (println (+ 30 0))
>> (println (+ 30 1))
>> (println (+ 30 2))
>> (println (+ 30 3))
>> (println (+ 30 4))))
>>
>>
>> :add-time
>> 30
>> 31
>> 32
>> 33
>> 34
>> "Elapsed time: 0.01344 msecs"
>>
>> Still seems pretty slow to just print 5 lines with a single addition each.
>>
>> The `time` macro is very simple, and is often used as introductory
>> example of how macros work and when they are needed:
>>
>> (defmacro time
>> "Evaluates expr and prints the time it took. Returns the value of
>> expr."
>> {:added "1.0"}
>> [expr]
>> `(let [start# (. System (nanoTime))
>> ret# ~expr]
>> (prn (str "Elapsed time: " (/ (double (- (. System (nanoTime)) start#))
>> 1000000.0) " msecs"))
>> ret#))
>>
>>
>> I coincidentally had a homegrown timer available with nearly identical
>> code. It has results:
>>
>> (prof/with-timer-print :add-prof
>> (do
>> (println (+ 10 0))
>> (println (+ 10 1))
>> (println (+ 10 2))
>> (println (+ 10 3))
>> (println (+ 10 4))))
>>
>>
>> 10
>> 11
>> 12
>> 13
>> 14
>> :with-timer-print :add-prof 0.000048
>>
>>
>>
>> and
>>
>> (prof/with-timer-print :eval-prof
>> (do
>> (println (eval (quote (+ 20 0))))
>> (println (eval (quote (+ 20 1))))
>> (println (eval (quote (+ 20 2))))
>> (println (eval (quote (+ 20 3))))
>> (println (eval (quote (+ 20 4))))))
>>
>>
>> 20
>> 21
>> 22
>> 23
>> 24
>> :with-timer-print :eval-prof 0.001041
>>
>> So we see the times are much, much shorter. The timing code is nearly
>> identical to clojure.core/time:
>>
>> (defmacro with-timer-result
>> "Times execution of Clojure forms, returning a result map like:
>> {:result result :seconds seconds} "
>> [& forms]
>> `(let [start# (System/nanoTime)
>> result# (do ~@forms)
>> stop# (System/nanoTime)
>> elapsed# (double (- stop# start#))
>> seconds# (/ elapsed# 1e9)]
>> {:result result#
>> :seconds seconds#}))
>>
>> (defmacro with-timer-print
>> "Times execution of Clojure forms, printing the result to the screen. "
>> [id & forms]
>> (when-not (keyword? id)
>> (throw (ex-info "id must be a keyword" (vals->map id))))
>> `(let [result-map# (with-timer-result ~@forms)]
>> (println (format ":with-timer-print %s %12.6f" ~id (grab :seconds
>> result-map#)))
>> (grab :result result-map#)))
>>
>>
>> Does anyone have an idea of why `clojure.core/time` gives such insanely
>> inflated results?
>>
>> Alan
>>
>> PS. I ran the above 4 sequences multiple times using lein-test-refresh,
>> and these were the shortest I could get. I'm pretty confident the answer
>> is not loading, compiling, or JIT related.
>>
>>
>>
>> --
>> You received this message because you are subscribed to the Google
>> Groups "Clojure" group.
>> To post to this group, send email to clojure@googlegroups.com
>> Note that posts from new members are moderated - please be patient with
>> your first post.
>> To unsubscribe from this group, send email to
>> clojure+unsubscr...@googlegroups.com
>> For more options, visit this group at
>> http://groups.google.com/group/clojure?hl=en
>> ---
>> You received this message because you are subscribed to the Google Groups
>> "Clojure" group.
>> To unsubscribe from this group and stop receiving emails from it, send an
>> email to clojure+unsubscr...@googlegroups.com.
>> To view this discussion on the web visit
>> https://groups.google.com/d/msgid/clojure/CAN67zA0wp8vv6xbWDAPTFNrz8CpcDOv7o0_eY9%3DYxYqNdZY1RQ%40mail.gmail.com
>> <https://groups.google.com/d/msgid/clojure/CAN67zA0wp8vv6xbWDAPTFNrz8CpcDOv7o0_eY9%3DYxYqNdZY1RQ%40mail.gmail.com?utm_medium=email&utm_source=footer>
>> .
>>
> --
> You received this message because you are subscribed to the Google
> Groups "Clojure" group.
> To post to this group, send email to clojure@googlegroups.com
> Note that posts from new members are moderated - please be patient with
> your first post.
> To unsubscribe from this group, send email to
> clojure+unsubscr...@googlegroups.com
> For more options, visit this group at
> http://groups.google.com/group/clojure?hl=en
> ---
> You received this message because you are subscribed to the Google Groups
> "Clojure" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to clojure+unsubscr...@googlegroups.com.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/clojure/CADQBrAR0qGbHboZtiSvj1JhUf06HZ8jVP-zNoN3sr4PrDLEx0A%40mail.gmail.com
> <https://groups.google.com/d/msgid/clojure/CADQBrAR0qGbHboZtiSvj1JhUf06HZ8jVP-zNoN3sr4PrDLEx0A%40mail.gmail.com?utm_medium=email&utm_source=footer>
> .
>
--
You received this message because you are subscribed to the Google
Groups "Clojure" group.
To post to this group, send email to clojure@googlegroups.com
Note that posts from new members are moderated - please be patient with your
first post.
To unsubscribe from this group, send email to
clojure+unsubscr...@googlegroups.com
For more options, visit this group at
http://groups.google.com/group/clojure?hl=en
---
You received this message because you are subscribed to the Google Groups
"Clojure" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to clojure+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/clojure/CAN67zA2G8L4h%3DpvbT7WuxM4AJSDzLHsOnSsXxcqSU45gpMgqKg%40mail.gmail.com.
