I am running two embedded loops that might take a long time. Would like to time the inner while
loop. What can I do?
-
2What I would do is put the inner loop inside a function and then [profile](https://www.gnu.org/software/emacs/manual/html_node/elisp/Profiling.html) the code. I most often use the `elp` profiler. That will give you the totail execution time for the function as well as the time per call, which is exactly what you want. You can also use `benchmark-call`, which is described in the linked paged above. – NickD Oct 25 '22 at 00:49
1 Answers
Here's how to use the elp
profiler to do what you want (see Profiling in the Emacs Lisp Reference manual for more details).
As I suggested in the comment, the idea is to write your nested loops as two functions:
(defun outer-loop (l m)
(let ((sum 0))
(cl-dotimes (i l sum)
(setq sum (+ sum (inner-loop m))))))
(defun inner-loop (n)
(let ((sum 0))
(cl-dotimes (i n sum)
(setq sum (+ sum (log (+ 1 i)))))))
Calling outer-loop
like this: (outer-loop 1000 10000)
will run the outer loop 1000 times and each time around the inner-loop
function will be called with an argument of 10000, so it will loop 10000 times executing its body on each call (the body is basically a nonsensical calculation: just something to burn some CPU time).
To profile the functions, you first say M-x elp-instrument-list RET (outer-loop inner-loop)
providing the names of the functions that you want to profile in a list, then run the call with (outer-loop 1000 10000)
, or maybe with smaller numbers depending on how fast your machine is: with the numbers above, my machine takes a few seconds to finish. You can then look at the profiling results with M-x elp-result
. In my case, that produced the following results:
Function name Call Count Elapsed Time Average Time
-----------------------------------------------------
outer-loop 1 5.094440009 5.094440009
inner-loop 1000 5.0910220809 0.0050910220
so the 1000 calls of inner-loop
took a little over 5 seconds, so each call took about 5ms on average.
Another way to measure is by using benchmark
. The doc string says:
(benchmark REPETITIONS FORM)
Print the time taken for REPETITIONS executions of FORM.
so you can measure 1000 repetitions of the inner loop with:
(benchmark 1000 '(inner-loop 10000))
"Elapsed time: 5.166497s (2.494692s in 12 GCs)"
Again the result is a bit more than 5 seconds for 1000 repetitions but you'll have to do the division yourself to find the per-call average time. OTOH, it tells you how many garbage collections were done and how long they took, which might be useful information.

- 27,023
- 3
- 23
- 42