profiler.el 32 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908
  1. ;;; profiler.el --- UI and helper functions for Emacs's native profiler -*- lexical-binding: t -*-
  2. ;; Copyright (C) 2012-2017 Free Software Foundation, Inc.
  3. ;; Author: Tomohiro Matsuyama <tomo@cx4a.org>
  4. ;; Keywords: lisp
  5. ;; This file is part of GNU Emacs.
  6. ;; GNU Emacs is free software: you can redistribute it and/or modify
  7. ;; it under the terms of the GNU General Public License as published by
  8. ;; the Free Software Foundation, either version 3 of the License, or
  9. ;; (at your option) any later version.
  10. ;; GNU Emacs is distributed in the hope that it will be useful,
  11. ;; but WITHOUT ANY WARRANTY; without even the implied warranty of
  12. ;; MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  13. ;; GNU General Public License for more details.
  14. ;; You should have received a copy of the GNU General Public License
  15. ;; along with GNU Emacs. If not, see <http://www.gnu.org/licenses/>.
  16. ;;; Commentary:
  17. ;; See Info node `(elisp)Profiling'.
  18. ;;; Code:
  19. (require 'cl-lib)
  20. (defgroup profiler nil
  21. "Emacs profiler."
  22. :group 'lisp
  23. :version "24.3"
  24. :prefix "profiler-")
  25. (defconst profiler-version "24.3")
  26. (defcustom profiler-sampling-interval 1000000
  27. "Default sampling interval in nanoseconds."
  28. :type 'integer
  29. :group 'profiler)
  30. ;;; Utilities
  31. (defun profiler-ensure-string (object)
  32. (cond ((stringp object)
  33. object)
  34. ((symbolp object)
  35. (symbol-name object))
  36. ((numberp object)
  37. (number-to-string object))
  38. (t
  39. (format "%s" object))))
  40. (defun profiler-format-percent (number divisor)
  41. (format "%d%%" (floor (* 100.0 number) divisor)))
  42. (defun profiler-format-number (number)
  43. "Format NUMBER in human readable string."
  44. (if (and (integerp number) (> number 0))
  45. (cl-loop with i = (% (1+ (floor (log number 10))) 3)
  46. for c in (append (number-to-string number) nil)
  47. if (= i 0)
  48. collect ?, into s
  49. and do (setq i 3)
  50. collect c into s
  51. do (cl-decf i)
  52. finally return
  53. (apply 'string (if (eq (car s) ?,) (cdr s) s)))
  54. (profiler-ensure-string number)))
  55. (defun profiler-format (fmt &rest args)
  56. (cl-loop for (width align subfmt) in fmt
  57. for arg in args
  58. for str = (cond
  59. ((consp subfmt)
  60. (apply 'profiler-format subfmt arg))
  61. ((stringp subfmt)
  62. (format subfmt arg))
  63. ((and (symbolp subfmt)
  64. (fboundp subfmt))
  65. (funcall subfmt arg))
  66. (t
  67. (profiler-ensure-string arg)))
  68. for len = (length str)
  69. if (< width len)
  70. collect (progn (put-text-property (max 0 (- width 2)) len
  71. 'invisible 'profiler str)
  72. str) into frags
  73. else
  74. collect
  75. (let ((padding (make-string (max 0 (- width len)) ?\s)))
  76. (cl-ecase align
  77. (left (concat str padding))
  78. (right (concat padding str))))
  79. into frags
  80. finally return (apply #'concat frags)))
  81. ;;; Entries
  82. (defun profiler-format-entry (entry)
  83. "Format ENTRY in human readable string. ENTRY would be a
  84. function name of a function itself."
  85. (cond ((memq (car-safe entry) '(closure lambda))
  86. (format "#<lambda 0x%x>" (sxhash entry)))
  87. ((byte-code-function-p entry)
  88. (format "#<compiled 0x%x>" (sxhash entry)))
  89. ((or (subrp entry) (symbolp entry) (stringp entry))
  90. (format "%s" entry))
  91. (t
  92. (format "#<unknown 0x%x>" (sxhash entry)))))
  93. (defun profiler-fixup-entry (entry)
  94. (if (symbolp entry)
  95. entry
  96. (profiler-format-entry entry)))
  97. ;;; Backtraces
  98. (defun profiler-fixup-backtrace (backtrace)
  99. (apply 'vector (mapcar 'profiler-fixup-entry backtrace)))
  100. ;;; Logs
  101. ;; The C code returns the log in the form of a hash-table where the keys are
  102. ;; vectors (of size profiler-max-stack-depth, holding truncated
  103. ;; backtraces, where the first element is the top of the stack) and
  104. ;; the values are integers (which count how many times this backtrace
  105. ;; has been seen, multiplied by a "weight factor" which is either the
  106. ;; sampling-interval or the memory being allocated).
  107. (defun profiler-compare-logs (log1 log2)
  108. "Compare LOG1 with LOG2 and return diff."
  109. (let ((newlog (make-hash-table :test 'equal)))
  110. ;; Make a copy of `log1' into `newlog'.
  111. (maphash (lambda (backtrace count) (puthash backtrace count newlog))
  112. log1)
  113. (maphash (lambda (backtrace count)
  114. (puthash backtrace (- (gethash backtrace log1 0) count)
  115. newlog))
  116. log2)
  117. newlog))
  118. (defun profiler-fixup-log (log)
  119. (let ((newlog (make-hash-table :test 'equal)))
  120. (maphash (lambda (backtrace count)
  121. (puthash (profiler-fixup-backtrace backtrace)
  122. count newlog))
  123. log)
  124. newlog))
  125. ;;; Profiles
  126. (cl-defstruct (profiler-profile (:type vector)
  127. (:constructor profiler-make-profile))
  128. (tag 'profiler-profile)
  129. (version profiler-version)
  130. ;; - `type' has a value indicating the kind of profile (`memory' or `cpu').
  131. ;; - `log' indicates the profile log.
  132. ;; - `timestamp' has a value giving the time when the profile was obtained.
  133. ;; - `diff-p' indicates if this profile represents a diff between two profiles.
  134. type log timestamp diff-p)
  135. (defun profiler-compare-profiles (profile1 profile2)
  136. "Compare PROFILE1 with PROFILE2 and return diff."
  137. (unless (eq (profiler-profile-type profile1)
  138. (profiler-profile-type profile2))
  139. (error "Can't compare different type of profiles"))
  140. (profiler-make-profile
  141. :type (profiler-profile-type profile1)
  142. :timestamp (current-time)
  143. :diff-p t
  144. :log (profiler-compare-logs
  145. (profiler-profile-log profile1)
  146. (profiler-profile-log profile2))))
  147. (defun profiler-fixup-profile (profile)
  148. "Fixup PROFILE so that the profile could be serialized into file."
  149. (profiler-make-profile
  150. :type (profiler-profile-type profile)
  151. :timestamp (profiler-profile-timestamp profile)
  152. :diff-p (profiler-profile-diff-p profile)
  153. :log (profiler-fixup-log (profiler-profile-log profile))))
  154. (defun profiler-write-profile (profile filename &optional confirm)
  155. "Write PROFILE into file FILENAME."
  156. (with-temp-buffer
  157. (let (print-level print-length)
  158. (print (profiler-fixup-profile profile)
  159. (current-buffer)))
  160. (write-file filename confirm)))
  161. (defun profiler-read-profile (filename)
  162. "Read profile from file FILENAME."
  163. ;; FIXME: tag and version check
  164. (with-temp-buffer
  165. (insert-file-contents filename)
  166. (goto-char (point-min))
  167. (read (current-buffer))))
  168. (defun profiler-running-p (&optional mode)
  169. "Return non-nil if the profiler is running.
  170. Optional argument MODE means only check for the specified mode (cpu or mem)."
  171. (cond ((eq mode 'cpu) (and (fboundp 'profiler-cpu-running-p)
  172. (profiler-cpu-running-p)))
  173. ((eq mode 'mem) (profiler-memory-running-p))
  174. (t (or (profiler-running-p 'cpu)
  175. (profiler-running-p 'mem)))))
  176. (defun profiler-cpu-profile ()
  177. "Return CPU profile."
  178. (when (profiler-running-p 'cpu)
  179. (profiler-make-profile
  180. :type 'cpu
  181. :timestamp (current-time)
  182. :log (profiler-cpu-log))))
  183. (defun profiler-memory-profile ()
  184. "Return memory profile."
  185. (when (profiler-memory-running-p)
  186. (profiler-make-profile
  187. :type 'memory
  188. :timestamp (current-time)
  189. :log (profiler-memory-log))))
  190. ;;; Calltrees
  191. (cl-defstruct (profiler-calltree (:constructor profiler-make-calltree))
  192. entry
  193. (count 0) (count-percent "")
  194. parent children)
  195. (defun profiler-calltree-leaf-p (tree)
  196. (null (profiler-calltree-children tree)))
  197. (defun profiler-calltree-count< (a b)
  198. (cond ((eq (profiler-calltree-entry a) t) t)
  199. ((eq (profiler-calltree-entry b) t) nil)
  200. (t (< (profiler-calltree-count a)
  201. (profiler-calltree-count b)))))
  202. (defun profiler-calltree-count> (a b)
  203. (not (profiler-calltree-count< a b)))
  204. (defun profiler-calltree-depth (tree)
  205. (let ((d 0))
  206. (while (setq tree (profiler-calltree-parent tree))
  207. (cl-incf d))
  208. d))
  209. (defun profiler-calltree-find (tree entry)
  210. "Return a child tree of ENTRY under TREE."
  211. (let (result (children (profiler-calltree-children tree)))
  212. (while (and children (null result))
  213. (let ((child (car children)))
  214. (when (function-equal (profiler-calltree-entry child) entry)
  215. (setq result child))
  216. (setq children (cdr children))))
  217. result))
  218. (defun profiler-calltree-walk (calltree function)
  219. (funcall function calltree)
  220. (dolist (child (profiler-calltree-children calltree))
  221. (profiler-calltree-walk child function)))
  222. (defun profiler-calltree-build-1 (tree log &optional reverse)
  223. ;; This doesn't try to stitch up partial backtraces together.
  224. ;; We still use it for reverse calltrees, but for forward calltrees, we use
  225. ;; profiler-calltree-build-unified instead now.
  226. (maphash
  227. (lambda (backtrace count)
  228. (let ((node tree)
  229. (max (length backtrace)))
  230. (dotimes (i max)
  231. (let ((entry (aref backtrace (if reverse i (- max i 1)))))
  232. (when entry
  233. (let ((child (profiler-calltree-find node entry)))
  234. (unless child
  235. (setq child (profiler-make-calltree
  236. :entry entry :parent node))
  237. (push child (profiler-calltree-children node)))
  238. (cl-incf (profiler-calltree-count child) count)
  239. (setq node child)))))))
  240. log))
  241. (define-hash-table-test 'profiler-function-equal #'function-equal
  242. (lambda (f) (cond
  243. ((byte-code-function-p f) (aref f 1))
  244. ((eq (car-safe f) 'closure) (cddr f))
  245. (t f))))
  246. (defun profiler-calltree-build-unified (tree log)
  247. ;; Let's try to unify all those partial backtraces into a single
  248. ;; call tree. First, we record in fun-map all the functions that appear
  249. ;; in `log' and where they appear.
  250. (let ((fun-map (make-hash-table :test 'profiler-function-equal))
  251. (parent-map (make-hash-table :test 'eq))
  252. (leftover-tree (profiler-make-calltree
  253. :entry (intern "...") :parent tree)))
  254. (push leftover-tree (profiler-calltree-children tree))
  255. (maphash
  256. (lambda (backtrace _count)
  257. (let ((max (length backtrace)))
  258. ;; Don't record the head elements in there, since we want to use this
  259. ;; fun-map to find parents of partial backtraces, but parents only
  260. ;; make sense if they have something "above".
  261. (dotimes (i (1- max))
  262. (let ((f (aref backtrace i)))
  263. (when f
  264. (push (cons i backtrace) (gethash f fun-map)))))))
  265. log)
  266. ;; Then, for each partial backtrace, try to find a parent backtrace
  267. ;; (i.e. a backtrace that describes (part of) the truncated part of
  268. ;; the partial backtrace). For a partial backtrace like "[f3 f2 f1]" (f3
  269. ;; is deeper), any backtrace that includes f1 could be a parent; and indeed
  270. ;; the counts of this partial backtrace could each come from a different
  271. ;; parent backtrace (some of which may not even be in `log'). So we should
  272. ;; consider each backtrace that includes f1 and give it some percentage of
  273. ;; `count'. But we can't know for sure what percentage to give to each
  274. ;; possible parent.
  275. ;; The "right" way might be to give a percentage proportional to the counts
  276. ;; already registered for that parent, or some such statistical principle.
  277. ;; But instead, we will give all our counts to a single "best
  278. ;; matching" parent. So let's look for the best matching parent, and store
  279. ;; the result in parent-map.
  280. ;; Using the "best matching parent" is important also to try and avoid
  281. ;; stitching together backtraces that can't possibly go together.
  282. ;; For example, when the head is `apply' (or `mapcar', ...), we want to
  283. ;; make sure we don't just use any parent that calls `apply', since most of
  284. ;; them would never, in turn, cause apply to call the subsequent function.
  285. (maphash
  286. (lambda (backtrace _count)
  287. (let* ((max (1- (length backtrace)))
  288. (head (aref backtrace max))
  289. (best-parent nil)
  290. (best-match (1+ max))
  291. (parents (gethash head fun-map)))
  292. (pcase-dolist (`(,i . ,parent) parents)
  293. (when t ;; (<= (- max i) best-match) ;Else, it can't be better.
  294. (let ((match max)
  295. (imatch i))
  296. (cl-assert (>= match imatch))
  297. (cl-assert (function-equal (aref backtrace max)
  298. (aref parent i)))
  299. (while (progn
  300. (cl-decf imatch) (cl-decf match)
  301. (when (> imatch 0)
  302. (function-equal (aref backtrace match)
  303. (aref parent imatch)))))
  304. (when (< match best-match)
  305. (cl-assert (<= (- max i) best-match))
  306. ;; Let's make sure this parent is not already our child: we
  307. ;; don't want cycles here!
  308. (let ((valid t)
  309. (tmp-parent parent))
  310. (while (setq tmp-parent
  311. (if (eq tmp-parent backtrace)
  312. (setq valid nil)
  313. (cdr (gethash tmp-parent parent-map)))))
  314. (when valid
  315. (setq best-match match)
  316. (setq best-parent (cons i parent))))))))
  317. (puthash backtrace best-parent parent-map)))
  318. log)
  319. ;; Now we have a single parent per backtrace, so we have a unified tree.
  320. ;; Let's build the actual call-tree from it.
  321. (maphash
  322. (lambda (backtrace count)
  323. (let ((node tree)
  324. (parents (list (cons -1 backtrace)))
  325. (tmp backtrace)
  326. (max (length backtrace)))
  327. (while (setq tmp (gethash tmp parent-map))
  328. (push tmp parents)
  329. (setq tmp (cdr tmp)))
  330. (when (aref (cdar parents) (1- max))
  331. (cl-incf (profiler-calltree-count leftover-tree) count)
  332. (setq node leftover-tree))
  333. (pcase-dolist (`(,i . ,parent) parents)
  334. (let ((j (1- max)))
  335. (while (> j i)
  336. (let ((f (aref parent j)))
  337. (cl-decf j)
  338. (when f
  339. (let ((child (profiler-calltree-find node f)))
  340. (unless child
  341. (setq child (profiler-make-calltree
  342. :entry f :parent node))
  343. (push child (profiler-calltree-children node)))
  344. (cl-incf (profiler-calltree-count child) count)
  345. (setq node child)))))))))
  346. log)))
  347. (defun profiler-calltree-compute-percentages (tree)
  348. (let ((total-count 0))
  349. ;; FIXME: the memory profiler's total wraps around all too easily!
  350. (dolist (child (profiler-calltree-children tree))
  351. (cl-incf total-count (profiler-calltree-count child)))
  352. (unless (zerop total-count)
  353. (profiler-calltree-walk
  354. tree (lambda (node)
  355. (setf (profiler-calltree-count-percent node)
  356. (profiler-format-percent (profiler-calltree-count node)
  357. total-count)))))))
  358. (cl-defun profiler-calltree-build (log &key reverse)
  359. (let ((tree (profiler-make-calltree)))
  360. (if reverse
  361. (profiler-calltree-build-1 tree log reverse)
  362. (profiler-calltree-build-unified tree log))
  363. (profiler-calltree-compute-percentages tree)
  364. tree))
  365. (defun profiler-calltree-sort (tree predicate)
  366. (let ((children (profiler-calltree-children tree)))
  367. (setf (profiler-calltree-children tree) (sort children predicate))
  368. (dolist (child (profiler-calltree-children tree))
  369. (profiler-calltree-sort child predicate))))
  370. ;;; Report rendering
  371. (defcustom profiler-report-closed-mark "+"
  372. "An indicator of closed calltrees."
  373. :type 'string
  374. :group 'profiler)
  375. (defcustom profiler-report-open-mark "-"
  376. "An indicator of open calltrees."
  377. :type 'string
  378. :group 'profiler)
  379. (defcustom profiler-report-leaf-mark " "
  380. "An indicator of calltree leaves."
  381. :type 'string
  382. :group 'profiler)
  383. (defvar profiler-report-cpu-line-format
  384. '((50 left)
  385. (24 right ((19 right)
  386. (5 right)))))
  387. (defvar profiler-report-memory-line-format
  388. '((55 left)
  389. (19 right ((14 right profiler-format-number)
  390. (5 right)))))
  391. (defvar-local profiler-report-profile nil
  392. "The current profile.")
  393. (defvar-local profiler-report-reversed nil
  394. "True if calltree is rendered in bottom-up. Do not touch this
  395. variable directly.")
  396. (defvar-local profiler-report-order nil
  397. "The value can be `ascending' or `descending'. Do not touch
  398. this variable directly.")
  399. (defun profiler-report-make-entry-part (entry)
  400. (let ((string (cond
  401. ((eq entry t)
  402. "Others")
  403. ((and (symbolp entry)
  404. (fboundp entry))
  405. (propertize (symbol-name entry)
  406. 'face 'link
  407. 'mouse-face 'highlight
  408. 'help-echo "\
  409. mouse-2: jump to definition\n\
  410. RET: expand or collapse"))
  411. (t
  412. (profiler-format-entry entry)))))
  413. (propertize string 'profiler-entry entry)))
  414. (defun profiler-report-make-name-part (tree)
  415. (let* ((entry (profiler-calltree-entry tree))
  416. (depth (profiler-calltree-depth tree))
  417. (indent (make-string (* (1- depth) 1) ?\s))
  418. (mark (if (profiler-calltree-leaf-p tree)
  419. profiler-report-leaf-mark
  420. profiler-report-closed-mark))
  421. (entry (profiler-report-make-entry-part entry)))
  422. (format "%s%s %s" indent mark entry)))
  423. (defun profiler-report-header-line-format (fmt &rest args)
  424. (let* ((header (apply #'profiler-format fmt args))
  425. (escaped (replace-regexp-in-string "%" "%%" header)))
  426. (concat " " escaped)))
  427. (defun profiler-report-line-format (tree)
  428. (let ((diff-p (profiler-profile-diff-p profiler-report-profile))
  429. (name-part (profiler-report-make-name-part tree))
  430. (count (profiler-calltree-count tree))
  431. (count-percent (profiler-calltree-count-percent tree)))
  432. (profiler-format (cl-ecase (profiler-profile-type profiler-report-profile)
  433. (cpu profiler-report-cpu-line-format)
  434. (memory profiler-report-memory-line-format))
  435. name-part
  436. (if diff-p
  437. (list (if (> count 0)
  438. (format "+%s" count)
  439. count)
  440. "")
  441. (list count count-percent)))))
  442. (defun profiler-report-insert-calltree (tree)
  443. (let ((line (profiler-report-line-format tree)))
  444. (insert (propertize (concat line "\n") 'calltree tree))))
  445. (defun profiler-report-insert-calltree-children (tree)
  446. (mapc #'profiler-report-insert-calltree
  447. (profiler-calltree-children tree)))
  448. ;;; Report mode
  449. (defvar profiler-report-mode-map
  450. (let ((map (make-sparse-keymap)))
  451. (define-key map "n" 'profiler-report-next-entry)
  452. (define-key map "p" 'profiler-report-previous-entry)
  453. ;; I find it annoying more than helpful to not be able to navigate
  454. ;; normally with the cursor keys. --Stef
  455. ;; (define-key map [down] 'profiler-report-next-entry)
  456. ;; (define-key map [up] 'profiler-report-previous-entry)
  457. (define-key map "\r" 'profiler-report-toggle-entry)
  458. (define-key map "\t" 'profiler-report-toggle-entry)
  459. (define-key map "i" 'profiler-report-toggle-entry)
  460. (define-key map [mouse-1] 'profiler-report-toggle-entry)
  461. (define-key map "f" 'profiler-report-find-entry)
  462. (define-key map "j" 'profiler-report-find-entry)
  463. (define-key map [mouse-2] 'profiler-report-find-entry)
  464. (define-key map "d" 'profiler-report-describe-entry)
  465. (define-key map "C" 'profiler-report-render-calltree)
  466. (define-key map "B" 'profiler-report-render-reversed-calltree)
  467. (define-key map "A" 'profiler-report-ascending-sort)
  468. (define-key map "D" 'profiler-report-descending-sort)
  469. (define-key map "=" 'profiler-report-compare-profile)
  470. (define-key map (kbd "C-x C-w") 'profiler-report-write-profile)
  471. (easy-menu-define profiler-report-menu map "Menu for Profiler Report mode."
  472. '("Profiler"
  473. ["Next Entry" profiler-report-next-entry :active t
  474. :help "Move to next entry"]
  475. ["Previous Entry" profiler-report-previous-entry :active t
  476. :help "Move to previous entry"]
  477. "--"
  478. ["Toggle Entry" profiler-report-toggle-entry
  479. :active (profiler-report-calltree-at-point)
  480. :help "Expand or collapse the current entry"]
  481. ["Find Entry" profiler-report-find-entry
  482. ;; FIXME should deactivate if not on a known function.
  483. :active (profiler-report-calltree-at-point)
  484. :help "Find the definition of the current entry"]
  485. ["Describe Entry" profiler-report-describe-entry
  486. :active (profiler-report-calltree-at-point)
  487. :help "Show the documentation of the current entry"]
  488. "--"
  489. ["Show Calltree" profiler-report-render-calltree
  490. :active profiler-report-reversed
  491. :help "Show calltree view"]
  492. ["Show Reversed Calltree" profiler-report-render-reversed-calltree
  493. :active (not profiler-report-reversed)
  494. :help "Show reversed calltree view"]
  495. ["Sort Ascending" profiler-report-ascending-sort
  496. :active (not (eq profiler-report-order 'ascending))
  497. :help "Sort calltree view in ascending order"]
  498. ["Sort Descending" profiler-report-descending-sort
  499. :active (not (eq profiler-report-order 'descending))
  500. :help "Sort calltree view in descending order"]
  501. "--"
  502. ["Compare Profile..." profiler-report-compare-profile :active t
  503. :help "Compare current profile with another"]
  504. ["Write Profile..." profiler-report-write-profile :active t
  505. :help "Write current profile to a file"]
  506. "--"
  507. ["Start Profiler" profiler-start :active (not (profiler-running-p))
  508. :help "Start profiling"]
  509. ["Stop Profiler" profiler-stop :active (profiler-running-p)
  510. :help "Stop profiling"]
  511. ["New Report" profiler-report :active (profiler-running-p)
  512. :help "Make a new report"]))
  513. map)
  514. "Keymap for `profiler-report-mode'.")
  515. (defun profiler-report-make-buffer-name (profile)
  516. (format "*%s-Profiler-Report %s*"
  517. (cl-ecase (profiler-profile-type profile) (cpu 'CPU) (memory 'Memory))
  518. (format-time-string "%Y-%m-%d %T" (profiler-profile-timestamp profile))))
  519. (defun profiler-report-setup-buffer-1 (profile)
  520. "Make a buffer for PROFILE and return it."
  521. (let* ((buf-name (profiler-report-make-buffer-name profile))
  522. (buffer (get-buffer-create buf-name)))
  523. (with-current-buffer buffer
  524. (profiler-report-mode)
  525. (setq profiler-report-profile profile
  526. profiler-report-reversed nil
  527. profiler-report-order 'descending))
  528. buffer))
  529. (defun profiler-report-setup-buffer (profile)
  530. "Make a buffer for PROFILE with rendering the profile and
  531. return it."
  532. (let ((buffer (profiler-report-setup-buffer-1 profile)))
  533. (with-current-buffer buffer
  534. (profiler-report-render-calltree))
  535. buffer))
  536. (define-derived-mode profiler-report-mode special-mode "Profiler-Report"
  537. "Profiler Report Mode."
  538. (add-to-invisibility-spec '(profiler . t))
  539. (setq buffer-read-only t
  540. buffer-undo-list t
  541. truncate-lines t))
  542. ;;; Report commands
  543. (defun profiler-report-calltree-at-point (&optional point)
  544. (get-text-property (or point (point)) 'calltree))
  545. (defun profiler-report-move-to-entry ()
  546. (let ((point (next-single-property-change
  547. (line-beginning-position) 'profiler-entry)))
  548. (if point
  549. (goto-char point)
  550. (back-to-indentation))))
  551. (defun profiler-report-next-entry ()
  552. "Move cursor to next entry."
  553. (interactive)
  554. (forward-line)
  555. (profiler-report-move-to-entry))
  556. (defun profiler-report-previous-entry ()
  557. "Move cursor to previous entry."
  558. (interactive)
  559. (forward-line -1)
  560. (profiler-report-move-to-entry))
  561. (defun profiler-report-expand-entry (&optional full)
  562. "Expand entry at point.
  563. With a prefix argument, expand the whole subtree."
  564. (interactive "P")
  565. (save-excursion
  566. (beginning-of-line)
  567. (when (search-forward (concat profiler-report-closed-mark " ")
  568. (line-end-position) t)
  569. (let ((tree (profiler-report-calltree-at-point)))
  570. (when tree
  571. (let ((inhibit-read-only t))
  572. (replace-match (concat profiler-report-open-mark " "))
  573. (forward-line)
  574. (let ((first (point))
  575. (last (copy-marker (point) t)))
  576. (profiler-report-insert-calltree-children tree)
  577. (when full
  578. (goto-char first)
  579. (while (< (point) last)
  580. (profiler-report-expand-entry)
  581. (forward-line 1))))
  582. t))))))
  583. (defun profiler-report-collapse-entry ()
  584. "Collapse entry at point."
  585. (interactive)
  586. (save-excursion
  587. (beginning-of-line)
  588. (when (search-forward (concat profiler-report-open-mark " ")
  589. (line-end-position) t)
  590. (let* ((tree (profiler-report-calltree-at-point))
  591. (depth (profiler-calltree-depth tree))
  592. (start (line-beginning-position 2))
  593. d)
  594. (when tree
  595. (let ((inhibit-read-only t))
  596. (replace-match (concat profiler-report-closed-mark " "))
  597. (while (and (eq (forward-line) 0)
  598. (let ((child (get-text-property (point) 'calltree)))
  599. (and child
  600. (numberp (setq d (profiler-calltree-depth child)))))
  601. (> d depth)))
  602. (delete-region start (line-beginning-position)))))
  603. t)))
  604. (defun profiler-report-toggle-entry (&optional arg)
  605. "Expand entry at point if the tree is collapsed,
  606. otherwise collapse. With prefix argument, expand all subentries
  607. below entry at point."
  608. (interactive "P")
  609. (or (profiler-report-expand-entry arg)
  610. (profiler-report-collapse-entry)))
  611. (defun profiler-report-find-entry (&optional event)
  612. "Find entry at point."
  613. (interactive (list last-nonmenu-event))
  614. (with-current-buffer
  615. (if event (window-buffer (posn-window (event-start event)))
  616. (current-buffer))
  617. (and event (setq event (event-end event))
  618. (posn-set-point event))
  619. (let ((tree (profiler-report-calltree-at-point)))
  620. (when tree
  621. (let ((entry (profiler-calltree-entry tree)))
  622. (find-function entry))))))
  623. (defun profiler-report-describe-entry ()
  624. "Describe entry at point."
  625. (interactive)
  626. (let ((tree (profiler-report-calltree-at-point)))
  627. (when tree
  628. (let ((entry (profiler-calltree-entry tree)))
  629. (require 'help-fns)
  630. (describe-function entry)))))
  631. (cl-defun profiler-report-render-calltree-1
  632. (profile &key reverse (order 'descending))
  633. (let ((calltree (profiler-calltree-build
  634. (profiler-profile-log profile)
  635. :reverse reverse)))
  636. (setq header-line-format
  637. (cl-ecase (profiler-profile-type profile)
  638. (cpu
  639. (profiler-report-header-line-format
  640. profiler-report-cpu-line-format
  641. "Function" (list "CPU samples" "%")))
  642. (memory
  643. (profiler-report-header-line-format
  644. profiler-report-memory-line-format
  645. "Function" (list "Bytes" "%")))))
  646. (let ((predicate (cl-ecase order
  647. (ascending #'profiler-calltree-count<)
  648. (descending #'profiler-calltree-count>))))
  649. (profiler-calltree-sort calltree predicate))
  650. (let ((inhibit-read-only t))
  651. (erase-buffer)
  652. (profiler-report-insert-calltree-children calltree)
  653. (goto-char (point-min))
  654. (profiler-report-move-to-entry))))
  655. (defun profiler-report-rerender-calltree ()
  656. (profiler-report-render-calltree-1 profiler-report-profile
  657. :reverse profiler-report-reversed
  658. :order profiler-report-order))
  659. (defun profiler-report-render-calltree ()
  660. "Render calltree view."
  661. (interactive)
  662. (setq profiler-report-reversed nil)
  663. (profiler-report-rerender-calltree))
  664. (defun profiler-report-render-reversed-calltree ()
  665. "Render reversed calltree view."
  666. (interactive)
  667. (setq profiler-report-reversed t)
  668. (profiler-report-rerender-calltree))
  669. (defun profiler-report-ascending-sort ()
  670. "Sort calltree view in ascending order."
  671. (interactive)
  672. (setq profiler-report-order 'ascending)
  673. (profiler-report-rerender-calltree))
  674. (defun profiler-report-descending-sort ()
  675. "Sort calltree view in descending order."
  676. (interactive)
  677. (setq profiler-report-order 'descending)
  678. (profiler-report-rerender-calltree))
  679. (defun profiler-report-profile (profile)
  680. (switch-to-buffer (profiler-report-setup-buffer profile)))
  681. (defun profiler-report-profile-other-window (profile)
  682. (switch-to-buffer-other-window (profiler-report-setup-buffer profile)))
  683. (defun profiler-report-profile-other-frame (profile)
  684. (switch-to-buffer-other-frame (profiler-report-setup-buffer profile)))
  685. (defun profiler-report-compare-profile (buffer)
  686. "Compare the current profile with another."
  687. (interactive (list (read-buffer "Compare to: ")))
  688. (let* ((profile1 (with-current-buffer buffer profiler-report-profile))
  689. (profile2 profiler-report-profile)
  690. (diff-profile (profiler-compare-profiles profile1 profile2)))
  691. (profiler-report-profile diff-profile)))
  692. (defun profiler-report-write-profile (filename &optional confirm)
  693. "Write the current profile into file FILENAME."
  694. (interactive
  695. (list (read-file-name "Write profile: " default-directory)
  696. (not current-prefix-arg)))
  697. (profiler-write-profile profiler-report-profile
  698. filename
  699. confirm))
  700. ;;; Profiler commands
  701. ;;;###autoload
  702. (defun profiler-start (mode)
  703. "Start/restart profilers.
  704. MODE can be one of `cpu', `mem', or `cpu+mem'.
  705. If MODE is `cpu' or `cpu+mem', time-based profiler will be started.
  706. Also, if MODE is `mem' or `cpu+mem', then memory profiler will be started."
  707. (interactive
  708. (list (if (not (fboundp 'profiler-cpu-start)) 'mem
  709. (intern (completing-read "Mode (default cpu): "
  710. '("cpu" "mem" "cpu+mem")
  711. nil t nil nil "cpu")))))
  712. (cl-ecase mode
  713. (cpu
  714. (profiler-cpu-start profiler-sampling-interval)
  715. (message "CPU profiler started"))
  716. (mem
  717. (profiler-memory-start)
  718. (message "Memory profiler started"))
  719. (cpu+mem
  720. (profiler-cpu-start profiler-sampling-interval)
  721. (profiler-memory-start)
  722. (message "CPU and memory profiler started"))))
  723. (defun profiler-stop ()
  724. "Stop started profilers. Profiler logs will be kept."
  725. (interactive)
  726. (let ((cpu (if (fboundp 'profiler-cpu-stop) (profiler-cpu-stop)))
  727. (mem (profiler-memory-stop)))
  728. (message "%s profiler stopped"
  729. (cond ((and mem cpu) "CPU and memory")
  730. (mem "Memory")
  731. (cpu "CPU")
  732. (t "No")))))
  733. (defun profiler-reset ()
  734. "Reset profiler logs."
  735. (interactive)
  736. (when (fboundp 'profiler-cpu-log)
  737. (ignore (profiler-cpu-log)))
  738. (ignore (profiler-memory-log))
  739. t)
  740. (defun profiler-report-cpu ()
  741. (let ((profile (profiler-cpu-profile)))
  742. (when profile
  743. (profiler-report-profile-other-window profile))))
  744. (defun profiler-report-memory ()
  745. (let ((profile (profiler-memory-profile)))
  746. (when profile
  747. (profiler-report-profile-other-window profile))))
  748. (defun profiler-report ()
  749. "Report profiling results."
  750. (interactive)
  751. (profiler-report-cpu)
  752. (profiler-report-memory))
  753. ;;;###autoload
  754. (defun profiler-find-profile (filename)
  755. "Open profile FILENAME."
  756. (interactive
  757. (list (read-file-name "Find profile: " default-directory)))
  758. (profiler-report-profile (profiler-read-profile filename)))
  759. ;;;###autoload
  760. (defun profiler-find-profile-other-window (filename)
  761. "Open profile FILENAME."
  762. (interactive
  763. (list (read-file-name "Find profile: " default-directory)))
  764. (profiler-report-profile-other-window (profiler-read-profile filename)))
  765. ;;;###autoload
  766. (defun profiler-find-profile-other-frame (filename)
  767. "Open profile FILENAME."
  768. (interactive
  769. (list (read-file-name "Find profile: " default-directory)))
  770. (profiler-report-profile-other-frame(profiler-read-profile filename)))
  771. ;;; Profiling helpers
  772. ;; (cl-defmacro with-cpu-profiling ((&key sampling-interval) &rest body)
  773. ;; `(unwind-protect
  774. ;; (progn
  775. ;; (ignore (profiler-cpu-log))
  776. ;; (profiler-cpu-start ,sampling-interval)
  777. ;; ,@body)
  778. ;; (profiler-cpu-stop)
  779. ;; (profiler--report-cpu)))
  780. ;; (defmacro with-memory-profiling (&rest body)
  781. ;; `(unwind-protect
  782. ;; (progn
  783. ;; (ignore (profiler-memory-log))
  784. ;; (profiler-memory-start)
  785. ;; ,@body)
  786. ;; (profiler-memory-stop)
  787. ;; (profiler--report-memory)))
  788. (provide 'profiler)
  789. ;;; profiler.el ends here