;;; elp.el --- Emacs Lisp Profiler
-;; Copyright (C) 1994 Barry A. Warsaw
-;; Copyright (C) 1994 Free Software Foundation, Inc.
+;; Copyright (C) 1994,1995,1997,1998, 2001 Free Software Foundation, Inc.
-;; Author: 1994 Barry A. Warsaw <bwarsaw@cnri.reston.va.us>
-;; Maintainer: tools-help@anthem.nlm.nih.gov
-;; Created: 26-Feb-1994
-;; Version: 2.22
-;; Last Modified: 1994/12/23 17:46:21
-;; Keywords: Emacs Lisp Profile Timing
+;; Author: Barry A. Warsaw
+;; Maintainer: FSF
+;; Created: 26-Feb-1994
+;; Keywords: debugging lisp tools
;; This file is part of GNU Emacs.
;; GNU General Public License for more details.
;; You should have received a copy of the GNU General Public License
-;; along with GNU Emacs; see the file COPYING. If not, write to
-;; the Free Software Foundation, 675 Mass Ave, Cambridge, MA 02139, USA.
+;; along with GNU Emacs; see the file COPYING. If not, write to the
+;; Free Software Foundation, Inc., 59 Temple Place - Suite 330,
+;; Boston, MA 02111-1307, USA.
;;; Commentary:
;;
-;; This program is based on the only two existing Emacs Lisp profilers
-;; that I'm aware of, Boaz Ben-Zvi's profile.el, and Root Boy Jim's
-;; profiler.el. Both were written for Emacs 18 and both were pretty
-;; good first shots at profiling, but I found that they didn't provide
-;; the functionality or interface that I wanted. So I wrote this.
-;; I've tested elp in both Emacs 19's. There's no point in even
-;; trying to make this work with Emacs 18.
-
-;; Unlike previous profilers, elp uses Emacs 19's built-in function
-;; current-time to return interval times. This obviates the need for
-;; both an external C program and Emacs processes to communicate with
-;; such a program, and thus simplifies the package as a whole. One
-;; small shortcut: I throw away the most significant 16 bits of
-;; seconds returned by current-time since I doubt anyone will ever
-;; want to profile stuff on the order of 18 hours. 2^16 == 65536
-;; seconds == ~1092 minutes == ~18 hours.
-
-;; Note that there are plenty of factors that could make the times
-;; reported unreliable, including the accuracy and granularity of your
-;; system clock, and the overhead spent in lisp calculating and
-;; recording the intervals. The latter I figure is pretty constant
-;; so, while the times may not be entirely accurate, I think they'll
-;; give you a good feel for the relative amount of work spent in the
-;; various lisp routines you are profiling. Note further that times
-;; are calculated using wall-clock time, so other system load will
-;; affect accuracy too.
-
-;; Here is a list of variable you can use to customize elp:
-;; elp-function-list
-;; elp-reset-after-results
-;; elp-sort-by-function
-;; elp-report-limit
-;;
-;; Here is a list of the interactive commands you can use:
-;; elp-instrument-function
-;; elp-restore-function
-;; elp-instrument-list
-;; elp-restore-list
-;; elp-instrument-package
-;; elp-restore-all
-;; elp-reset-function
-;; elp-reset-list
-;; elp-reset-all
-;; elp-set-master
-;; elp-unset-master
-;; elp-results
-;; elp-submit-bug-report
-;;
-;; Here are some brief usage notes. If you want to profile a bunch of
-;; functions, set elp-function-list to the list of symbols, then call
-;; elp-instrument-list. This hacks the functions so that profiling
-;; information is recorded whenever they are called. To print out the
-;; current results, use elp-results. With elp-reset-after-results set
-;; to non-nil, profiling information will be reset whenever the
-;; results are displayed. You can also reset all profiling info at
-;; any time with elp-reset-all.
+;; If you want to profile a bunch of functions, set elp-function-list
+;; to the list of symbols, then do a M-x elp-instrument-list. This
+;; hacks those functions so that profiling information is recorded
+;; whenever they are called. To print out the current results, use
+;; M-x elp-results. If you want output to go to standard-output
+;; instead of a separate buffer, setq elp-use-standard-output to
+;; non-nil. With elp-reset-after-results set to non-nil, profiling
+;; information will be reset whenever the results are displayed. You
+;; can also reset all profiling info at any time with M-x
+;; elp-reset-all.
;;
;; You can also instrument all functions in a package, provided that
-;; the package follows the GNU coding standard of a common textural
-;; prefix. Use the elp-instrument-package command for this.
+;; the package follows the GNU coding standard of a common textual
+;; prefix. Use M-x elp-instrument-package for this.
;;
;; If you want to sort the results, set elp-sort-by-function to some
;; predicate function. The three most obvious choices are predefined:
;; elp-sort-by-call-count, elp-sort-by-average-time, and
-;; elp-sort-by-total-time. Also, you can prune from the output
-;; display, all functions that have been called fewer than a given
-;; number of times by setting elp-report-limit to that number.
+;; elp-sort-by-total-time. Also, you can prune from the output, all
+;; functions that have been called fewer than a given number of times
+;; by setting elp-report-limit.
;;
;; Elp can instrument byte-compiled functions just as easily as
;; interpreted functions, but it cannot instrument macros. However,
;; when you redefine a function (e.g. with eval-defun), you'll need to
-;; re-instrument it with elp-instrument-function. Re-instrumenting
-;; resets profiling information for that function. Elp can also
-;; handle interactive functions (i.e. commands), but of course any
-;; time spent idling for user prompts will show up in the timing
-;; results.
+;; re-instrument it with M-x elp-instrument-function. This will also
+;; reset profiling information for that function. Elp can handle
+;; interactive functions (i.e. commands), but of course any time spent
+;; idling for user prompts will show up in the timing results.
;;
;; You can also designate a `master' function. Profiling times will
;; be gathered for instrumented functions only during execution of
;;
;; and you want to find out the amount of time spent in bar and foo,
;; but only during execution of bar, make bar the master. The call of
-;; foo from baz will not add to foo's total timing sums. Use
-;; elp-set-master and elp-unset-master to utilize this feature. Only
-;; one master function can be used at a time.
+;; foo from baz will not add to foo's total timing sums. Use M-x
+;; elp-set-master and M-x elp-unset-master to utilize this feature.
+;; Only one master function can be set at a time.
;; You can restore any function's original function definition with
;; elp-restore-function. The other instrument, restore, and reset
;; functions are provided for symmetry.
-;; LCD Archive Entry:
-;; elp|Barry A. Warsaw|tools-help@anthem.nlm.nih.gov|
-;; Emacs Lisp Profiler|
-;; 1994/12/23 17:46:21|2.22|~/misc/elp.el.Z|
+;; Here is a list of variable you can use to customize elp:
+;; elp-function-list
+;; elp-reset-after-results
+;; elp-sort-by-function
+;; elp-report-limit
+;;
+;; Here is a list of the interactive commands you can use:
+;; elp-instrument-function
+;; elp-restore-function
+;; elp-instrument-list
+;; elp-restore-list
+;; elp-instrument-package
+;; elp-restore-all
+;; elp-reset-function
+;; elp-reset-list
+;; elp-reset-all
+;; elp-set-master
+;; elp-unset-master
+;; elp-results
+
+;; Note that there are plenty of factors that could make the times
+;; reported unreliable, including the accuracy and granularity of your
+;; system clock, and the overhead spent in lisp calculating and
+;; recording the intervals. I figure the latter is pretty constant,
+;; so while the times may not be entirely accurate, I think they'll
+;; give you a good feel for the relative amount of work spent in the
+;; various lisp routines you are profiling. Note further that times
+;; are calculated using wall-clock time, so other system load will
+;; affect accuracy too.
+
+;;; Background:
+
+;; This program was inspired by the only two existing Emacs Lisp
+;; profilers that I'm aware of, Boaz Ben-Zvi's profile.el, and Root
+;; Boy Jim's profiler.el. Both were written for Emacs 18 and both were
+;; pretty good first shots at profiling, but I found that they didn't
+;; provide the functionality or interface that I wanted, so I wrote
+;; this. I've tested elp in XEmacs 19 and Emacs 19. There's no point
+;; in even trying to make this work with Emacs 18.
+
+;; Unlike previous profilers, elp uses Emacs 19's built-in function
+;; current-time to return interval times. This obviates the need for
+;; both an external C program and Emacs processes to communicate with
+;; such a program, and thus simplifies the package as a whole.
+
+;; TBD:
+;; Make this act like a real profiler, so that it records time spent
+;; in all branches of execution.
;;; Code:
\f
-;; start user configuration variables
+;; start of user configuration variables
;; vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
-(defvar elp-function-list nil
- "*List of function to profile.")
+(defgroup elp nil
+ "Emacs Lisp Profiler"
+ :group 'lisp)
+
+(defcustom elp-function-list nil
+ "*List of functions to profile.
+Used by the command `elp-instrument-list'."
+ :type '(repeat function)
+ :group 'elp)
-(defvar elp-reset-after-results t
+(defcustom elp-reset-after-results t
"*Non-nil means reset all profiling info after results are displayed.
-Results are displayed with the `elp-results' command.")
+Results are displayed with the `elp-results' command."
+ :type 'boolean
+ :group 'elp)
-(defvar elp-sort-by-function nil
+(defcustom elp-sort-by-function 'elp-sort-by-total-time
"*Non-nil specifies elp results sorting function.
These functions are currently available:
\"element of LIST\" is really a 4 element vector where element 0 is
the call count, element 1 is the total time spent in the function,
element 2 is the average time spent in the function, and element 3 is
-the symbol's name string.")
+the symbol's name string."
+ :type 'function
+ :group 'elp)
-(defvar elp-report-limit nil
+(defcustom elp-report-limit 1
"*Prevents some functions from being displayed in the results buffer.
If a number, no function that has been called fewer than that number
of times will be displayed in the output buffer. If nil, all
-functions will be displayed.")
+functions will be displayed."
+ :type '(choice integer
+ (const :tag "Show All" nil))
+ :group 'elp)
+(defcustom elp-use-standard-output nil
+ "*Non-nil says to output to `standard-output' instead of a buffer."
+ :type 'boolean
+ :group 'elp)
-;; ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
-;; end user configuration variables
+(defcustom elp-recycle-buffers-p t
+ "*nil says to not recycle the `elp-results-buffer'.
+In other words, a new unique buffer is create every time you run
+\\[elp-results]."
+ :type 'boolean
+ :group 'elp)
-\f
-(defconst elp-version "2.22"
- "ELP version number.")
-(defconst elp-help-address "tools-help@anthem.nlm.nih.gov"
- "Address accepting submissions of bug reports and questions.")
+;; ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
+;; end of user configuration variables
+\f
(defvar elp-results-buffer "*ELP Profiling Results*"
"Buffer name for outputting profiling results.")
(defvar elp-master nil
"Master function symbol.")
+(defvar elp-not-profilable
+ '(elp-wrapper elp-elapsed-time error call-interactively apply current-time interactive-p)
+ "List of functions that cannot be profiled.
+Those functions are used internally by the profiling code and profiling
+them would thus lead to infinite recursion.")
+
+(defun elp-not-profilable-p (fun)
+ (or (memq fun elp-not-profilable)
+ (keymapp fun)
+ (condition-case nil
+ (when (subrp (symbol-function fun))
+ (eq 'unevalled (cdr (subr-arity (symbol-function fun)))))
+ (error nil))))
+
\f
;;;###autoload
(defun elp-instrument-function (funsym)
"Instrument FUNSYM for profiling.
FUNSYM must be a symbol of a defined function."
(interactive "aFunction to instrument: ")
- ;; TBD what should we do if the function is already instrumented???
+ ;; restore the function. this is necessary to avoid infinite
+ ;; recursion of already instrumented functions (i.e. elp-wrapper
+ ;; calling elp-wrapper ad infinitum). it is better to simply
+ ;; restore the function than to throw an error. this will work
+ ;; properly in the face of eval-defun because if the function was
+ ;; redefined, only the timer info will be nil'd out since
+ ;; elp-restore-function is smart enough not to trash the new
+ ;; definition.
+ (elp-restore-function funsym)
(let* ((funguts (symbol-function funsym))
(infovec (vector 0 0 funguts))
(newguts '(lambda (&rest args))))
+ ;; We cannot profile functions used internally during profiling.
+ (when (elp-not-profilable-p funsym)
+ (error "ELP cannot profile the function: %s" funsym))
;; we cannot profile macros
(and (eq (car-safe funguts) 'macro)
- (error "ELP cannot profile macro %s" funsym))
+ (error "ELP cannot profile macro: %s" funsym))
+ ;; TBD: at some point it might be better to load the autoloaded
+ ;; function instead of throwing an error. if we do this, then we
+ ;; probably want elp-instrument-package to be updated with the
+ ;; newly loaded list of functions. i'm not sure it's smart to do
+ ;; the autoload here, since that could have side effects, and
+ ;; elp-instrument-function is similar (in my mind) to defun-ish
+ ;; type functionality (i.e. it shouldn't execute the function).
+ (and (eq (car-safe funguts) 'autoload)
+ (error "ELP cannot profile autoloaded function: %s" funsym))
;; put rest of newguts together
(if (commandp funsym)
(setq newguts (append newguts '((interactive)))))
- (setq newguts (append newguts (list
- (list 'elp-wrapper
- (list 'quote funsym)
- (list 'and
- '(interactive-p)
- (not (not (commandp funsym))))
- 'args))))
+ (setq newguts (append newguts `((elp-wrapper
+ (quote ,funsym)
+ ,(when (commandp funsym)
+ '(interactive-p))
+ args))))
;; to record profiling times, we set the symbol's function
;; definition so that it runs the elp-wrapper function with the
;; function symbol as an argument. We place the old function
;; put the info vector on the property list
(put funsym elp-timer-info-property infovec)
- ;; set the symbol's new profiling function definition to run
- ;; elp-wrapper
- (fset funsym newguts)
+ ;; Set the symbol's new profiling function definition to run
+ ;; elp-wrapper.
+ (let ((advice-info (get funsym 'ad-advice-info)))
+ (if advice-info
+ (progn
+ ;; If function is advised, don't let Advice change
+ ;; its definition from under us during the `fset'.
+ (put funsym 'ad-advice-info nil)
+ (fset funsym newguts)
+ (put funsym 'ad-advice-info advice-info))
+ (fset funsym newguts)))
;; add this function to the instrumentation list
- (or (memq funsym elp-all-instrumented-list)
- (setq elp-all-instrumented-list
- (cons funsym elp-all-instrumented-list)))
- ))
+ (unless (memq funsym elp-all-instrumented-list)
+ (push funsym elp-all-instrumented-list))))
-;;;###autoload
(defun elp-restore-function (funsym)
"Restore an instrumented function to its original definition.
Argument FUNSYM is the symbol of a defined function."
;; because its possible the function got un-instrumented due to
;; circumstances beyond our control. Also, check to make sure
;; that the current function symbol points to elp-wrapper. If
- ;; not, then the user probably did an eval-defun while the
- ;; function was instrumented and we don't want to destroy the new
- ;; definition.
+ ;; not, then the user probably did an eval-defun, or loaded a
+ ;; byte-compiled version, while the function was instrumented and
+ ;; we don't want to destroy the new definition. can it ever be
+ ;; the case that a lisp function can be compiled instrumented?
(and info
+ (functionp funsym)
+ (not (byte-code-function-p (symbol-function funsym)))
(assq 'elp-wrapper (symbol-function funsym))
(fset funsym (aref info 2)))))
\\[elp-instrument-package] RET elp- RET"
(interactive "sPrefix of package to instrument: ")
+ (if (zerop (length prefix))
+ (error "Instrumenting all Emacs functions would render Emacs unusable"))
(elp-instrument-list
- (mapcar 'intern (all-completions prefix obarray
- (function
- (lambda (sym)
- (and (fboundp sym)
- (not (eq (car-safe
- (symbol-function sym))
- 'macro)))))))))
+ (mapcar
+ 'intern
+ (all-completions
+ prefix obarray
+ (lambda (sym)
+ (and (fboundp sym)
+ (not (or (memq (car-safe (symbol-function sym)) '(autoload macro))
+ (elp-not-profilable-p sym)))))))))
(defun elp-restore-list (&optional list)
"Restore the original definitions for all functions in `elp-function-list'.
(interactive "aFunction to reset: ")
(let ((info (get funsym elp-timer-info-property)))
(or info
- (error "%s is not instrumented for profiling." funsym))
+ (error "%s is not instrumented for profiling" funsym))
(aset info 0 0) ;reset call counter
(aset info 1 0.0) ;reset total time
;; don't muck with aref 2 as that is the old symbol definition
elp-record-p t))
\f
-(defsubst elp-get-time ()
- ;; get current time in seconds and microseconds. I throw away the
- ;; most significant 16 bits of seconds since I doubt we'll ever want
- ;; to profile lisp on the order of 18 hours. See notes at top of file.
- (let ((now (current-time)))
- (+ (float (nth 1 now)) (/ (float (nth 2 now)) 1000000.0))))
+(defsubst elp-elapsed-time (start end)
+ (+ (* (- (car end) (car start)) 65536.0)
+ (- (car (cdr end)) (car (cdr start)))
+ (/ (- (car (cdr (cdr end))) (car (cdr (cdr start)))) 1000000.0)))
(defun elp-wrapper (funsym interactive-p args)
"This function has been instrumented for profiling by the ELP.
(func (aref info 2))
result)
(or func
- (error "%s is not instrumented for profiling." funsym))
+ (error "%s is not instrumented for profiling" funsym))
(if (not elp-record-p)
;; when not recording, just call the original function symbol
;; and return the results.
(call-interactively func)
(apply func args)))
;; we are recording times
- (let ((enter-time (elp-get-time)))
+ (let (enter-time exit-time)
;; increment the call-counter
(aset info 0 (1+ (aref info 0)))
;; now call the old symbol function, checking to see if it
;; should be called interactively. make sure we return the
;; correct value
- (setq result
- (if interactive-p
- (call-interactively func)
- (apply func args)))
+ (if interactive-p
+ (setq enter-time (current-time)
+ result (call-interactively func)
+ exit-time (current-time))
+ (setq enter-time (current-time)
+ result (apply func args)
+ exit-time (current-time)))
;; calculate total time in function
- (aset info 1 (+ (aref info 1) (- (elp-get-time) enter-time)))
+ (aset info 1 (+ (aref info 1) (elp-elapsed-time enter-time exit-time)))
))
;; turn off recording if this is the master function
(if (and elp-master
displayed."
(interactive)
(let ((curbuf (current-buffer))
- (resultsbuf (get-buffer-create elp-results-buffer)))
+ (resultsbuf (if elp-recycle-buffers-p
+ (get-buffer-create elp-results-buffer)
+ (generate-new-buffer elp-results-buffer))))
(set-buffer resultsbuf)
(erase-buffer)
(beginning-of-buffer)
;; now pop up results buffer
(set-buffer curbuf)
(pop-to-buffer resultsbuf)
+ ;; copy results to standard-output?
+ (if (or elp-use-standard-output noninteractive)
+ (princ (buffer-substring (point-min) (point-max))))
;; reset profiling info if desired
(and elp-reset-after-results
(elp-reset-all))))
-\f
-(eval-when-compile
- (require 'reporter))
-
-;;;###autoload
-(defun elp-submit-bug-report ()
- "Submit via mail, a bug report on elp."
- (interactive)
- (and
- (y-or-n-p "Do you want to submit a report on elp? ")
- (require 'reporter)
- (reporter-submit-bug-report
- elp-help-address (concat "elp " elp-version)
- '(elp-report-limit
- elp-reset-after-results
- elp-sort-by-function))))
-
+(defun elp-unload-hook ()
+ (elp-restore-all))
\f
(provide 'elp)
-;; elp.el ends here
+
+;;; elp.el ends here