aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorStefan Monnier2012-09-24 10:38:10 -0400
committerStefan Monnier2012-09-24 10:38:10 -0400
commit3d80c99f3817bf5eccd6acc6a79498a4fde979a4 (patch)
tree5377692a9d9b96157a42b8ae693a8f7d18a8bc85
parent0970d85fef9830e3b8e5cbfbdc04dbf00cc4c027 (diff)
downloademacs-3d80c99f3817bf5eccd6acc6a79498a4fde979a4.tar.gz
emacs-3d80c99f3817bf5eccd6acc6a79498a4fde979a4.zip
Rewrite sampler to use Elisp hash-tables.
* src/profiler.c: Remove filtering functionality. (is_in_trace, Qgc): Remove vars. (make_log, record_backtrace, Fsample_profiler_log): Rewrite, using Elisp hash-tables. (approximate_median, evict_lower_half): New functions. (cpu_log): Rename from sample_log. (cpu_gc_count): New var. (Fsample_profiler_reset, Fmemory_profiler_reset): Remove. (sigprof_handler): Add count to cpu_gc_count during GC, detected via backtrace_list. (block_sigprof, unblock_sigprof): Remove. (gc_probe, mark_profiler): Remove functions. (syms_of_profiler): Staticpro cpu_log and memory_log. * lisp/profiler.el (profiler-sample-interval): Move before first use. Change default to 1ms. (profiler-entry=, profiler-backtrace-reverse, profiler-log-fixup-slot) (profiler-calltree-elapsed<, profiler-calltree-elapsed>): Remove functions. (profiler-entry-format): Don't use type-of. (profiler-slot, profiler-log): Remove structs. (profiler-log-timestamp, profiler-log-type, profiler-log-diff-p): Redefine for new log representation. (profiler-log-diff, profiler-log-fixup, profiler-calltree-build-1): Rewrite for new log representation. (profiler-calltree): Remove `elapsed' fields. (profiler-calltree-count<, profiler-report-make-entry-part): Remove gc special case. (profiler-calltree-find): Use equal. (profiler-calltree-walk): Remove `args'; rely on closures instead. (profiler-calltree-compute-percentages-1): Remove; inlined. (profiler-calltree-compute-percentages): Simplify. (profiler-report-log, profiler-report-reversed) (profiler-report-order): Use defvar-local. (profiler-report-line-format): Remove `elapsed', do a bit of CSE. (profiler-report-mode-map): Remove up/down bindings. (profiler-report-make-buffer-name): Simplify by CSE. (profiler-report-mode): Remove redundant code. (profiler-report-expand-entry, profiler-report-collapse-entry): Use inhibit-read-only. (profiler-report-render-calltree-1): Simplify by CSE. (profiler-reset): Rewrite for new subroutines. (profiler--report-cpu): Rename from sample-profiler-report. (profiler--report-memory): Rename from memory-profiler-report. * src/alloc.c (Fgarbage_collect): Record itself in backtrace_list. Don't set is_in_trace any more. Don't call mark_profiler. Only call gc_probe for the memory profiler. (syms_of_alloc): Define Qautomatic_gc. * src/lisp.h (SXHASH_COMBINE): Move back to... * src/fns.c (SXHASH_COMBINE): ...here. * src/xdisp.c (Qautomatic_redisplay): New constant. (redisplay_internal): Record itself in backtrace_list. (syms_of_xdisp): Define Qautomatic_redisplay. * .dir-locals.el (indent-tabs-mode): Remove personal preference.
-rw-r--r--.dir-locals.el1
-rw-r--r--ChangeLog4
-rw-r--r--lisp/ChangeLog48
-rw-r--r--lisp/profiler.el366
-rw-r--r--src/ChangeLog28
-rw-r--r--src/alloc.c26
-rw-r--r--src/fns.c7
-rw-r--r--src/lisp.h11
-rw-r--r--src/profiler.c1030
-rw-r--r--src/xdisp.c18
10 files changed, 422 insertions, 1117 deletions
diff --git a/.dir-locals.el b/.dir-locals.el
index b92f848d3eb..5bee88267c8 100644
--- a/.dir-locals.el
+++ b/.dir-locals.el
@@ -1,5 +1,4 @@
1((nil . ((tab-width . 8) 1((nil . ((tab-width . 8)
2 (indent-tabs-mode . t)
3 (sentence-end-double-space . t) 2 (sentence-end-double-space . t)
4 (fill-column . 70))) 3 (fill-column . 70)))
5 (c-mode . ((c-file-style . "GNU"))) 4 (c-mode . ((c-file-style . "GNU")))
diff --git a/ChangeLog b/ChangeLog
index 4f339482a98..f4426fa36da 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,7 @@
12012-09-24 Stefan Monnier <monnier@iro.umontreal.ca>
2
3 * .dir-locals.el (indent-tabs-mode): Remove personal preference.
4
12012-08-21 Paul Eggert <eggert@cs.ucla.edu> 52012-08-21 Paul Eggert <eggert@cs.ucla.edu>
2 6
3 Merge from gnulib, incorporating: 7 Merge from gnulib, incorporating:
diff --git a/lisp/ChangeLog b/lisp/ChangeLog
index d8134f2c046..64fb7e2ffc7 100644
--- a/lisp/ChangeLog
+++ b/lisp/ChangeLog
@@ -1,3 +1,35 @@
12012-09-24 Stefan Monnier <monnier@iro.umontreal.ca>
2
3 * profiler.el (profiler-sample-interval): Move before first use.
4 Change default to 1ms.
5 (profiler-entry=, profiler-backtrace-reverse, profiler-log-fixup-slot)
6 (profiler-calltree-elapsed<, profiler-calltree-elapsed>): Remove functions.
7 (profiler-entry-format): Don't use type-of.
8 (profiler-slot, profiler-log): Remove structs.
9 (profiler-log-timestamp, profiler-log-type, profiler-log-diff-p):
10 Redefine for new log representation.
11 (profiler-log-diff, profiler-log-fixup, profiler-calltree-build-1):
12 Rewrite for new log representation.
13 (profiler-calltree): Remove `elapsed' fields.
14 (profiler-calltree-count<, profiler-report-make-entry-part):
15 Remove gc special case.
16 (profiler-calltree-find): Use equal.
17 (profiler-calltree-walk): Remove `args'; rely on closures instead.
18 (profiler-calltree-compute-percentages-1): Remove; inlined.
19 (profiler-calltree-compute-percentages): Simplify.
20 (profiler-report-log, profiler-report-reversed)
21 (profiler-report-order): Use defvar-local.
22 (profiler-report-line-format): Remove `elapsed', do a bit of CSE.
23 (profiler-report-mode-map): Remove up/down bindings.
24 (profiler-report-make-buffer-name): Simplify by CSE.
25 (profiler-report-mode): Remove redundant code.
26 (profiler-report-expand-entry, profiler-report-collapse-entry):
27 Use inhibit-read-only.
28 (profiler-report-render-calltree-1): Simplify by CSE.
29 (profiler-reset): Rewrite for new subroutines.
30 (profiler--report-cpu): Rename from sample-profiler-report.
31 (profiler--report-memory): Rename from memory-profiler-report.
32
12012-08-22 Tomohiro Matsuyama <tomo@cx4a.org> 332012-08-22 Tomohiro Matsuyama <tomo@cx4a.org>
2 34
3 * profiler.el: Switch to cl-lib. 35 * profiler.el: Switch to cl-lib.
@@ -35,8 +67,8 @@
35 * window.el (window-point-1, set-window-point-1): Remove. 67 * window.el (window-point-1, set-window-point-1): Remove.
36 (window-in-direction, record-window-buffer) 68 (window-in-direction, record-window-buffer)
37 (set-window-buffer-start-and-point, split-window-below) 69 (set-window-buffer-start-and-point, split-window-below)
38 (window--state-get-1, display-buffer-record-window): Replace 70 (window--state-get-1, display-buffer-record-window):
39 calls to window-point-1 and set-window-point-1 by calls to 71 Replace calls to window-point-1 and set-window-point-1 by calls to
40 window-point and set-window-point respectively. 72 window-point and set-window-point respectively.
41 73
422012-08-21 Glenn Morris <rgm@gnu.org> 742012-08-21 Glenn Morris <rgm@gnu.org>
@@ -154,8 +186,8 @@
154 (yank-excluded-properties): Add font-lock-face and category. 186 (yank-excluded-properties): Add font-lock-face and category.
155 (yank): Doc fix. 187 (yank): Doc fix.
156 188
157 * subr.el (remove-yank-excluded-properties): Obey 189 * subr.el (remove-yank-excluded-properties):
158 yank-handled-properties. The special handling of font-lock-face 190 Obey yank-handled-properties. The special handling of font-lock-face
159 and category is now done this way, instead of being hard-coded. 191 and category is now done this way, instead of being hard-coded.
160 (insert-for-yank-1): Remove font-lock-face handling. 192 (insert-for-yank-1): Remove font-lock-face handling.
161 (yank-handle-font-lock-face-property) 193 (yank-handle-font-lock-face-property)
@@ -169,8 +201,8 @@
169 201
1702012-08-17 Michael Albinus <michael.albinus@gmx.de> 2022012-08-17 Michael Albinus <michael.albinus@gmx.de>
171 203
172 * net/tramp-sh.el (tramp-sh-handle-start-file-process): Eliminate 204 * net/tramp-sh.el (tramp-sh-handle-start-file-process):
173 superfluous prompt. (Bug#12203) 205 Eliminate superfluous prompt. (Bug#12203)
174 206
1752012-08-17 Chong Yidong <cyd@gnu.org> 2072012-08-17 Chong Yidong <cyd@gnu.org>
176 208
@@ -197,8 +229,8 @@
197 (next-buffer, previous-buffer, split-window, balance-windows-2) 229 (next-buffer, previous-buffer, split-window, balance-windows-2)
198 (set-window-text-height, window-buffer-height) 230 (set-window-text-height, window-buffer-height)
199 (fit-window-to-buffer, shrink-window-if-larger-than-buffer) 231 (fit-window-to-buffer, shrink-window-if-larger-than-buffer)
200 (truncated-partial-width-window-p): Minor code adjustments. In 232 (truncated-partial-width-window-p): Minor code adjustments.
201 doc-strings state whether the argument window has to denote a 233 In doc-strings state whether the argument window has to denote a
202 live, valid or any window. 234 live, valid or any window.
203 235
2042012-08-16 Phil Sainty <psainty@orcon.net.nz> (tiny change) 2362012-08-16 Phil Sainty <psainty@orcon.net.nz> (tiny change)
diff --git a/lisp/profiler.el b/lisp/profiler.el
index 1777fc00bde..00ee99a6132 100644
--- a/lisp/profiler.el
+++ b/lisp/profiler.el
@@ -32,7 +32,11 @@
32 :group 'lisp 32 :group 'lisp
33 :prefix "profiler-") 33 :prefix "profiler-")
34 34
35 35(defcustom profiler-sample-interval 1
36 "Default sample interval in millisecond."
37 :type 'integer
38 :group 'profiler)
39
36;;; Utilities 40;;; Utilities
37 41
38(defun profiler-ensure-string (object) 42(defun profiler-ensure-string (object)
@@ -90,55 +94,34 @@
90 94
91;;; Entries 95;;; Entries
92 96
93(defun profiler-entry= (entry1 entry2)
94 "Return t if ENTRY1 and ENTRY2 are same."
95 (or (eq entry1 entry2)
96 (and (stringp entry1)
97 (stringp entry2)
98 (string= entry1 entry2))))
99
100(defun profiler-entry-format (entry) 97(defun profiler-entry-format (entry)
101 "Format ENTRY in human readable string. ENTRY would be a 98 "Format ENTRY in human readable string. ENTRY would be a
102function name of a function itself." 99function name of a function itself."
103 (cond ((and (consp entry) 100 (cond ((memq (car-safe entry) '(closure lambda))
104 (or (eq (car entry) 'lambda) 101 (format "#<lambda 0x%x>" (sxhash entry)))
105 (eq (car entry) 'closure))) 102 ((byte-code-function-p entry)
106 (format "#<closure 0x%x>" (sxhash entry)))
107 ((eq (type-of entry) 'compiled-function)
108 (format "#<compiled 0x%x>" (sxhash entry))) 103 (format "#<compiled 0x%x>" (sxhash entry)))
109 ((subrp entry) 104 ((or (subrp entry) (symbolp entry) (stringp entry))
110 (subr-name entry)) 105 (format "%s" entry))
111 ((symbolp entry)
112 (symbol-name entry))
113 ((stringp entry)
114 entry)
115 (t 106 (t
116 (format "#<unknown 0x%x>" (sxhash entry))))) 107 (format "#<unknown 0x%x>" (sxhash entry)))))
117 108
118
119;;; Backtrace data structure
120
121(defun profiler-backtrace-reverse (backtrace)
122 (cl-case (car backtrace)
123 ((t gc)
124 ;; Make sure Others node and GC node always be at top.
125 (cons (car backtrace)
126 (reverse (cdr backtrace))))
127 (t (reverse backtrace))))
128
129
130;;; Slot data structure
131
132(cl-defstruct (profiler-slot (:type list)
133 (:constructor profiler-make-slot))
134 backtrace count elapsed)
135
136
137;;; Log data structure 109;;; Log data structure
138 110
139(cl-defstruct (profiler-log (:type list) 111;; The C code returns the log in the form of a hash-table where the keys are
140 (:constructor profiler-make-log)) 112;; vectors (of size profiler-max-stack-depth, holding truncated
141 type diff-p timestamp slots) 113;; backtraces, where the first element is the top of the stack) and
114;; the values are integers (which count how many times this backtrace
115;; has been seen, multiplied by a "weight factor" which is either the
116;; sample-interval or the memory being allocated).
117;; We extend it by adding a few other entries to the hash-table, most notably:
118;; - Key `type' has a value indicating the kind of log (`memory' or `cpu').
119;; - Key `timestamp' has a value giving the time when the log was obtained.
120;; - Key `diff-p' indicates if this log represents a diff between two logs.
121
122(defun profiler-log-timestamp (log) (gethash 'timestamp log))
123(defun profiler-log-type (log) (gethash 'type log))
124(defun profiler-log-diff-p (log) (gethash 'diff-p log))
142 125
143(defun profiler-log-diff (log1 log2) 126(defun profiler-log-diff (log1 log2)
144 "Compare LOG1 with LOG2 and return a diff log. Both logs must 127 "Compare LOG1 with LOG2 and return a diff log. Both logs must
@@ -146,16 +129,17 @@ be same type."
146 (unless (eq (profiler-log-type log1) 129 (unless (eq (profiler-log-type log1)
147 (profiler-log-type log2)) 130 (profiler-log-type log2))
148 (error "Can't compare different type of logs")) 131 (error "Can't compare different type of logs"))
149 (let ((slots (profiler-log-slots log2))) 132 (let ((newlog (make-hash-table :test 'equal)))
150 (dolist (slot (profiler-log-slots log1)) 133 ;; Make a copy of `log1' into `newlog'.
151 (push (profiler-make-slot :backtrace (profiler-slot-backtrace slot) 134 (maphash (lambda (backtrace count) (puthash backtrace count newlog))
152 :count (- (profiler-slot-count slot)) 135 log1)
153 :elapsed (- (profiler-slot-elapsed slot))) 136 (puthash 'diff-p t newlog)
154 slots)) 137 (maphash (lambda (backtrace count)
155 (profiler-make-log :type (profiler-log-type log1) 138 (when (vectorp backtrace)
156 :diff-p t 139 (puthash backtrace (- (gethash backtrace log1 0) count)
157 :timestamp (current-time) 140 newlog)))
158 :slots slots))) 141 log2)
142 newlog))
159 143
160(defun profiler-log-fixup-entry (entry) 144(defun profiler-log-fixup-entry (entry)
161 (if (symbolp entry) 145 (if (symbolp entry)
@@ -165,21 +149,16 @@ be same type."
165(defun profiler-log-fixup-backtrace (backtrace) 149(defun profiler-log-fixup-backtrace (backtrace)
166 (mapcar 'profiler-log-fixup-entry backtrace)) 150 (mapcar 'profiler-log-fixup-entry backtrace))
167 151
168(defun profiler-log-fixup-slot (slot)
169 (let ((backtrace (profiler-slot-backtrace slot)))
170 (profiler-make-slot :backtrace (profiler-log-fixup-backtrace backtrace)
171 :count (profiler-slot-count slot)
172 :elapsed (profiler-slot-elapsed slot))))
173
174(defun profiler-log-fixup (log) 152(defun profiler-log-fixup (log)
175 "Fixup LOG so that the log could be serialized into file." 153 "Fixup LOG so that the log could be serialized into file."
176 (cl-loop for slot in (profiler-log-slots log) 154 (let ((newlog (make-hash-table :test 'equal)))
177 collect (profiler-log-fixup-slot slot) into slots 155 (maphash (lambda (backtrace count)
178 finally return 156 (puthash (if (not (vectorp backtrace))
179 (profiler-make-log :type (profiler-log-type log) 157 backtrace
180 :diff-p (profiler-log-diff-p log) 158 (profiler-log-fixup-backtrace backtrace))
181 :timestamp (profiler-log-timestamp log) 159 count newlog))
182 :slots slots))) 160 log)
161 newlog))
183 162
184(defun profiler-log-write-file (log filename &optional confirm) 163(defun profiler-log-write-file (log filename &optional confirm)
185 "Write LOG into FILENAME." 164 "Write LOG into FILENAME."
@@ -201,7 +180,6 @@ be same type."
201(cl-defstruct (profiler-calltree (:constructor profiler-make-calltree)) 180(cl-defstruct (profiler-calltree (:constructor profiler-make-calltree))
202 entry 181 entry
203 (count 0) (count-percent "") 182 (count 0) (count-percent "")
204 (elapsed 0) (elapsed-percent "")
205 parent children) 183 parent children)
206 184
207(defun profiler-calltree-leaf-p (tree) 185(defun profiler-calltree-leaf-p (tree)
@@ -210,25 +188,12 @@ be same type."
210(defun profiler-calltree-count< (a b) 188(defun profiler-calltree-count< (a b)
211 (cond ((eq (profiler-calltree-entry a) t) t) 189 (cond ((eq (profiler-calltree-entry a) t) t)
212 ((eq (profiler-calltree-entry b) t) nil) 190 ((eq (profiler-calltree-entry b) t) nil)
213 ((eq (profiler-calltree-entry a) 'gc) t)
214 ((eq (profiler-calltree-entry b) 'gc) nil)
215 (t (< (profiler-calltree-count a) 191 (t (< (profiler-calltree-count a)
216 (profiler-calltree-count b))))) 192 (profiler-calltree-count b)))))
217 193
218(defun profiler-calltree-count> (a b) 194(defun profiler-calltree-count> (a b)
219 (not (profiler-calltree-count< a b))) 195 (not (profiler-calltree-count< a b)))
220 196
221(defun profiler-calltree-elapsed< (a b)
222 (cond ((eq (profiler-calltree-entry a) t) t)
223 ((eq (profiler-calltree-entry b) t) nil)
224 ((eq (profiler-calltree-entry a) 'gc) t)
225 ((eq (profiler-calltree-entry b) 'gc) nil)
226 (t (< (profiler-calltree-elapsed a)
227 (profiler-calltree-elapsed b)))))
228
229(defun profiler-calltree-elapsed> (a b)
230 (not (profiler-calltree-elapsed< a b)))
231
232(defun profiler-calltree-depth (tree) 197(defun profiler-calltree-depth (tree)
233 (let ((parent (profiler-calltree-parent tree))) 198 (let ((parent (profiler-calltree-parent tree)))
234 (if (null parent) 199 (if (null parent)
@@ -239,58 +204,47 @@ be same type."
239 "Return a child tree of ENTRY under TREE." 204 "Return a child tree of ENTRY under TREE."
240 ;; OPTIMIZED 205 ;; OPTIMIZED
241 (let (result (children (profiler-calltree-children tree))) 206 (let (result (children (profiler-calltree-children tree)))
207 ;; FIXME: Use `assoc'.
242 (while (and children (null result)) 208 (while (and children (null result))
243 (let ((child (car children))) 209 (let ((child (car children)))
244 (when (profiler-entry= (profiler-calltree-entry child) entry) 210 (when (equal (profiler-calltree-entry child) entry)
245 (setq result child)) 211 (setq result child))
246 (setq children (cdr children)))) 212 (setq children (cdr children))))
247 result)) 213 result))
248 214
249(defun profiler-calltree-walk (calltree function &rest args) 215(defun profiler-calltree-walk (calltree function)
250 (apply function calltree args) 216 (funcall function calltree)
251 (dolist (child (profiler-calltree-children calltree)) 217 (dolist (child (profiler-calltree-children calltree))
252 (apply 'profiler-calltree-walk child function args))) 218 (profiler-calltree-walk child function)))
253 219
254(defun profiler-calltree-build-1 (tree log &optional reverse) 220(defun profiler-calltree-build-1 (tree log &optional reverse)
255 (dolist (slot (profiler-log-slots log)) 221 (maphash
256 (let ((backtrace (profiler-slot-backtrace slot)) 222 (lambda (backtrace count)
257 (count (profiler-slot-count slot)) 223 (when (vectorp backtrace)
258 (elapsed (profiler-slot-elapsed slot)) 224 (let ((node tree)
259 (node tree)) 225 (max (length backtrace)))
260 (dolist (entry (if reverse 226 (dotimes (i max)
261 backtrace 227 (let ((entry (aref backtrace (if reverse i (- max i 1)))))
262 (profiler-backtrace-reverse backtrace))) 228 (when entry
263 (let ((child (profiler-calltree-find node entry))) 229 (let ((child (profiler-calltree-find node entry)))
264 (unless child 230 (unless child
265 (setq child (profiler-make-calltree :entry entry :parent node)) 231 (setq child (profiler-make-calltree
266 (push child (profiler-calltree-children node))) 232 :entry entry :parent node))
267 (cl-incf (profiler-calltree-count child) count) 233 (push child (profiler-calltree-children node)))
268 (cl-incf (profiler-calltree-elapsed child) elapsed) 234 (cl-incf (profiler-calltree-count child) count)
269 (setq node child)))))) 235 (setq node child))))))))
270 236 log))
271(defun profiler-calltree-compute-percentages-1 (node total-count total-elapsed)
272 (unless (zerop total-count)
273 (setf (profiler-calltree-count-percent node)
274 (profiler-format-percent (profiler-calltree-count node)
275 total-count)))
276 (unless (zerop total-elapsed)
277 (setf (profiler-calltree-elapsed-percent node)
278 (profiler-format-percent (profiler-calltree-elapsed node)
279 total-elapsed))))
280 237
281(defun profiler-calltree-compute-percentages (tree) 238(defun profiler-calltree-compute-percentages (tree)
282 (let ((total-count 0) 239 (let ((total-count 0))
283 (total-elapsed 0))
284 (dolist (child (profiler-calltree-children tree)) 240 (dolist (child (profiler-calltree-children tree))
285 (if (eq (profiler-calltree-entry child) 'gc) 241 (cl-incf total-count (profiler-calltree-count child)))
286 (profiler-calltree-compute-percentages child) 242 (unless (zerop total-count)
287 (cl-incf total-count (profiler-calltree-count child)) 243 (profiler-calltree-walk
288 (cl-incf total-elapsed (profiler-calltree-elapsed child)))) 244 tree (lambda (node)
289 (dolist (child (profiler-calltree-children tree)) 245 (setf (profiler-calltree-count-percent node)
290 (unless (eq (profiler-calltree-entry child) 'gc) 246 (profiler-format-percent (profiler-calltree-count node)
291 (profiler-calltree-walk 247 total-count)))))))
292 child 'profiler-calltree-compute-percentages-1
293 total-count total-elapsed)))))
294 248
295(cl-defun profiler-calltree-build (log &key reverse) 249(cl-defun profiler-calltree-build (log &key reverse)
296 (let ((tree (profiler-make-calltree))) 250 (let ((tree (profiler-make-calltree)))
@@ -332,14 +286,14 @@ be same type."
332 (19 right ((14 right profiler-format-nbytes) 286 (19 right ((14 right profiler-format-nbytes)
333 (5 right))))) 287 (5 right)))))
334 288
335(defvar profiler-report-log nil 289(defvar-local profiler-report-log nil
336 "The current profiler log.") 290 "The current profiler log.")
337 291
338(defvar profiler-report-reversed nil 292(defvar-local profiler-report-reversed nil
339 "True if calltree is rendered in bottom-up. Do not touch this 293 "True if calltree is rendered in bottom-up. Do not touch this
340variable directly.") 294variable directly.")
341 295
342(defvar profiler-report-order nil 296(defvar-local profiler-report-order nil
343 "The value can be `ascending' or `descending'. Do not touch 297 "The value can be `ascending' or `descending'. Do not touch
344this variable directly.") 298this variable directly.")
345 299
@@ -347,8 +301,6 @@ this variable directly.")
347 (let ((string (cond 301 (let ((string (cond
348 ((eq entry t) 302 ((eq entry t)
349 "Others") 303 "Others")
350 ((eq entry 'gc)
351 "Garbage Collection")
352 ((and (symbolp entry) 304 ((and (symbolp entry)
353 (fboundp entry)) 305 (fboundp entry))
354 (propertize (symbol-name entry) 306 (propertize (symbol-name entry)
@@ -357,7 +309,7 @@ this variable directly.")
357 'help-echo "mouse-2 or RET jumps to definition")) 309 'help-echo "mouse-2 or RET jumps to definition"))
358 (t 310 (t
359 (profiler-entry-format entry))))) 311 (profiler-entry-format entry)))))
360 (propertize string 'entry entry))) 312 (propertize string 'profiler-entry entry)))
361 313
362(defun profiler-report-make-name-part (tree) 314(defun profiler-report-make-name-part (tree)
363 (let* ((entry (profiler-calltree-entry tree)) 315 (let* ((entry (profiler-calltree-entry tree))
@@ -377,31 +329,18 @@ this variable directly.")
377(defun profiler-report-line-format (tree) 329(defun profiler-report-line-format (tree)
378 (let ((diff-p (profiler-log-diff-p profiler-report-log)) 330 (let ((diff-p (profiler-log-diff-p profiler-report-log))
379 (name-part (profiler-report-make-name-part tree)) 331 (name-part (profiler-report-make-name-part tree))
380 (elapsed (profiler-calltree-elapsed tree))
381 (elapsed-percent (profiler-calltree-elapsed-percent tree))
382 (count (profiler-calltree-count tree)) 332 (count (profiler-calltree-count tree))
383 (count-percent (profiler-calltree-count-percent tree))) 333 (count-percent (profiler-calltree-count-percent tree)))
384 (cl-ecase (profiler-log-type profiler-report-log) 334 (profiler-format (cl-ecase (profiler-log-type profiler-report-log)
385 (sample 335 (cpu profiler-report-sample-line-format)
386 (if diff-p 336 (memory profiler-report-memory-line-format))
387 (profiler-format profiler-report-sample-line-format 337 name-part
388 name-part 338 (if diff-p
389 (list (if (> elapsed 0) 339 (list (if (> count 0)
390 (format "+%s" elapsed) 340 (format "+%s" count)
391 elapsed) 341 count)
392 "")) 342 "")
393 (profiler-format profiler-report-sample-line-format 343 (list count count-percent)))))
394 name-part (list elapsed elapsed-percent))))
395 (memory
396 (if diff-p
397 (profiler-format profiler-report-memory-line-format
398 name-part
399 (list (if (> count 0)
400 (format "+%s" count)
401 count)
402 ""))
403 (profiler-format profiler-report-memory-line-format
404 name-part (list count count-percent)))))))
405 344
406(defun profiler-report-insert-calltree (tree) 345(defun profiler-report-insert-calltree (tree)
407 (let ((line (profiler-report-line-format tree))) 346 (let ((line (profiler-report-line-format tree)))
@@ -416,10 +355,13 @@ this variable directly.")
416 355
417(defvar profiler-report-mode-map 356(defvar profiler-report-mode-map
418 (let ((map (make-sparse-keymap))) 357 (let ((map (make-sparse-keymap)))
358 ;; FIXME: Add menu.
419 (define-key map "n" 'profiler-report-next-entry) 359 (define-key map "n" 'profiler-report-next-entry)
420 (define-key map "p" 'profiler-report-previous-entry) 360 (define-key map "p" 'profiler-report-previous-entry)
421 (define-key map [down] 'profiler-report-next-entry) 361 ;; I find it annoying more than helpful to not be able to navigate
422 (define-key map [up] 'profiler-report-previous-entry) 362 ;; normally with the cursor keys. --Stef
363 ;; (define-key map [down] 'profiler-report-next-entry)
364 ;; (define-key map [up] 'profiler-report-previous-entry)
423 (define-key map "\r" 'profiler-report-toggle-entry) 365 (define-key map "\r" 'profiler-report-toggle-entry)
424 (define-key map "\t" 'profiler-report-toggle-entry) 366 (define-key map "\t" 'profiler-report-toggle-entry)
425 (define-key map "i" 'profiler-report-toggle-entry) 367 (define-key map "i" 'profiler-report-toggle-entry)
@@ -437,10 +379,9 @@ this variable directly.")
437 map)) 379 map))
438 380
439(defun profiler-report-make-buffer-name (log) 381(defun profiler-report-make-buffer-name (log)
440 (let ((time (format-time-string "%Y-%m-%d %T" (profiler-log-timestamp log)))) 382 (format "*%s-Profiler-Report %s*"
441 (cl-ecase (profiler-log-type log) 383 (cl-ecase (profiler-log-type log) (cpu 'CPU) (memory 'Memory))
442 (sample (format "*CPU-Profiler-Report %s*" time)) 384 (format-time-string "%Y-%m-%d %T" (profiler-log-timestamp log))))
443 (memory (format "*Memory-Profiler-Report %s*" time)))))
444 385
445(defun profiler-report-setup-buffer (log) 386(defun profiler-report-setup-buffer (log)
446 "Make a buffer for LOG and return it." 387 "Make a buffer for LOG and return it."
@@ -455,10 +396,6 @@ this variable directly.")
455 396
456(define-derived-mode profiler-report-mode special-mode "Profiler-Report" 397(define-derived-mode profiler-report-mode special-mode "Profiler-Report"
457 "Profiler Report Mode." 398 "Profiler Report Mode."
458 (make-local-variable 'profiler-report-log)
459 (make-local-variable 'profiler-report-reversed)
460 (make-local-variable 'profiler-report-order)
461 (use-local-map profiler-report-mode-map)
462 (setq buffer-read-only t 399 (setq buffer-read-only t
463 buffer-undo-list t 400 buffer-undo-list t
464 truncate-lines t)) 401 truncate-lines t))
@@ -470,7 +407,8 @@ this variable directly.")
470 (get-text-property (point) 'calltree)) 407 (get-text-property (point) 'calltree))
471 408
472(defun profiler-report-move-to-entry () 409(defun profiler-report-move-to-entry ()
473 (let ((point (next-single-property-change (line-beginning-position) 'entry))) 410 (let ((point (next-single-property-change (line-beginning-position)
411 'profiler-entry)))
474 (if point 412 (if point
475 (goto-char point) 413 (goto-char point)
476 (back-to-indentation)))) 414 (back-to-indentation))))
@@ -496,7 +434,7 @@ this variable directly.")
496 (line-end-position) t) 434 (line-end-position) t)
497 (let ((tree (profiler-report-calltree-at-point))) 435 (let ((tree (profiler-report-calltree-at-point)))
498 (when tree 436 (when tree
499 (let ((buffer-read-only nil)) 437 (let ((inhibit-read-only t))
500 (replace-match (concat profiler-report-open-mark " ")) 438 (replace-match (concat profiler-report-open-mark " "))
501 (forward-line) 439 (forward-line)
502 (profiler-report-insert-calltree-children tree) 440 (profiler-report-insert-calltree-children tree)
@@ -514,7 +452,7 @@ this variable directly.")
514 (start (line-beginning-position 2)) 452 (start (line-beginning-position 2))
515 d) 453 d)
516 (when tree 454 (when tree
517 (let ((buffer-read-only nil)) 455 (let ((inhibit-read-only t))
518 (replace-match (concat profiler-report-closed-mark " ")) 456 (replace-match (concat profiler-report-closed-mark " "))
519 (while (and (eq (forward-line) 0) 457 (while (and (eq (forward-line) 0)
520 (let ((child (get-text-property (point) 'calltree))) 458 (let ((child (get-text-property (point) 'calltree)))
@@ -549,29 +487,25 @@ otherwise collapse."
549 (require 'help-fns) 487 (require 'help-fns)
550 (describe-function entry))))) 488 (describe-function entry)))))
551 489
552(cl-defun profiler-report-render-calltree-1 (log &key reverse (order 'descending)) 490(cl-defun profiler-report-render-calltree-1
491 (log &key reverse (order 'descending))
553 (let ((calltree (profiler-calltree-build profiler-report-log 492 (let ((calltree (profiler-calltree-build profiler-report-log
554 :reverse reverse))) 493 :reverse reverse)))
555 (cl-ecase (profiler-log-type log) 494 (setq header-line-format
556 (sample 495 (cl-ecase (profiler-log-type log)
557 (setq header-line-format 496 (cpu
558 (profiler-report-header-line-format 497 (profiler-report-header-line-format
559 profiler-report-sample-line-format 498 profiler-report-sample-line-format
560 "Function" (list "Time (ms)" "%"))) 499 "Function" (list "Time (ms)" "%")))
561 (let ((predicate (cl-ecase order 500 (memory
562 (ascending 'profiler-calltree-elapsed<)
563 (descending 'profiler-calltree-elapsed>))))
564 (profiler-calltree-sort calltree predicate)))
565 (memory
566 (setq header-line-format
567 (profiler-report-header-line-format 501 (profiler-report-header-line-format
568 profiler-report-memory-line-format 502 profiler-report-memory-line-format
569 "Function" (list "Bytes" "%"))) 503 "Function" (list "Bytes" "%")))))
570 (let ((predicate (cl-ecase order 504 (let ((predicate (cl-ecase order
571 (ascending 'profiler-calltree-count<) 505 (ascending #'profiler-calltree-count<)
572 (descending 'profiler-calltree-count>)))) 506 (descending #'profiler-calltree-count>))))
573 (profiler-calltree-sort calltree predicate)))) 507 (profiler-calltree-sort calltree predicate))
574 (let ((buffer-read-only nil)) 508 (let ((inhibit-read-only t))
575 (erase-buffer) 509 (erase-buffer)
576 (profiler-report-insert-calltree-children calltree) 510 (profiler-report-insert-calltree-children calltree)
577 (goto-char (point-min)) 511 (goto-char (point-min))
@@ -632,19 +566,15 @@ otherwise collapse."
632 566
633;;; Profiler commands 567;;; Profiler commands
634 568
635(defcustom profiler-sample-interval 10
636 "Default sample interval in millisecond."
637 :type 'integer
638 :group 'profiler)
639
640;;;###autoload 569;;;###autoload
641(defun profiler-start (mode) 570(defun profiler-start (mode)
642 "Start/restart profilers. MODE can be one of `cpu', `mem', 571 "Start/restart profilers.
643and `cpu+mem'. If MODE is `cpu' or `cpu+mem', sample profiler 572MODE can be one of `cpu', `mem', or `cpu+mem'.
644will be started. Also, if MODE is `mem' or `cpu+mem', then 573If MODE is `cpu' or `cpu+mem', time-based profiler will be started.
645memory profiler will be started." 574Also, if MODE is `mem' or `cpu+mem', then memory profiler will be started."
646 (interactive 575 (interactive
647 (list (intern (completing-read "Mode: " '("cpu" "mem" "cpu+mem") 576 (list (intern (completing-read "Mode (default cpu): "
577 '("cpu" "mem" "cpu+mem")
648 nil t nil nil "cpu")))) 578 nil t nil nil "cpu"))))
649 (cl-ecase mode 579 (cl-ecase mode
650 (cpu 580 (cpu
@@ -679,25 +609,29 @@ memory profiler will be started."
679(defun profiler-reset () 609(defun profiler-reset ()
680 "Reset profiler log." 610 "Reset profiler log."
681 (interactive) 611 (interactive)
682 (sample-profiler-reset) 612 (ignore (sample-profiler-log))
683 (memory-profiler-reset) 613 (ignore (memory-profiler-log))
684 t) 614 t)
685 615
686(defun sample-profiler-report () 616(defun profiler--report-cpu ()
687 (let ((sample-log (sample-profiler-log))) 617 (let ((log (sample-profiler-log)))
688 (when sample-log 618 (when log
689 (profiler-report-log sample-log)))) 619 (puthash 'type 'cpu log)
620 (puthash 'timestamp (current-time) log)
621 (profiler-report-log log))))
690 622
691(defun memory-profiler-report () 623(defun profiler--report-memory ()
692 (let ((memory-log (memory-profiler-log))) 624 (let ((log (memory-profiler-log)))
693 (when memory-log 625 (when log
694 (profiler-report-log memory-log)))) 626 (puthash 'type 'memory log)
627 (puthash 'timestamp (current-time) log)
628 (profiler-report-log log))))
695 629
696(defun profiler-report () 630(defun profiler-report ()
697 "Report profiling results." 631 "Report profiling results."
698 (interactive) 632 (interactive)
699 (sample-profiler-report) 633 (profiler--report-cpu)
700 (memory-profiler-report)) 634 (profiler--report-memory))
701 635
702;;;###autoload 636;;;###autoload
703(defun profiler-find-log (filename) 637(defun profiler-find-log (filename)
@@ -709,25 +643,23 @@ memory profiler will be started."
709 643
710;;; Profiling helpers 644;;; Profiling helpers
711 645
712(cl-defmacro with-sample-profiling ((&key (interval profiler-sample-interval)) &rest body) 646(cl-defmacro with-sample-profiling ((&key interval) &rest body)
713 `(progn 647 `(unwind-protect
714 (sample-profiler-start ,interval) 648 (progn
715 (sample-profiler-reset) 649 (ignore (sample-profiler-log))
716 (unwind-protect 650 (sample-profiler-start ,interval)
717 (progn ,@body) 651 ,@body)
718 (sample-profiler-stop) 652 (sample-profiler-stop)
719 (sample-profiler-report) 653 (profiler--report-cpu)))
720 (sample-profiler-reset)))) 654
721 655(defmacro with-memory-profiling (&rest body)
722(cl-defmacro with-memory-profiling (() &rest body) 656 `(unwind-protect
723 `(progn 657 (progn
724 (memory-profiler-start) 658 (ignore (memory-profiler-log))
725 (memory-profiler-reset) 659 (memory-profiler-start)
726 (unwind-protect 660 ,@body)
727 (progn ,@body) 661 (memory-profiler-stop)
728 (memory-profiler-stop) 662 (profiler--report-memory)))
729 (memory-profiler-report)
730 (memory-profiler-reset))))
731 663
732(provide 'profiler) 664(provide 'profiler)
733;;; profiler.el ends here 665;;; profiler.el ends here
diff --git a/src/ChangeLog b/src/ChangeLog
index feb9c6219fb..1b90ae8b976 100644
--- a/src/ChangeLog
+++ b/src/ChangeLog
@@ -1,3 +1,31 @@
12012-09-24 Stefan Monnier <monnier@iro.umontreal.ca>
2
3 * xdisp.c (Qautomatic_redisplay): New constant.
4 (redisplay_internal): Record itself in backtrace_list.
5 (syms_of_xdisp): Define Qautomatic_redisplay.
6
7 * profiler.c: Remove filtering functionality.
8 (is_in_trace, Qgc): Remove vars.
9 (make_log, record_backtrace, Fsample_profiler_log):
10 Rewrite, using Elisp hash-tables.
11 (approximate_median, evict_lower_half): New functions.
12 (cpu_log): Rename from sample_log.
13 (cpu_gc_count): New var.
14 (Fsample_profiler_reset, Fmemory_profiler_reset): Remove.
15 (sigprof_handler): Add count to cpu_gc_count during GC, detected via
16 backtrace_list.
17 (block_sigprof, unblock_sigprof): Remove.
18 (gc_probe, mark_profiler): Remove functions.
19 (syms_of_profiler): Staticpro cpu_log and memory_log.
20
21 * lisp.h (SXHASH_COMBINE): Move back to...
22 * fns.c (SXHASH_COMBINE): ...here.
23
24 * alloc.c (Fgarbage_collect): Record itself in backtrace_list.
25 Don't set is_in_trace any more. Don't call mark_profiler.
26 Only call gc_probe for the memory profiler.
27 (syms_of_alloc): Define Qautomatic_gc.
28
12012-09-15 Tomohiro Matsuyama <tomo@cx4a.org> 292012-09-15 Tomohiro Matsuyama <tomo@cx4a.org>
2 30
3 * alloc.c (emacs_blocked_malloc): Remove redundant MALLOC_PROBE. 31 * alloc.c (emacs_blocked_malloc): Remove redundant MALLOC_PROBE.
diff --git a/src/alloc.c b/src/alloc.c
index 36adb49f835..2fc93f825d1 100644
--- a/src/alloc.c
+++ b/src/alloc.c
@@ -264,6 +264,7 @@ static Lisp_Object Qintervals;
264static Lisp_Object Qbuffers; 264static Lisp_Object Qbuffers;
265static Lisp_Object Qstring_bytes, Qvector_slots, Qheap; 265static Lisp_Object Qstring_bytes, Qvector_slots, Qheap;
266static Lisp_Object Qgc_cons_threshold; 266static Lisp_Object Qgc_cons_threshold;
267Lisp_Object Qautomatic_gc;
267Lisp_Object Qchar_table_extra_slots; 268Lisp_Object Qchar_table_extra_slots;
268 269
269/* Hook run after GC has finished. */ 270/* Hook run after GC has finished. */
@@ -5421,6 +5422,7 @@ See Info node `(elisp)Garbage Collection'. */)
5421 EMACS_TIME start; 5422 EMACS_TIME start;
5422 Lisp_Object retval = Qnil; 5423 Lisp_Object retval = Qnil;
5423 size_t tot_before = 0; 5424 size_t tot_before = 0;
5425 struct backtrace backtrace;
5424 5426
5425 if (abort_on_gc) 5427 if (abort_on_gc)
5426 abort (); 5428 abort ();
@@ -5430,6 +5432,14 @@ See Info node `(elisp)Garbage Collection'. */)
5430 if (pure_bytes_used_before_overflow) 5432 if (pure_bytes_used_before_overflow)
5431 return Qnil; 5433 return Qnil;
5432 5434
5435 /* Record this function, so it appears on the profiler's backtraces. */
5436 backtrace.next = backtrace_list;
5437 backtrace.function = &Qautomatic_gc;
5438 backtrace.args = &Qautomatic_gc;
5439 backtrace.nargs = 0;
5440 backtrace.debug_on_exit = 0;
5441 backtrace_list = &backtrace;
5442
5433 check_cons_list (); 5443 check_cons_list ();
5434 5444
5435 /* Don't keep undo information around forever. 5445 /* Don't keep undo information around forever.
@@ -5486,7 +5496,6 @@ See Info node `(elisp)Garbage Collection'. */)
5486 shrink_regexp_cache (); 5496 shrink_regexp_cache ();
5487 5497
5488 gc_in_progress = 1; 5498 gc_in_progress = 1;
5489 is_in_trace = 1;
5490 5499
5491 /* Mark all the special slots that serve as the roots of accessibility. */ 5500 /* Mark all the special slots that serve as the roots of accessibility. */
5492 5501
@@ -5538,8 +5547,6 @@ See Info node `(elisp)Garbage Collection'. */)
5538 mark_backtrace (); 5547 mark_backtrace ();
5539#endif 5548#endif
5540 5549
5541 mark_profiler ();
5542
5543#ifdef HAVE_WINDOW_SYSTEM 5550#ifdef HAVE_WINDOW_SYSTEM
5544 mark_fringe_data (); 5551 mark_fringe_data ();
5545#endif 5552#endif
@@ -5607,7 +5614,6 @@ See Info node `(elisp)Garbage Collection'. */)
5607 check_cons_list (); 5614 check_cons_list ();
5608 5615
5609 gc_in_progress = 0; 5616 gc_in_progress = 0;
5610 is_in_trace = 0;
5611 5617
5612 consing_since_gc = 0; 5618 consing_since_gc = 0;
5613 if (gc_cons_threshold < GC_DEFAULT_THRESHOLD / 10) 5619 if (gc_cons_threshold < GC_DEFAULT_THRESHOLD / 10)
@@ -5720,24 +5726,19 @@ See Info node `(elisp)Garbage Collection'. */)
5720 gcs_done++; 5726 gcs_done++;
5721 5727
5722 /* Collect profiling data. */ 5728 /* Collect profiling data. */
5723 if (sample_profiler_running || memory_profiler_running) 5729 if (memory_profiler_running)
5724 { 5730 {
5725 size_t swept = 0; 5731 size_t swept = 0;
5726 size_t elapsed = 0;
5727 if (memory_profiler_running) 5732 if (memory_profiler_running)
5728 { 5733 {
5729 size_t tot_after = total_bytes_of_live_objects (); 5734 size_t tot_after = total_bytes_of_live_objects ();
5730 if (tot_before > tot_after) 5735 if (tot_before > tot_after)
5731 swept = tot_before - tot_after; 5736 swept = tot_before - tot_after;
5732 } 5737 }
5733 if (sample_profiler_running) 5738 malloc_probe (swept);
5734 {
5735 EMACS_TIME since_start = sub_emacs_time (current_emacs_time (), start);
5736 elapsed = EMACS_TIME_TO_DOUBLE (since_start) * 1000;
5737 }
5738 gc_probe (swept, elapsed);
5739 } 5739 }
5740 5740
5741 backtrace_list = backtrace.next;
5741 return retval; 5742 return retval;
5742} 5743}
5743 5744
@@ -6867,6 +6868,7 @@ do hash-consing of the objects allocated to pure space. */);
6867 DEFSYM (Qstring_bytes, "string-bytes"); 6868 DEFSYM (Qstring_bytes, "string-bytes");
6868 DEFSYM (Qvector_slots, "vector-slots"); 6869 DEFSYM (Qvector_slots, "vector-slots");
6869 DEFSYM (Qheap, "heap"); 6870 DEFSYM (Qheap, "heap");
6871 DEFSYM (Qautomatic_gc, "Automatic GC");
6870 6872
6871 DEFSYM (Qgc_cons_threshold, "gc-cons-threshold"); 6873 DEFSYM (Qgc_cons_threshold, "gc-cons-threshold");
6872 DEFSYM (Qchar_table_extra_slots, "char-table-extra-slots"); 6874 DEFSYM (Qchar_table_extra_slots, "char-table-extra-slots");
diff --git a/src/fns.c b/src/fns.c
index 3cb66534e0c..3225fefc5e3 100644
--- a/src/fns.c
+++ b/src/fns.c
@@ -4096,6 +4096,13 @@ sweep_weak_hash_tables (void)
4096 4096
4097#define SXHASH_MAX_LEN 7 4097#define SXHASH_MAX_LEN 7
4098 4098
4099/* Combine two integers X and Y for hashing. The result might not fit
4100 into a Lisp integer. */
4101
4102#define SXHASH_COMBINE(X, Y) \
4103 ((((EMACS_UINT) (X) << 4) + ((EMACS_UINT) (X) >> (BITS_PER_EMACS_INT - 4))) \
4104 + (EMACS_UINT) (Y))
4105
4099/* Hash X, returning a value that fits into a Lisp integer. */ 4106/* Hash X, returning a value that fits into a Lisp integer. */
4100#define SXHASH_REDUCE(X) \ 4107#define SXHASH_REDUCE(X) \
4101 ((((X) ^ (X) >> (BITS_PER_EMACS_INT - FIXNUM_BITS))) & INTMASK) 4108 ((((X) ^ (X) >> (BITS_PER_EMACS_INT - FIXNUM_BITS))) & INTMASK)
diff --git a/src/lisp.h b/src/lisp.h
index 894b18c838c..09a812829a3 100644
--- a/src/lisp.h
+++ b/src/lisp.h
@@ -2679,11 +2679,6 @@ extern void init_syntax_once (void);
2679extern void syms_of_syntax (void); 2679extern void syms_of_syntax (void);
2680 2680
2681/* Defined in fns.c */ 2681/* Defined in fns.c */
2682/* Combine two integers X and Y for hashing. The result might not fit
2683 into a Lisp integer. */
2684#define SXHASH_COMBINE(X, Y) \
2685 ((((EMACS_UINT) (X) << 4) + ((EMACS_UINT) (X) >> (BITS_PER_EMACS_INT - 4))) \
2686 + (EMACS_UINT) (Y))
2687extern Lisp_Object QCrehash_size, QCrehash_threshold; 2682extern Lisp_Object QCrehash_size, QCrehash_threshold;
2688enum { NEXT_ALMOST_PRIME_LIMIT = 11 }; 2683enum { NEXT_ALMOST_PRIME_LIMIT = 11 };
2689EXFUN (Fidentity, 1) ATTRIBUTE_CONST; 2684EXFUN (Fidentity, 1) ATTRIBUTE_CONST;
@@ -2921,6 +2916,7 @@ build_string (const char *str)
2921 2916
2922extern Lisp_Object pure_cons (Lisp_Object, Lisp_Object); 2917extern Lisp_Object pure_cons (Lisp_Object, Lisp_Object);
2923extern void make_byte_code (struct Lisp_Vector *); 2918extern void make_byte_code (struct Lisp_Vector *);
2919extern Lisp_Object Qautomatic_gc;
2924extern Lisp_Object Qchar_table_extra_slots; 2920extern Lisp_Object Qchar_table_extra_slots;
2925extern struct Lisp_Vector *allocate_vector (EMACS_INT); 2921extern struct Lisp_Vector *allocate_vector (EMACS_INT);
2926extern struct Lisp_Vector *allocate_pseudovector (int memlen, int lisplen, int tag); 2922extern struct Lisp_Vector *allocate_pseudovector (int memlen, int lisplen, int tag);
@@ -3532,19 +3528,14 @@ void syms_of_dbusbind (void);
3532/* Defined in profiler.c */ 3528/* Defined in profiler.c */
3533extern bool sample_profiler_running; 3529extern bool sample_profiler_running;
3534extern bool memory_profiler_running; 3530extern bool memory_profiler_running;
3535extern bool is_in_trace;
3536extern Lisp_Object Qgc;
3537extern void malloc_probe (size_t); 3531extern void malloc_probe (size_t);
3538extern void gc_probe (size_t, size_t); 3532extern void gc_probe (size_t, size_t);
3539#define ENTER_TRACE (is_in_trace = 1)
3540#define LEAVE_TRACE (is_in_trace = 0)
3541#define MALLOC_PROBE(size) \ 3533#define MALLOC_PROBE(size) \
3542 do { \ 3534 do { \
3543 if (memory_profiler_running) \ 3535 if (memory_profiler_running) \
3544 malloc_probe (size); \ 3536 malloc_probe (size); \
3545 } while (0) 3537 } while (0)
3546 3538
3547extern void mark_profiler (void);
3548extern void syms_of_profiler (void); 3539extern void syms_of_profiler (void);
3549 3540
3550#ifdef DOS_NT 3541#ifdef DOS_NT
diff --git a/src/profiler.c b/src/profiler.c
index 0ef20a9a70c..5eaaaf3330f 100644
--- a/src/profiler.c
+++ b/src/profiler.c
@@ -33,702 +33,103 @@ bool sample_profiler_running;
33 33
34bool memory_profiler_running; 34bool memory_profiler_running;
35 35
36/* True during tracing. */
37
38bool is_in_trace;
39
40/* Tag for GC entry. */
41
42Lisp_Object Qgc;
43
44static void sigprof_handler (int, siginfo_t *, void *); 36static void sigprof_handler (int, siginfo_t *, void *);
45static void block_sigprof (void);
46static void unblock_sigprof (void);
47
48
49/* Pattern matching. */
50
51enum pattern_type
52{
53 pattern_exact, /* foo */
54 pattern_body_exact, /* *foo* */
55 pattern_pre_any, /* *foo */
56 pattern_post_any, /* foo* */
57 pattern_body_any /* foo*bar */
58};
59
60struct pattern
61{
62 enum pattern_type type;
63 char *exact;
64 char *extra;
65 int exact_length;
66 int extra_length;
67};
68
69static struct pattern *
70parse_pattern (const char *pattern)
71{
72 int length = strlen (pattern);
73 enum pattern_type type;
74 char *exact;
75 char *extra = 0;
76 struct pattern *pat =
77 (struct pattern *) xmalloc (sizeof (struct pattern));
78
79 if (length > 1
80 && *pattern == '*'
81 && pattern[length - 1] == '*')
82 {
83 type = pattern_body_exact;
84 exact = xstrdup (pattern + 1);
85 exact[length - 2] = 0;
86 }
87 else if (*pattern == '*')
88 {
89 type = pattern_pre_any;
90 exact = xstrdup (pattern + 1);
91 }
92 else if (pattern[length - 1] == '*')
93 {
94 type = pattern_post_any;
95 exact = xstrdup (pattern);
96 exact[length - 1] = 0;
97 }
98 else if (strchr (pattern, '*'))
99 {
100 type = pattern_body_any;
101 exact = xstrdup (pattern);
102 extra = strchr (exact, '*');
103 *extra++ = 0;
104 }
105 else
106 {
107 type = pattern_exact;
108 exact = xstrdup (pattern);
109 }
110
111 pat->type = type;
112 pat->exact = exact;
113 pat->extra = extra;
114 pat->exact_length = strlen (exact);
115 pat->extra_length = extra ? strlen (extra) : 0;
116
117 return pat;
118}
119
120static void
121free_pattern (struct pattern *pattern)
122{
123 xfree (pattern->exact);
124 xfree (pattern);
125}
126
127static int
128pattern_match_1 (enum pattern_type type,
129 const char *exact,
130 int exact_length,
131 const char *string,
132 int length)
133{
134 if (exact_length > length)
135 return 0;
136 switch (type)
137 {
138 case pattern_exact:
139 return exact_length == length && !strncmp (exact, string, length);
140 case pattern_body_exact:
141 return strstr (string, exact) != 0;
142 case pattern_pre_any:
143 return !strncmp (exact, string + (length - exact_length), exact_length);
144 case pattern_post_any:
145 return !strncmp (exact, string, exact_length);
146 case pattern_body_any:
147 return 0;
148 }
149}
150
151static int
152pattern_match (struct pattern *pattern, const char *string)
153{
154 int length = strlen (string);
155 switch (pattern->type)
156 {
157 case pattern_body_any:
158 if (pattern->exact_length + pattern->extra_length > length)
159 return 0;
160 return pattern_match_1 (pattern_post_any,
161 pattern->exact,
162 pattern->exact_length,
163 string, length)
164 && pattern_match_1 (pattern_pre_any,
165 pattern->extra,
166 pattern->extra_length,
167 string, length);
168 default:
169 return pattern_match_1 (pattern->type,
170 pattern->exact,
171 pattern->exact_length,
172 string, length);
173 }
174}
175
176#if 0
177static int
178match (const char *pattern, const char *string)
179{
180 int res;
181 struct pattern *pat = parse_pattern (pattern);
182 res = pattern_match (pat, string);
183 free_pattern (pat);
184 return res;
185}
186
187static void
188should_match (const char *pattern, const char *string)
189{
190 putchar (match (pattern, string) ? '.' : 'F');
191}
192
193static void
194should_not_match (const char *pattern, const char *string)
195{
196 putchar (match (pattern, string) ? 'F' : '.');
197}
198
199static void
200pattern_match_tests (void)
201{
202 should_match ("", "");
203 should_not_match ("", "a");
204 should_match ("a", "a");
205 should_not_match ("a", "ab");
206 should_not_match ("ab", "a");
207 should_match ("*a*", "a");
208 should_match ("*a*", "ab");
209 should_match ("*a*", "ba");
210 should_match ("*a*", "bac");
211 should_not_match ("*a*", "");
212 should_not_match ("*a*", "b");
213 should_match ("*", "");
214 should_match ("*", "a");
215 should_match ("a*", "a");
216 should_match ("a*", "ab");
217 should_not_match ("a*", "");
218 should_not_match ("a*", "ba");
219 should_match ("*a", "a");
220 should_match ("*a", "ba");
221 should_not_match ("*a", "");
222 should_not_match ("*a", "ab");
223 should_match ("a*b", "ab");
224 should_match ("a*b", "acb");
225 should_match ("a*b", "aab");
226 should_match ("a*b", "abb");
227 should_not_match ("a*b", "");
228 should_not_match ("a*b", "");
229 should_not_match ("a*b", "abc");
230 puts ("");
231}
232#endif
233
234
235/* Filters. */
236
237static struct pattern *filter_pattern;
238
239/* Set the current filter pattern. If PATTERN is null, unset the
240 current filter pattern instead. */
241
242static void
243set_filter_pattern (const char *pattern)
244{
245 if (sample_profiler_running)
246 block_sigprof ();
247
248 if (filter_pattern)
249 {
250 free_pattern (filter_pattern);
251 filter_pattern = 0;
252 }
253 if (pattern)
254 filter_pattern = parse_pattern (pattern);
255
256 if (sample_profiler_running)
257 unblock_sigprof ();
258}
259
260/* Return true if the current filter pattern is matched with FUNCTION.
261 FUNCTION should be a symbol or a subroutine, otherwise return
262 false. */
263
264static int
265apply_filter_1 (Lisp_Object function)
266{
267 const char *name;
268
269 if (!filter_pattern)
270 return 1;
271
272 if (SYMBOLP (function))
273 name = SDATA (SYMBOL_NAME (function));
274 else if (SUBRP (function))
275 name = XSUBR (function)->symbol_name;
276 else
277 return 0;
278
279 return pattern_match (filter_pattern, name);
280}
281
282/* Return true if the current filter pattern is matched with at least
283 one entry in BACKLIST. */
284
285static int
286apply_filter (struct backtrace *backlist)
287{
288 while (backlist)
289 {
290 if (apply_filter_1 (*backlist->function))
291 return 1;
292 backlist = backlist->next;
293 }
294 return 0;
295}
296
297DEFUN ("profiler-set-filter-pattern",
298 Fprofiler_set_filter_pattern, Sprofiler_set_filter_pattern,
299 1, 1, "sPattern: ",
300 doc: /* Set the current filter pattern. PATTERN can contain
301one or two wildcards (*) as follows:
302
303- foo
304- *foo
305- foo*
306- *foo*
307- foo*bar
308
309If PATTERN is nil or an empty string, then unset the current filter
310pattern. */)
311 (Lisp_Object pattern)
312{
313 if (NILP (pattern)
314 || (STRINGP (pattern) && !SREF (pattern, 0)))
315 {
316 set_filter_pattern (0);
317 message ("Profiler filter pattern unset");
318 return Qt;
319 }
320 else if (!STRINGP (pattern))
321 error ("Invalid type of profiler filter pattern");
322
323 set_filter_pattern (SDATA (pattern));
324
325 return Qt;
326}
327 37
328 38
329/* Backtraces. */ 39/* Logs. */
330 40
41typedef struct Lisp_Hash_Table log_t;
331 42
332static Lisp_Object 43static Lisp_Object
333make_backtrace (int size) 44make_log (int heap_size, int max_stack_depth)
334{ 45{
335 return Fmake_vector (make_number (size), Qnil); 46 /* We use a standard Elisp hash-table object, but we use it in
47 a special way. This is OK as long as the object is not exposed
48 to Elisp, i.e. until it is returned by *-profiler-log, after which
49 it can't be used any more. */
50 Lisp_Object log = make_hash_table (Qequal, make_number (heap_size),
51 make_float (DEFAULT_REHASH_SIZE),
52 make_float (DEFAULT_REHASH_THRESHOLD),
53 Qnil, Qnil, Qnil);
54 struct Lisp_Hash_Table *h = XHASH_TABLE (log);
55
56 /* What is special about our hash-tables is that the keys are pre-filled
57 with the vectors we'll put in them. */
58 int i = ASIZE (h->key_and_value) / 2;
59 while (0 < i)
60 set_hash_key_slot (h, --i,
61 Fmake_vector (make_number (max_stack_depth), Qnil));
62 return log;
336} 63}
337 64
338static EMACS_UINT 65/* Evict the least used half of the hash_table.
339backtrace_hash (Lisp_Object backtrace)
340{
341 int i;
342 EMACS_UINT hash = 0;
343 for (i = 0; i < ASIZE (backtrace); i++)
344 /* FIXME */
345 hash = SXHASH_COMBINE (XUINT (AREF (backtrace, i)), hash);
346 return hash;
347}
348 66
349static int 67 When the table is full, we have to evict someone.
350backtrace_equal (Lisp_Object a, Lisp_Object b) 68 The easiest and most efficient is to evict the value we're about to add
351{ 69 (i.e. once the table is full, stop sampling).
352 int i, j;
353 70
354 for (i = 0, j = 0;; i++, j++) 71 We could also pick the element with the lowest count and evict it,
355 { 72 but finding it is O(N) and for that amount of work we get very
356 Lisp_Object x = i < ASIZE (a) ? AREF (a, i) : Qnil; 73 little in return: for the next sample, this latest sample will have
357 Lisp_Object y = j < ASIZE (b) ? AREF (b, j) : Qnil; 74 count==1 and will hence be a prime candidate for eviction :-(
358 if (NILP (x) && NILP (y))
359 break;
360 else if (!EQ (x, y))
361 return 0;
362 }
363 75
364 return 1; 76 So instead, we take O(N) time to eliminate more or less half of the
365} 77 entries (the half with the lowest counts). So we get an amortized
78 cost of O(1) and we get O(N) time for a new entry to grow larger
79 than the other least counts before a new round of eviction. */
366 80
367static Lisp_Object 81static EMACS_INT approximate_median (log_t *log,
368backtrace_object_1 (Lisp_Object backtrace, int i) 82 ptrdiff_t start, ptrdiff_t size)
369{ 83{
370 if (i >= ASIZE (backtrace) || NILP (AREF (backtrace, i))) 84 eassert (size > 0);
371 return Qnil; 85 if (size < 2)
86 return XINT (HASH_VALUE (log, start));
87 if (size < 3)
88 /* Not an actual median, but better for our application than
89 choosing either of the two numbers. */
90 return ((XINT (HASH_VALUE (log, start))
91 + XINT (HASH_VALUE (log, start + 1)))
92 / 2);
372 else 93 else
373 return Fcons (AREF (backtrace, i), backtrace_object_1 (backtrace, i + 1));
374}
375
376/* Convert BACKTRACE to a list. */
377
378static Lisp_Object
379backtrace_object (Lisp_Object backtrace)
380{
381 backtrace_object_1 (backtrace, 0);
382}
383
384
385/* Slots. */
386
387/* Slot data structure. */
388
389struct slot
390{
391 /* Point to next free slot or next hash table link. */
392 struct slot *next;
393 /* Point to previous hash table link. */
394 struct slot *prev;
395 /* Backtrace object with fixed size. */
396 Lisp_Object backtrace;
397 /* How many times a profiler sees the slot, or how much resouce
398 allocated during profiling. */
399 size_t count;
400 /* How long the slot takes to execute. */
401 size_t elapsed;
402 /* True in used. */
403 unsigned char used : 1;
404};
405
406static void
407mark_slot (struct slot *slot)
408{
409 mark_object (slot->backtrace);
410}
411
412/* Convert SLOT to a list. */
413
414static Lisp_Object
415slot_object (struct slot *slot)
416{
417 return list3 (backtrace_object (slot->backtrace),
418 make_number (slot->count),
419 make_number (slot->elapsed));
420}
421
422
423
424/* Slot heaps. */
425
426struct slot_heap
427{
428 /* Number of slots allocated to the heap. */
429 unsigned int size;
430 /* Actual data area. */
431 struct slot *data;
432 /* Free list. */
433 struct slot *free_list;
434};
435
436static void
437clear_slot_heap (struct slot_heap *heap)
438{
439 int i;
440 struct slot *data;
441 struct slot *free_list;
442
443 data = heap->data;
444
445 /* Mark all slots unsused. */
446 for (i = 0; i < heap->size; i++)
447 data[i].used = 0;
448
449 /* Rebuild a free list. */
450 free_list = heap->free_list = heap->data;
451 for (i = 1; i < heap->size; i++)
452 { 94 {
453 free_list->next = &data[i]; 95 ptrdiff_t newsize = size / 3;
454 free_list = free_list->next; 96 ptrdiff_t start2 = start + newsize;
97 EMACS_INT i1 = approximate_median (log, start, newsize);
98 EMACS_INT i2 = approximate_median (log, start2, newsize);
99 EMACS_INT i3 = approximate_median (log, start2 + newsize,
100 size - 2 * newsize);
101 return (i1 < i2
102 ? (i2 < i3 ? i2 : (i1 < i3 ? i3 : i1))
103 : (i1 < i3 ? i1 : (i2 < i3 ? i3 : i2)));
455 } 104 }
456 free_list->next = 0;
457} 105}
458 106
459/* Make a slot heap with SIZE. MAX_STACK_DEPTH is a fixed size of 107static void evict_lower_half (log_t *log)
460 allocated slots. */
461
462static struct slot_heap *
463make_slot_heap (unsigned int size, int max_stack_depth)
464{ 108{
465 int i; 109 ptrdiff_t size = ASIZE (log->key_and_value) / 2;
466 struct slot_heap *heap; 110 EMACS_INT median = approximate_median (log, 0, size);
467 struct slot *data; 111 ptrdiff_t i;
468 112
469 data = (struct slot *) xmalloc (sizeof (struct slot) * size);
470 for (i = 0; i < size; i++) 113 for (i = 0; i < size; i++)
471 data[i].backtrace = make_backtrace (max_stack_depth); 114 /* Evict not only values smaller but also values equal to the median,
472 115 so as to make sure we evict something no matter what. */
473 heap = (struct slot_heap *) xmalloc (sizeof (struct slot_heap)); 116 if (XINT (HASH_VALUE (log, i)) <= median)
474 heap->size = size; 117 {
475 heap->data = data; 118 Lisp_Object key = HASH_KEY (log, i);
476 clear_slot_heap (heap); 119 { /* FIXME: we could make this more efficient. */
477 120 Lisp_Object tmp;
478 return heap; 121 XSET_HASH_TABLE (tmp, log); /* FIXME: Use make_lisp_ptr. */
479} 122 Fremhash (key, tmp);
480 123 }
481static void 124 eassert (EQ (log->next_free, make_number (i)));
482free_slot_heap (struct slot_heap *heap) 125 {
483{ 126 int j;
484 int i; 127 eassert (VECTORP (key));
485 struct slot *data = heap->data; 128 for (j = 0; j < ASIZE (key); j++)
486 for (i = 0; i < heap->size; i++) 129 ASET (key, i, Qnil);
487 data[i].backtrace = Qnil; 130 }
488 xfree (data); 131 set_hash_key_slot (log, i, key);
489 xfree (heap); 132 }
490}
491
492static void
493mark_slot_heap (struct slot_heap *heap)
494{
495 int i;
496 for (i = 0; i < heap->size; i++)
497 mark_slot (&heap->data[i]);
498}
499
500/* Allocate one slot from HEAP. Return 0 if no free slot in HEAP. */
501
502static struct slot *
503allocate_slot (struct slot_heap *heap)
504{
505 struct slot *slot;
506 if (!heap->free_list)
507 return 0;
508 slot = heap->free_list;
509 slot->count = 0;
510 slot->elapsed = 0;
511 slot->used = 1;
512 heap->free_list = heap->free_list->next;
513 return slot;
514}
515
516static void
517free_slot (struct slot_heap *heap, struct slot *slot)
518{
519 eassert (slot->used);
520 slot->used = 0;
521 slot->next = heap->free_list;
522 heap->free_list = slot;
523}
524
525/* Return a minimal slot from HEAP. "Minimal" means that such a slot
526 is meaningless for profiling. */
527
528static struct slot *
529min_slot (struct slot_heap *heap)
530{
531 int i;
532 struct slot *min = 0;
533 for (i = 0; i < heap->size; i++)
534 {
535 struct slot *slot = &heap->data[i];
536 if (!min || (slot->used && slot->count < min->count))
537 min = slot;
538 }
539 return min;
540}
541
542
543/* Slot hash tables. */
544
545struct slot_table
546{
547 /* Number of slot buckets. */
548 unsigned int size;
549 /* Buckets data area. */
550 struct slot **data;
551};
552
553static void
554clear_slot_table (struct slot_table *table)
555{
556 int i;
557 for (i = 0; i < table->size; i++)
558 table->data[i] = 0;
559}
560
561static struct slot_table *
562make_slot_table (int size)
563{
564 struct slot_table *table
565 = (struct slot_table *) xmalloc (sizeof (struct slot_table));
566 table->size = size;
567 table->data = (struct slot **) xmalloc (sizeof (struct slot *) * size);
568 clear_slot_table (table);
569 return table;
570}
571
572static void
573free_slot_table (struct slot_table *table)
574{
575 xfree (table->data);
576 xfree (table);
577}
578
579static void
580remove_slot (struct slot_table *table, struct slot *slot)
581{
582 if (slot->prev)
583 slot->prev->next = slot->next;
584 else
585 {
586 EMACS_UINT hash = backtrace_hash (slot->backtrace);
587 table->data[hash % table->size] = slot->next;
588 }
589 if (slot->next)
590 slot->next->prev = slot->prev;
591}
592
593
594/* Logs. */
595
596struct log
597{
598 /* Type of log in symbol. `sample' or `memory'. */
599 Lisp_Object type;
600 /* Backtrace for working. */
601 Lisp_Object backtrace;
602 struct slot_heap *slot_heap;
603 struct slot_table *slot_table;
604 size_t others_count;
605 size_t others_elapsed;
606};
607
608static struct log *
609make_log (const char *type, int heap_size, int max_stack_depth)
610{
611 struct log *log =
612 (struct log *) xmalloc (sizeof (struct log));
613 log->type = intern (type);
614 log->backtrace = make_backtrace (max_stack_depth);
615 log->slot_heap = make_slot_heap (heap_size, max_stack_depth);
616 /* Number of buckets of hash table will be 10% of HEAP_SIZE. */
617 log->slot_table = make_slot_table (max (256, heap_size) / 10);
618 log->others_count = 0;
619 log->others_elapsed = 0;
620 return log;
621}
622
623static void
624free_log (struct log *log)
625{
626 log->backtrace = Qnil;
627 free_slot_heap (log->slot_heap);
628 free_slot_table (log->slot_table);
629}
630
631static void
632mark_log (struct log *log)
633{
634 mark_object (log->type);
635 mark_object (log->backtrace);
636 mark_slot_heap (log->slot_heap);
637}
638
639static void
640clear_log (struct log *log)
641{
642 clear_slot_heap (log->slot_heap);
643 clear_slot_table (log->slot_table);
644 log->others_count = 0;
645 log->others_elapsed = 0;
646}
647
648/* Evint SLOT from LOG and accumulate the slot counts into others
649 counts. */
650
651static void
652evict_slot (struct log *log, struct slot *slot)
653{
654 log->others_count += slot->count;
655 log->others_elapsed += slot->elapsed;
656 remove_slot (log->slot_table, slot);
657 free_slot (log->slot_heap, slot);
658}
659
660/* Evict a minimal slot from LOG. */
661
662static void
663evict_min_slot (struct log *log)
664{
665 struct slot *min = min_slot (log->slot_heap);
666 if (min)
667 evict_slot (log, min);
668}
669
670/* Allocate a new slot for BACKTRACE from LOG. The returen value must
671 be a valid pointer to the slot. */
672
673static struct slot *
674new_slot (struct log *log, Lisp_Object backtrace)
675{
676 int i;
677 struct slot *slot = allocate_slot (log->slot_heap);
678
679 /* If failed to allocate a slot, free some slots to make a room in
680 heap. */
681 if (!slot)
682 {
683 evict_min_slot (log);
684 slot = allocate_slot (log->slot_heap);
685 /* Must be allocated. */
686 eassert (slot);
687 }
688
689 slot->prev = 0;
690 slot->next = 0;
691
692 /* Assign BACKTRACE to the slot. */
693 for (i = 0; i < ASIZE (backtrace); i++)
694 ASET (slot->backtrace, i, AREF (backtrace, i));
695
696 return slot;
697}
698
699/* Make sure that a slot for BACKTRACE is in LOG and return the
700 slot. The return value must be a valid pointer to the slot. */
701
702static struct slot *
703ensure_slot (struct log *log, Lisp_Object backtrace)
704{
705 EMACS_UINT hash = backtrace_hash (backtrace);
706 int index = hash % log->slot_table->size;
707 struct slot *slot = log->slot_table->data[index];
708 struct slot *prev = slot;
709
710 /* Looking up in hash table bucket. */
711 while (slot)
712 {
713 if (backtrace_equal (backtrace, slot->backtrace))
714 goto found;
715 prev = slot;
716 slot = slot->next;
717 }
718
719 /* If not found, allocate a new slot for BACKTRACE from LOG and link
720 it with bucket chain. */
721 slot = new_slot (log, backtrace);
722 if (prev)
723 {
724 slot->prev = prev;
725 prev->next = slot;
726 }
727 else
728 log->slot_table->data[index] = slot;
729
730 found:
731 return slot;
732} 133}
733 134
734/* Record the current backtrace in LOG. BASE is a special name for 135/* Record the current backtrace in LOG. BASE is a special name for
@@ -738,83 +139,60 @@ ensure_slot (struct log *log, Lisp_Object backtrace)
738 took. */ 139 took. */
739 140
740static void 141static void
741record_backtrace_under (struct log *log, Lisp_Object base, 142record_backtrace (log_t *log, size_t count)
742 size_t count, size_t elapsed)
743{ 143{
744 int i = 0;
745 Lisp_Object backtrace = log->backtrace;
746 struct backtrace *backlist = backtrace_list; 144 struct backtrace *backlist = backtrace_list;
145 Lisp_Object backtrace;
146 ptrdiff_t index, i = 0;
147 ptrdiff_t asize;
747 148
748 /* First of all, apply filter on the bactkrace. */ 149 if (!INTEGERP (log->next_free))
749 if (!apply_filter (backlist)) return; 150 evict_lower_half (log);
151 index = XINT (log->next_free);
750 152
751 /* Record BASE if necessary. */ 153 /* Get a "working memory" vector. */
752 if (!NILP (base) && ASIZE (backtrace) > 0) 154 backtrace = HASH_KEY (log, index);
753 ASET (backtrace, i++, base); 155 asize = ASIZE (backtrace);
754 156
755 /* Copy the backtrace contents into working memory. */ 157 /* Copy the backtrace contents into working memory. */
756 for (; i < ASIZE (backtrace) && backlist; backlist = backlist->next) 158 for (; i < asize && backlist; i++, backlist = backlist->next)
757 { 159 ASET (backtrace, i, *backlist->function);
758 Lisp_Object function = *backlist->function;
759 if (FUNCTIONP (function))
760 ASET (backtrace, i++, function);
761 }
762 /* Make sure that unused space of working memory is filled with
763 nil. */
764 for (; i < ASIZE (backtrace); i++)
765 ASET (backtrace, i, Qnil);
766
767 /* If the backtrace is not empty, */
768 if (!NILP (AREF (backtrace, 0)))
769 {
770 /* then record counts. */
771 struct slot *slot = ensure_slot (log, backtrace);
772 slot->count += count;
773 slot->elapsed += elapsed;
774 }
775}
776
777static void
778record_backtrace (struct log *log, size_t count, size_t elapsed)
779{
780 record_backtrace_under (log, Qnil, count, elapsed);
781}
782
783/* Convert LOG to a list. */
784 160
785static Lisp_Object 161 /* Make sure that unused space of working memory is filled with nil. */
786log_object (struct log *log) 162 for (; i < asize; i++)
787{ 163 ASET (backtrace, i, Qnil);
788 int i;
789 Lisp_Object slots = Qnil;
790
791 if (log->others_count != 0 || log->others_elapsed != 0)
792 {
793 /* Add others slot. */
794 Lisp_Object others_slot
795 = list3 (list1 (Qt),
796 make_number (log->others_count),
797 make_number (log->others_elapsed));
798 slots = list1 (others_slot);
799 }
800
801 for (i = 0; i < log->slot_heap->size; i++)
802 {
803 struct slot *s = &log->slot_heap->data[i];
804 if (s->used)
805 {
806 Lisp_Object slot = slot_object (s);
807 slots = Fcons (slot, slots);
808 }
809 }
810 164
811 return list4 (log->type, Qnil, Fcurrent_time (), slots); 165 { /* We basically do a `gethash+puthash' here, except that we have to be
166 careful to avoid memory allocation since we're in a signal
167 handler, and we optimize the code to try and avoid computing the
168 hash+lookup twice. See fns.c:Fputhash for reference. */
169 EMACS_UINT hash;
170 ptrdiff_t j = hash_lookup (log, backtrace, &hash);
171 if (j >= 0)
172 set_hash_value_slot (log, j,
173 make_number (count + XINT (HASH_VALUE (log, j))));
174 else
175 { /* BEWARE! hash_put in general can allocate memory.
176 But currently it only does that if log->next_free is nil. */
177 int j;
178 eassert (!NILP (log->next_free));
179 j = hash_put (log, backtrace, make_number (count), hash);
180 /* Let's make sure we've put `backtrace' right where it
181 already was to start with. */
182 eassert (index == j);
183
184 /* FIXME: If the hash-table is almost full, we should set
185 some global flag so that some Elisp code can offload its
186 data elsewhere, so as to avoid the eviction code. */
187 }
188 }
812} 189}
813
814 190
815/* Sample profiler. */ 191/* Sample profiler. */
816 192
817static struct log *sample_log; 193static Lisp_Object cpu_log;
194/* Separate counter for the time spent in the GC. */
195static EMACS_INT cpu_gc_count;
818 196
819/* The current sample interval in millisecond. */ 197/* The current sample interval in millisecond. */
820 198
@@ -833,10 +211,12 @@ take samples each SAMPLE-INTERVAL in millisecond. See also
833 if (sample_profiler_running) 211 if (sample_profiler_running)
834 error ("Sample profiler is already running"); 212 error ("Sample profiler is already running");
835 213
836 if (!sample_log) 214 if (NILP (cpu_log))
837 sample_log = make_log ("sample", 215 {
838 profiler_slot_heap_size, 216 cpu_gc_count = 0;
839 profiler_max_stack_depth); 217 cpu_log = make_log (profiler_slot_heap_size,
218 profiler_max_stack_depth);
219 }
840 220
841 current_sample_interval = XINT (sample_interval); 221 current_sample_interval = XINT (sample_interval);
842 222
@@ -869,27 +249,6 @@ DEFUN ("sample-profiler-stop", Fsample_profiler_stop, Ssample_profiler_stop,
869 return Qt; 249 return Qt;
870} 250}
871 251
872DEFUN ("sample-profiler-reset", Fsample_profiler_reset, Ssample_profiler_reset,
873 0, 0, 0,
874 doc: /* Clear sample profiler log. */)
875 (void)
876{
877 if (sample_log)
878 {
879 if (sample_profiler_running)
880 {
881 block_sigprof ();
882 clear_log (sample_log);
883 unblock_sigprof ();
884 }
885 else
886 {
887 free_log (sample_log);
888 sample_log = 0;
889 }
890 }
891}
892
893DEFUN ("sample-profiler-running-p", 252DEFUN ("sample-profiler-running-p",
894 Fsample_profiler_running_p, Ssample_profiler_running_p, 253 Fsample_profiler_running_p, Ssample_profiler_running_p,
895 0, 0, 0, 254 0, 0, 0,
@@ -907,28 +266,24 @@ DEFUN ("sample-profiler-log",
907log is collected and SLOTS is a list of slots. */) 266log is collected and SLOTS is a list of slots. */)
908 (void) 267 (void)
909{ 268{
910 int i; 269 Lisp_Object result = cpu_log;
911 Lisp_Object result = Qnil; 270 /* Here we're making the log visible to Elisp , so it's not safe any
912 271 more for our use afterwards since we can't rely on its special
913 if (sample_log) 272 pre-allocated keys anymore. So we have to allocate a new one. */
914 { 273 cpu_log = (sample_profiler_running
915 if (sample_profiler_running) 274 ? make_log (profiler_slot_heap_size, profiler_max_stack_depth)
916 { 275 : Qnil);
917 block_sigprof (); 276 Fputhash (Fmake_vector (make_number (1), Qautomatic_gc),
918 result = log_object (sample_log); 277 make_number (cpu_gc_count),
919 unblock_sigprof (); 278 result);
920 } 279 cpu_gc_count = 0;
921 else
922 result = log_object (sample_log);
923 }
924
925 return result; 280 return result;
926} 281}
927 282
928 283
929/* Memory profiler. */ 284/* Memory profiler. */
930 285
931static struct log *memory_log; 286static Lisp_Object memory_log;
932 287
933DEFUN ("memory-profiler-start", Fmemory_profiler_start, Smemory_profiler_start, 288DEFUN ("memory-profiler-start", Fmemory_profiler_start, Smemory_profiler_start,
934 0, 0, 0, 289 0, 0, 0,
@@ -939,9 +294,8 @@ DEFUN ("memory-profiler-start", Fmemory_profiler_start, Smemory_profiler_start,
939 if (memory_profiler_running) 294 if (memory_profiler_running)
940 error ("Memory profiler is already running"); 295 error ("Memory profiler is already running");
941 296
942 if (!memory_log) 297 if (NILP (memory_log))
943 memory_log = make_log ("memory", 298 memory_log = make_log (profiler_slot_heap_size,
944 profiler_slot_heap_size,
945 profiler_max_stack_depth); 299 profiler_max_stack_depth);
946 300
947 memory_profiler_running = 1; 301 memory_profiler_running = 1;
@@ -962,24 +316,6 @@ DEFUN ("memory-profiler-stop",
962 return Qt; 316 return Qt;
963} 317}
964 318
965DEFUN ("memory-profiler-reset",
966 Fmemory_profiler_reset, Smemory_profiler_reset,
967 0, 0, 0,
968 doc: /* Clear memory profiler log. */)
969 (void)
970{
971 if (memory_log)
972 {
973 if (memory_profiler_running)
974 clear_log (memory_log);
975 else
976 {
977 free_log (memory_log);
978 memory_log = 0;
979 }
980 }
981}
982
983DEFUN ("memory-profiler-running-p", 319DEFUN ("memory-profiler-running-p",
984 Fmemory_profiler_running_p, Smemory_profiler_running_p, 320 Fmemory_profiler_running_p, Smemory_profiler_running_p,
985 0, 0, 0, 321 0, 0, 0,
@@ -997,11 +333,13 @@ DEFUN ("memory-profiler-log",
997log is collected and SLOTS is a list of slots. */) 333log is collected and SLOTS is a list of slots. */)
998 (void) 334 (void)
999{ 335{
1000 Lisp_Object result = Qnil; 336 Lisp_Object result = memory_log;
1001 337 /* Here we're making the log visible to Elisp , so it's not safe any
1002 if (memory_log) 338 more for our use afterwards since we can't rely on its special
1003 result = log_object (memory_log); 339 pre-allocated keys anymore. So we have to allocate a new one. */
1004 340 memory_log = (memory_profiler_running
341 ? make_log (profiler_slot_heap_size, profiler_max_stack_depth)
342 : Qnil);
1005 return result; 343 return result;
1006} 344}
1007 345
@@ -1013,73 +351,31 @@ log is collected and SLOTS is a list of slots. */)
1013static void 351static void
1014sigprof_handler (int signal, siginfo_t *info, void *ctx) 352sigprof_handler (int signal, siginfo_t *info, void *ctx)
1015{ 353{
1016 if (!is_in_trace && sample_log) 354 eassert (HASH_TABLE_P (cpu_log));
1017 record_backtrace (sample_log, 1, current_sample_interval); 355 if (backtrace_list && EQ (*backtrace_list->function, Qautomatic_gc))
1018} 356 /* Special case the time-count inside GC because the hash-table
1019 357 code is not prepared to be used while the GC is running.
1020static void 358 More specifically it uses ASIZE at many places where it does
1021block_sigprof (void) 359 not expect the ARRAY_MARK_FLAG to be set. We could try and
1022{ 360 harden the hash-table code, but it doesn't seem worth the
1023 sigset_t sigset; 361 effort. */
1024 sigemptyset (&sigset); 362 cpu_gc_count += current_sample_interval;
1025 sigaddset (&sigset, SIGPROF); 363 else
1026 sigprocmask (SIG_BLOCK, &sigset, 0); 364 record_backtrace (XHASH_TABLE (cpu_log), current_sample_interval);
1027}
1028
1029static void
1030unblock_sigprof (void)
1031{
1032 sigset_t sigset;
1033 sigemptyset (&sigset);
1034 sigaddset (&sigset, SIGPROF);
1035 sigprocmask (SIG_UNBLOCK, &sigset, 0);
1036} 365}
1037 366
1038/* Record that the current backtrace allocated SIZE bytes. */ 367/* Record that the current backtrace allocated SIZE bytes. */
1039 368/* FIXME: Inline it everywhere! */
1040void 369void
1041malloc_probe (size_t size) 370malloc_probe (size_t size)
1042{ 371{
1043 if (memory_log) 372 if (HASH_TABLE_P (memory_log))
1044 record_backtrace (memory_log, size, 0); 373 record_backtrace (XHASH_TABLE (memory_log), size);
1045}
1046
1047/* Record that GC happened in the current backtrace. */
1048
1049void
1050gc_probe (size_t size, size_t elapsed)
1051{
1052 if (sample_log)
1053 record_backtrace_under (sample_log, Qgc, 1, elapsed);
1054 if (memory_log)
1055 record_backtrace_under (memory_log, Qgc, size, elapsed);
1056}
1057
1058
1059
1060void
1061mark_profiler (void)
1062{
1063 if (sample_log)
1064 {
1065 if (sample_profiler_running)
1066 {
1067 block_sigprof ();
1068 mark_log (sample_log);
1069 unblock_sigprof ();
1070 }
1071 else
1072 mark_log (sample_log);
1073 }
1074 if (memory_log)
1075 mark_log (memory_log);
1076} 374}
1077 375
1078void 376void
1079syms_of_profiler (void) 377syms_of_profiler (void)
1080{ 378{
1081 DEFSYM (Qgc, "gc");
1082
1083 DEFVAR_INT ("profiler-max-stack-depth", profiler_max_stack_depth, 379 DEFVAR_INT ("profiler-max-stack-depth", profiler_max_stack_depth,
1084 doc: /* FIXME */); 380 doc: /* FIXME */);
1085 profiler_max_stack_depth = 16; 381 profiler_max_stack_depth = 16;
@@ -1087,17 +383,19 @@ syms_of_profiler (void)
1087 doc: /* FIXME */); 383 doc: /* FIXME */);
1088 profiler_slot_heap_size = 10000; 384 profiler_slot_heap_size = 10000;
1089 385
1090 defsubr (&Sprofiler_set_filter_pattern); 386 cpu_log = memory_log = Qnil;
387 staticpro (&cpu_log);
388 staticpro (&memory_log);
1091 389
390 /* FIXME: Rename things to start with "profiler-", to use "cpu" instead of
391 "sample", and to make them sound like they're internal or something. */
1092 defsubr (&Ssample_profiler_start); 392 defsubr (&Ssample_profiler_start);
1093 defsubr (&Ssample_profiler_stop); 393 defsubr (&Ssample_profiler_stop);
1094 defsubr (&Ssample_profiler_reset);
1095 defsubr (&Ssample_profiler_running_p); 394 defsubr (&Ssample_profiler_running_p);
1096 defsubr (&Ssample_profiler_log); 395 defsubr (&Ssample_profiler_log);
1097 396
1098 defsubr (&Smemory_profiler_start); 397 defsubr (&Smemory_profiler_start);
1099 defsubr (&Smemory_profiler_stop); 398 defsubr (&Smemory_profiler_stop);
1100 defsubr (&Smemory_profiler_reset);
1101 defsubr (&Smemory_profiler_running_p); 399 defsubr (&Smemory_profiler_running_p);
1102 defsubr (&Smemory_profiler_log); 400 defsubr (&Smemory_profiler_log);
1103} 401}
diff --git a/src/xdisp.c b/src/xdisp.c
index f5edb4b16f8..ccfa251fd1c 100644
--- a/src/xdisp.c
+++ b/src/xdisp.c
@@ -333,10 +333,10 @@ static Lisp_Object Qinhibit_eval_during_redisplay;
333static Lisp_Object Qbuffer_position, Qposition, Qobject; 333static Lisp_Object Qbuffer_position, Qposition, Qobject;
334static Lisp_Object Qright_to_left, Qleft_to_right; 334static Lisp_Object Qright_to_left, Qleft_to_right;
335 335
336/* Cursor shapes */ 336/* Cursor shapes. */
337Lisp_Object Qbar, Qhbar, Qbox, Qhollow; 337Lisp_Object Qbar, Qhbar, Qbox, Qhollow;
338 338
339/* Pointer shapes */ 339/* Pointer shapes. */
340static Lisp_Object Qarrow, Qhand; 340static Lisp_Object Qarrow, Qhand;
341Lisp_Object Qtext; 341Lisp_Object Qtext;
342 342
@@ -347,6 +347,7 @@ static Lisp_Object Qfontification_functions;
347 347
348static Lisp_Object Qwrap_prefix; 348static Lisp_Object Qwrap_prefix;
349static Lisp_Object Qline_prefix; 349static Lisp_Object Qline_prefix;
350static Lisp_Object Qautomatic_redisplay;
350 351
351/* Non-nil means don't actually do any redisplay. */ 352/* Non-nil means don't actually do any redisplay. */
352 353
@@ -12931,12 +12932,13 @@ redisplay_internal (void)
12931 struct frame *sf; 12932 struct frame *sf;
12932 int polling_stopped_here = 0; 12933 int polling_stopped_here = 0;
12933 Lisp_Object old_frame = selected_frame; 12934 Lisp_Object old_frame = selected_frame;
12935 struct backtrace backtrace;
12934 12936
12935 /* Non-zero means redisplay has to consider all windows on all 12937 /* Non-zero means redisplay has to consider all windows on all
12936 frames. Zero means, only selected_window is considered. */ 12938 frames. Zero means, only selected_window is considered. */
12937 int consider_all_windows_p; 12939 int consider_all_windows_p;
12938 12940
12939 /* Non-zero means redisplay has to redisplay the miniwindow */ 12941 /* Non-zero means redisplay has to redisplay the miniwindow. */
12940 int update_miniwindow_p = 0; 12942 int update_miniwindow_p = 0;
12941 12943
12942 TRACE ((stderr, "redisplay_internal %d\n", redisplaying_p)); 12944 TRACE ((stderr, "redisplay_internal %d\n", redisplaying_p));
@@ -12974,6 +12976,14 @@ redisplay_internal (void)
12974 ++redisplaying_p; 12976 ++redisplaying_p;
12975 specbind (Qinhibit_free_realized_faces, Qnil); 12977 specbind (Qinhibit_free_realized_faces, Qnil);
12976 12978
12979 /* Record this function, so it appears on the profiler's backtraces. */
12980 backtrace.next = backtrace_list;
12981 backtrace.function = &Qautomatic_redisplay;
12982 backtrace.args = &Qautomatic_redisplay;
12983 backtrace.nargs = 0;
12984 backtrace.debug_on_exit = 0;
12985 backtrace_list = &backtrace;
12986
12977 { 12987 {
12978 Lisp_Object tail, frame; 12988 Lisp_Object tail, frame;
12979 12989
@@ -13671,6 +13681,7 @@ redisplay_internal (void)
13671#endif /* HAVE_WINDOW_SYSTEM */ 13681#endif /* HAVE_WINDOW_SYSTEM */
13672 13682
13673 end_of_redisplay: 13683 end_of_redisplay:
13684 backtrace_list = backtrace.next;
13674 unbind_to (count, Qnil); 13685 unbind_to (count, Qnil);
13675 RESUME_POLLING; 13686 RESUME_POLLING;
13676} 13687}
@@ -28696,6 +28707,7 @@ syms_of_xdisp (void)
28696 staticpro (&Vmessage_stack); 28707 staticpro (&Vmessage_stack);
28697 28708
28698 DEFSYM (Qinhibit_redisplay, "inhibit-redisplay"); 28709 DEFSYM (Qinhibit_redisplay, "inhibit-redisplay");
28710 DEFSYM (Qautomatic_redisplay, "Automatic Redisplay");
28699 28711
28700 message_dolog_marker1 = Fmake_marker (); 28712 message_dolog_marker1 = Fmake_marker ();
28701 staticpro (&message_dolog_marker1); 28713 staticpro (&message_dolog_marker1);