unofficial mirror of emacs-devel@gnu.org 
 help / color / mirror / code / Atom feed
blob bf8aacccc37a8f8af3a76aed1245238bd0754a19 33278 bytes (raw)
name: lisp/profiler.el 	 # note: path name is non-authoritative(*)

  1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
683
684
685
686
687
688
689
690
691
692
693
694
695
696
697
698
699
700
701
702
703
704
705
706
707
708
709
710
711
712
713
714
715
716
717
718
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
734
735
736
737
738
739
740
741
742
743
744
745
746
747
748
749
750
751
752
753
754
755
756
757
758
759
760
761
762
763
764
765
766
767
768
769
770
771
772
773
774
775
776
777
778
779
780
781
782
783
784
785
786
787
788
789
790
791
792
793
794
795
796
797
798
799
800
801
802
803
804
805
806
807
808
809
810
811
812
813
814
815
816
817
818
819
820
821
822
823
824
825
826
827
828
829
830
831
832
833
834
835
836
837
838
839
840
841
842
843
844
845
846
847
848
849
850
851
852
853
854
855
856
857
858
859
860
861
862
863
864
865
866
867
868
869
870
871
872
873
874
875
876
877
878
879
880
881
882
883
884
885
886
887
888
889
890
891
892
893
894
895
896
897
898
899
900
901
902
903
904
905
906
907
908
909
910
911
912
913
914
915
916
917
918
919
920
921
922
923
 
;;; profiler.el --- UI and helper functions for Emacs's native profiler -*- lexical-binding: t -*-

;; Copyright (C) 2012-2020 Free Software Foundation, Inc.

;; Author: Tomohiro Matsuyama <tomo@cx4a.org>
;; Keywords: lisp

;; This file is part of GNU Emacs.

;; GNU Emacs is free software: you can redistribute it and/or modify
;; it under the terms of the GNU General Public License as published by
;; the Free Software Foundation, either version 3 of the License, or
;; (at your option) any later version.

;; GNU Emacs is distributed in the hope that it will be useful,
;; but WITHOUT ANY WARRANTY; without even the implied warranty of
;; MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
;; GNU General Public License for more details.

;; You should have received a copy of the GNU General Public License
;; along with GNU Emacs.  If not, see <https://www.gnu.org/licenses/>.

;;; Commentary:

;; See Info node `(elisp)Profiling'.

;;; Code:

(require 'cl-lib)

(defgroup profiler nil
  "Emacs profiler."
  :group 'lisp
  :version "24.3"
  :prefix "profiler-")

(defconst profiler-version "24.3")

(defcustom profiler-sampling-interval 1000000
  "Default sampling interval in nanoseconds."
  :type 'integer
  :group 'profiler)

\f
;;; Utilities

(defun profiler-ensure-string (object)
  (cond ((stringp object)
	 object)
	((symbolp object)
	 (symbol-name object))
	((numberp object)
	 (number-to-string object))
	(t
	 (format "%s" object))))

(defun profiler-format-percent (number divisor)
  (format "%d%%" (floor (* 100.0 number) divisor)))

(defun profiler-format-number (number)
  "Format NUMBER in human readable string."
  (if (and (integerp number) (> number 0))
      (cl-loop with i = (% (1+ (floor (log number 10))) 3)
	       for c in (append (number-to-string number) nil)
	       if (= i 0)
	       collect ?, into s
	       and do (setq i 3)
	       collect c into s
	       do (cl-decf i)
	       finally return
	       (apply 'string (if (eq (car s) ?,) (cdr s) s)))
    (profiler-ensure-string number)))

(defun profiler-format (fmt &rest args)
  (cl-loop for (width align subfmt) in fmt
	   for arg in args
	   for str = (cond
		      ((consp subfmt)
		       (apply 'profiler-format subfmt arg))
		      ((stringp subfmt)
		       (format subfmt arg))
		      ((and (symbolp subfmt)
			    (fboundp subfmt))
		       (funcall subfmt arg))
		      (t
		       (profiler-ensure-string arg)))
	   for len = (length str)
	   if (< width len)
           collect (progn (put-text-property (max 0 (- width 2)) len
                                             'invisible 'profiler str)
                          str) into frags
	   else
	   collect
           (let ((padding (make-string (max 0 (- width len)) ?\s)))
	     (cl-ecase align
	       (left (concat str padding))
	       (right (concat padding str))))
	   into frags
	   finally return (apply #'concat frags)))

\f
;;; Entries

(defun profiler-format-entry (entry)
  "Format ENTRY in human readable string.  ENTRY would be a
function name of a function itself."
  (cond ((memq (car-safe entry) '(closure lambda))
	 (format "#<lambda %#x>" (sxhash entry)))
	((byte-code-function-p entry)
	 (format "#<compiled %#x>" (sxhash entry)))
	((or (subrp entry) (symbolp entry) (stringp entry))
	 (format "%s" entry))
	(t
	 (format "#<unknown %#x>" (sxhash entry)))))

(defun profiler-fixup-entry (entry)
  (if (symbolp entry)
      entry
    (profiler-format-entry entry)))

\f
;;; Backtraces

(defun profiler-fixup-backtrace (backtrace)
  (apply 'vector (mapcar 'profiler-fixup-entry backtrace)))

\f
;;; Logs

;; The C code returns the log in the form of a hash-table where the keys are
;; vectors (of size profiler-max-stack-depth, holding truncated
;; backtraces, where the first element is the top of the stack) and
;; the values are integers (which count how many times this backtrace
;; has been seen, multiplied by a "weight factor" which is either the
;; sampling-interval or the memory being allocated).

(defun profiler-compare-logs (log1 log2)
  "Compare LOG1 with LOG2 and return diff."
  (let ((newlog (make-hash-table :test 'equal)))
    ;; Make a copy of `log1' into `newlog'.
    (maphash (lambda (backtrace count) (puthash backtrace count newlog))
             log1)
    (maphash (lambda (backtrace count)
               (puthash backtrace (- (gethash backtrace log1 0) count)
                        newlog))
             log2)
    newlog))

(defun profiler-fixup-log (log)
  (let ((newlog (make-hash-table :test 'equal)))
    (maphash (lambda (backtrace count)
               (puthash (profiler-fixup-backtrace backtrace)
                        count newlog))
             log)
    newlog))

\f
;;; Profiles

(cl-defstruct (profiler-profile (:type vector)
                                (:constructor profiler-make-profile))
  (tag 'profiler-profile)
  (version profiler-version)
  ;; - `type' has a value indicating the kind of profile (`memory' or `cpu').
  ;; - `log' indicates the profile log.
  ;; - `timestamp' has a value giving the time when the profile was obtained.
  ;; - `diff-p' indicates if this profile represents a diff between two profiles.
  type log timestamp diff-p)

(defun profiler-compare-profiles (profile1 profile2)
  "Compare PROFILE1 with PROFILE2 and return diff."
  (unless (eq (profiler-profile-type profile1)
	      (profiler-profile-type profile2))
    (error "Can't compare different type of profiles"))
  (profiler-make-profile
   :type (profiler-profile-type profile1)
   :timestamp (current-time)
   :diff-p t
   :log (profiler-compare-logs
         (profiler-profile-log profile1)
         (profiler-profile-log profile2))))

(defun profiler-fixup-profile (profile)
  "Fixup PROFILE so that the profile could be serialized into file."
  (profiler-make-profile
   :type (profiler-profile-type profile)
   :timestamp (profiler-profile-timestamp profile)
   :diff-p (profiler-profile-diff-p profile)
   :log (profiler-fixup-log (profiler-profile-log profile))))

(defun profiler-write-profile (profile filename &optional confirm)
  "Write PROFILE into file FILENAME."
  (with-temp-buffer
    (let (print-level print-length)
      (print (profiler-fixup-profile profile)
             (current-buffer)))
    (write-file filename confirm)))

(defun profiler-read-profile (filename)
  "Read profile from file FILENAME."
  ;; FIXME: tag and version check
  (with-temp-buffer
    (insert-file-contents filename)
    (goto-char (point-min))
    (read (current-buffer))))

(defun profiler-running-p (&optional mode)
  "Return non-nil if the profiler is running.
Optional argument MODE means only check for the specified mode (cpu or mem)."
  (cond ((eq mode 'cpu) (and (fboundp 'profiler-cpu-running-p)
                             (profiler-cpu-running-p)))
        ((eq mode 'mem) (profiler-memory-running-p))
        (t (or (profiler-running-p 'cpu)
               (profiler-running-p 'mem)))))

(defvar profiler-cpu-log nil)
(defvar profiler-memory-log nil)

(defun profiler-cpu-profile ()
  "Return CPU profile."
  (profiler-make-profile
   :type 'cpu
   :timestamp (current-time)
   :log profiler-cpu-log))

(defun profiler-memory-profile ()
  "Return memory profile."
  (profiler-make-profile
   :type 'memory
   :timestamp (current-time)
   :log profiler-memory-log))

\f
;;; Calltrees

(cl-defstruct (profiler-calltree (:constructor profiler-make-calltree))
  entry
  (count 0) (count-percent "")
  parent children)

(defun profiler-calltree-leaf-p (tree)
  (null (profiler-calltree-children tree)))

(defun profiler-calltree-count< (a b)
  (cond ((eq (profiler-calltree-entry a) t) t)
	((eq (profiler-calltree-entry b) t) nil)
	(t (< (profiler-calltree-count a)
	      (profiler-calltree-count b)))))

(defun profiler-calltree-count> (a b)
  (not (profiler-calltree-count< a b)))

(defun profiler-calltree-depth (tree)
  (let ((d 0))
    (while (setq tree (profiler-calltree-parent tree))
      (cl-incf d))
    d))

(defun profiler-calltree-find (tree entry)
  "Return a child tree of ENTRY under TREE."
  (let (result (children (profiler-calltree-children tree)))
    (while (and children (null result))
      (let ((child (car children)))
	(when (function-equal (profiler-calltree-entry child) entry)
	  (setq result child))
	(setq children (cdr children))))
    result))

(defun profiler-calltree-walk (calltree function)
  (funcall function calltree)
  (dolist (child (profiler-calltree-children calltree))
    (profiler-calltree-walk child function)))

(defun profiler-calltree-build-1 (tree log &optional reverse)
  ;; This doesn't try to stitch up partial backtraces together.
  ;; We still use it for reverse calltrees, but for forward calltrees, we use
  ;; profiler-calltree-build-unified instead now.
  (maphash
   (lambda (backtrace count)
     (let ((node tree)
           (max (length backtrace)))
       (dotimes (i max)
         (let ((entry (aref backtrace (if reverse i (- max i 1)))))
           (when entry
             (let ((child (profiler-calltree-find node entry)))
               (unless child
                 (setq child (profiler-make-calltree
                              :entry entry :parent node))
                 (push child (profiler-calltree-children node)))
               (cl-incf (profiler-calltree-count child) count)
               (setq node child)))))))
   log))


(define-hash-table-test 'profiler-function-equal #'function-equal
  (lambda (f) (cond
          ((byte-code-function-p f) (aref f 1))
          ((eq (car-safe f) 'closure) (cddr f))
          (t f))))

(defun profiler-calltree-build-unified (tree log)
  ;; Let's try to unify all those partial backtraces into a single
  ;; call tree.  First, we record in fun-map all the functions that appear
  ;; in `log' and where they appear.
  (let ((fun-map (make-hash-table :test 'profiler-function-equal))
        (parent-map (make-hash-table :test 'eq))
        (leftover-tree (profiler-make-calltree
                        :entry '... :parent tree)))
    (push leftover-tree (profiler-calltree-children tree))
    (maphash
     (lambda (backtrace _count)
       (let ((max (length backtrace)))
         ;; Don't record the head elements in there, since we want to use this
         ;; fun-map to find parents of partial backtraces, but parents only
         ;; make sense if they have something "above".
         (dotimes (i (1- max))
           (let ((f (aref backtrace i)))
             (when f
               (push (cons i backtrace) (gethash f fun-map)))))))
     log)
    ;; Then, for each partial backtrace, try to find a parent backtrace
    ;; (i.e. a backtrace that describes (part of) the truncated part of
    ;; the partial backtrace).  For a partial backtrace like "[f3 f2 f1]" (f3
    ;; is deeper), any backtrace that includes f1 could be a parent; and indeed
    ;; the counts of this partial backtrace could each come from a different
    ;; parent backtrace (some of which may not even be in `log').  So we should
    ;; consider each backtrace that includes f1 and give it some percentage of
    ;; `count'.  But we can't know for sure what percentage to give to each
    ;; possible parent.
    ;; The "right" way might be to give a percentage proportional to the counts
    ;; already registered for that parent, or some such statistical principle.
    ;; But instead, we will give all our counts to a single "best
    ;; matching" parent.  So let's look for the best matching parent, and store
    ;; the result in parent-map.
    ;; Using the "best matching parent" is important also to try and avoid
    ;; stitching together backtraces that can't possibly go together.
    ;; For example, when the head is `apply' (or `mapcar', ...), we want to
    ;; make sure we don't just use any parent that calls `apply', since most of
    ;; them would never, in turn, cause apply to call the subsequent function.
    (maphash
     (lambda (backtrace _count)
       (let* ((max (1- (length backtrace)))
              (head (aref backtrace max))
              (best-parent nil)
              (best-match (1+ max))
              (parents (gethash head fun-map)))
         (pcase-dolist (`(,i . ,parent) parents)
           (when t ;; (<= (- max i) best-match) ;Else, it can't be better.
             (let ((match max)
                   (imatch i))
               (cl-assert (>= match imatch))
               (cl-assert (function-equal (aref backtrace max)
                                          (aref parent i)))
               (while (progn
                        (cl-decf imatch) (cl-decf match)
                        (when (> imatch 0)
                          (function-equal (aref backtrace match)
                                          (aref parent imatch)))))
               (when (< match best-match)
                 (cl-assert (<= (- max i) best-match))
                 ;; Let's make sure this parent is not already our child: we
                 ;; don't want cycles here!
                 (let ((valid t)
                       (tmp-parent parent))
                   (while (setq tmp-parent
                                (if (eq tmp-parent backtrace)
                                    (setq valid nil)
                                  (cdr (gethash tmp-parent parent-map)))))
                   (when valid
                     (setq best-match match)
                     (setq best-parent (cons i parent))))))))
         (puthash backtrace best-parent parent-map)))
     log)
    ;; Now we have a single parent per backtrace, so we have a unified tree.
    ;; Let's build the actual call-tree from it.
    (maphash
     (lambda (backtrace count)
       (let ((node tree)
             (parents (list (cons -1 backtrace)))
             (tmp backtrace)
             (max (length backtrace)))
         (while (setq tmp (gethash tmp parent-map))
           (push tmp parents)
           (setq tmp (cdr tmp)))
         (when (aref (cdar parents) (1- max))
           (cl-incf (profiler-calltree-count leftover-tree) count)
           (setq node leftover-tree))
         (pcase-dolist (`(,i . ,parent) parents)
           (let ((j (1- max)))
             (while (> j i)
               (let ((f (aref parent j)))
                 (cl-decf j)
                 (when f
                   (let ((child (profiler-calltree-find node f)))
                     (unless child
                       (setq child (profiler-make-calltree
                                    :entry f :parent node))
                       (push child (profiler-calltree-children node)))
                     (cl-incf (profiler-calltree-count child) count)
                     (setq node child)))))))))
     log)))

(defun profiler-calltree-compute-percentages (tree)
  (let ((total-count 0))
    ;; FIXME: the memory profiler's total wraps around all too easily!
    (dolist (child (profiler-calltree-children tree))
      (cl-incf total-count (profiler-calltree-count child)))
    (unless (zerop total-count)
      (profiler-calltree-walk
       tree (lambda (node)
              (setf (profiler-calltree-count-percent node)
                    (profiler-format-percent (profiler-calltree-count node)
                                             total-count)))))))

(cl-defun profiler-calltree-build (log &key reverse)
  (let ((tree (profiler-make-calltree)))
    (if reverse
        (profiler-calltree-build-1 tree log reverse)
      (profiler-calltree-build-unified tree log))
    (profiler-calltree-compute-percentages tree)
    tree))

(defun profiler-calltree-sort (tree predicate)
  (let ((children (profiler-calltree-children tree)))
    (setf (profiler-calltree-children tree) (sort children predicate))
    (dolist (child (profiler-calltree-children tree))
      (profiler-calltree-sort child predicate))))

\f
;;; Report rendering

(defcustom profiler-report-closed-mark "+"
  "An indicator of closed calltrees."
  :type 'string
  :group 'profiler)

(defcustom profiler-report-open-mark "-"
  "An indicator of open calltrees."
  :type 'string
  :group 'profiler)

(defcustom profiler-report-leaf-mark " "
  "An indicator of calltree leaves."
  :type 'string
  :group 'profiler)

(defvar profiler-report-cpu-line-format
  '((50 left)
    (24 right ((19 right)
	       (5 right)))))

(defvar profiler-report-memory-line-format
  '((55 left)
    (19 right ((14 right profiler-format-number)
	       (5 right)))))

(defvar-local profiler-report-profile nil
  "The current profile.")

(defvar-local profiler-report-reversed nil
  "True if calltree is rendered in bottom-up.  Do not touch this
variable directly.")

(defvar-local profiler-report-order nil
  "The value can be `ascending' or `descending'.  Do not touch
this variable directly.")

(defun profiler-report-make-entry-part (entry)
  (let ((string (cond
		 ((eq entry t)
		  "Others")
		 ((and (symbolp entry)
		       (fboundp entry))
		  (propertize (symbol-name entry)
			      'face 'link
                              'follow-link "\r"
			      'mouse-face 'highlight
			      'help-echo "\
mouse-2: jump to definition\n\
RET: expand or collapse"))
		 (t
		  (profiler-format-entry entry)))))
    (propertize string 'profiler-entry entry)))

(defun profiler-report-make-name-part (tree)
  (let* ((entry (profiler-calltree-entry tree))
	 (depth (profiler-calltree-depth tree))
	 (indent (make-string (* (1- depth) 1) ?\s))
	 (mark (if (profiler-calltree-leaf-p tree)
		   profiler-report-leaf-mark
		 profiler-report-closed-mark))
	 (entry (profiler-report-make-entry-part entry)))
    (format "%s%s %s" indent mark entry)))

(defun profiler-report-header-line-format (fmt &rest args)
  (let* ((header (apply #'profiler-format fmt args))
	 (escaped (replace-regexp-in-string "%" "%%" header)))
    (concat " " escaped)))

(defun profiler-report-line-format (tree)
  (let ((diff-p (profiler-profile-diff-p profiler-report-profile))
	(name-part (profiler-report-make-name-part tree))
	(count (profiler-calltree-count tree))
	(count-percent (profiler-calltree-count-percent tree)))
    (profiler-format (cl-ecase (profiler-profile-type profiler-report-profile)
		       (cpu profiler-report-cpu-line-format)
		       (memory profiler-report-memory-line-format))
		     name-part
		     (if diff-p
			 (list (if (> count 0)
				   (format "+%s" count)
				 count)
			       "")
		       (list count count-percent)))))

(defun profiler-report-insert-calltree (tree)
  (let ((line (profiler-report-line-format tree)))
    (insert (propertize (concat line "\n") 'calltree tree))))

(defun profiler-report-insert-calltree-children (tree)
  (mapc #'profiler-report-insert-calltree
	(profiler-calltree-children tree)))

\f
;;; Report mode

(defvar profiler-report-mode-map
  (let ((map (make-sparse-keymap)))
    (define-key map "n"	    'profiler-report-next-entry)
    (define-key map "p"	    'profiler-report-previous-entry)
    ;; I find it annoying more than helpful to not be able to navigate
    ;; normally with the cursor keys.  --Stef
    ;; (define-key map [down]  'profiler-report-next-entry)
    ;; (define-key map [up]    'profiler-report-previous-entry)
    (define-key map "\r"    'profiler-report-toggle-entry)
    (define-key map "\t"    'profiler-report-toggle-entry)
    (define-key map "i"     'profiler-report-toggle-entry)
    (define-key map "f"     'profiler-report-find-entry)
    (define-key map "j"     'profiler-report-find-entry)
    (define-key map [follow-link] 'mouse-face)
    (define-key map [mouse-2] 'profiler-report-find-entry)
    (define-key map "d"	    'profiler-report-describe-entry)
    (define-key map "C"	    'profiler-report-render-calltree)
    (define-key map "B"	    'profiler-report-render-reversed-calltree)
    (define-key map "A"	    'profiler-report-ascending-sort)
    (define-key map "D"	    'profiler-report-descending-sort)
    (define-key map "="	    'profiler-report-compare-profile)
    (define-key map (kbd "C-x C-w") 'profiler-report-write-profile)
    (easy-menu-define  profiler-report-menu map "Menu for Profiler Report mode."
      '("Profiler"
        ["Next Entry" profiler-report-next-entry :active t
         :help "Move to next entry"]
        ["Previous Entry" profiler-report-previous-entry :active t
         :help "Move to previous entry"]
        "--"
        ["Toggle Entry" profiler-report-toggle-entry
         :active (profiler-report-calltree-at-point)
         :help "Expand or collapse the current entry"]
        ["Find Entry" profiler-report-find-entry
         ;; FIXME should deactivate if not on a known function.
         :active (profiler-report-calltree-at-point)
         :help "Find the definition of the current entry"]
        ["Describe Entry" profiler-report-describe-entry
         :active (profiler-report-calltree-at-point)
         :help "Show the documentation of the current entry"]
        "--"
        ["Show Calltree" profiler-report-render-calltree
         :active profiler-report-reversed
         :help "Show calltree view"]
        ["Show Reversed Calltree" profiler-report-render-reversed-calltree
         :active (not profiler-report-reversed)
         :help "Show reversed calltree view"]
        ["Sort Ascending" profiler-report-ascending-sort
         :active (not (eq profiler-report-order 'ascending))
         :help "Sort calltree view in ascending order"]
        ["Sort Descending" profiler-report-descending-sort
         :active (not (eq profiler-report-order 'descending))
         :help "Sort calltree view in descending order"]
        "--"
        ["Compare Profile..." profiler-report-compare-profile :active t
         :help "Compare current profile with another"]
        ["Write Profile..." profiler-report-write-profile :active t
         :help "Write current profile to a file"]
        "--"
        ["Start Profiler" profiler-start :active (not (profiler-running-p))
         :help "Start profiling"]
        ["Stop Profiler" profiler-stop :active (profiler-running-p)
         :help "Stop profiling"]
        ["New Report" profiler-report :active (profiler-running-p)
         :help "Make a new report"]))
      map)
  "Keymap for `profiler-report-mode'.")

(defun profiler-report-make-buffer-name (profile)
  (format "*%s-Profiler-Report %s*"
          (cl-ecase (profiler-profile-type profile) (cpu 'CPU) (memory 'Memory))
          (format-time-string "%Y-%m-%d %T" (profiler-profile-timestamp profile))))

(defun profiler-report-setup-buffer-1 (profile)
  "Make a buffer for PROFILE and return it."
  (let* ((buf-name (profiler-report-make-buffer-name profile))
	 (buffer (get-buffer-create buf-name)))
    (with-current-buffer buffer
      (profiler-report-mode)
      (setq profiler-report-profile profile
	    profiler-report-reversed nil
	    profiler-report-order 'descending))
    buffer))

(defun profiler-report-setup-buffer (profile)
  "Make a buffer for PROFILE with rendering the profile and
return it."
  (let ((buffer (profiler-report-setup-buffer-1 profile)))
    (with-current-buffer buffer
      (profiler-report-render-calltree))
    buffer))

(defun profiler--xref-backend () 'elisp)

(define-derived-mode profiler-report-mode special-mode "Profiler-Report"
  "Profiler Report Mode."
  (add-to-invisibility-spec '(profiler . t))
  (add-hook 'xref-backend-functions #'profiler--xref-backend nil t)
  (setq buffer-read-only t
	buffer-undo-list t
	truncate-lines t))

\f
;;; Report commands

(defun profiler-report-calltree-at-point (&optional point)
  (get-text-property (or point (point)) 'calltree))

(defun profiler-report-move-to-entry ()
  (let ((point (next-single-property-change
                (line-beginning-position) 'profiler-entry)))
    (if point
	(goto-char point)
      (back-to-indentation))))

(defun profiler-report-next-entry ()
  "Move cursor to next entry."
  (interactive)
  (forward-line)
  (profiler-report-move-to-entry))

(defun profiler-report-previous-entry ()
  "Move cursor to previous entry."
  (interactive)
  (forward-line -1)
  (profiler-report-move-to-entry))

(defun profiler-report-expand-entry (&optional full)
  "Expand entry at point.
With a prefix argument, expand the whole subtree."
  (interactive "P")
  (save-excursion
    (beginning-of-line)
    (when (search-forward (concat profiler-report-closed-mark " ")
			  (line-end-position) t)
      (let ((tree (profiler-report-calltree-at-point)))
	(when tree
	  (let ((inhibit-read-only t))
	    (replace-match (concat profiler-report-open-mark " "))
	    (forward-line)
            (let ((first (point))
                  (last (copy-marker (point) t)))
              (profiler-report-insert-calltree-children tree)
              (when full
                (goto-char first)
                (while (< (point) last)
                  (profiler-report-expand-entry)
                  (forward-line 1))))
	    t))))))

(defun profiler-report-collapse-entry ()
  "Collapse entry at point."
  (interactive)
  (save-excursion
    (beginning-of-line)
    (when (search-forward (concat profiler-report-open-mark " ")
			  (line-end-position) t)
      (let* ((tree (profiler-report-calltree-at-point))
	     (depth (profiler-calltree-depth tree))
	     (start (line-beginning-position 2))
	     d)
	(when tree
	  (let ((inhibit-read-only t))
	    (replace-match (concat profiler-report-closed-mark " "))
	    (while (and (eq (forward-line) 0)
			(let ((child (get-text-property (point) 'calltree)))
			  (and child
			       (numberp (setq d (profiler-calltree-depth child)))))
			(> d depth)))
	    (delete-region start (line-beginning-position)))))
      t)))

(defun profiler-report-toggle-entry (&optional arg)
  "Expand entry at point if the tree is collapsed,
otherwise collapse.  With prefix argument, expand all subentries
below entry at point."
  (interactive "P")
  (or (profiler-report-expand-entry arg)
      (profiler-report-collapse-entry)))

(defun profiler-report-find-entry (&optional event)
  "Find entry at point."
  (interactive (list last-nonmenu-event))
  (with-current-buffer
      (if event (window-buffer (posn-window (event-start event)))
        (current-buffer))
    (and event (setq event (event-end event))
         (posn-set-point event))
    (let ((tree (profiler-report-calltree-at-point)))
      (when tree
        (let ((entry (profiler-calltree-entry tree)))
          (find-function entry))))))

(defun profiler-report-describe-entry ()
  "Describe entry at point."
  (interactive)
  (let ((tree (profiler-report-calltree-at-point)))
    (when tree
      (let ((entry (profiler-calltree-entry tree)))
	(require 'help-fns)
	(describe-function entry)))))

(cl-defun profiler-report-render-calltree-1
    (profile &key reverse (order 'descending))
  (let ((calltree (profiler-calltree-build
                   (profiler-profile-log profile)
                   :reverse reverse)))
    (setq header-line-format
	  (cl-ecase (profiler-profile-type profile)
	    (cpu
	     (profiler-report-header-line-format
	      profiler-report-cpu-line-format
	      "Function" (list "CPU samples" "%")))
	    (memory
	     (profiler-report-header-line-format
	      profiler-report-memory-line-format
	      "Function" (list "Bytes" "%")))))
    (let ((predicate (cl-ecase order
		       (ascending #'profiler-calltree-count<)
		       (descending #'profiler-calltree-count>))))
      (profiler-calltree-sort calltree predicate))
    (let ((inhibit-read-only t))
      (erase-buffer)
      (profiler-report-insert-calltree-children calltree)
      (goto-char (point-min))
      (profiler-report-move-to-entry))))

(defun profiler-report-rerender-calltree ()
  (profiler-report-render-calltree-1 profiler-report-profile
				     :reverse profiler-report-reversed
				     :order profiler-report-order))

(defun profiler-report-render-calltree ()
  "Render calltree view."
  (interactive)
  (setq profiler-report-reversed nil)
  (profiler-report-rerender-calltree))

(defun profiler-report-render-reversed-calltree ()
  "Render reversed calltree view."
  (interactive)
  (setq profiler-report-reversed t)
  (profiler-report-rerender-calltree))

(defun profiler-report-ascending-sort ()
  "Sort calltree view in ascending order."
  (interactive)
  (setq profiler-report-order 'ascending)
  (profiler-report-rerender-calltree))

(defun profiler-report-descending-sort ()
  "Sort calltree view in descending order."
  (interactive)
  (setq profiler-report-order 'descending)
  (profiler-report-rerender-calltree))

(defun profiler-report-profile (profile)
  (switch-to-buffer (profiler-report-setup-buffer profile)))

(defun profiler-report-profile-other-window (profile)
  (switch-to-buffer-other-window (profiler-report-setup-buffer profile)))

(defun profiler-report-profile-other-frame (profile)
  (switch-to-buffer-other-frame (profiler-report-setup-buffer profile)))

(defun profiler-report-compare-profile (buffer)
  "Compare the current profile with another."
  (interactive (list (read-buffer "Compare to: ")))
  (let* ((profile1 (with-current-buffer buffer profiler-report-profile))
	 (profile2 profiler-report-profile)
	 (diff-profile (profiler-compare-profiles profile1 profile2)))
    (profiler-report-profile diff-profile)))

(defun profiler-report-write-profile (filename &optional confirm)
  "Write the current profile into file FILENAME."
  (interactive
   (list (read-file-name "Write profile: " default-directory)
	 (not current-prefix-arg)))
  (profiler-write-profile profiler-report-profile
                          filename
                          confirm))

\f
;;; Profiler commands

;;;###autoload
(defun profiler-start (mode)
  "Start/restart profilers.
MODE can be one of `cpu', `mem', or `cpu+mem'.
If MODE is `cpu' or `cpu+mem', time-based profiler will be started.
Also, if MODE is `mem' or `cpu+mem', then memory profiler will be started."
  (interactive
   (list (if (not (fboundp 'profiler-cpu-start)) 'mem
           (intern (completing-read (format-prompt "Mode" "cpu")
                                    '("cpu" "mem" "cpu+mem")
                                    nil t nil nil "cpu")))))
  (cl-ecase mode
    (cpu
     (profiler-cpu-start profiler-sampling-interval)
     (message "CPU profiler started"))
    (mem
     (profiler-memory-start)
     (message "Memory profiler started"))
    (cpu+mem
     (profiler-cpu-start profiler-sampling-interval)
     (profiler-memory-start)
     (message "CPU and memory profiler started"))))

(defun profiler-stop ()
  "Stop started profilers.  Profiler logs will be kept."
  (interactive)
  (when (and (fboundp 'profiler-cpu-running-p)
             (profiler-cpu-running-p))
    (setq profiler-cpu-log (profiler-cpu-log)))
  (when (profiler-memory-running-p)
    (setq profiler-memory-log (profiler-memory-log)))
  (let ((cpu (when (fboundp 'profiler-cpu-stop) (profiler-cpu-stop)))
        (mem (profiler-memory-stop)))
    (message "%s profiler stopped"
             (cond ((and mem cpu) "CPU and memory")
                   (mem "Memory")
                   (cpu "CPU")
                   (t "No")))))

(defun profiler-reset ()
  "Reset profiler logs."
  (interactive)
  (when (and (fboundp 'profiler-cpu-running-p) (profiler-cpu-running-p))
    (profiler-cpu-stop))
  (when (profiler-memory-running-p)
    (profiler-memory-stop))
  (setq profiler-cpu-log nil
        profiler-memory-log nil))

(defun profiler-report-cpu ()
  (when profiler-cpu-log
    (profiler-report-profile-other-window (profiler-cpu-profile))))

(defun profiler-report-memory ()
  (when profiler-memory-log
    (profiler-report-profile-other-window (profiler-memory-profile))))

(defun profiler-report ()
  "Report profiling results."
  (interactive)
  (when (and (fboundp 'profiler-cpu-running-p) (profiler-cpu-running-p))
    (setq profiler-cpu-log (profiler-cpu-log)))
  (when (profiler-memory-running-p)
    (setq profiler-memory-log (profiler-memory-log)))
  (if (and (not profiler-cpu-log) (not profiler-memory-log))
      (user-error "No profiler run recorded")
    (profiler-report-cpu)
    (profiler-report-memory)))

;;;###autoload
(defun profiler-find-profile (filename)
  "Open profile FILENAME."
  (interactive
   (list (read-file-name "Find profile: " default-directory)))
  (profiler-report-profile (profiler-read-profile filename)))

;;;###autoload
(defun profiler-find-profile-other-window (filename)
  "Open profile FILENAME."
  (interactive
   (list (read-file-name "Find profile: " default-directory)))
  (profiler-report-profile-other-window (profiler-read-profile filename)))

;;;###autoload
(defun profiler-find-profile-other-frame (filename)
  "Open profile FILENAME."
  (interactive
   (list (read-file-name "Find profile: " default-directory)))
  (profiler-report-profile-other-frame(profiler-read-profile filename)))

\f
;;; Profiling helpers

;; (cl-defmacro with-cpu-profiling ((&key sampling-interval) &rest body)
;;   `(unwind-protect
;;        (progn
;;          (ignore (profiler-cpu-log))
;;          (profiler-cpu-start ,sampling-interval)
;;          ,@body)
;;      (profiler-cpu-stop)
;;      (profiler--report-cpu)))

;; (defmacro with-memory-profiling (&rest body)
;;   `(unwind-protect
;;        (progn
;;          (ignore (profiler-memory-log))
;;          (profiler-memory-start)
;;          ,@body)
;;      (profiler-memory-stop)
;;      (profiler--report-memory)))

(provide 'profiler)
;;; profiler.el ends here

debug log:

solving bf8aacccc3 ...
found bf8aacccc3 in https://git.savannah.gnu.org/cgit/emacs.git

(*) Git path names are given by the tree(s) the blob belongs to.
    Blobs themselves have no identifier aside from the hash of its contents.^

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/emacs.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).