1

I am running two embedded loops that might take a long time. Would like to time the inner while loop. What can I do?

Drew
  • 75,699
  • 9
  • 109
  • 225
Dilna
  • 1,173
  • 3
  • 10
  • 2
    What 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 Answers1

1

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.

NickD
  • 27,023
  • 3
  • 23
  • 42