profiler.el 32 KB

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