e8357221d354dc71c13b063af8b1bb479a9ee2b1
[sbcl.git] / src / code / ntrace.lisp
1 ;;;; a tracing facility based on breakpoints
2
3 ;;;; This software is part of the SBCL system. See the README file for
4 ;;;; more information.
5 ;;;;
6 ;;;; This software is derived from the CMU CL system, which was
7 ;;;; written at Carnegie Mellon University and released into the
8 ;;;; public domain. The software is in the public domain and is
9 ;;;; provided with absolutely no warranty. See the COPYING and CREDITS
10 ;;;; files for more information.
11
12 (in-package "SB-DEBUG") ; (SB-, not SB!, since we're built in warm load.)
13
14 ;;; FIXME: Why, oh why, doesn't the SB-DEBUG package use the SB-DI
15 ;;; package? That would let us get rid of a whole lot of stupid
16 ;;; prefixes..
17
18 (defvar *trace-values* nil
19   #+sb-doc
20   "This is bound to the returned values when evaluating :BREAK-AFTER and
21    :PRINT-AFTER forms.")
22
23 (defvar *trace-indentation-step* 2
24   #+sb-doc
25   "the increase in trace indentation at each call level")
26
27 (defvar *max-trace-indentation* 40
28   #+sb-doc
29   "If the trace indentation exceeds this value, then indentation restarts at
30    0.")
31
32 (defvar *trace-encapsulate-default* :default
33   #+sb-doc
34   "the default value for the :ENCAPSULATE option to TRACE")
35 \f
36 ;;;; internal state
37
38 ;;; a hash table that maps each traced function to the TRACE-INFO. The
39 ;;; entry for a closure is the shared function-entry object.
40 (defvar *traced-functions* (make-hash-table :test 'eq))
41
42 ;;; A TRACE-INFO object represents all the information we need to
43 ;;; trace a given function.
44 (def!struct (trace-info
45              (:make-load-form-fun sb-kernel:just-dump-it-normally)
46              (:print-object (lambda (x stream)
47                               (print-unreadable-object (x stream :type t)
48                                 (prin1 (trace-info-what x) stream)))))
49   ;; the original representation of the thing traced
50   (what nil :type (or function cons symbol))
51   ;; Is WHAT a function name whose definition we should track?
52   (named nil)
53   ;; Is tracing to be done by encapsulation rather than breakpoints?
54   ;; T implies NAMED.
55   (encapsulated *trace-encapsulate-default*)
56   ;; Has this trace been untraced?
57   (untraced nil)
58   ;; breakpoints we set up to trigger tracing
59   (start-breakpoint nil :type (or sb-di:breakpoint null))
60   (end-breakpoint nil :type (or sb-di:breakpoint null))
61   ;; the list of function names for WHEREIN, or NIL if unspecified
62   (wherein nil :type list)
63
64   ;; The following slots represent the forms that we are supposed to
65   ;; evaluate on each iteration. Each form is represented by a cons
66   ;; (Form . Function), where the Function is the cached result of
67   ;; coercing Form to a function. Forms which use the current
68   ;; environment are converted with PREPROCESS-FOR-EVAL, which gives
69   ;; us a one-arg function. Null environment forms also have one-arg
70   ;; functions, but the argument is ignored. NIL means unspecified
71   ;; (the default.)
72
73   ;; current environment forms
74   (condition nil)
75   (break nil)
76   ;; List of current environment forms
77   (print () :type list)
78   ;; null environment forms
79   (condition-after nil)
80   (break-after nil)
81   ;; list of null environment forms
82   (print-after () :type list))
83
84 ;;; This is a list of conses (fun-end-cookie . condition-satisfied),
85 ;;; which we use to note distinct dynamic entries into functions. When
86 ;;; we enter a traced function, we add a entry to this list holding
87 ;;; the new end-cookie and whether the trace condition was satisfied.
88 ;;; We must save the trace condition so that the after breakpoint
89 ;;; knows whether to print. The length of this list tells us the
90 ;;; indentation to use for printing TRACE messages.
91 ;;;
92 ;;; This list also helps us synchronize the TRACE facility dynamically
93 ;;; for detecting non-local flow of control. Whenever execution hits a
94 ;;; :FUN-END breakpoint used for TRACE'ing, we look for the
95 ;;; FUN-END-COOKIE at the top of *TRACED-ENTRIES*. If it is not
96 ;;; there, we discard any entries that come before our cookie.
97 ;;;
98 ;;; When we trace using encapsulation, we bind this variable and add
99 ;;; (NIL . CONDITION-SATISFIED), so a NIL "cookie" marks an
100 ;;; encapsulated tracing.
101 (defvar *traced-entries* ())
102 (declaim (list *traced-entries*))
103
104 ;;; This variable is used to discourage infinite recursions when some
105 ;;; trace action invokes a function that is itself traced. In this
106 ;;; case, we quietly ignore the inner tracing.
107 (defvar *in-trace* nil)
108 \f
109 ;;;; utilities
110
111 ;;; Given a function name, a function or a macro name, return the raw
112 ;;; definition and some information. "Raw" means that if the result is
113 ;;; a closure, we strip off the closure and return the bare code. The
114 ;;; second value is T if the argument was a function name. The third
115 ;;; value is one of :COMPILED, :COMPILED-CLOSURE, :INTERPRETED,
116 ;;; :INTERPRETED-CLOSURE and :FUNCALLABLE-INSTANCE.
117 (defun trace-fdefinition (x)
118   (multiple-value-bind (res named-p)
119       (typecase x
120         (symbol
121          (cond ((special-operator-p x)
122                 (error "can't trace special form ~S" x))
123                ((macro-function x))
124                (t
125                 (values (fdefinition x) t))))
126         (function x)
127         (t (values (fdefinition x) t)))
128     (case (sb-kernel:get-type res)
129       (#.sb-vm:closure-header-widetag
130        (values (sb-kernel:%closure-fun res)
131                named-p
132                :compiled-closure))
133       (#.sb-vm:funcallable-instance-header-widetag
134        (values res named-p :funcallable-instance))
135       (t (values res named-p :compiled)))))
136
137 ;;; When a function name is redefined, and we were tracing that name,
138 ;;; then untrace the old definition and trace the new one.
139 (defun trace-redefined-update (fname new-value)
140   (when (fboundp fname)
141     (let* ((fun (trace-fdefinition fname))
142            (info (gethash fun *traced-functions*)))
143       (when (and info (trace-info-named info))
144         (untrace-1 fname)
145         (trace-1 fname info new-value)))))
146 (push #'trace-redefined-update *setf-fdefinition-hook*)
147
148 ;;; Annotate some forms to evaluate with pre-converted functions. Each
149 ;;; form is really a cons (exp . function). Loc is the code location
150 ;;; to use for the lexical environment. If Loc is NIL, evaluate in the
151 ;;; null environment. If Form is NIL, just return NIL.
152 (defun coerce-form (form loc)
153   (when form
154     (let ((exp (car form)))
155       (if (sb-di:code-location-p loc)
156           (let ((fun (sb-di:preprocess-for-eval exp loc)))
157             (cons exp
158                   #'(lambda (frame)
159                       (let ((*current-frame* frame))
160                         (funcall fun frame)))))
161           (let* ((bod (ecase loc
162                         ((nil) exp)
163                         (:encapsulated
164                          `(flet ((sb-debug:arg (n)
165                                    (declare (special argument-list))
166                                    (elt argument-list n)))
167                             (declare (ignorable #'sb-debug:arg))
168                             ,exp))))
169                  (fun (coerce `(lambda () ,bod) 'function)))
170             (cons exp
171                   #'(lambda (frame)
172                       (declare (ignore frame))
173                       (let ((*current-frame* nil))
174                         (funcall fun)))))))))
175 (defun coerce-form-list (forms loc)
176   (mapcar #'(lambda (x) (coerce-form x loc)) forms))
177
178 ;;; Print indentation according to the number of trace entries.
179 ;;; Entries whose condition was false don't count.
180 (defun print-trace-indentation ()
181   (let ((depth 0))
182     (dolist (entry *traced-entries*)
183       (when (cdr entry) (incf depth)))
184     (format t
185             "~@V,0T~D: "
186             (+ (mod (* depth *trace-indentation-step*)
187                     (- *max-trace-indentation* *trace-indentation-step*))
188                *trace-indentation-step*)
189             depth)))
190
191 ;;; Return true if one of the Names appears on the stack below Frame.
192 (defun trace-wherein-p (frame names)
193   (do ((frame (sb-di:frame-down frame) (sb-di:frame-down frame)))
194       ((not frame) nil)
195     (when (member (sb-di:debug-fun-name (sb-di:frame-debug-fun frame))
196                   names
197                   :test #'equal)
198       (return t))))
199
200 ;;; Handle print and print-after options.
201 (defun trace-print (frame forms)
202   (dolist (ele forms)
203     (fresh-line)
204     (print-trace-indentation)
205     (format t "~S = ~S" (car ele) (funcall (cdr ele) frame))))
206
207 ;;; Test a break option, and break if true.
208 (defun trace-maybe-break (info break where frame)
209   (when (and break (funcall (cdr break) frame))
210     (sb-di:flush-frames-above frame)
211     (let ((*stack-top-hint* frame))
212       (break "breaking ~A traced call to ~S:"
213              where
214              (trace-info-what info)))))
215
216 ;;; This function discards any invalid cookies on our simulated stack.
217 ;;; Encapsulated entries are always valid, since we bind
218 ;;; *TRACED-ENTRIES* in the encapsulation.
219 (defun discard-invalid-entries (frame)
220   (loop
221     (when (or (null *traced-entries*)
222               (let ((cookie (caar *traced-entries*)))
223                 (or (not cookie)
224                     (sb-di:fun-end-cookie-valid-p frame cookie))))
225       (return))
226     (pop *traced-entries*)))
227 \f
228 ;;;; hook functions
229
230 ;;; Return a closure that can be used for a function start breakpoint
231 ;;; hook function and a closure that can be used as the
232 ;;; FUN-END-COOKIE function. The first communicates the sense of
233 ;;; the Condition to the second via a closure variable.
234 (defun trace-start-breakpoint-fun (info)
235   (let (conditionp)
236     (values
237      #'(lambda (frame bpt)
238          (declare (ignore bpt))
239          (discard-invalid-entries frame)
240          (let ((condition (trace-info-condition info))
241                (wherein (trace-info-wherein info)))
242            (setq conditionp
243                  (and (not *in-trace*)
244                       (or (not condition)
245                           (funcall (cdr condition) frame))
246                       (or (not wherein)
247                           (trace-wherein-p frame wherein)))))
248
249          (when conditionp
250            (let ((sb-kernel:*current-level* 0)
251                  (*standard-output* *trace-output*)
252                  (*in-trace* t))
253              (fresh-line)
254              (print-trace-indentation)
255              (if (trace-info-encapsulated info)
256                  (locally (declare (special basic-definition argument-list))
257                    (prin1 `(,(trace-info-what info) ,@argument-list)))
258                  (print-frame-call frame))
259              (terpri)
260              (trace-print frame (trace-info-print info)))
261            (trace-maybe-break info (trace-info-break info) "before" frame)))
262
263      #'(lambda (frame cookie)
264          (declare (ignore frame))
265          (push (cons cookie conditionp) *traced-entries*)))))
266
267 ;;; This prints a representation of the return values delivered.
268 ;;; First, this checks to see that cookie is at the top of
269 ;;; *TRACED-ENTRIES*; if it is not, then we need to adjust this list
270 ;;; to determine the correct indentation for output. We then check to
271 ;;; see whether the function is still traced and that the condition
272 ;;; succeeded before printing anything.
273 (defun trace-end-breakpoint-fun (info)
274   #'(lambda (frame bpt *trace-values* cookie)
275       (declare (ignore bpt))
276       (unless (eq cookie (caar *traced-entries*))
277         (setf *traced-entries*
278               (member cookie *traced-entries* :key #'car)))
279
280       (let ((entry (pop *traced-entries*)))
281         (when (and (not (trace-info-untraced info))
282                    (or (cdr entry)
283                        (let ((cond (trace-info-condition-after info)))
284                          (and cond (funcall (cdr cond) frame)))))
285           (let ((sb-kernel:*current-level* 0)
286                 (*standard-output* *trace-output*)
287                 (*in-trace* t))
288             (fresh-line)
289             (pprint-logical-block (*standard-output* nil)
290               (print-trace-indentation)
291               (pprint-indent :current 2)
292               (format t "~S returned" (trace-info-what info))
293               (dolist (v *trace-values*)
294                 (write-char #\space)
295                 (pprint-newline :linear)
296                 (prin1 v)))
297             (terpri)
298             (trace-print frame (trace-info-print-after info)))
299           (trace-maybe-break info
300                              (trace-info-break-after info)
301                              "after"
302                              frame)))))
303 \f
304 ;;; This function is called by the trace encapsulation. It calls the
305 ;;; breakpoint hook functions with NIL for the breakpoint and cookie, which
306 ;;; we have cleverly contrived to work for our hook functions.
307 (defun trace-call (info)
308   (multiple-value-bind (start cookie) (trace-start-breakpoint-fun info)
309     (let ((frame (sb-di:frame-down (sb-di:top-frame))))
310       (funcall start frame nil)
311       (let ((*traced-entries* *traced-entries*))
312         (declare (special basic-definition argument-list))
313         (funcall cookie frame nil)
314         (let ((vals
315                (multiple-value-list
316                 (apply basic-definition argument-list))))
317           (funcall (trace-end-breakpoint-fun info) frame nil vals nil)
318           (values-list vals))))))
319 \f
320 ;;; Trace one function according to the specified options. We copy the
321 ;;; trace info (it was a quoted constant), fill in the functions, and
322 ;;; then install the breakpoints or encapsulation.
323 ;;;
324 ;;; If non-null, DEFINITION is the new definition of a function that
325 ;;; we are automatically retracing.
326 (defun trace-1 (function-or-name info &optional definition)
327   (multiple-value-bind (fun named kind)
328       (if definition
329           (values definition t
330                   (nth-value 2 (trace-fdefinition definition)))
331           (trace-fdefinition function-or-name))
332     (when (gethash fun *traced-functions*)
333       (warn "~S is already TRACE'd, untracing it." function-or-name)
334       (untrace-1 fun))
335
336     (let* ((debug-fun (sb-di:fun-debug-fun fun))
337            (encapsulated
338             (if (eq (trace-info-encapsulated info) :default)
339                 (ecase kind
340                   (:compiled nil)
341                   (:compiled-closure
342                    (unless (functionp function-or-name)
343                      (warn "tracing shared code for ~S:~%  ~S"
344                            function-or-name
345                            fun))
346                    nil)
347                   ((:interpreted :interpreted-closure :funcallable-instance)
348                    t))
349                 (trace-info-encapsulated info)))
350            (loc (if encapsulated
351                     :encapsulated
352                     (sb-di:debug-fun-start-location debug-fun)))
353            (info (make-trace-info
354                   :what function-or-name
355                   :named named
356                   :encapsulated encapsulated
357                   :wherein (trace-info-wherein info)
358                   :condition (coerce-form (trace-info-condition info) loc)
359                   :break (coerce-form (trace-info-break info) loc)
360                   :print (coerce-form-list (trace-info-print info) loc)
361                   :break-after (coerce-form (trace-info-break-after info) nil)
362                   :condition-after
363                   (coerce-form (trace-info-condition-after info) nil)
364                   :print-after
365                   (coerce-form-list (trace-info-print-after info) nil))))
366
367       (dolist (wherein (trace-info-wherein info))
368         (unless (or (stringp wherein)
369                     (fboundp wherein))
370           (warn ":WHEREIN name ~S is not a defined global function."
371                 wherein)))
372
373       (cond
374        (encapsulated
375         (unless named
376           (error "can't use encapsulation to trace anonymous function ~S"
377                  fun))
378         (encapsulate function-or-name 'trace `(trace-call ',info)))
379        (t
380         (multiple-value-bind (start-fun cookie-fun)
381             (trace-start-breakpoint-fun info)
382           (let ((start (sb-di:make-breakpoint start-fun debug-fun
383                                               :kind :fun-start))
384                 (end (sb-di:make-breakpoint
385                       (trace-end-breakpoint-fun info)
386                       debug-fun :kind :fun-end
387                       :fun-end-cookie cookie-fun)))
388             (setf (trace-info-start-breakpoint info) start)
389             (setf (trace-info-end-breakpoint info) end)
390             ;; The next two forms must be in the order in which they
391             ;; appear, since the start breakpoint must run before the
392             ;; fun-end breakpoint's start helper (which calls the
393             ;; cookie function.) One reason is that cookie function
394             ;; requires that the CONDITIONP shared closure variable be
395             ;; initialized.
396             (sb-di:activate-breakpoint start)
397             (sb-di:activate-breakpoint end)))))
398
399       (setf (gethash fun *traced-functions*) info)))
400
401   function-or-name)
402 \f
403 ;;;; the TRACE macro
404
405 ;;; Parse leading trace options off of SPECS, modifying INFO
406 ;;; accordingly. The remaining portion of the list is returned when we
407 ;;; encounter a plausible function name.
408 (defun parse-trace-options (specs info)
409   (let ((current specs))
410     (loop
411       (when (endp current) (return))
412       (let ((option (first current))
413             (value (cons (second current) nil)))
414         (case option
415           (:report (error "stub: The :REPORT option is not yet implemented."))
416           (:condition (setf (trace-info-condition info) value))
417           (:condition-after
418            (setf (trace-info-condition info) (cons nil nil))
419            (setf (trace-info-condition-after info) value))
420           (:condition-all
421            (setf (trace-info-condition info) value)
422            (setf (trace-info-condition-after info) value))
423           (:wherein
424            (setf (trace-info-wherein info)
425                  (if (listp (car value)) (car value) value)))
426           (:encapsulate
427            (setf (trace-info-encapsulated info) (car value)))
428           (:break (setf (trace-info-break info) value))
429           (:break-after (setf (trace-info-break-after info) value))
430           (:break-all
431            (setf (trace-info-break info) value)
432            (setf (trace-info-break-after info) value))
433           (:print
434            (setf (trace-info-print info)
435                  (append (trace-info-print info) (list value))))
436           (:print-after
437            (setf (trace-info-print-after info)
438                  (append (trace-info-print-after info) (list value))))
439           (:print-all
440            (setf (trace-info-print info)
441                  (append (trace-info-print info) (list value)))
442            (setf (trace-info-print-after info)
443                  (append (trace-info-print-after info) (list value))))
444           (t (return)))
445         (pop current)
446         (unless current
447           (error "missing argument to ~S TRACE option" option))
448         (pop current)))
449     current))
450
451 ;;; Compute the expansion of TRACE in the non-trivial case (arguments
452 ;;; specified.) If there are no :FUNCTION specs, then don't use a LET.
453 ;;; This allows TRACE to be used without the full interpreter.
454 (defun expand-trace (specs)
455   (collect ((binds)
456             (forms))
457     (let* ((global-options (make-trace-info))
458            (current (parse-trace-options specs global-options)))
459       (loop
460         (when (endp current) (return))
461         (let ((name (pop current))
462               (options (copy-trace-info global-options)))
463           (cond
464            ((eq name :function)
465             (let ((temp (gensym)))
466               (binds `(,temp ,(pop current)))
467               (forms `(trace-1 ,temp ',options))))
468            ((and (keywordp name)
469                  (not (or (fboundp name) (macro-function name))))
470             (error "unknown TRACE option: ~S" name))
471            (t
472             (forms `(trace-1 ',name ',options))))
473           (setq current (parse-trace-options current options)))))
474
475     (if (binds)
476         `(let ,(binds) (list ,@(forms)))
477         `(list ,@(forms)))))
478
479 (defun %list-traced-functions ()
480   (loop for x being each hash-value in *traced-functions*
481         collect (trace-info-what x)))
482
483 (defmacro trace (&rest specs)
484   #+sb-doc
485   "TRACE {Option Global-Value}* {Name {Option Value}*}*
486    TRACE is a debugging tool that provides information when specified functions
487    are called. In its simplest form:
488        (trace Name-1 Name-2 ...)
489    (The Names are not evaluated.)
490
491    Options allow modification of the default behavior. Each option is a pair
492    of an option keyword and a value form. Global options are specified before
493    the first name, and affect all functions traced by a given use of TRACE.
494    Options may also be interspersed with function names, in which case they
495    act as local options, only affecting tracing of the immediately preceding
496    function name. Local options override global options.
497
498    By default, TRACE causes a printout on *TRACE-OUTPUT* each time that
499    one of the named functions is entered or returns. (This is the
500    basic, ANSI Common Lisp behavior of TRACE.) As an SBCL extension, the
501    :REPORT SB-EXT:PROFILE option can be used to instead cause information
502    to be silently recorded to be inspected later using the SB-EXT:PROFILE
503    function.
504
505    The following options are defined:
506
507    :REPORT Report-Type
508        If Report-Type is TRACE (the default) then information is reported
509        by printing immediately. If Report-Type is SB-EXT:PROFILE, information
510        is recorded for later summary by calls to SB-EXT:PROFILE. If
511        Report-Type is NIL, then the only effect of the trace is to execute
512        other options (e.g. PRINT or BREAK).
513
514    :CONDITION Form
515    :CONDITION-AFTER Form
516    :CONDITION-ALL Form
517        If :CONDITION is specified, then TRACE does nothing unless Form
518        evaluates to true at the time of the call. :CONDITION-AFTER is
519        similar, but suppresses the initial printout, and is tested when the
520        function returns. :CONDITION-ALL tries both before and after.
521
522    :BREAK Form
523    :BREAK-AFTER Form
524    :BREAK-ALL Form
525        If specified, and Form evaluates to true, then the debugger is invoked
526        at the start of the function, at the end of the function, or both,
527        according to the respective option. 
528
529    :PRINT Form
530    :PRINT-AFTER Form
531    :PRINT-ALL Form
532        In addition to the usual printout, the result of evaluating Form is
533        printed at the start of the function, at the end of the function, or
534        both, according to the respective option. Multiple print options cause
535        multiple values to be printed.
536
537    :WHEREIN Names
538        If specified, Names is a function name or list of names. TRACE does
539        nothing unless a call to one of those functions encloses the call to
540        this function (i.e. it would appear in a backtrace.)  Anonymous
541        functions have string names like \"DEFUN FOO\". 
542
543    :ENCAPSULATE {:DEFAULT | T | NIL}
544        If T, the tracing is done via encapsulation (redefining the function
545        name) rather than by modifying the function. :DEFAULT is the default,
546        and means to use encapsulation for interpreted functions and funcallable
547        instances, breakpoints otherwise. When encapsulation is used, forms are
548        *not* evaluated in the function's lexical environment, but SB-DEBUG:ARG
549        can still be used.
550
551    :FUNCTION Function-Form
552        This is a not really an option, but rather another way of specifying
553        what function to trace. The Function-Form is evaluated immediately,
554        and the resulting function is traced.
555
556    :CONDITION, :BREAK and :PRINT forms are evaluated in the lexical environment
557    of the called function; SB-DEBUG:VAR and SB-DEBUG:ARG can be used. The
558    -AFTER and -ALL forms are evaluated in the null environment."
559   (if specs
560       (expand-trace specs)
561       '(%list-traced-functions)))
562 \f
563 ;;;; untracing
564
565 ;;; Untrace one function.
566 (defun untrace-1 (function-or-name)
567   (let* ((fun (trace-fdefinition function-or-name))
568          (info (gethash fun *traced-functions*)))
569     (cond
570      ((not info)
571       (warn "Function is not TRACEd: ~S" function-or-name))
572      (t
573       (cond
574        ((trace-info-encapsulated info)
575         (unencapsulate (trace-info-what info) 'trace))
576        (t
577         (sb-di:delete-breakpoint (trace-info-start-breakpoint info))
578         (sb-di:delete-breakpoint (trace-info-end-breakpoint info))))
579       (setf (trace-info-untraced info) t)
580       (remhash fun *traced-functions*)))))
581
582 ;;; Untrace all traced functions.
583 (defun untrace-all ()
584   (dolist (fun (%list-traced-functions))
585     (untrace-1 fun))
586   t)
587
588 (defmacro untrace (&rest specs)
589   #+sb-doc
590   "Remove tracing from the specified functions. With no args, untrace all
591    functions."
592   (if specs
593       (collect ((res))
594         (let ((current specs))
595           (loop
596             (unless current (return))
597             (let ((name (pop current)))
598               (res (if (eq name :function)
599                        `(untrace-1 ,(pop current))
600                        `(untrace-1 ',name)))))
601           `(progn ,@(res) t)))
602       '(untrace-all)))