time-fnc.sl 5.1 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171
  1. ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
  2. ;;
  3. ;; Time-fnc.sl : code to time function calls.
  4. ;;
  5. ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
  6. ;;
  7. ;; Written by Douglas Lanam. (November 1982).
  8. ;;
  9. ;; To be compiled inside `pfrl' using the command:
  10. ;; (compile-file time-fnc).
  11. ;;
  12. ;; The object created is usuable in any psl on machine it is compiled for.
  13. ;;
  14. ;; Usage:
  15. ;;
  16. ;; do
  17. ;; (timef function-name-1 function-name-2 ...)
  18. ;;
  19. ;; Timef is a fexpr.
  20. ;; It will redefine the functions named so that timing information is
  21. ;; kept on these functions.
  22. ;; This information is kept on the property list of the function name.
  23. ;; The properties used are `time' and `number-of-calls'.
  24. ;;
  25. ;; (get function-name 'time) gives you the total time in the function.
  26. ;; (not counting gc time).
  27. ;; Note, this is the time from entrance to exit.
  28. ;; The timef function redefines the function with an
  29. ;; unwind-protect, so calls that are interrupted
  30. ;; by *throws are counted.
  31. ;;
  32. ;; (get function-name 'number-of-calls) gives you the number of times
  33. ;; the function is called.
  34. ;;
  35. ;; To stop timing do :
  36. ;; (untimef function-name1 ..)
  37. ;; or do (untimef) for all functions.
  38. ;; (untimef) is a fexpr.
  39. ;;
  40. ;; To print timing information do
  41. ;; (print-time-info function-name-1 function-name-2 ..)
  42. ;;
  43. ;; or do (print-time-info) for timing information on all function names.
  44. ;;
  45. ;; special variables used:
  46. ;; *timed-functions* : list of all functions currently being timed.
  47. ;; *all-timed-functions* : list of all functions ever timed in the
  48. ;; current session.
  49. ;;
  50. ;; Comment: if tr is called on a called on a function that is already
  51. ;; being timed, and then untimef is called on the function, the
  52. ;; function will no longer be traced.
  53. ;;
  54. (defvar *timed-functions* nil)
  55. (defvar *all-timed-functions* nil)
  56. (defun timef fexpr (names)
  57. (cond ((null names) *timed-functions*)
  58. ((f-mapc
  59. '(lambda (x)
  60. (or (memq x *timed-functions*)
  61. (let ((a (getd x)))
  62. (cond (a (put x 'orig-function-def a)
  63. (setq *timed-functions*
  64. (cons x *timed-functions*))
  65. (or (memq x *all-timed-functions*)
  66. (setq *all-timed-functions*
  67. (cons x *all-timed-functions*)))
  68. (set-up-time-function
  69. (car a) x (cdr a)))
  70. (t (princ x)
  71. (princ " is not a defined function.")
  72. (terpri))))))
  73. names))))
  74. (defun set-up-time-function (type x old-func)
  75. (let ((y (cond ((codep old-func)
  76. (code-number-of-arguments old-func))
  77. (t (length (cadr old-func)))))
  78. (args) (function) (result-var (gensym)) (gc-time-var (gensym))
  79. (time-var (gensym)))
  80. (do ((i y (difference i 1)))
  81. ((= i 0))
  82. (setq args (cons (gensym) args)))
  83. (putd x type
  84. `(lambda ,args
  85. (time-function ',x ',old-func
  86. (list (time) . ,args))))
  87. x))
  88. (defvar |* timing time *| 0)
  89. #+dec20
  90. (defvar *call-overhead-time* 0.147)
  91. #+vax
  92. (defvar *call-overhead-time* 0.1)
  93. #+dec20
  94. (defvar *time-overhead-time* 0.437)
  95. #+vax
  96. (defvar *time-overhead-time* 1.3)
  97. (defvar |* number of sub time calls *| 0)
  98. (defun time-function (name function-pointer arguments)
  99. (let ((itime-var (car arguments)) (result) (n)
  100. (endt) (total-fnc-time) (time-var) (gc-time-var))
  101. (unwind-protect
  102. (let ((|* timing time *| 0)
  103. (|* number of sub time calls *| 0))
  104. (unwind-protect
  105. (let () (setq gc-time-var gctime* time-var (time)
  106. result (apply function-pointer (cdr arguments))
  107. endt (time))
  108. result)
  109. (cond
  110. (time-var
  111. (or endt (setq endt (time)))
  112. (Setq n |* number of sub time calls *|)
  113. (put name 'number-of-sub-time-calls
  114. (+ n (or (get name 'number-of-sub-time-calls) 0)))
  115. (setq total-fnc-time (- (- endt time-var) |* timing time *|))
  116. (put name 'time
  117. (+ (or (get name 'time) 0)
  118. (- total-fnc-time (- gctime* gc-time-var))))
  119. (put name 'number-of-calls
  120. (1+ (or (get name 'number-of-calls) 0)))))))
  121. (prog ()
  122. (setq |* timing time *|
  123. (- (- |* timing time *| itime-var) total-fnc-time)))
  124. (setq |* number of sub time calls *|
  125. (1+ |* number of sub time calls *|))
  126. (setq |* timing time *| (+ |* timing time *| (time)))))))
  127. (defun untimef fexpr (names)
  128. (f-mapc '(lambda (x)
  129. (cond ((memq x *timed-functions*)
  130. (let ((a (get x 'orig-function-def)))
  131. (cond (a (putd x (car a) (cdr a)))))
  132. (setq *timed-functions*
  133. (delq x *timed-functions*)))))
  134. (or names *timed-functions*)))
  135. (defun print-time-info fexpr (names)
  136. (f-mapc '(lambda (x)
  137. (let ((n (get x 'number-of-calls))
  138. (ns (get x 'number-of-sub-time-calls))
  139. (time) (t1 (get x 'time)))
  140. (princ x) (princ " ")
  141. (tab 20)
  142. (princ (or n 0)) (princ " calls")
  143. (cond (n
  144. (setq time
  145. (max 0
  146. (difference
  147. (difference
  148. (or t1 0)
  149. (times *call-overhead-time*
  150. (or n 0)))
  151. (times *time-overhead-time*
  152. (or ns 0)))))
  153. (tab 31) (princ time) (princ " ms")
  154. (tab 48)
  155. (princ (quotient (float time) (float n)))
  156. (princ " ms\/call")))
  157. (terpri)))
  158. (or names *all-timed-functions*))
  159. (terpri))