Re: [O] Bug: finding close tasks has infinite loop [9.0.5 (release_9.0.5-433-ge65be5 @ /home/hs/.emacs.d/git/org-mode/lisp/)]

[Stefan-W. Hahn]

Mail von Stefan-W. Hahn, Fri, 07 Apr 2017 at 09:39:30 +0200:

Hello,

I tried an instrumented version with code below and got an hint where the
time get consumed.

> #+BEGIN_QUOTE
> ** DONE Task                                                                 
> :@status:
> CLOSED: [2017-02-17 Fr 14:08]
>    :CLOCK:
>    CLOCK: [2016-03-07 Mo 12:58]--[2016-03-07 Mo 14:09] =>  1:11

979 CLOCK lines, gives 1958 org-time entries.

>    CLOCK: [2011-09-26 Mo 13:02]--[2011-09-26 Mo 13:48] =>  0:46
>    :END:
>    Added: [2011-09-26 Mo]
> 
> #+END_QUOTE
> 

With following code I let it run. It came to an end after 119 seconds:

#+BEGIN_SRC emacs-lisp

(defmacro profile-org (times &rest body)
    `(let (output)
       (dolist (p '("org-"))  ; symbol prefixes to instrument
         (elp-instrument-package p))
       (dotimes (x ,times)
         ,@body)
       (elp-results)
       (elp-restore-all)
       (point-min)
       (forward-line 20)
       (delete-region (point) (point-max))
       (setq output (buffer-substring-no-properties (point-min) (point-max)))
       (kill-buffer)
       (delete-window)
       output))

(let ((org-agenda-files
       '("~/notes/bug/test.org")))
  (profile-org 1
               (org-tags-view nil "+CLOSED<=\"<-1m>\"")))
#+END_SRC

This is the elp-result:

#+BEGIN_QUOTE

Back to top level
org-tags-view                                                 1           
119.90470040  119.90470040
org-scan-tags                                                 1           
119.89504432  119.89504432
org-entry-properties                                          2           
119.89459378  59.947296892
org-cached-entry-get                                          1           
119.89455419  119.89455419
org-element-context                                           1959        
119.88264565  0.0611958374
org-element-at-point                                          1959        
119.87516006  0.0611920163
org-element--parse-to                                         1959        
119.61624070  0.0610598472
org-element--current-element                                  963339      
106.53174518  0.0001105859
org-element-clock-parser                                      959420      
77.279206300  8.054...e-05
org-element-timestamp-parser                                  961380      
60.700601205  6.313...e-05
org-parse-time-string                                         1920801     
32.491741821  1.691...e-05
org-get-limited-outline-regexp                                969216      
10.924480618  1.127...e-05
org-at-heading-p                                              967259      
4.0055616979  4.141...e-06
org-element--cache-put                                        963339      
2.1260797540  2.206...e-06
org-element-drawer-parser                                     1959        
0.5903366010  0.0003013458
org-element-planning-parser                                   1959        
0.0443325489  2.263...e-05
org-element--collect-affiliated-keywords                      1960        
0.0102636800  5.236...e-06
org-agenda-prepare                                            1           
0.008041049   0.008041049
org-agenda-mode                                               1           
0.002911944   0.002911944
org-agenda-prepare-buffers                                    1           
0.002577423   0.002577423

#+END_QUOTE

It gives an amazing number of calles to org-parse-time-string, around 981
calls or each org-timestamp.

With kind regards,
Stefan

-- 
Stefan-W. Hahn                          It is easy to make things.
                                        It is hard to make things simple.