From mboxrd@z Thu Jan 1 00:00:00 1970 From: "Sebastien Vauban" Subject: Re: elp-instrument-package does not return anything Date: Mon, 24 Dec 2012 14:44:06 +0100 Message-ID: <804njbpntl.fsf@somewhere.org> References: <80pq23niub.fsf@somewhere.org> Mime-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Return-path: List-Id: "General discussions about Org-mode." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: emacs-orgmode-bounces+geo-emacs-orgmode=m.gmane.org-mXXj517/zsQ@public.gmane.org Sender: emacs-orgmode-bounces+geo-emacs-orgmode=m.gmane.org-mXXj517/zsQ@public.gmane.org To: emacs-orgmode-mXXj517/zsQ@public.gmane.org Hello, (I did not see my previous answer to this, so redoing it) "Sebastien Vauban" wrote: > For the sake of finding potential bottlenecks in my config, I'm looking b= ack > at elp. > > I've the following minimal Emacs config file for the current work: [...] > > Though, for whatever unknown reason, when calling elp-results, I just get= info > about font-lock. > > Nothing about Org!? > > I'm really out of ideas about what to do to get those Org profiling resul= ts? > Any idea of what I'm doing wrong (I guess)? As found out by Bastien, one needs to require the packages first, before instrumenting them. Not automatic! OK, so, with the new Emacs *minimal config*: --8<---------------cut here---------------start------------->8--- ;; activate debugging (setq debug-on-error t) (setq debug-on-quit t) ;; change the pathnames appropriately! (add-to-list 'load-path (expand-file-name "~/src/org-mode/lisp")) (add-to-list 'load-path (expand-file-name "~/src/org-mode/contrib/lisp")) (require 'org) (require 'org-agenda) (require 'outline) (require 'font-lock) (require 'flyspell) (require 'ispell) (require 'calendar) (require 'cal-iso) (require 'diary-lib) ;; profile some times... CAUTION: require the packages first (to get result= s)! (when (require 'elp) ;; the most important ones (elp-instrument-package "org") (elp-instrument-package "org-agenda") (elp-instrument-package "outline") (elp-instrument-package "font-lock") (elp-instrument-package "flyspell") (elp-instrument-package "ispell") (elp-instrument-package "emacs-leuven") (elp-instrument-package "calendar") (elp-instrument-package "cal-iso") (elp-instrument-package "diary-lib") (global-set-key "\C-ce" 'elp-results)) ;; improve readability of profile results, give milliseconds (defun elp-pack-number (number width) (format (concat "%" (number-to-string (- width 3)) ".2f") (* 100 (string-to-number number)))) (setq org-agenda-files (append ;; org-directory (file-expand-wildcards "~/Personal/*.org") (file-expand-wildcards "~/Projects/*.org"))) (defconst em/emacs-load-time-start (float-time)) (org-agenda-list) (message "Loading Minimal Emacs... Done (in %.2f s)" (- (float-time) em/emacs-load-time-start)) --8<---------------cut here---------------end--------------->8--- Generating the agenda for 43 files, and more or less 75 entries to display, takes between 17 and 20 seconds, in this case 19 seconds: --8<---------------cut here---------------start------------->8--- org-agenda-list 1 1= 9.156 19.156 org-agenda-prepare 1 1= 1.141 11.141 org-agenda-prepare-buffers 1 1= 1.078 11.078 org-get-agenda-file-buffer 344 1= 1.064000000 0.0321627906 org-agenda-get-day-entries 301 7= .5179999999 0.0249767441 org-agenda-get-scheduled 301 4= .5180000000 0.0150099667 org-mode 43 3= .7710000000 0.0876976744 org-entry-get 2601 2= .0339999999 0.0007820069 org-back-to-heading 11116 1= .9679999999 0.0001770421 org-get-property-block 2601 1= .9089999999 0.0007339484 outline-back-to-heading 11116 1= .7799999999 0.0001601295 org-set-startup-visibility 43 1= .391 0.0323488372 org-agenda-get-deadlines 301 1= .36 0.0045182724 org-get-todo-state 3782 1= .3399999999 0.0003543098 org-agenda-files 46 0= .8050000000 0.0175000000 org-cycle-internal-global 43 0= .7810000000 0.0181627906 org-cycle 43 0= .7810000000 0.0181627906 org-install-agenda-files-menu 43 0= .7740000000 0.0180000000 org-agenda-skip 4636 0= .7170000000 0.0001546591 org-agenda-get-sexps 301 0= .7020000000 0.0023322259 outline-next-heading 7764 0= .6780000000 8.73...e-005 org-overview 43 0= .6720000000 0.0156279069 outline-map-region 43 0= .6090000000 0.0141627906 org-load-modules-maybe 86 0= .594 0.0069069767 org-time-string-to-absolute 3759 0= .5170000000 0.0001375365 org-parse-time-string 4088 0= .5 0.0001223091 org-set-regexps-and-options 43 0= .4970000000 0.0115581395 org-cycle-hide-drawers 86 0= .4050000000 0.0047093023 org-find-base-buffer-visiting 344 0= .4040000000 0.0011744186 org-agenda-get-timestamps 301 0= .3590000000 0.0011926910 org-agenda-get-blocks 301 0= .3470000000 0.0011528239 org-diary-sexp-entry 714 0= .3280000000 0.0004593837 org-flag-drawer 1396 0= .2970000000 0.0002127507 org-before-first-heading-p 2602 0= .2820000000 0.0001083781 org-outline-level 4313 0= .265 6.14...e-005 org-cycle-show-empty-lines 86 0= .2050000000 0.0023837209 org-agenda-finalize-entries 4 0= .203 0.05075 org-macro-initialize-templates 43 0= .1730000000 0.0040232558 org-get-tags-at 84 0= .1710000000 0.0020357142 org-up-heading-safe 225 0= .14 0.0006222222 org-entries-lessp 372 0= .14 0.0003763440 org-all-targets 43 0= .138 0.0032093023 org-update-radio-target-regexp 43 0= .138 0.0032093023 org-babel-hide-all-hashes 43 0= .127 0.0029534883 org-time-string-to-time 168 0= .125 0.0007440476 org-closest-date 161 0= .11 0.0006832298 org-agenda-format-item 84 0= .109 0.0012976190 org-in-src-block-p 4636 0= .093 2.00...e-005 org-file-contents 16 0= .093 0.0058125 org-agenda-align-tags 1 0= .093 0.093 org-agenda-finalize 1 0= .093 0.093 org-refresh-category-properties 43 0= .092 0.0021395348 org-set-visibility-according-to-property 43 0= .078 0.0018139534 org-fit-window-to-buffer 1 0= .078 0.078 org-agenda-skip-eval 9124 0= .078 8.54...e-006 org-agenda-fit-window-to-buffer 1 0= .078 0.078 outline-flag-region 1672 0= .078 4.66...e-005 org-agenda-highlight-todo 84 0= .063 0.00075 org-agenda-todayp 609 0= .062 0.0001018062 ... --8<---------------cut here---------------end--------------->8--- Is this normal? For a 6-year old laptop? In particular, when looking at the top entries: --8<---------------cut here---------------start------------->8--- org-agenda-list 1 1= 9.156 19.156 org-agenda-prepare 1 1= 1.141 11.141 org-agenda-prepare-buffers 1 1= 1.078 11.078 org-get-agenda-file-buffer 344 1= 1.064000000 0.0321627906 org-agenda-get-day-entries 301 7= .5179999999 0.0249767441 org-agenda-get-scheduled 301 4= .5180000000 0.0150099667 org-mode 43 3= .7710000000 0.0876976744 --8<---------------cut here---------------end--------------->8--- I'm amazed by: - the difference between the 3 seconds for the 43 calls to `org-mode' and t= he final 19 seconds for the list to be displayed - the difference as well between the top 2 functions: `org-agenda-prepare' "only" takes 11 seconds, while `org-agenda-list' consumes another 8=C2=A0seconds... Any comment on this? Best regards, Seb --=20 Sebastien Vauban