From: eliben
Subject: timing operations & garbage collection
Date: 
Message-ID: <yqcofa2bud1.fsf@lnx-baruch.haifa.ibm.com>
Greetings,

I follow the examples in PAIP, and came to playing with (time):

(defun f (n) (dotimes (i n) nil))

Trying to run it with various n's, I noticed an interesting thing:


[6]> (time (f 1000000))

Real time: 2.441448 sec.
Run time: 1.13 sec.
Space: 0 Bytes
NIL
[7]> (time (f 1000000))

Real time: 2.607478 sec.
Run time: 1.14 sec.
Space: 0 Bytes
NIL
[8]> (time (f 1000000))

Real time: 3.433636 sec.
Run time: 1.14 sec.
Space: 0 Bytes
NIL
[9]> (time (f 1000000))

Real time: 3.934572 sec.
Run time: 1.14 sec.
Space: 0 Bytes
NIL
[10]> (time (f 1000000))

Real time: 4.012283 sec.
Run time: 1.15 sec.
Space: 0 Bytes
NIL
[11]> (time (f 1000000))

Real time: 4.154645 sec.
Run time: 1.13 sec.
Space: 0 Bytes
NIL
[12]> (gc)
524288
[13]> (time (f 1000000))

Real time: 2.55649 sec.
Run time: 1.14 sec.
Space: 0 Bytes
NIL
[14]> (time (f 1000000))

Real time: 2.674802 sec.
Run time: 1.14 sec.
Space: 0 Bytes
NIL



Note that with each run, it takes longer to loop 1e6 times. However,
after I garbage-collect manually, the time decreases to its start
point again (and starts growing again, afterwards).

Why is this so ?

My Lisp is GNU Clisp 2.28, running on a Linux box

Eli

From: Lorance Stinson
Subject: Re: timing operations & garbage collection
Date: 
Message-ID: <3DA5AA93.D6777227@worldpbx.com>
> Note that with each run, it takes longer to loop 1e6 times. However,
> after I garbage-collect manually, the time decreases to its start
> point again (and starts growing again, afterwards).
I have run across this behavior many times, even with a compiled function.
If you pause a few seconds between each try the time will not increase.
This also occures with CMUCL in much the same way.
> 
> Why is this so ?
I'm not completely sure what the cause is. I'm willing to bet it is a
combination of many things. Garbage collection can cause this to happen.
The VM sub system in Liux can cause this, and each version of the VM sub
system can and often does have different affects. Your best bet is to run
it many times and average out the time. Then use the average as a guide
line. Never assume that these numbers actually mean anything. Also check
out the various profiling packages available. I recomment the  metering
package in CLOCC. Look at http://ww.telent.net/cliki/index for more
information.
> 
> My Lisp is GNU Clisp 2.28, running on a Linux box
> 
> Eli

-- 
Lorance Stinson <·······@worldpbx.com> http://www.worldpbx.com/
Codito, Ergo Sum (I Code, therefore I am)
From: Barry Margolin
Subject: Re: timing operations & garbage collection
Date: 
Message-ID: <Z7gp9.5$Wg1.1165@paloalto-snr1.gtei.net>
In article <···············@lnx-baruch.haifa.ibm.com>,
eliben  <······@ppc256.haifa.ibm.com> wrote:
>Note that with each run, it takes longer to loop 1e6 times. However,
>after I garbage-collect manually, the time decreases to its start
>point again (and starts growing again, afterwards).

Notice, however, that it's only the real time, not the CPU time, that's
increasing.  You're probably paging more, because the garbage you're
creating is increasing your process size.

Since your function doesn't actually cons anything, the garbage is
presumably being created internally by the interpreter.  If you compile
your function you should see the problem go away.

-- 
Barry Margolin, ······@genuity.net
Genuity, Woburn, MA
*** DON'T SEND TECHNICAL QUESTIONS DIRECTLY TO ME, post them to newsgroups.
Please DON'T copy followups to me -- I'll assume it wasn't posted to the group.