[net.lang.lisp] execution profile of franz functions?

gb@vax135.UUCP (Gary Bishop) (09/13/85)

How do I measure the execution time of my intrepreted and compiled franz
functions?  "prof" as used with C functions would be nice and the liszt
compiler seems to support the -p switch, but how do I get a mon.out?
Has anyone come up with a more flexible system?

Smalltalk80 has a "spyon" facility that will evaluate an expression and
then print a nicely formatted listing of where the time went.  Anybody
done something like that for franz?

cpr0@bunny.UUCP (C. Rosebrugh) (09/24/85)

> How do I measure the execution time of my intrepreted and compiled franz
> functions?  "prof" as used with C functions would be nice and the liszt
> compiler seems to support the -p switch, but how do I get a mon.out?
> Has anyone come up with a more flexible system?
> 
> Smalltalk80 has a "spyon" facility that will evaluate an expression and
> then print a nicely formatted listing of where the time went.  Anybody
> done something like that for franz?

Hi. A guy here (Tim Blackman) wrote, and I modified, the following 
stuff to get the execution time of code. It runs for us under 
Ultrix Franz Lisp on a Vax 11/785. 
Load this code in, then surround your code by the
                 macro "timer" => (timer (plus ....)  ).
Good Luck - I hope it's useful.

;;;Variable used for determining the format of the timer output.
;;;See function "elapsed-time".
(setq elapsed-time-format 'long)

(defun uconcat (&rest args &aux (base 10.) (*nopoint t))
   (format nil "~{~a~}" args))

;;; Elapsed-time -- Returns a print string for the elapsed time.  The
;;; arguments are given in seconds.  If one argument is provided, then
;;; that number of seconds is converted.  If two arguments are given,
;;; the absolute value of their difference is given.  There are two
;;; output formats, determined by the value of the global variable
;;; "elapsed-time-format":  long = "6 hours 35 minutes 6.54 seconds",
;;; short = "6:35:06.54".
(defun elapsed-time (time1 &optional (time2 nil time2p))
  (if (null time2p)
      (elapsed-time* time1)
      (elapsed-time* (abs (- time1 time2)))))

(defun elapsed-time* (x &aux hours minutes seconds)
  (cond ((floatp x)
	 (setq seconds (difference x (* 60 (fix (quotient x 60)))))
	 (setq x (fix (quotient x 60))))
	(t (setq seconds (mod x 60))
	   (setq x (*quo x 60))))
  (setq minutes (mod x 60)
	hours (*quo x 60))
  (cond ((eq elapsed-time-format 'long)
	 (if (floatp seconds)
	     (setq seconds
		   (cond ((zerop (fix seconds))
			  (format nil "~2f" seconds))
			 ((<& (fix seconds) 10)
			  (format nil "~3f" seconds))
			 (t (format nil "~4f" seconds)))))
	 (if (zerop hours)
	     (if (zerop minutes)
		 (format nil "~d second~:p" seconds)
		 (format nil "~d minute~:p ~d second~:p" minutes seconds))
	     (format nil "~d hour~:p ~d minute~:p ~d second~:p"
		     hours minutes seconds)))
	(t (uconcat
	     (cond ((zerop hours) "00")
		   ((<& hours 10) (uconcat "0" hours))
		   (t hours))
	     ":"
	     (cond ((zerop minutes) "00")
		   ((<& minutes 10) (uconcat "0" minutes))
		   (t minutes))
	     ":"
	   (if (floatp seconds)
	       (cond ((zerop (fix seconds)) "00")
		     ((<& (fix seconds) 10) (format nil "0~3f" seconds))
		     (t (format nil "~4f" seconds)))
	       (if (<& seconds 10)
		   (uconcat "0" seconds)
		   seconds))))))


;;; timer -- prints out the timings for processing the enclosed lisp
;;; expression.  the expression should not be quoted, e.g.  (timer (setq
;;; a 'b)) the format of the resulting times is controlled by the global
;;; variable "elapsed-time-format".  see elapsed-time.
#+franz
(defmacro timer (arg)
  `(let (start-time start-ptime finish-time finish-ptime value)
	(setq start-time (sys:time)
	      start-ptime (ptime)
	      value ,arg
	      finish-ptime (ptime)
	      finish-time (sys:time))
	(terpri)
	(princ "timings:")
	(terpri)
	(princ (uconcat "  elapsed:            "
			(elapsed-time start-time finish-time)))
	(terpri)
	(princ (uconcat "  processor:          "
			(elapsed-time
			  (quotient (float (difference (car finish-ptime)
						       (car start-ptime)))
				    60.0))))
	(terpri)
	(princ (uconcat "  garbage collector:  "
			(elapsed-time
			  (quotient (float (difference (cadr finish-ptime)
						       (cadr start-ptime)))
				    60.0))))
	(terpri)
	value))

				Christopher Rosebrugh
				GTE Laboratories, Waltham, Mass.
				cpr0@gte-labs.CSNET
				uucp...!harvard!bunny!cpr0