From: Richard Szopa
Subject: iteration, recursion, profiling
Date: 
Message-ID: <1194525186.946254.231610@t8g2000prg.googlegroups.com>
Hello,

I have two versions of the same function:

(defun insert-into-sorted (elt lst n fun)
  "Insert `elt' into the first `N' elements of `lst' providing this
  leaves `lst' `fun'-sorted."
  (cond ((< n 1) lst)
        ((null lst) (list elt))
        ((funcall fun elt (car lst))
         (cons elt (butlast  lst)))
        (t (cons (car lst) (insert-into-sorted elt (cdr lst) (1- n)
fun)))))

(defun insert-into-sorted-2 (elt lst n fun)
  (iter (for index index-of-sequence lst)
        (for e in lst)
        (for i from 0 to n)
        (when (funcall fun elt e)
          (return (append (subseq lst 0 index) (cons elt (subseq lst
index (1- (length lst)))))))
        (finally (return lst))))

I assumed that the second one would be faster. However, after turning
on profiling and running a couple of times the following code:

(let ((rand (sort (iter (for i from 1 to 50000) (collect (random
1000000))) #'<))

                (winners ())
                (winners2 ()))
            (iter (for el in rand) (setf winners (insert-into-sorted
el winners 5 #'<)))
            (iter (for el in rand) (setf winners2 (insert-into-
sorted-2 el winners2 5 #'<)))

            'OK)

I got the following result:

  seconds  |   consed   |   calls   |  sec/call  |  name
------------------------------------------------------------
     0.043 |          0 |   215,000 |  0.0000002 | INSERT-INTO-
SORTED-2
     0.000 | 55,849,272 | 1,961,115 |   0.000000 | INSERT-INTO-SORTED
------------------------------------------------------------
     0.043 | 55,849,272 | 2,176,115 |            | Total

estimated total profiling overhead: 3.74 seconds
overhead estimation parameters:
  2.4e-8s/call, 1.72e-6s total profiling, 6.56e-7s internal profiling

On the other hand, when I run the thing with time, I get the
following:

INSERT-INTO-SORTED
Evaluation took:
  0.612 seconds of real time
  0.332021 seconds of user run time
  0.264016 seconds of system run time
  [Run times include 0.02 seconds GC run time.]
  0 calls to %EVAL
  0 page faults and
  9,212,088 bytes consed.
INSERT-INTO-SORTED2
Evaluation took:
  0.093 seconds of real time
  0.052003 seconds of user run time
  0.036003 seconds of system run time
  0 calls to %EVAL
  0 page faults and
  1,200,352 bytes consed.

which If I am right means, that the version with iter is faster,
contrary to what says the profiler!

What am I doing wrong? Could anybody help me to make sense of this?

Thanks,

    -- Richard

From: Juho Snellman
Subject: Re: iteration, recursion, profiling
Date: 
Message-ID: <87wsss69ql.fsf@vasara.proghammer.com>
Richard Szopa <·············@gmail.com> writes:
> which If I am right means, that the version with iter is faster,
> contrary to what says the profiler!
> 
> What am I doing wrong? Could anybody help me to make sense of this?

You're not doing anything wrong. The SBCL instrumenting profiler tries
to estimate the profiling overhead per function call, and adjusts the
measured times based on those results. In this case it's overestimated
the overhead, and adjusted the amount of time that a single call to
the recursive version takes to 0 seconds.

I recommend using the statistical profiler instead. See the SBCL
manual for details on how to use it.

-- 
Juho Snellman
From: Richard Szopa
Subject: Re: iteration, recursion, profiling
Date: 
Message-ID: <1194622275.467743.48140@50g2000hsm.googlegroups.com>
On Nov 8, 4:24 pm, Juho Snellman <······@iki.fi> wrote:

> You're not doing anything wrong. The SBCL instrumenting profiler tries
> to estimate the profiling overhead per function call, and adjusts the
> measured times based on those results. In this case it's overestimated
> the overhead, and adjusted the amount of time that a single call to
> the recursive version takes to 0 seconds.
>
> I recommend using the statistical profiler instead. See the SBCL
> manual for details on how to use it.

Thanks for your answer, I'll take a look at the statistical profiler.
A friend also pointed that by sorting RAND I was testing the worse
case scenario, which was a copy&paste error (in other tests I was
inserting a random number into RAND). And that 50 thousand numbers is
quite a small test set.

Cheers,

    -- Richard