emacs-orgmode
[Top][All Lists]
Advanced

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [O] Huge performance problems to open some Org files


From: Sebastien Vauban
Subject: Re: [O] Huge performance problems to open some Org files
Date: Fri, 13 May 2011 00:27:21 +0200
User-agent: Gnus/5.13 (Gnus v5.13) Emacs/23.1.50 (windows-nt)

Hi Andrew, Vladimir, Nick, Achim, Carsten & al,

Vladimir Alexiev wrote:
> Sébastien Vauban <address@hidden> writes:
>> Believe me or not, but C-g has not effect during those 7 seconds. It simply
>> does not stop anything
>
> Sounds like emacs is waiting inside some blocking call, and waits until it
> times out. Likely a network call. Do you have any tramp/efs/angeftp stuff
> going on?

This has gotten worse. But, now, I have some proofs about what I experience:
opening the attached Org file (2 KB) consumes me 191 seconds, yes 191 seconds,
even when done after the agenda view has been launched -- I mean, all agenda
files and all Org files have been read...

--8<---------------cut here---------------start------------->8---
| find-file | start |c:/home/sva/Public/tags-opening-it-is-sloooooooooow.org | 
___ |
+-> Requiring `org-exp' (already loaded)
OVERVIEW in c:/home/sva/Public/tags-opening-it-is-sloooooooooow.org
Checking for library `filladapt'...
+-> Requiring `filladapt' (already loaded)
Checking for library `filladapt'... Found
+-> Requiring `outline-mode-easy-bindings' (already loaded)
+-> Requiring `bytecomp' (already loaded)
Checking for library `filladapt'...
+-> Requiring `filladapt' (already loaded)
Checking for library `filladapt'... Found
| find-file | stop | c:/home/sva/Public/tags-opening-it-is-sloooooooooow.org | 
191.3 |
--8<---------------cut here---------------end--------------->8---

Note that the variance is 0.1 second, over 3 Emacs restarts!  Pretty
reproducible...

To obtain the above trace, I've added the following bits to my .emacs file:

#+begin_src emacs-lisp
         ;; redefine require to leave a trace of packages being loaded
         (if (not (fboundp 'orig-require))
             (fset 'orig-require (symbol-function 'require))
           (message "The code to redefine `require' should not be loaded 
twice"))

         (defvar my/require-depth 0)

         (defun require (feature &optional filename noerror)
           "Leave a trace of packages being loaded."
           (cond ((member feature features)
                  (message "%sRequiring `%s' (already loaded)"
                           (concat (make-string (* 2 my/require-depth) ? )
                                   "+-> ")
                           feature))
                 (t
                  (message "%sRequiring `%s'"
                           (concat (make-string (* 2 my/require-depth) ? )
                                   "+-> ")
                           feature)
                  (let ((my/require-depth (+ 1 my/require-depth)))
                    (orig-require feature filename noerror))
                  (message "%sRequiring `%s'...done"
                           (concat (make-string (* 2 my/require-depth) ? )
                                   "+-> ")
                           feature))))

      (defvar missing-packages-list nil
        "List of packages that `try-require' can't find.")

      ;; attempt to load a feature/library, failing silently
      (defun try-require (feature)
        "Attempt to load a library or module. Return true if the
      library given as argument is successfully loaded. If not, instead
      of an error, just add the package to a list of missing packages."
        (condition-case err
            ;; protected form
            (progn
              (message "Checking for library `%s'..." feature)
              (if (stringp feature)
                  (load-library feature)
                (require feature))
              (message "Checking for library `%s'... Found" feature))
          ;; error handler
          (file-error  ; condition
           (progn
             (message "Checking for library `%s'... Missing" feature)
             (add-to-list 'missing-packages-list feature 'append))
           nil)))

(defadvice find-file (around my-find-file activate)
  "Open FILENAME and report time spent."
  (let* ((my-filename (ad-get-arg 0))
         (find-file-time-start (float-time)))
    (message (concat "| find-file | start |" my-filename " | ___ |"))
    ad-do-it
    (message "| find-file | stop | %s | %.1f |"
             my-filename
             (- (float-time) find-file-time-start))))
#+end_src

Trying to profile:

#+begin_src emacs-lisp
  (elp-instrument-package "org")
  (elp-instrument-package "outline")
  (elp-instrument-package "font-lock")
  (elp-instrument-package "flyspell")
  (elp-instrument-package "bytecomp")
  (elp-instrument-package "color-theme")
  (elp-instrument-package "company")
  (elp-instrument-package "custom")
  (elp-instrument-package "files")
  (elp-instrument-package "filladapt")
  (elp-instrument-package "help-fns")
  (elp-instrument-package "ispell")
  (elp-instrument-package "outline-mode-easy-bindings"))
#+end_src

did not help finding the culprit:

--8<---------------cut here---------------start------------->8---
custom-declare-variable                                    1733        0.735    
     0.0004241200
flyspell-mode                                              51          
0.4210000000  0.0082549019
flyspell-post-command-hook                                 10          
0.3759999999  0.0375999999
custom-initialize-default                                  33          0.375    
     0.0113636363
flyspell-word                                              9           
0.3609999999  0.0401111111
outline-back-to-heading                                    5684        
0.3430000000  6.03...e-005
custom-initialize-reset                                    1699        
0.3280000000  0.0001930547
flyspell-mode-on                                           50          0.281    
     0.0056200000
ispell-init-process                                        98          0.265    
     0.0027040816
flyspell-accept-buffer-local-defs                          107         0.251    
     0.0023457943
ispell-accept-buffer-local-defs                            98          0.251    
     0.0025612244
outline-map-region                                         47          
0.2200000000  0.0046808510
custom-declare-face                                        133         
0.2190000000  0.0016466165
ispell-accept-output                                       2           
0.2019999999  0.1009999999
outline-next-heading                                       5095        
0.1720000000  3.37...e-005
font-lock-set-defaults                                     580         0.125    
     0.0002155172
font-lock-add-keywords                                     226         0.125    
     0.0005530973
font-lock-compile-keywords                                 180         0.125    
     0.0006944444
ispell-buffer-local-words                                  98          0.125    
     0.0012755102
ispell-buffer-local-parsing                                97          
0.0939999999  0.0009690721
color-theme-install-faces                                  1           
0.0779999999  0.0779999999
color-theme-install                                        1           
0.0779999999  0.0779999999
color-theme-leuven                                         1           
0.0779999999  0.0779999999
font-lock-default-fontify-region                           24          0.077    
     0.0032083333
font-lock-fontify-keywords-region                          24          0.077    
     0.0032083333
font-lock-fontify-region                                   24          0.077    
     0.0032083333
ispell-check-version                                       2           0.047    
     0.0235
ispell-call-process                                        2           0.047    
     0.0235
outline-show-heading                                       240         0.032    
     0.0001333333
outline-on-heading-p                                       5750        0.032    
     5.56...e-006
flyspell-word-search-forward                               2           0.032    
     0.016
custom-handle-keyword                                      2611        0.032    
     1.22...e-005
ispell-buffer-local-dict                                   98          0.032    
     0.0003265306
flyspell-check-spell-program                               50          0.03     
     0.0006
outline-flag-region                                        1375        0.016    
     1.16...e-005
flyspell-get-word                                          12          0.016    
     0.0013333333
color-theme-filter                                         3           0.016    
     0.0053333333
ispell-get-otherchars                                      12          0.016    
     0.0013333333
ispell-start-process                                       2           0.016    
     0.008
ispell-internal-change-dictionary                          98          0.016    
     0.0001632653
font-lock-default-fontify-buffer                           7           0.015    
     0.0021428571
font-lock-fontify-buffer                                   7           0.015    
     0.0021428571
flyspell-check-pre-word-p                                  10          0.015    
     0.0015
outline-invisible-p                                        98          0.0      
     0.0
outline-previous-heading                                   419         0.0      
     0.0
outline-up-heading                                         38          0.0      
     0.0
outline-end-of-heading                                     359         0.0      
     0.0
outline-mode                                               49          0.0      
     0.0
font-lock-prepend-text-property                            59          0.0      
     0.0
font-lock-update-removed-keyword-alist                     1           0.0      
     0.0
font-lock-mode-internal                                    101         0.0      
     0.0
font-lock-extend-region-wholelines                         26          0.0      
     0.0
font-lock-extend-jit-lock-region-after-change              12          0.0      
     0.0
font-lock-unfontify-buffer                                 2           0.0      
     0.0
font-lock-choose-keywords                                  51          0.0      
     0.0
font-lock-remove-keywords                                  225         0.0      
     0.0
font-lock-mode                                             208         0.0      
     0.0
font-lock-unfontify-region                                 26          0.0      
     0.0
font-lock-after-unfontify-buffer                           2           0.0      
     0.0
font-lock-default-function                                 208         0.0      
     0.0
font-lock-after-fontify-buffer                             7           0.0      
     0.0
font-lock-change-mode                                      51          0.0      
     0.0
font-lock-turn-off-thing-lock                              2           0.0      
     0.0
font-lock-extend-region-multiline                          26          0.0      
     0.0
font-lock-eval-keywords                                    102         0.0      
     0.0
font-lock-default-unfontify-buffer                         2           0.0      
     0.0
font-lock-compile-keyword                                  7464        0.0      
     0.0
font-lock-fontify-syntactically-region                     7           0.0      
     0.0
font-lock-default-unfontify-region                         26          0.0      
     0.0
font-lock-value-in-major-mode                              249         0.0      
     0.0
font-lock-turn-on-thing-lock                               99          0.0      
     0.0
flyspell-word-search-backward                              2           0.0      
     0.0
flyspell-hack-local-variables-hook                         48          0.0      
     0.0
flyspell-check-word-p                                      10          0.0      
     0.0
flyspell-delete-all-overlays                               1           0.0      
     0.0
flyspell-kill-ispell-hook                                  5           0.0      
     0.0
flyspell-highlight-duplicate-region                        1           0.0      
     0.0
flyspell-after-change-function                             12          0.0      
     0.0
flyspell-delay-commands                                    49          0.0      
     0.0
flyspell-pre-command-hook                                  10          0.0      
     0.0
flyspell-get-not-casechars                                 19          0.0      
     0.0
flyspell-prog-mode                                         1           0.0      
     0.0
flyspell-highlight-incorrect-region                        1           0.0      
     0.0
flyspell-mode-off                                          1           0.0      
     0.0
flyspell-deplacement-command                               196         0.0      
     0.0
flyspell-delay-command                                     294         0.0      
     0.0
flyspell-generic-progmode-verify                           8           0.0      
     0.0
flyspell-deplacement-commands                              49          0.0      
     0.0
flyspell-get-casechars                                     12          0.0      
     0.0
flyspell-delete-region-overlays                            38          0.0      
     0.0
flyspell-unhighlight-at                                    12          0.0      
     0.0
color-theme-frame-params                                   1           0.0      
     0.0
color-theme-alist                                          2           0.0      
     0.0
color-theme-spec-compat                                    448         0.0      
     0.0
color-theme-variables                                      1           0.0      
     0.0
color-theme-plist-delete                                   8           0.0      
     0.0
color-theme-install-frame-params                           1           0.0      
     0.0
color-theme-install-variables                              1           0.0      
     0.0
color-theme-faces                                          1           0.0      
     0.0
color-theme-alist-reduce                                   2           0.0      
     0.0
color-theme-spec-filter                                    1           0.0      
     0.0
color-theme-canonic                                        1           0.0      
     0.0
custom-handle-all-keywords                                 82          0.0      
     0.0
custom-add-link                                            136         0.0      
     0.0
custom-add-to-group                                        2183        0.0      
     0.0
custom-declare-group                                       200         0.0      
     0.0
custom-current-group                                       25          0.0      
     0.0
custom-add-version                                         237         0.0      
     0.0
custom-initialize-set                                      1           0.0      
     0.0
custom-set-default                                         2           0.0      
     0.0
custom-add-option                                          4           0.0      
     0.0
custom-add-dependencies                                    2           0.0      
     0.0
ispell-get-casechars                                       13          0.0      
     0.0
ispell-send-string                                         208         0.0      
     0.0
ispell-set-spellchecker-params                             59          0.0      
     0.0
ispell-process-status                                      98          0.0      
     0.0
ispell-check-minver                                        8           0.0      
     0.0
ispell-get-decoded-string                                  44          0.0      
     0.0
ispell-parse-output                                        7           0.0      
     0.0
ispell-get-ispell-args                                     2           0.0      
     0.0
ispell-get-extended-character-mode                         99          0.0      
     0.0
ispell-get-not-casechars                                   19          0.0      
     0.0
ispell-filter                                              9           0.0      
     0.0
ispell-get-many-otherchars-p                               12          0.0      
     0.0
ispell-get-coding-system                                   90          0.0      
     0.0
ispell-decode-string                                       43          0.0      
     0.0
ispell-kill-ispell                                         5           0.0      
     0.0
--8<---------------cut here---------------end--------------->8---

Any idea in which direction to go?

Environment:
  Org-mode version 7.5 (release_7.5.274.gd6aba.dirty)
  GNU Emacs 23.1.50.1 (i386-mingw-nt5.1.2600) of 2009-10-14 on LENNART-69DE564 
(patched)
  on Windows XP SP3

Best regards,
  Seb

-- 
Sébastien Vauban

Attachment: tags-opening-it-is-sloooooooooow.org
Description: Text Data


reply via email to

[Prev in Thread] Current Thread [Next in Thread]