diff options
| author | Richard M. Stallman | 1997-04-12 19:14:18 +0000 |
|---|---|---|
| committer | Richard M. Stallman | 1997-04-12 19:14:18 +0000 |
| commit | 9b267ebada375513f5c87319ac70f718b13203d7 (patch) | |
| tree | 1cbb9d151d01a3b1280e4d3bd8e04f3bd54a0ef1 | |
| parent | a9a44ed170d462f5d634f3e1743dae0791bbb2b7 (diff) | |
| download | emacs-9b267ebada375513f5c87319ac70f718b13203d7.tar.gz emacs-9b267ebada375513f5c87319ac70f718b13203d7.zip | |
(elp-functionp): New function.
(elp-instrument-package): Don't attempt to instrument autoload functions.
(elp-elapsed-time): New function to calculate the different between
two `current-time' lists. This no longer throws away the top 16 bits
of information.
(elp-wrapper): Use elp-elapsed-time instead of elp-get-time. Also,
call `current-time' as close to the function entrance and exit as
possible so more of the overhead is eliminated from the times.
(elp-get-time): Obsolete, deleted.
(elp-restore-function):
When restoring, do not check assq elp-wrapper
if the symbol-function is a compiled lisp function (i.e. byte coded).
If it is byte-coded, it could not have been instrumented.
Don't do the symbol-function restoration if
the symbol has no function definition.
(elp-instrument-function): Always `restore' the funsym before instrumenting.
Fail if function is an autoload symbol.
(elp-instrument-list): Remove unnecessary condition-case.
(elp-results):
Noninteractive as a function is non-portable, use the
variable instead. buffer-substring with 3 arguments is non-portable.
(elp-instrument-function, elp-instrument-list):
Handle function symbols that have already been instrumented. Do
not instrument them twice.
(elp-recycle-buffers-p): New variable.
(elp-report-limit, elp-sort-by-function): New default values.
(elp-use-standard-output): New variable.
(elp-results): Optionally dump results to standard-output.
| -rw-r--r-- | lisp/emacs-lisp/elp.el | 148 |
1 files changed, 100 insertions, 48 deletions
diff --git a/lisp/emacs-lisp/elp.el b/lisp/emacs-lisp/elp.el index 7c07e900b38..52084311124 100644 --- a/lisp/emacs-lisp/elp.el +++ b/lisp/emacs-lisp/elp.el | |||
| @@ -2,12 +2,12 @@ | |||
| 2 | 2 | ||
| 3 | ;; Copyright (C) 1994 Free Software Foundation, Inc. | 3 | ;; Copyright (C) 1994 Free Software Foundation, Inc. |
| 4 | 4 | ||
| 5 | ;; Author: 1994 Barry A. Warsaw <bwarsaw@cnri.reston.va.us> | 5 | ;; Author: 1994-1997 Barry A. Warsaw |
| 6 | ;; Maintainer: tools-help@anthem.nlm.nih.gov | 6 | ;; Maintainer: tools-help@python.org |
| 7 | ;; Created: 26-Feb-1994 | 7 | ;; Created: 26-Feb-1994 |
| 8 | ;; Version: 2.23 | 8 | ;; Version: 2.39 |
| 9 | ;; Last Modified: 1994/12/28 22:39:31 | 9 | ;; Last Modified: 1997/02/28 18:15:35 |
| 10 | ;; Keywords: Emacs Lisp Profile Timing | 10 | ;; Keywords: debugging lisp tools |
| 11 | 11 | ||
| 12 | ;; This file is part of GNU Emacs. | 12 | ;; This file is part of GNU Emacs. |
| 13 | 13 | ||
| @@ -32,10 +32,12 @@ | |||
| 32 | ;; to the list of symbols, then do a M-x elp-instrument-list. This | 32 | ;; to the list of symbols, then do a M-x elp-instrument-list. This |
| 33 | ;; hacks those functions so that profiling information is recorded | 33 | ;; hacks those functions so that profiling information is recorded |
| 34 | ;; whenever they are called. To print out the current results, use | 34 | ;; whenever they are called. To print out the current results, use |
| 35 | ;; M-x elp-results. With elp-reset-after-results set to non-nil, | 35 | ;; M-x elp-results. If you want output to go to standard-output |
| 36 | ;; profiling information will be reset whenever the results are | 36 | ;; instead of a separate buffer, setq elp-use-standard-output to |
| 37 | ;; displayed. You can also reset all profiling info at any time with | 37 | ;; non-nil. With elp-reset-after-results set to non-nil, profiling |
| 38 | ;; M-x elp-reset-all. | 38 | ;; information will be reset whenever the results are displayed. You |
| 39 | ;; can also reset all profiling info at any time with M-x | ||
| 40 | ;; elp-reset-all. | ||
| 39 | ;; | 41 | ;; |
| 40 | ;; You can also instrument all functions in a package, provided that | 42 | ;; You can also instrument all functions in a package, provided that |
| 41 | ;; the package follows the GNU coding standard of a common textural | 43 | ;; the package follows the GNU coding standard of a common textural |
| @@ -113,27 +115,27 @@ | |||
| 113 | ;; give you a good feel for the relative amount of work spent in the | 115 | ;; give you a good feel for the relative amount of work spent in the |
| 114 | ;; various lisp routines you are profiling. Note further that times | 116 | ;; various lisp routines you are profiling. Note further that times |
| 115 | ;; are calculated using wall-clock time, so other system load will | 117 | ;; are calculated using wall-clock time, so other system load will |
| 116 | ;; affect accuracy too. You cannot profile anything longer than ~18 | 118 | ;; affect accuracy too. |
| 117 | ;; hours since I throw away the most significant 16 bits of seconds | ||
| 118 | ;; returned by current-time: 2^16 == 65536 seconds == ~1092 minutes == | ||
| 119 | ;; ~18 hours. I doubt you will ever want to profile stuff on the | ||
| 120 | ;; order of 18 hours anyway. | ||
| 121 | 119 | ||
| 122 | ;;; Background: | 120 | ;;; Background: |
| 123 | 121 | ||
| 124 | ;; This program is based on the only two existing Emacs Lisp profilers | 122 | ;; This program is based on the only two existing Emacs Lisp profilers |
| 125 | ;; that I'm aware of, Boaz Ben-Zvi's profile.el, and Root Boy Jim's | 123 | ;; that I'm aware of, Boaz Ben-Zvi's profile.el, and Root Boy Jim's |
| 126 | ;; profiler.el. Both were written for Emacs 18 and both were pretty | 124 | ;; profiler.el. Both were written for Emacs 18 and both were pretty |
| 127 | ;; good first shots at profiling, but I found that they didn't provide | 125 | ;; good first shots at profiling, but I found that they didn't provide |
| 128 | ;; the functionality or interface that I wanted. So I wrote this. | 126 | ;; the functionality or interface that I wanted. So I wrote this. |
| 129 | ;; I've tested elp in GNU Emacs 19 and in GNU XEmacs. There's no | 127 | ;; I've tested elp in Emacs 19 and in XEmacs. There's no point in |
| 130 | ;; point in even trying to make this work with Emacs 18. | 128 | ;; even trying to make this work with Emacs 18. |
| 131 | 129 | ||
| 132 | ;; Unlike previous profilers, elp uses Emacs 19's built-in function | 130 | ;; Unlike previous profilers, elp uses Emacs 19's built-in function |
| 133 | ;; current-time to return interval times. This obviates the need for | 131 | ;; current-time to return interval times. This obviates the need for |
| 134 | ;; both an external C program and Emacs processes to communicate with | 132 | ;; both an external C program and Emacs processes to communicate with |
| 135 | ;; such a program, and thus simplifies the package as a whole. | 133 | ;; such a program, and thus simplifies the package as a whole. |
| 136 | 134 | ||
| 135 | ;; TBD: | ||
| 136 | ;; Make this act like a real profiler, so that it records time spent | ||
| 137 | ;; in all branches of execution. | ||
| 138 | |||
| 137 | ;;; Code: | 139 | ;;; Code: |
| 138 | 140 | ||
| 139 | 141 | ||
| @@ -141,13 +143,14 @@ | |||
| 141 | ;; vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv | 143 | ;; vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv |
| 142 | 144 | ||
| 143 | (defvar elp-function-list nil | 145 | (defvar elp-function-list nil |
| 144 | "*List of function to profile.") | 146 | "*List of function to profile. |
| 147 | Used by the command `elp-instrument-list'.") | ||
| 145 | 148 | ||
| 146 | (defvar elp-reset-after-results t | 149 | (defvar elp-reset-after-results t |
| 147 | "*Non-nil means reset all profiling info after results are displayed. | 150 | "*Non-nil means reset all profiling info after results are displayed. |
| 148 | Results are displayed with the `elp-results' command.") | 151 | Results are displayed with the `elp-results' command.") |
| 149 | 152 | ||
| 150 | (defvar elp-sort-by-function nil | 153 | (defvar elp-sort-by-function 'elp-sort-by-total-time |
| 151 | "*Non-nil specifies elp results sorting function. | 154 | "*Non-nil specifies elp results sorting function. |
| 152 | These functions are currently available: | 155 | These functions are currently available: |
| 153 | 156 | ||
| @@ -162,21 +165,29 @@ the call count, element 1 is the total time spent in the function, | |||
| 162 | element 2 is the average time spent in the function, and element 3 is | 165 | element 2 is the average time spent in the function, and element 3 is |
| 163 | the symbol's name string.") | 166 | the symbol's name string.") |
| 164 | 167 | ||
| 165 | (defvar elp-report-limit nil | 168 | (defvar elp-report-limit 1 |
| 166 | "*Prevents some functions from being displayed in the results buffer. | 169 | "*Prevents some functions from being displayed in the results buffer. |
| 167 | If a number, no function that has been called fewer than that number | 170 | If a number, no function that has been called fewer than that number |
| 168 | of times will be displayed in the output buffer. If nil, all | 171 | of times will be displayed in the output buffer. If nil, all |
| 169 | functions will be displayed.") | 172 | functions will be displayed.") |
| 170 | 173 | ||
| 174 | (defvar elp-use-standard-output nil | ||
| 175 | "*Non-nil says to output to `standard-output' instead of a buffer.") | ||
| 176 | |||
| 177 | (defvar elp-recycle-buffers-p t | ||
| 178 | "*Nil says to not recycle the `elp-results-buffer'. | ||
| 179 | In other words, a new unique buffer is create every time you run | ||
| 180 | \\[elp-results].") | ||
| 181 | |||
| 171 | 182 | ||
| 172 | ;; ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ | 183 | ;; ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ |
| 173 | ;; end user configuration variables | 184 | ;; end of user configuration variables |
| 174 | 185 | ||
| 175 | 186 | ||
| 176 | (defconst elp-version "2.23" | 187 | (defconst elp-version "2.39" |
| 177 | "ELP version number.") | 188 | "ELP version number.") |
| 178 | 189 | ||
| 179 | (defconst elp-help-address "tools-help@anthem.nlm.nih.gov" | 190 | (defconst elp-help-address "tools-help@python.org" |
| 180 | "Address accepting submissions of bug reports and questions.") | 191 | "Address accepting submissions of bug reports and questions.") |
| 181 | 192 | ||
| 182 | (defvar elp-results-buffer "*ELP Profiling Results*" | 193 | (defvar elp-results-buffer "*ELP Profiling Results*" |
| @@ -196,18 +207,50 @@ This variable is set by the master function.") | |||
| 196 | "Master function symbol.") | 207 | "Master function symbol.") |
| 197 | 208 | ||
| 198 | 209 | ||
| 210 | ;; Emacs/XEmacs compatibility. | ||
| 211 | (if (fboundp 'functionp) | ||
| 212 | (defalias 'elp-functionp 'functionp) | ||
| 213 | ;; Lift XEmacs 19.13's functionp from subr.el | ||
| 214 | (defun elp-functionp (obj) | ||
| 215 | "Returns t if OBJ is a function, nil otherwise." | ||
| 216 | (cond | ||
| 217 | ((symbolp obj) (fboundp obj)) | ||
| 218 | ((subrp obj)) | ||
| 219 | ((compiled-function-p obj)) | ||
| 220 | ((consp obj) | ||
| 221 | (if (eq (car obj) 'lambda) (listp (car (cdr obj))))) | ||
| 222 | (t nil)))) | ||
| 223 | |||
| 224 | |||
| 199 | ;;;###autoload | 225 | ;;;###autoload |
| 200 | (defun elp-instrument-function (funsym) | 226 | (defun elp-instrument-function (funsym) |
| 201 | "Instrument FUNSYM for profiling. | 227 | "Instrument FUNSYM for profiling. |
| 202 | FUNSYM must be a symbol of a defined function." | 228 | FUNSYM must be a symbol of a defined function." |
| 203 | (interactive "aFunction to instrument: ") | 229 | (interactive "aFunction to instrument: ") |
| 204 | ;; TBD what should we do if the function is already instrumented??? | 230 | ;; restore the function. this is necessary to avoid infinite |
| 231 | ;; recursion of already instrumented functions (i.e. elp-wrapper | ||
| 232 | ;; calling elp-wrapper ad infinitum). it is better to simply | ||
| 233 | ;; restore the function than to throw an error. this will work | ||
| 234 | ;; properly in the face of eval-defun because if the function was | ||
| 235 | ;; redefined, only the timer info will be nil'd out since | ||
| 236 | ;; elp-restore-function is smart enough not to trash the new | ||
| 237 | ;; definition. | ||
| 238 | (elp-restore-function funsym) | ||
| 205 | (let* ((funguts (symbol-function funsym)) | 239 | (let* ((funguts (symbol-function funsym)) |
| 206 | (infovec (vector 0 0 funguts)) | 240 | (infovec (vector 0 0 funguts)) |
| 207 | (newguts '(lambda (&rest args)))) | 241 | (newguts '(lambda (&rest args)))) |
| 208 | ;; we cannot profile macros | 242 | ;; we cannot profile macros |
| 209 | (and (eq (car-safe funguts) 'macro) | 243 | (and (eq (car-safe funguts) 'macro) |
| 210 | (error "ELP cannot profile macro %s" funsym)) | 244 | (error "ELP cannot profile macro: %s" funsym)) |
| 245 | ;; TBD: at some point it might be better to load the autoloaded | ||
| 246 | ;; function instead of throwing an error. if we do this, then we | ||
| 247 | ;; probably want elp-instrument-package to be updated with the | ||
| 248 | ;; newly loaded list of functions. i'm not sure it's smart to do | ||
| 249 | ;; the autoload here, since that could have side effects, and | ||
| 250 | ;; elp-instrument-function is similar (in my mind) to defun-ish | ||
| 251 | ;; type functionality (i.e. it shouldn't execute the function). | ||
| 252 | (and (eq (car-safe funguts) 'autoload) | ||
| 253 | (error "ELP cannot profile autoloaded function: %s" funsym)) | ||
| 211 | ;; put rest of newguts together | 254 | ;; put rest of newguts together |
| 212 | (if (commandp funsym) | 255 | (if (commandp funsym) |
| 213 | (setq newguts (append newguts '((interactive))))) | 256 | (setq newguts (append newguts '((interactive))))) |
| @@ -273,10 +316,13 @@ Argument FUNSYM is the symbol of a defined function." | |||
| 273 | ;; because its possible the function got un-instrumented due to | 316 | ;; because its possible the function got un-instrumented due to |
| 274 | ;; circumstances beyond our control. Also, check to make sure | 317 | ;; circumstances beyond our control. Also, check to make sure |
| 275 | ;; that the current function symbol points to elp-wrapper. If | 318 | ;; that the current function symbol points to elp-wrapper. If |
| 276 | ;; not, then the user probably did an eval-defun while the | 319 | ;; not, then the user probably did an eval-defun, or loaded a |
| 277 | ;; function was instrumented and we don't want to destroy the new | 320 | ;; byte-compiled version, while the function was instrumented and |
| 278 | ;; definition. | 321 | ;; we don't want to destroy the new definition. can it ever be |
| 322 | ;; the case that a lisp function can be compiled instrumented? | ||
| 279 | (and info | 323 | (and info |
| 324 | (elp-functionp funsym) | ||
| 325 | (not (compiled-function-p (symbol-function funsym))) | ||
| 280 | (assq 'elp-wrapper (symbol-function funsym)) | 326 | (assq 'elp-wrapper (symbol-function funsym)) |
| 281 | (fset funsym (aref info 2))))) | 327 | (fset funsym (aref info 2))))) |
| 282 | 328 | ||
| @@ -296,13 +342,13 @@ For example, to instrument all ELP functions, do the following: | |||
| 296 | \\[elp-instrument-package] RET elp- RET" | 342 | \\[elp-instrument-package] RET elp- RET" |
| 297 | (interactive "sPrefix of package to instrument: ") | 343 | (interactive "sPrefix of package to instrument: ") |
| 298 | (elp-instrument-list | 344 | (elp-instrument-list |
| 299 | (mapcar 'intern (all-completions prefix obarray | 345 | (mapcar 'intern |
| 300 | (function | 346 | (all-completions prefix obarray |
| 301 | (lambda (sym) | 347 | (function |
| 302 | (and (fboundp sym) | 348 | (lambda (sym) |
| 303 | (not (memq (car-safe | 349 | (and (fboundp sym) |
| 304 | (symbol-function sym)) | 350 | (not (memq (car-safe (symbol-function sym)) |
| 305 | '(macro keymap autoload)))))))))) | 351 | '(autoload macro)))))))))) |
| 306 | 352 | ||
| 307 | (defun elp-restore-list (&optional list) | 353 | (defun elp-restore-list (&optional list) |
| 308 | "Restore the original definitions for all functions in `elp-function-list'. | 354 | "Restore the original definitions for all functions in `elp-function-list'. |
| @@ -359,12 +405,10 @@ Use optional LIST if provided instead." | |||
| 359 | elp-record-p t)) | 405 | elp-record-p t)) |
| 360 | 406 | ||
| 361 | 407 | ||
| 362 | (defsubst elp-get-time () | 408 | (defsubst elp-elapsed-time (start end) |
| 363 | ;; get current time in seconds and microseconds. I throw away the | 409 | (+ (* (- (car end) (car start)) 65536.0) |
| 364 | ;; most significant 16 bits of seconds since I doubt we'll ever want | 410 | (- (car (cdr end)) (car (cdr start))) |
| 365 | ;; to profile lisp on the order of 18 hours. See notes at top of file. | 411 | (/ (- (car (cdr (cdr end))) (car (cdr (cdr start)))) 1000000.0))) |
| 366 | (let ((now (current-time))) | ||
| 367 | (+ (float (nth 1 now)) (/ (float (nth 2 now)) 1000000.0)))) | ||
| 368 | 412 | ||
| 369 | (defun elp-wrapper (funsym interactive-p args) | 413 | (defun elp-wrapper (funsym interactive-p args) |
| 370 | "This function has been instrumented for profiling by the ELP. | 414 | "This function has been instrumented for profiling by the ELP. |
| @@ -388,18 +432,21 @@ original definition, use \\[elp-restore-function] or \\[elp-restore-all]." | |||
| 388 | (call-interactively func) | 432 | (call-interactively func) |
| 389 | (apply func args))) | 433 | (apply func args))) |
| 390 | ;; we are recording times | 434 | ;; we are recording times |
| 391 | (let ((enter-time (elp-get-time))) | 435 | (let (enter-time exit-time) |
| 392 | ;; increment the call-counter | 436 | ;; increment the call-counter |
| 393 | (aset info 0 (1+ (aref info 0))) | 437 | (aset info 0 (1+ (aref info 0))) |
| 394 | ;; now call the old symbol function, checking to see if it | 438 | ;; now call the old symbol function, checking to see if it |
| 395 | ;; should be called interactively. make sure we return the | 439 | ;; should be called interactively. make sure we return the |
| 396 | ;; correct value | 440 | ;; correct value |
| 397 | (setq result | 441 | (if interactive-p |
| 398 | (if interactive-p | 442 | (setq enter-time (current-time) |
| 399 | (call-interactively func) | 443 | result (call-interactively func) |
| 400 | (apply func args))) | 444 | exit-time (current-time)) |
| 445 | (setq enter-time (current-time) | ||
| 446 | result (apply func args) | ||
| 447 | exit-time (current-time))) | ||
| 401 | ;; calculate total time in function | 448 | ;; calculate total time in function |
| 402 | (aset info 1 (+ (aref info 1) (- (elp-get-time) enter-time))) | 449 | (aset info 1 (+ (aref info 1) (elp-elapsed-time enter-time exit-time))) |
| 403 | )) | 450 | )) |
| 404 | ;; turn off recording if this is the master function | 451 | ;; turn off recording if this is the master function |
| 405 | (if (and elp-master | 452 | (if (and elp-master |
| @@ -480,7 +527,9 @@ information for all instrumented functions are reset after results are | |||
| 480 | displayed." | 527 | displayed." |
| 481 | (interactive) | 528 | (interactive) |
| 482 | (let ((curbuf (current-buffer)) | 529 | (let ((curbuf (current-buffer)) |
| 483 | (resultsbuf (get-buffer-create elp-results-buffer))) | 530 | (resultsbuf (if elp-recycle-buffers-p |
| 531 | (get-buffer-create elp-results-buffer) | ||
| 532 | (generate-new-buffer elp-results-buffer)))) | ||
| 484 | (set-buffer resultsbuf) | 533 | (set-buffer resultsbuf) |
| 485 | (erase-buffer) | 534 | (erase-buffer) |
| 486 | (beginning-of-buffer) | 535 | (beginning-of-buffer) |
| @@ -536,6 +585,9 @@ displayed." | |||
| 536 | ;; now pop up results buffer | 585 | ;; now pop up results buffer |
| 537 | (set-buffer curbuf) | 586 | (set-buffer curbuf) |
| 538 | (pop-to-buffer resultsbuf) | 587 | (pop-to-buffer resultsbuf) |
| 588 | ;; copy results to standard-output? | ||
| 589 | (if (or elp-use-standard-output noninteractive) | ||
| 590 | (princ (buffer-substring (point-min) (point-max)))) | ||
| 539 | ;; reset profiling info if desired | 591 | ;; reset profiling info if desired |
| 540 | (and elp-reset-after-results | 592 | (and elp-reset-after-results |
| 541 | (elp-reset-all)))) | 593 | (elp-reset-all)))) |