diff options
| author | Stefan Monnier | 2013-10-08 23:32:35 -0400 |
|---|---|---|
| committer | Stefan Monnier | 2013-10-08 23:32:35 -0400 |
| commit | 79804536d8ccea5ed28745fae5650f3ec4805eda (patch) | |
| tree | dc88cce755bf9f8e72822f3c65f5849ef3c4b751 | |
| parent | 238150c8ff55ab6d74f0fdcc7f163c8ee98c3749 (diff) | |
| download | emacs-79804536d8ccea5ed28745fae5650f3ec4805eda.tar.gz emacs-79804536d8ccea5ed28745fae5650f3ec4805eda.zip | |
* lisp/profiler.el: Create a more coherent calltree from partial backtraces.
(profiler-format): Hide the tail with `invisible' so that C-s can still
find the hidden elements.
(profiler-calltree-depth): Don't recurse so enthusiastically.
(profiler-function-equal): New hash-table-test.
(profiler-calltree-build-unified): New function.
(profiler-calltree-build): Use it.
(profiler-report-make-name-part): Indent the calltree less.
(profiler-report-mode): Add visibility specs for profiler-format.
(profiler-report-expand-entry, profiler-report-toggle-entry):
Expand the whole subtree when provided with a prefix arg.
* src/fns.c (hashfn_user_defined): Allow hash functions to return any
Lisp_Object.
| -rw-r--r-- | lisp/ChangeLog | 14 | ||||
| -rw-r--r-- | lisp/profiler.el | 164 | ||||
| -rw-r--r-- | src/ChangeLog | 5 | ||||
| -rw-r--r-- | src/fns.c | 10 |
4 files changed, 166 insertions, 27 deletions
diff --git a/lisp/ChangeLog b/lisp/ChangeLog index 73bf12dfb4b..dbfd158f003 100644 --- a/lisp/ChangeLog +++ b/lisp/ChangeLog | |||
| @@ -1,3 +1,17 @@ | |||
| 1 | 2013-10-09 Stefan Monnier <monnier@iro.umontreal.ca> | ||
| 2 | |||
| 3 | * profiler.el: Create a more coherent calltree from partial backtraces. | ||
| 4 | (profiler-format): Hide the tail with `invisible' so that C-s can still | ||
| 5 | find the hidden elements. | ||
| 6 | (profiler-calltree-depth): Don't recurse so enthusiastically. | ||
| 7 | (profiler-function-equal): New hash-table-test. | ||
| 8 | (profiler-calltree-build-unified): New function. | ||
| 9 | (profiler-calltree-build): Use it. | ||
| 10 | (profiler-report-make-name-part): Indent the calltree less. | ||
| 11 | (profiler-report-mode): Add visibility specs for profiler-format. | ||
| 12 | (profiler-report-expand-entry, profiler-report-toggle-entry): | ||
| 13 | Expand the whole subtree when provided with a prefix arg. | ||
| 14 | |||
| 1 | 2013-10-09 Dmitry Gutov <dgutov@yandex.ru> | 15 | 2013-10-09 Dmitry Gutov <dgutov@yandex.ru> |
| 2 | 16 | ||
| 3 | * progmodes/ruby-mode.el (ruby-smie-rules): Indent after hanging | 17 | * progmodes/ruby-mode.el (ruby-smie-rules): Indent after hanging |
diff --git a/lisp/profiler.el b/lisp/profiler.el index 93ab10015ea..84c377e9c9d 100644 --- a/lisp/profiler.el +++ b/lisp/profiler.el | |||
| @@ -27,6 +27,7 @@ | |||
| 27 | ;;; Code: | 27 | ;;; Code: |
| 28 | 28 | ||
| 29 | (require 'cl-lib) | 29 | (require 'cl-lib) |
| 30 | (require 'pcase) | ||
| 30 | 31 | ||
| 31 | (defgroup profiler nil | 32 | (defgroup profiler nil |
| 32 | "Emacs profiler." | 33 | "Emacs profiler." |
| @@ -86,10 +87,12 @@ | |||
| 86 | (profiler-ensure-string arg))) | 87 | (profiler-ensure-string arg))) |
| 87 | for len = (length str) | 88 | for len = (length str) |
| 88 | if (< width len) | 89 | if (< width len) |
| 89 | collect (substring str 0 width) into frags | 90 | collect (progn (put-text-property (max 0 (- width 2)) len |
| 91 | 'invisible 'profiler str) | ||
| 92 | str) into frags | ||
| 90 | else | 93 | else |
| 91 | collect | 94 | collect |
| 92 | (let ((padding (make-string (- width len) ?\s))) | 95 | (let ((padding (make-string (max 0 (- width len)) ?\s))) |
| 93 | (cl-ecase align | 96 | (cl-ecase align |
| 94 | (left (concat str padding)) | 97 | (left (concat str padding)) |
| 95 | (right (concat padding str)))) | 98 | (right (concat padding str)))) |
| @@ -248,10 +251,10 @@ Optional argument MODE means only check for the specified mode (cpu or mem)." | |||
| 248 | (not (profiler-calltree-count< a b))) | 251 | (not (profiler-calltree-count< a b))) |
| 249 | 252 | ||
| 250 | (defun profiler-calltree-depth (tree) | 253 | (defun profiler-calltree-depth (tree) |
| 251 | (let ((parent (profiler-calltree-parent tree))) | 254 | (let ((d 0)) |
| 252 | (if (null parent) | 255 | (while (setq tree (profiler-calltree-parent tree)) |
| 253 | 0 | 256 | (cl-incf d)) |
| 254 | (1+ (profiler-calltree-depth parent))))) | 257 | d)) |
| 255 | 258 | ||
| 256 | (defun profiler-calltree-find (tree entry) | 259 | (defun profiler-calltree-find (tree entry) |
| 257 | "Return a child tree of ENTRY under TREE." | 260 | "Return a child tree of ENTRY under TREE." |
| @@ -269,10 +272,9 @@ Optional argument MODE means only check for the specified mode (cpu or mem)." | |||
| 269 | (profiler-calltree-walk child function))) | 272 | (profiler-calltree-walk child function))) |
| 270 | 273 | ||
| 271 | (defun profiler-calltree-build-1 (tree log &optional reverse) | 274 | (defun profiler-calltree-build-1 (tree log &optional reverse) |
| 272 | ;; FIXME: Do a better job of reconstructing a complete call-tree | 275 | ;; This doesn't try to stitch up partial backtraces together. |
| 273 | ;; when the backtraces have been truncated. Ideally, we should be | 276 | ;; We still use it for reverse calltrees, but for forward calltrees, we use |
| 274 | ;; able to reduce profiler-max-stack-depth to 3 or 4 and still | 277 | ;; profiler-calltree-build-unified instead now. |
| 275 | ;; get a meaningful call-tree. | ||
| 276 | (maphash | 278 | (maphash |
| 277 | (lambda (backtrace count) | 279 | (lambda (backtrace count) |
| 278 | (let ((node tree) | 280 | (let ((node tree) |
| @@ -289,6 +291,115 @@ Optional argument MODE means only check for the specified mode (cpu or mem)." | |||
| 289 | (setq node child))))))) | 291 | (setq node child))))))) |
| 290 | log)) | 292 | log)) |
| 291 | 293 | ||
| 294 | |||
| 295 | (define-hash-table-test 'profiler-function-equal #'function-equal | ||
| 296 | (lambda (f) (cond | ||
| 297 | ((byte-code-function-p f) (aref f 1)) | ||
| 298 | ((eq (car-safe f) 'closure) (cddr f)) | ||
| 299 | (t f)))) | ||
| 300 | |||
| 301 | (defun profiler-calltree-build-unified (tree log) | ||
| 302 | ;; Let's try to unify all those partial backtraces into a single | ||
| 303 | ;; call tree. First, we record in fun-map all the functions that appear | ||
| 304 | ;; in `log' and where they appear. | ||
| 305 | (let ((fun-map (make-hash-table :test 'profiler-function-equal)) | ||
| 306 | (parent-map (make-hash-table :test 'eq)) | ||
| 307 | (leftover-tree (profiler-make-calltree | ||
| 308 | :entry (intern "...") :parent tree))) | ||
| 309 | (push leftover-tree (profiler-calltree-children tree)) | ||
| 310 | (maphash | ||
| 311 | (lambda (backtrace _count) | ||
| 312 | (let ((max (length backtrace))) | ||
| 313 | ;; Don't record the head elements in there, since we want to use this | ||
| 314 | ;; fun-map to find parents of partial backtraces, but parents only | ||
| 315 | ;; make sense if they have something "above". | ||
| 316 | (dotimes (i (1- max)) | ||
| 317 | (let ((f (aref backtrace i))) | ||
| 318 | (when f | ||
| 319 | (push (cons i backtrace) (gethash f fun-map))))))) | ||
| 320 | log) | ||
| 321 | ;; Then, for each partial backtrace, try to find a parent backtrace | ||
| 322 | ;; (i.e. a backtrace that describes (part of) the truncated part of | ||
| 323 | ;; the partial backtrace). For a partial backtrace like "[f3 f2 f1]" (f3 | ||
| 324 | ;; is deeper), any backtrace that includes f1 could be a parent; and indeed | ||
| 325 | ;; the counts of this partial backtrace could each come from a different | ||
| 326 | ;; parent backtrace (some of which may not even be in `log'). So we should | ||
| 327 | ;; consider each backtrace that includes f1 and give it some percentage of | ||
| 328 | ;; `count'. But we can't know for sure what percentage to give to each | ||
| 329 | ;; possible parent. | ||
| 330 | ;; The "right" way might be to give a percentage proportional to the counts | ||
| 331 | ;; already registered for that parent, or some such statistical principle. | ||
| 332 | ;; But instead, we will give all our counts to a single "best | ||
| 333 | ;; matching" parent. So let's look for the best matching parent, and store | ||
| 334 | ;; the result in parent-map. | ||
| 335 | ;; Using the "best matching parent" is important also to try and avoid | ||
| 336 | ;; stitching together backtraces that can't possibly go together. | ||
| 337 | ;; For example, when the head is `apply' (or `mapcar', ...), we want to | ||
| 338 | ;; make sure we don't just use any parent that calls `apply', since most of | ||
| 339 | ;; them would never, in turn, cause apply to call the subsequent function. | ||
| 340 | (maphash | ||
| 341 | (lambda (backtrace _count) | ||
| 342 | (let* ((max (1- (length backtrace))) | ||
| 343 | (head (aref backtrace max)) | ||
| 344 | (best-parent nil) | ||
| 345 | (best-match (1+ max)) | ||
| 346 | (parents (gethash head fun-map))) | ||
| 347 | (pcase-dolist (`(,i . ,parent) parents) | ||
| 348 | (when t ;; (<= (- max i) best-match) ;Else, it can't be better. | ||
| 349 | (let ((match max) | ||
| 350 | (imatch i)) | ||
| 351 | (cl-assert (>= match imatch)) | ||
| 352 | (cl-assert (function-equal (aref backtrace max) | ||
| 353 | (aref parent i))) | ||
| 354 | (while (progn | ||
| 355 | (cl-decf imatch) (cl-decf match) | ||
| 356 | (when (> imatch 0) | ||
| 357 | (function-equal (aref backtrace match) | ||
| 358 | (aref parent imatch))))) | ||
| 359 | (when (< match best-match) | ||
| 360 | (cl-assert (<= (- max i) best-match)) | ||
| 361 | ;; Let's make sure this parent is not already our child: we | ||
| 362 | ;; don't want cycles here! | ||
| 363 | (let ((valid t) | ||
| 364 | (tmp-parent parent)) | ||
| 365 | (while (setq tmp-parent | ||
| 366 | (if (eq tmp-parent backtrace) | ||
| 367 | (setq valid nil) | ||
| 368 | (cdr (gethash tmp-parent parent-map))))) | ||
| 369 | (when valid | ||
| 370 | (setq best-match match) | ||
| 371 | (setq best-parent (cons i parent)))))))) | ||
| 372 | (puthash backtrace best-parent parent-map))) | ||
| 373 | log) | ||
| 374 | ;; Now we have a single parent per backtrace, so we have a unified tree. | ||
| 375 | ;; Let's build the actual call-tree from it. | ||
| 376 | (maphash | ||
| 377 | (lambda (backtrace count) | ||
| 378 | (let ((node tree) | ||
| 379 | (parents (list (cons -1 backtrace))) | ||
| 380 | (tmp backtrace) | ||
| 381 | (max (length backtrace))) | ||
| 382 | (while (setq tmp (gethash tmp parent-map)) | ||
| 383 | (push tmp parents) | ||
| 384 | (setq tmp (cdr tmp))) | ||
| 385 | (when (aref (cdar parents) (1- max)) | ||
| 386 | (cl-incf (profiler-calltree-count leftover-tree) count) | ||
| 387 | (setq node leftover-tree)) | ||
| 388 | (pcase-dolist (`(,i . ,parent) parents) | ||
| 389 | (let ((j (1- max))) | ||
| 390 | (while (> j i) | ||
| 391 | (let ((f (aref parent j))) | ||
| 392 | (cl-decf j) | ||
| 393 | (when f | ||
| 394 | (let ((child (profiler-calltree-find node f))) | ||
| 395 | (unless child | ||
| 396 | (setq child (profiler-make-calltree | ||
| 397 | :entry f :parent node)) | ||
| 398 | (push child (profiler-calltree-children node))) | ||
| 399 | (cl-incf (profiler-calltree-count child) count) | ||
| 400 | (setq node child))))))))) | ||
| 401 | log))) | ||
| 402 | |||
| 292 | (defun profiler-calltree-compute-percentages (tree) | 403 | (defun profiler-calltree-compute-percentages (tree) |
| 293 | (let ((total-count 0)) | 404 | (let ((total-count 0)) |
| 294 | ;; FIXME: the memory profiler's total wraps around all too easily! | 405 | ;; FIXME: the memory profiler's total wraps around all too easily! |
| @@ -303,7 +414,9 @@ Optional argument MODE means only check for the specified mode (cpu or mem)." | |||
| 303 | 414 | ||
| 304 | (cl-defun profiler-calltree-build (log &key reverse) | 415 | (cl-defun profiler-calltree-build (log &key reverse) |
| 305 | (let ((tree (profiler-make-calltree))) | 416 | (let ((tree (profiler-make-calltree))) |
| 306 | (profiler-calltree-build-1 tree log reverse) | 417 | (if reverse |
| 418 | (profiler-calltree-build-1 tree log reverse) | ||
| 419 | (profiler-calltree-build-unified tree log)) | ||
| 307 | (profiler-calltree-compute-percentages tree) | 420 | (profiler-calltree-compute-percentages tree) |
| 308 | tree)) | 421 | tree)) |
| 309 | 422 | ||
| @@ -371,7 +484,7 @@ RET: expand or collapse")) | |||
| 371 | (defun profiler-report-make-name-part (tree) | 484 | (defun profiler-report-make-name-part (tree) |
| 372 | (let* ((entry (profiler-calltree-entry tree)) | 485 | (let* ((entry (profiler-calltree-entry tree)) |
| 373 | (depth (profiler-calltree-depth tree)) | 486 | (depth (profiler-calltree-depth tree)) |
| 374 | (indent (make-string (* (1- depth) 2) ?\s)) | 487 | (indent (make-string (* (1- depth) 1) ?\s)) |
| 375 | (mark (if (profiler-calltree-leaf-p tree) | 488 | (mark (if (profiler-calltree-leaf-p tree) |
| 376 | profiler-report-leaf-mark | 489 | profiler-report-leaf-mark |
| 377 | profiler-report-closed-mark)) | 490 | profiler-report-closed-mark)) |
| @@ -379,7 +492,7 @@ RET: expand or collapse")) | |||
| 379 | (format "%s%s %s" indent mark entry))) | 492 | (format "%s%s %s" indent mark entry))) |
| 380 | 493 | ||
| 381 | (defun profiler-report-header-line-format (fmt &rest args) | 494 | (defun profiler-report-header-line-format (fmt &rest args) |
| 382 | (let* ((header (apply 'profiler-format fmt args)) | 495 | (let* ((header (apply #'profiler-format fmt args)) |
| 383 | (escaped (replace-regexp-in-string "%" "%%" header))) | 496 | (escaped (replace-regexp-in-string "%" "%%" header))) |
| 384 | (concat " " escaped))) | 497 | (concat " " escaped))) |
| 385 | 498 | ||
| @@ -404,7 +517,7 @@ RET: expand or collapse")) | |||
| 404 | (insert (propertize (concat line "\n") 'calltree tree)))) | 517 | (insert (propertize (concat line "\n") 'calltree tree)))) |
| 405 | 518 | ||
| 406 | (defun profiler-report-insert-calltree-children (tree) | 519 | (defun profiler-report-insert-calltree-children (tree) |
| 407 | (mapc 'profiler-report-insert-calltree | 520 | (mapc #'profiler-report-insert-calltree |
| 408 | (profiler-calltree-children tree))) | 521 | (profiler-calltree-children tree))) |
| 409 | 522 | ||
| 410 | 523 | ||
| @@ -502,6 +615,7 @@ return it." | |||
| 502 | 615 | ||
| 503 | (define-derived-mode profiler-report-mode special-mode "Profiler-Report" | 616 | (define-derived-mode profiler-report-mode special-mode "Profiler-Report" |
| 504 | "Profiler Report Mode." | 617 | "Profiler Report Mode." |
| 618 | (add-to-invisibility-spec '(profiler . t)) | ||
| 505 | (setq buffer-read-only t | 619 | (setq buffer-read-only t |
| 506 | buffer-undo-list t | 620 | buffer-undo-list t |
| 507 | truncate-lines t)) | 621 | truncate-lines t)) |
| @@ -531,9 +645,10 @@ return it." | |||
| 531 | (forward-line -1) | 645 | (forward-line -1) |
| 532 | (profiler-report-move-to-entry)) | 646 | (profiler-report-move-to-entry)) |
| 533 | 647 | ||
| 534 | (defun profiler-report-expand-entry () | 648 | (defun profiler-report-expand-entry (&optional full) |
| 535 | "Expand entry at point." | 649 | "Expand entry at point. |
| 536 | (interactive) | 650 | With a prefix argument, expand the whole subtree." |
| 651 | (interactive "P") | ||
| 537 | (save-excursion | 652 | (save-excursion |
| 538 | (beginning-of-line) | 653 | (beginning-of-line) |
| 539 | (when (search-forward (concat profiler-report-closed-mark " ") | 654 | (when (search-forward (concat profiler-report-closed-mark " ") |
| @@ -543,7 +658,14 @@ return it." | |||
| 543 | (let ((inhibit-read-only t)) | 658 | (let ((inhibit-read-only t)) |
| 544 | (replace-match (concat profiler-report-open-mark " ")) | 659 | (replace-match (concat profiler-report-open-mark " ")) |
| 545 | (forward-line) | 660 | (forward-line) |
| 546 | (profiler-report-insert-calltree-children tree) | 661 | (let ((first (point)) |
| 662 | (last (copy-marker (point) t))) | ||
| 663 | (profiler-report-insert-calltree-children tree) | ||
| 664 | (when full | ||
| 665 | (goto-char first) | ||
| 666 | (while (< (point) last) | ||
| 667 | (profiler-report-expand-entry) | ||
| 668 | (forward-line 1)))) | ||
| 547 | t)))))) | 669 | t)))))) |
| 548 | 670 | ||
| 549 | (defun profiler-report-collapse-entry () | 671 | (defun profiler-report-collapse-entry () |
| @@ -568,11 +690,11 @@ return it." | |||
| 568 | (delete-region start (line-beginning-position))))) | 690 | (delete-region start (line-beginning-position))))) |
| 569 | t))) | 691 | t))) |
| 570 | 692 | ||
| 571 | (defun profiler-report-toggle-entry () | 693 | (defun profiler-report-toggle-entry (&optional arg) |
| 572 | "Expand entry at point if the tree is collapsed, | 694 | "Expand entry at point if the tree is collapsed, |
| 573 | otherwise collapse." | 695 | otherwise collapse." |
| 574 | (interactive) | 696 | (interactive "P") |
| 575 | (or (profiler-report-expand-entry) | 697 | (or (profiler-report-expand-entry arg) |
| 576 | (profiler-report-collapse-entry))) | 698 | (profiler-report-collapse-entry))) |
| 577 | 699 | ||
| 578 | (defun profiler-report-find-entry (&optional event) | 700 | (defun profiler-report-find-entry (&optional event) |
diff --git a/src/ChangeLog b/src/ChangeLog index 5196eb230d8..a205ea72b7f 100644 --- a/src/ChangeLog +++ b/src/ChangeLog | |||
| @@ -1,3 +1,8 @@ | |||
| 1 | 2013-10-09 Stefan Monnier <monnier@iro.umontreal.ca> | ||
| 2 | |||
| 3 | * fns.c (hashfn_user_defined): Allow hash functions to return any | ||
| 4 | Lisp_Object. | ||
| 5 | |||
| 1 | 2013-10-08 Paul Eggert <eggert@cs.ucla.edu> | 6 | 2013-10-08 Paul Eggert <eggert@cs.ucla.edu> |
| 2 | 7 | ||
| 3 | Fix minor problems found by static checking. | 8 | Fix minor problems found by static checking. |
| @@ -3571,9 +3571,7 @@ hashfn_user_defined (struct hash_table_test *ht, Lisp_Object key) | |||
| 3571 | args[0] = ht->user_hash_function; | 3571 | args[0] = ht->user_hash_function; |
| 3572 | args[1] = key; | 3572 | args[1] = key; |
| 3573 | hash = Ffuncall (2, args); | 3573 | hash = Ffuncall (2, args); |
| 3574 | if (!INTEGERP (hash)) | 3574 | return hashfn_eq (ht, hash); |
| 3575 | signal_error ("Invalid hash code returned from user-supplied hash function", hash); | ||
| 3576 | return XUINT (hash); | ||
| 3577 | } | 3575 | } |
| 3578 | 3576 | ||
| 3579 | /* An upper bound on the size of a hash table index. It must fit in | 3577 | /* An upper bound on the size of a hash table index. It must fit in |
| @@ -4542,9 +4540,9 @@ compare keys, and HASH for computing hash codes of keys. | |||
| 4542 | 4540 | ||
| 4543 | TEST must be a function taking two arguments and returning non-nil if | 4541 | TEST must be a function taking two arguments and returning non-nil if |
| 4544 | both arguments are the same. HASH must be a function taking one | 4542 | both arguments are the same. HASH must be a function taking one |
| 4545 | argument and return an integer that is the hash code of the argument. | 4543 | argument and returning an object that is the hash code of the argument. |
| 4546 | Hash code computation should use the whole value range of integers, | 4544 | It should be the case that if (eq (funcall HASH x1) (funcall HASH x2)) |
| 4547 | including negative integers. */) | 4545 | returns nil, then (funcall TEST x1 x2) also returns nil. */) |
| 4548 | (Lisp_Object name, Lisp_Object test, Lisp_Object hash) | 4546 | (Lisp_Object name, Lisp_Object test, Lisp_Object hash) |
| 4549 | { | 4547 | { |
| 4550 | return Fput (name, Qhash_table_test, list2 (test, hash)); | 4548 | return Fput (name, Qhash_table_test, list2 (test, hash)); |