Article View: comp.lang.lisp.mcl
Article #635Re: Measuring elapsed CPU time
From: "Mark A. Tapia"
Date: Thu, 21 Jan 1993 14:37
Date: Thu, 21 Jan 1993 14:37
84 lines
3406 bytes
3406 bytes
On Thu Jan 21 05:07:05 1993, Joung-woo John Kim (joungwoo@mensa.usc.edu)
writes:
I'm trying to measure teh elasped CPU time during a lisp form has been run.
...
So I tried using builtin function GET-INTERNAL-RUN-TIME as follows,
but the following function defined by me usually it gives me either 0 or 1 no
matter how time-consuming task I give it.
John then describes a function of the form:
(defun CPU-time (form)
...
)
The problem is that the form is evaluated before the body of the
CPU-time function is invoked. If you want to time a function,
you need to convert your function to a macro. The following
macro does what you want
;; monitoring routines for timing
;; execute the form ntimes and give the title to it
(defpackage :timing (:use "COMMON-LISP" "CCL"))
(in-package :timing)
;; Execute form ntimes, optionally garbage collect (:gc t),
;; optionally prints the statistics (:print t), and
;; returns the following values and optionally prints them
;; title
;; number of times the form was executed
;; total cpu time
;; cpu time less gc time
;; total gc time
;; ephemeral gc time
(defmacro form-stats (title form &key (ntimes 1) (print t) (gc nil))
(let ((var1 (gensym))
(tot (gensym))
(run (gensym))
(values (gensym))
(tot-gc (gensym))
(new-gc (gensym))
(egc (gensym))
(new-egc (gensym)))
`(let (,tot ,run ,values)
(when ,gc
(gc))
(ccl::reset-consing)
(multiple-value-bind (,tot-gc ,egc)
(gctime)
(setq ,egc (- ,tot-gc ,egc))
(setq ,run (get-internal-run-time))
(dotimes (,var1 ,ntimes)
,form)
(multiple-value-bind (,new-gc ,new-egc)
(gctime)
(setq ,new-egc (- ,new-gc ,new-egc))
(setq ,tot-gc (- ,new-gc ,tot-gc)
,egc (- ,new-egc ,egc)
,tot (- (get-internal-run-time) , run)
,run (- ,tot ,tot-gc)
,run (float (/ ,run internal-time-units-per-second))
,tot-gc (float (/ ,tot-gc internal-time-units-per-second))
,egc (float (/ ,egc internal-time-units-per-second))
,tot (float (/ ,tot ,internal-time-units-per-second)))
(setq ,values
(format nil "~s ~d ~3f ~3f ~3f ~3f",title ,ntimes ,tot ,run
,tot-gc ,egc))
(when ,print (format t "~&~a~%" ,values))
(values ,title ,ntimes ,tot ,run ,tot-gc ,egc)
)))))
? (form-stats "simple loop"
(loop for i fixnum from 1 to 10000
collect i))
"simple loop" 1 1.1 0.13 1.0 1.0
"simple loop"
1
1.15
0.133
1.017
1.017
mark
You can also collect statistics on storage used.
Technical Details
Message-ID:
<93Jan21.093724est.144034@explorer.dgp.toronto.edu>Path:
arc1-ca.pugleaf.net!sparky!uunet!usc!cs.utexas.edu!sun-barr!ames!data.nas.nasa.gov!taligent!apple!cambridge.apple.com!@explorer.dgp.toronto.edu:markt@dgp.toronto.eduShow Full Headers
Complete Article Headers
Path: arc1-ca.pugleaf.net!sparky!uunet!usc!cs.utexas.edu!sun-barr!ames!data.nas.nasa.gov!taligent!apple!cambridge.apple.com!@explorer.dgp.toronto.edu:markt@dgp.toronto.edu
From: markt@dgp.toronto.edu ("Mark A. Tapia")
Newsgroups: comp.lang.lisp.mcl
Subject: Re: Measuring elapsed CPU time
Message-ID: <93Jan21.093724est.144034@explorer.dgp.toronto.edu>
Date: 21 Jan 93 14:37:15 GMT
Sender: owner-info-mcl@cambridge.apple.com
Lines: 84
Approved: comp.lang.lisp.mcl@Cambridge.Apple.C0M