How can I stop "leaking" memory?

[beat...@gmail.com]

Dear all,

I really love programming in Clojure, and have done so for the past
couple of months, building my company's software recommendation engine
in Clojure (not in production yet), which I originally wrote in Ruby.
However I have run into the following a memory problem, which actually
was pointed out by Christophe Grand in a response on stackoverflow
(http://stackoverflow.com/questions/749911/how-can-i-leak-memory-in-
clojure).

In my case I want to calculate (usage) correlations between items, and
pick for each item its most similar items. For example, If I compare
one item with 1.000.000 others, and calculate their similarities, then
next I sort the collection, and pick only the top (say 10) Artificial
code example:

(take 10 (sort (for [x (range 1000000)] (rand)))))

Now the problem is the memory usage, as it does not merely uses memory
space for 10 items, but it keeps a reference to the entire sequence.
If I leave out the sort its all ok, and done lazily.

Does anyone know how to sort and avoid large memory consumptions?

Thanks in advance.

(I'm running on Mac OSX with Java HotSpot(TM) 64-Bit Server VM (build
11.3-b02-83, mixed mode)

[Raoul Duke]

> Does anyone know how to sort and avoid large memory consumptions?

well, presumably the sort needs to look at all the data in order to be
able to sort it, no?! so it is kinda just a tough cookie reality that
the memory will be used.

on the other hand, maybe you can do some form of the Schwartzian Transform.

[Four of Seventeen]

On Jun 22, 6:46 pm, "beatle...@gmail.com" <beatle...@gmail.com> wrote:
> (take 10 (sort (for [x (range 1000000)] (rand)))))
>
> Now the problem is the memory usage, as it does not merely uses memory
> space for 10 items, but it keeps a reference to the entire sequence.
> If I leave out the sort its all ok, and done lazily.

Sort can't really be lazy without being unbelievably slow. I'm
guessing what you want is for the long sequence produced by sort to be
collectable garbage, aside from the ten items you take. Now the lazy
nature of take 10 is biting you in the butt. If you make it eager with
doall it *might* work. I'd instead do something like

(vec (take 10 (sort ... )))

which constructs a whole new vector of ten items and drops any
possible reference to the input. The GC should sweep away everything
but the ten-element vector as soon as the memory is needed elsewhere.

But this should not have been causing a stack overflow. If you're
getting stack overflows, it's something else. Most likely you have
very deep tail recursion and hoped it would be optimized like in
Scheme. That won't work; you have to make tail recursion explicit in
clojure using "(recur args)" instead of "(fn-name args)". You can also
use "recur" together with "loop" to make a loop inside a function.
It's "functional" in that, though the loop variables can be rebound
each time around the loop, it's conceptually equivalent to defining
and then calling a tail-recursive "letfn", and a lot less
syntactically messy.

Someone here recently wrote a macro, I forget its name, to make "lazy-
seq" similarly less messy to use. Search the site for "lazy-seq". It's
not as useful, because usually you've got something like "take" or
"take-while" or "map" that can be used to make the lazy sequence you
want, and rarely need to resort to "lazy-seq" itself.

But for now, you probably just need to use "recur" at your tail calls
to fix your stack overflows, unless you have multiple functions
calling each other with circularities. That's messier to tail-
optimize, unfortunately.

[Christophe Grand]

Hi all,

On Tue, Jun 23, 2009 at 4:16 AM, Four of Seventeen <fseve...@gmail.com> wrote:

On Jun 22, 6:46 pm, "beatle...@gmail.com" <beatle...@gmail.com> wrote:
> (take 10 (sort (for [x (range 1000000)] (rand)))))
>
> Now the problem is the memory usage, as it does not merely uses memory
> space for 10 items, but it keeps a reference to the entire sequence.
> If I leave out the sort its all ok, and done lazily.

Sort can't really be lazy without being unbelievably slow.

Selecting the top N out of n items is a O(n*sqrt(N)) operation so it's linear when n dominates N and thus must beat take + sort. Plus it won't retain the whole realized seq in memory.
Maybe contrib already has something like that, else sorted-map and rseq are your friends :-)

hth,

Christophe

--
Professional: http://cgrand.net/ (fr)
On Clojure: http://clj-me.blogspot.com/ (en)

[Daniel Lyons]

On Jun 22, 2009, at 11:36 PM, Christophe Grand wrote:

Selecting the top N out of n items is a O(n*sqrt(N)) operation so it's linear when n dominates N and thus must beat take + sort. Plus it won't retain the whole realized seq in memory.

Just because I'm curious, I can see how to do max in O(N) time, so I can see how to do top-n in O(n*N) ≈ O(N) time, but I don't see how to do that in sqrt(N) time. What's this algorithm called or how does it work?

— 

Daniel Lyons

[Christophe Grand]

I don't know if it has an official name but basically it's a modified tree-sort: for each item you insert a value in a sorted coll of size N and remove one item from this sorted coll, both ops are O(sqrt(N)) thus O(n*sqrt(N)) for processing an input whose length is n.

I'm away from a REPL but I had something like that in mind:
(defn top-n [coll n]
  (let [add #(assoc %1 %2 (inc (%1 %2 0))
         prune-min #(let [[[min n]] (rseq %)] (if (== 1 n) (dissoc % min) (assoc % (dec n))))
         seed (reduce add sorted-map (take n coll))]
    (reduce (comp prune-min add) seed (drop n coll))))

(top 3 [5 4 3 5 8 2 7]) ; should return {5 1, 7 1, 8 1}
; but
(top 3 [5 4 3 5 8 2]) ; should return {5 2, 8 1}

[Christophe Grand]

(assoc % (dec n)) should read: (assoc % min (dec n))

2009/6/23 Christophe Grand <chris...@cgrand.net>

[Daniel Lyons]

On Jun 23, 2009, at 1:47 AM, Christophe Grand wrote:

I don't know if it has an official name but basically it's a modified tree-sort: for each item you insert a value in a sorted coll of size N and remove one item from this sorted coll, both ops are O(sqrt(N)) thus O(n*sqrt(N)) for processing an input whose length is n.

I'm away from a REPL but I had something like that in mind:
(defn top-n [coll n]
  (let [add #(assoc %1 %2 (inc (%1 %2 0))
         prune-min #(let [[[min n]] (rseq %)] (if (== 1 n) (dissoc % min) (assoc % (dec n))))
         seed (reduce add sorted-map (take n coll))]
    (reduce (comp prune-min add) seed (drop n coll))))

(top 3 [5 4 3 5 8 2 7]) ; should return {5 1, 7 1, 8 1}
; but
(top 3 [5 4 3 5 8 2]) ; should return {5 2, 8 1}

I have to admit I don't really understand your code, so my apologies if I've missed something obvious.

I think if you consider each element of N and do an operation that costs sqrt(N) with it, you'd arrive at O(N*sqrt(N)), which I think would be worse than O(N log N) which is what you'd get from just sorting the whole structure and taking the top n items. Is it really sqrt(N)? I'm under the impression insertion into a balanced binary tree is O(log(N)), but wouldn't you still need to have N of them? This algorithm reminds me of heap sort.

— 

Daniel Lyons

[beat...@gmail.com]

On Jun 23, 4:16 am, Four of Seventeen <fsevent...@gmail.com> wrote:
> On Jun 22, 6:46 pm, "beatle...@gmail.com" <beatle...@gmail.com> wrote:
>
> > (take 10 (sort (for [x (range 1000000)] (rand)))))
>
> > Now the problem is the memory usage, as it does not merely uses memory
> > space for 10 items, but it keeps a reference to the entire sequence.
> > If I leave out the sort its all ok, and done lazily.
>
> Sort can't really be lazy without being unbelievably slow. I'm
> guessing what you want is for the long sequence produced by sort to be
> collectable garbage, aside from the ten items you take. Now the lazy
> nature of take 10 is biting you in the butt. If you make it eager with
> doall it *might* work. I'd instead do something like
>
> (vec (take 10 (sort ... )))
>
> which constructs a whole new vector of ten items and drops any
> possible reference to the input. The GC should sweep away everything
> but the ten-element vector as soon as the memory is needed elsewhere.

This is exactly what I was looking for. A way to drop the reference,
and letting the GC do its work.
Thanks!

>
> But this should not have been causing a stack overflow. If you're
> getting stack overflows, it's something else. Most likely you have
> very deep tail recursion and hoped it would be optimized like in
> Scheme. That won't work; you have to make tail recursion explicit in
> clojure using "(recur args)" instead of "(fn-name args)". You can also
> use "recur" together with "loop" to make a loop inside a function.
> It's "functional" in that, though the loop variables can be rebound
> each time around the loop, it's conceptually equivalent to defining
> and then calling a tail-recursive "letfn", and a lot less
> syntactically messy.

You're definitely right about that. Its something I already try to
take care of, by explicitly using loop / recur. (Or putting it in a
For, when possible)

[Jules]

Let N be the total number of elements in your collection (e.g.
1000,000), and n the number of elements that you want to take out of
this collection (e.g 10).

By sorting the collection of N elements you spend N log N time. By
repeatedly adding an to the small collection and removing the minimum
you spend N log n time (if you have a good sorted collection that
takes log n time to insert).

The algorithm spelled out in imperative pseudocode is:

def top_n(n,coll)
let result = new SortedCollection(take n from coll)
for x in (drop n from coll):
result.add(x)
result.deleteMinimum() // adding 1 element and removing 1 keeps
the result collection at size n
return result

Hope this helps,
Jules

[beat...@gmail.com]

On Jun 23, 7:36 am, Christophe Grand <christo...@cgrand.net> wrote:
> Hi all,
>

> On Tue, Jun 23, 2009 at 4:16 AM, Four of Seventeen <fsevent...@gmail.com>wrote:
>
>
>
> > On Jun 22, 6:46 pm, "beatle...@gmail.com" <beatle...@gmail.com> wrote:
> > > (take 10 (sort (for [x (range 1000000)] (rand)))))
>
> > > Now the problem is the memory usage, as it does not merely uses memory
> > > space for 10 items, but it keeps a reference to the entire sequence.
> > > If I leave out the sort its all ok, and done lazily.
>
> > Sort can't really be lazy without being unbelievably slow.
>
> Selecting the top N out of n items is a O(n*sqrt(N)) operation so it's
> linear when n dominates N and thus must beat take + sort. Plus it won't
> retain the whole realized seq in memory.
> Maybe contrib already has something like that, else sorted-map and rseq are
> your friends :-)

Nice suggestion, thanks.

[Daniel Lyons]

Jules,

On Jun 23, 2009, at 2:25 AM, Jules wrote:

> Let N be the total number of elements in your collection (e.g.

> 1,000,000), and n the number of elements that you want to take out of

> this collection (e.g 10).
>
> By sorting the collection of N elements you spend N log N time. By
> repeatedly adding an to the small collection and removing the minimum
> you spend N log n time (if you have a good sorted collection that
> takes log n time to insert).
>
> The algorithm spelled out in imperative pseudocode is:
>
> def top_n(n,coll)
> let result = new SortedCollection(take n from coll)
> for x in (drop n from coll):
> result.add(x)
> result.deleteMinimum() // adding 1 element and removing 1 keeps
> the result collection at size n
> return result
>
> Hope this helps,

Yes, this explains it. :) Thanks!

—
Daniel Lyons

[Christophe Grand]

On Tue, Jun 23, 2009 at 10:14 AM, Daniel Lyons <fus...@storytotell.org> wrote:

I have to admit I don't really understand your code, so my apologies if I've missed something obvious.

I think if you consider each element of N and do an operation that costs sqrt(N) with it, you'd arrive at O(N*sqrt(N)), which I think would be worse than O(N log N)

I guess I must take another coffee, you're right I talked about sqrt instead of log. My bad.

 

which is what you'd get from just sorting the whole structure and taking the top n items. Is it really sqrt(N)? I'm under the impression insertion into a balanced binary tree is O(log(N)), but wouldn't you still need to have N of them? This algorithm reminds me of heap sort.

The tree never grows beyond (N+1) items, so insertion/deletion is always O(log(N)). But you perform these operations for each item of the full seq, ie nth times (but not Nth times) thus O(n*log(N))

Christophe
 

[Bradbev]

A further optimization would be to keep track of the lowest value in
your "keep" set. A simple compare against that value will eliminate
many of the add/removes from the keep set.


Brad

[Four of Seventeen]

On Jun 23, 4:25 am, Jules <julesjac...@gmail.com> wrote:
> Let N be the total number of elements in your collection (e.g.
> 1000,000), and n the number of elements that you want to take out of
> this collection (e.g 10).
>
> By sorting the collection of N elements you spend N log N time. By
> repeatedly adding an to the small collection and removing the minimum
> you spend N log n time (if you have a good sorted collection that
> takes log n time to insert).
>
> The algorithm spelled out in imperative pseudocode is:
>
> def top_n(n,coll)
>   let result = new SortedCollection(take n from coll)
>   for x in (drop n from coll):
>     result.add(x)
>     result.deleteMinimum() // adding 1 element and removing 1 keeps
> the result collection at size n
>   return result
>
> Hope this helps,
> Jules

Here's the functional version (working Clojure code):

(defn top [n comptr coll]
(let [m (reduce #(assoc %1 %2 true) (sorted-map-by comptr)
(take n coll))]
(keys
(reduce #(let [t (assoc %1 %2 true)]
(dissoc t (first (last t)))) m (drop n coll)))))

Why a map with useless values? There's no sorted-set-by in
clojure.core. :(

This is the result:

user=> (time (top 10 #(> %1 %2) (range 5000000)))
"Elapsed time: 15755.155 msecs"
(4999999 4999998 4999997 4999996 4999995 4999994 4999993 4999992
4999991 4999990)
user=> (time (take 10 (sort #(> %1 %2) (range 5000000))))
"Elapsed time: 7938.67752 msecs"
(4999999 4999998 4999997 4999996 4999995 4999994 4999993 4999992
4999991 4999990)

This is a worst-case sort, in a sense, since the sequence has to be
completely reversed. Curiously, take 10 sort is faster than top 10 by
a factor of 2. It seems sorting five million items all at once is
faster than five million sequential sorted inserts into a ten-item
tree.

So top is using about twice as much time, and one five-hundred-
thousandth as much memory. Lesson: use top when you don't want a big
lazy sequence residing in memory all at once and use sort when you
want speed. :)

[Four of Seventeen]

On Jun 23, 10:46 pm, Bradbev <brad.beveri...@gmail.com> wrote:
> A further optimization would be to keep track of the lowest value in
> your "keep" set.  A simple compare against that value will eliminate
> many of the add/removes from the keep set.

(defn top [n comptr coll]
(let [m (reduce #(assoc %1 %2 true) (sorted-map-by comptr) (take n
coll))]
(keys

(reduce #(let [worst (first (last %1))]
(if (comptr %2 worst)
(assoc (dissoc %1 worst) %2 true)
%1)) m (drop n coll)))))

user=> (time (top 10 #(< %1 %2) (range 5000000)))

"Elapsed time: 11768.17628 msecs"
(0 1 2 3 4 5 6 7 8 9)

user=> (time (top 10 #(> %1 %2) (range 5000000)))

"Elapsed time: 17919.84428 msecs"

(4999999 4999998 4999997 4999996 4999995 4999994 4999993 4999992
4999991 4999990)

Marginally slower than the version without this optimization in the
worst case where every replacement must be done, and about 25% faster
in the best case where none must be done. Even then, it's still beat
by (take 10 (sort ... )).

Detailed results:

user=> (dotimes [_ 10] (time (take 10 (sort #(> %1 %2) (range
5000000)))))
"Elapsed time: 4669.87556 msecs"
"Elapsed time: 4893.38316 msecs"
"Elapsed time: 5013.23172 msecs"
"Elapsed time: 4990.9178 msecs"
"Elapsed time: 4892.86396 msecs"
"Elapsed time: 4875.61796 msecs"
"Elapsed time: 4897.41252 msecs"
"Elapsed time: 4808.3688 msecs"
"Elapsed time: 4885.01024 msecs"
"Elapsed time: 4825.45776 msecs"
nil
user=> (dotimes [_ 10] (time (take 10 (sort #(< %1 %2) (range
5000000)))))
"Elapsed time: 1915.16492 msecs"
"Elapsed time: 1893.42468 msecs"
"Elapsed time: 1787.757 msecs"
"Elapsed time: 1845.62508 msecs"
"Elapsed time: 1795.7726 msecs"
"Elapsed time: 1741.83024 msecs"
"Elapsed time: 1893.88368 msecs"
"Elapsed time: 1782.7532 msecs"
"Elapsed time: 1860.6954 msecs"
"Elapsed time: 1800.88284 msecs"
nil
user=> (dotimes [_ 10] (time (top 10 #(> %1 %2) (range 5000000))))
"Elapsed time: 15386.11028 msecs"
"Elapsed time: 14990.3236 msecs"
"Elapsed time: 16132.34848 msecs"
"Elapsed time: 15235.8524 msecs"
"Elapsed time: 15176.44992 msecs"
"Elapsed time: 14949.18796 msecs"
"Elapsed time: 15008.48088 msecs"
"Elapsed time: 14931.59616 msecs"
"Elapsed time: 15066.244 msecs"
"Elapsed time: 15013.44288 msecs"
nil
user=> (dotimes [_ 10] (time (top 10 #(< %1 %2) (range 5000000))))
"Elapsed time: 9880.3546 msecs"
"Elapsed time: 10076.03504 msecs"
"Elapsed time: 10145.5228 msecs"
"Elapsed time: 10393.19332 msecs"
"Elapsed time: 10482.33532 msecs"
"Elapsed time: 10184.82972 msecs"
"Elapsed time: 10156.60292 msecs"
"Elapsed time: 10089.50916 msecs"
"Elapsed time: 10266.2736 msecs"
"Elapsed time: 10054.39296 msecs"
nil

JIT has definitely had time to run. Normalized, we have these
proportions:
Sort best case: 3
Sort worst case: 8
Top best case: 17
Top worst case: 25

Even with the optimization, sort somehow beats top for speed. It looks
like top is best used to avoid major memory consumption for long seqs;
if you have the memory and need the speed, sort's better.

[Christophe Grand]

On Wed, Jun 24, 2009 at 7:02 AM, Four of Seventeen <fseve...@gmail.com> wrote:

(defn top [n comptr coll]
 (let [m (reduce #(assoc %1 %2 true) (sorted-map-by comptr)
           (take n coll))]
   (keys
     (reduce #(let [t (assoc %1 %2 true)]
                (dissoc t (first (last t)))) m (drop n coll)))))

Here is mine, now debugged:
(defn top-n
 ([n coll] (top-n n nil coll))
 ([n comparator coll]
  (let [empty-map (if comparator (sorted-map-by comparator) (sorted-map))
        add #(assoc %1 %2 (inc (%1 %2 0)))
        seed (reduce add empty-map (take n coll))
        prune-min #(let [[[min n]] (rseq %)] (if (== 1 n) (dissoc % min) (assoc % min (dec n))))]
    (reduce (comp prune-min add) seed (drop n coll)))))

 

Why a map with useless values? There's no sorted-set-by in
clojure.core. :(

I use values to account  for duplicate values:
user=> (top-n 3 [4 1 2 6 3 1])
{1 2, 2 1}

So top is using about twice as much time, and one five-hundred-
thousandth as much memory. Lesson: use top when you don't want a big
lazy sequence residing in memory all at once and use sort when you
want speed. :)

Agreed: constant factor matters :-)

[Richard Newman]

> Even with the optimization, sort somehow beats top for speed. It looks
> like top is best used to avoid major memory consumption for long seqs;
> if you have the memory and need the speed, sort's better.

This is an interesting characteristic I've noticed in sorting code. In
the past (I'm thinking of one Common Lisp app in particular) I've
spent time carefully crafting tree-based accumulators to collect
values into a sorted collection... only to find that it was slower
than just collecting the whole damn list and sorting it, even for very
large collections. Seems all those tree/map operations take time, and
library sort functions are fast!

[Christophe Grand]

Then use sort!

Prototype implementation:
(defn top2 [n comparator coll]
  (let [qtop #(take n (sort comparator (concat %1 %2)))]
    (reduce qtop (partition (* 10 n) coll))))

user=> (time (top2 10 #(> %1 %2) (range 5000000)))
"Elapsed time: 2990.945916 msecs"

(4999999 4999998 4999997 4999996 4999995 4999994 4999993 4999992 4999991 4999990)

user=> (time (take 10 (sort #(> %1 %2) (range 5000000))))
"Elapsed time: 4900.345365 msecs"

(4999999 4999998 4999997 4999996 4999995 4999994 4999993 4999992 4999991 4999990)

[Rich Hickey]

I still don't like unconditional add then prune-min. It is more than
2x as fast to check and add only if needed:

(defn top-n
([n coll] (top-n n nil coll))
([n comparator coll]
(let [empty-map (if comparator (sorted-map-by comparator) (sorted-map))
add #(assoc %1 %2 (inc (%1 %2 0)))
seed (reduce add empty-map (take n coll))

add-top #(let [[[min n]] (rseq %)]
(if (> min %2)
(add (if (== 1 n) (dissoc % min) (assoc % min (dec n))) %2)
%))]
(reduce add-top seed (drop n coll)))))

Rich

[Four of Seventeen]

On Jun 24, 2:43 am, Christophe Grand <christo...@cgrand.net> wrote:

> On Wed, Jun 24, 2009 at 7:53 AM, Richard Newman <holyg...@gmail.com> wrote:
>
> > > Even with the optimization, sort somehow beats top for speed. It looks
> > > like top is best used to avoid major memory consumption for long seqs;
> > > if you have the memory and need the speed, sort's better.
>
> > This is an interesting characteristic I've noticed in sorting code. In
> > the past (I'm thinking of one Common Lisp app in particular) I've
> > spent time carefully crafting tree-based accumulators to collect
> > values into a sorted collection... only to find that it was slower
> > than just collecting the whole damn list and sorting it, even for very
> > large collections. Seems all those tree/map operations take time, and
> > library sort functions are fast!
>
> Then use sort!
>
> Prototype implementation:
> (defn top2 [n comparator coll]
>   (let [qtop #(take n (sort comparator (concat %1 %2)))]
>     (reduce qtop (partition (* 10 n) coll))))
>
> user=> (time (top2 10 #(> %1 %2) (range 5000000)))
> "Elapsed time: 2990.945916 msecs"
> (4999999 4999998 4999997 4999996 4999995 4999994 4999993 4999992 4999991
> 4999990)
> user=> (time (take 10 (sort #(> %1 %2) (range 5000000))))
> "Elapsed time: 4900.345365 msecs"
> (4999999 4999998 4999997 4999996 4999995 4999994 4999993 4999992 4999991
> 4999990)

Interesting. This sorts the top n and a block of new values, keeps the
top n, and repeats. But there's a magic number there, the 10 in the
last line.

Let's make it a parameter:

user=> (defn top2 [n magic comparator coll]

(let [qtop #(take n (sort comparator (concat %1 %2)))]

(reduce qtop (partition (* magic n) coll))))
#'user/top2

Now we need to time it while varying "magic".

Because "time" doesn't give programmatic access to the time results:

user=> (defmacro nanotime [& body] `(let [start (System/nanotime)]
~@body (- (System/nanotime) start)))
#'user/nanotime

And here's the actual timing:

user=> (reduce (fn [m [k v]] (assoc m k v)) (sorted-map) (map (fn [x]
[(inc x) (nanotime (top2 10 (inc x) #(> %1 %2) (range 5000000)))])
(range 50)))
{1 5452225640, 2 3988404840, 3 3915592360, 4 3871197280, 5 3867781520,
6 3212079480, 7 3017036040, 8 2948082640, 9 3042258600, 10 3451045200,
11 3354897120, 12 3588940040, 13 3417661520, 14 3662480640, 15
3399276720, 16 3775287280, 17 3472468440, 18 3632485520, 19
3573744640, 20 5075479520, 21 3676971680, 22 3371000880, 23
3348059360, 24 3279114720, 25 3265615800, 26 3293525960, 27
3332391880, 28 3365864600, 29 3348332480, 30 3347164440, 31
3370046040, 32 3491169480, 33 3391363560, 34 3458141240, 35
3431893440, 36 3483074840, 37 3457540320, 38 3454273840, 39
3453719200, 40 3416257240, 41 3422167400, 42 3392571160, 43
3365732840, 44 3492066200, 45 3384547200, 46 3401731000, 47
3426350920, 48 3429235560, 49 3583296480, 50 3710430000}

Apparently, a magic factor of 8 gives the fastest time. The trend is
back upward from there.

It might not hold as the number to take varies away from 10, however.

[Four of Seventeen]

On Jun 24, 12:28 pm, Four of Seventeen <fsevent...@gmail.com> wrote:
> user=> (defmacro nanotime [& body] `(let [start (System/nanotime)]
> ~@body (- (System/nanotime) start)))
> #'user/nanotime

user=> (defmacro nanotime [& body] `(let [start# (System/nanotime)]
~@body (- (System/nanotime) start#)))
#'user/nanotime

Not sure how the # signs got dropped making that first post, but I'm
pretty sure it won't work without them.