Subject: Re: Timing the execution of a program silently
From: rpw3@rpw3.org (Rob Warnock)
Date: Sun, 26 Oct 2008 23:26:27 -0500
Newsgroups: comp.lang.lisp,comp.programming
Message-ID: <C66dnf92VsRu35jUnZ2dnUVZ_g2dnZ2d@speakeasy.net>
Robert Maas <seeWebInstead@teh.intarweb.org> wrote:
+---------------
| I want to write CGI applications that measure how much time they
| take ... absolutely imperative that nothing whatsoever spew to standard
| output or any other output during the running of the program being
| measured. Note that I'm using CMU Common Lisp here...
...
| So if I say (time (foo)) it runs (foo) and spews out the timing info.
| So I need to wrap the form with WITH-OUTPUT-TO-STRING to collect
| that spewed output in a string instead. But now when I try to
| evaluate that form, CMUCL spews out this warning message:
|   Warning:  TIME form in a non-null environment, forced to interpret.
|   Compiling entire form will produce more accurate times.
...[and much more convoluted stuff]...
| - Have I done precisely what's necessary to achieve the desired
|    goal, or is there an easier way to accomplish that goal in CMUCL?
+---------------

Well, I think you're making this way harder on yourself than it
really needs to be:

    cmu> (defun time-to-string (form)
	   (with-output-to-string (*standard-output*)
	     (let ((*error-output* *standard-output*)
		   (*trace-output* *standard-output*)
		   (*compile-print* nil))
	       (eval `(time ,form)))))

    TIME-TO-STRING
    cmu> (time-to-string (list '+ 1 2))

    "
    ; Evaluation took:
    ;   0.0f0 seconds of real time
    ;   6.0f-6 seconds of user run time
    ;   1.0f-6 seconds of system run time
    ;   2,967 CPU cycles
    ;   0 page faults and
    ;   0 bytes consed.
    ; 
    "
    cmu> 

+---------------
| So it looks like I need to build my entire form into a LAMBDA
| expression and then compile it...
+---------------

No, TIME will compile it for you. You just need to catch the
compilation messages, or suppress them entirely by binding
*COMPILE-PRINT* to NIL (see above).

+---------------
| - How would this task be accomplished, if it can be accomplished at
|    all, in other CGI-able languages, especially PHP or Perl or Java?
+---------------

Even with CMUCL, I would try to avoid constantly compiling at
HTTP request time wherever possible, by one or more of these
methods:

1. Don't use TIME at all; instead, time the calls yourself with
   a simple wrapper such as this:

    cmu> (defun timed-funcall (function &rest args)
	   (let* ((start-time (get-internal-run-time))
		  (results (multiple-value-list (apply function args)))
		  (end-time (get-internal-run-time)))
	     (values-list (cons (/ (float (- end-time start-time) 1.0f0)
				   internal-time-units-per-second)
                                results))))

    TIMED-FUNCALL
    cmu> (timed-funcall #'expt 2 100)

    0.0
    1267650600228229401496703205376
    cmu> (timed-funcall (lambda () (dotimes (i 100000)) 'done))

    0.67
    DONE
    cmu> (compile nil (lambda () (dotimes (i 100000)) 'done))
    ; Compiling LAMBDA NIL: 
    ; Compiling Top-Level Form: 

    #<Function "LAMBDA NIL" {488F4A01}>
    NIL
    NIL
    cmu> (timed-funcall *)

    0.0                <== Compiling really helps!!  ;-}
    DONE
    cmu> 

   Only if you really, *really* need to charge customers at a
   finer grain than INTERNAL-TIME-UNITS-PER-SECOND (100/s, on CMUCL)
   should you do anything more complicated than the above. And even
   in that case, rather than use all the hair of TIME, I would directly
   use the same internal CMUCL functions LISP::TIME-GET-SYS-INFO and/or
   LISP::CYCLE-COUNT/FLOAT that TIME uses [see "cmucl/src/code/time.lisp"]
   in a simple wrapper such as the above.

2. Use a persistent CMUCL daemon process and connect to it from
   the web server with either <http://www.cliki.net/mod_lisp>,
   if your hosting site allows you to add modules to Apache, or
   perhaps <http://rpw3.org/hacks/lisp/cgi_sock.c> if they don't.
   *Monster* speedup over running a new CMUCL process for each
   CGI request!!

3. Whether or not you can do #2, cache the compilation of your work units,
   either in memory (in case #2), or if all else fails then on disk as
   FASLs (".x86f", for CMUCL on x86) which you LOAD at CGI time if the
   source isn't out-of-date. Note: CMUCL makes this easy with a extension
   to LOAD -- (LOAD "foo" :IF-SOURCE-NEWER :COMPILE) is a sort of
   mini-"Make" if both "foo.lisp" and "foo.x86f" are visible, just
   loading "foo.x86f" unless "foo.lisp" is newer, in which case it
   recompiles it first, then loads. [If only one of them exists, it
   just silently loads that one. It never *creates* the FASL itself.]


-Rob

-----
Rob Warnock			<rpw3@rpw3.org>
627 26th Avenue			<URL:http://rpw3.org/>
San Mateo, CA 94403		(650)572-2607