emacs-orgmode@gnu.org archives
 help / color / mirror / code / Atom feed
* slow capture templates
@ 2014-05-22  7:07 jamil egdemir
  2014-05-22  8:49 ` Bastien
  0 siblings, 1 reply; 8+ messages in thread
From: jamil egdemir @ 2014-05-22  7:07 UTC (permalink / raw)
  To: emacs-orgmode

Hi,

I'm running into very slow capture templates since this morning with a
good 10-20 second delay each time I try to invoke them.  After
instrumenting org with elp and examining the results I get:

org-capture                                                   1
   42.157791853  42.157791853
org-capture-fill-template                                     1
   40.939494541  40.939494541
org-get-x-clipboard                                           5
   40.895240381  8.1790480762
org-get-x-clipboard-compat                                    5
   40.895134778  8.1790269558
org-capture-select-template                                   1
   1.168859672   1.168859672
org-mks                                                       1
   1.168828382   1.168828382
org-mode                                                      1
   0.043022998   0.043022998
org-install-agenda-files-menu                                 1
   0.041738898   0.041738898
org-agenda-files                                              2
   0.041651735   0.0208258675
org-current-time                                              2
   0.033159385   0.0165796925
org-capture-place-template                                    1
   0.009962929   0.009962929
<snip...>

Looks like those top four calls in the list are burning up a huge
amount of time.  The delay is independent of the particular template I
use and also occurs when I start up emacs without an init (emacs -q).

I'm working on OpenBSD 5.4.

Emacs and Org-mode version info:
(org-version)"8.2.6"
GNU Emacs 24.4.50.1 (x86_64-unknown-openbsd5.4, GTK+ Version 3.8.2)

This particular emacs was built from source pulled just this morning.
The delay in the capture templates is also present when using the
emacs from the OpenBSD package: (GNU Emacs 24.3.1
(x86_64-unknown-openbsd, GTK+ Version 3.8.2) of 2013-07-23 on
amd64-1.ports.openbsd.org.

I pushed the same org files and configurations to an ubuntu box and
tried the same profiling exercise with elp on emacs (24.3.1) with
org-mode 7.9.3f and the capture templates were quick and snappy.

My capture templates from my .emacs:

;; Capture templates for: TODO tasks, Notes, appointments, phone
calls, meetings, and org-protocol
(setq org-capture-templates
      (quote (("t" "todo" entry (file "~/workarea/personal/orgfiles/refile.org")
               "* TODO %?\n%U\n%a\n" :clock-in t :clock-resume t)
              ("r" "respond" entry (file
"~/workarea/personal/orgfiles/refile.org")
               "* NEXT Respond to %:from on %:subject\nSCHEDULED:
%t\n%U\n%a\n" :clock-in t :clock-resume t :immediate-finish t)
              ("n" "note" entry (file "~/workarea/personal/orgfiles/refile.org")
               "* %? :NOTE:\n%U\n%a\n" :clock-in t :clock-resume t)
              ("j" "Journal" entry (file+datetree
"~/workarea/personal/orgfiles/diary.org")
               "* %?\n%U\n" :clock-in t :clock-resume t)
              ("w" "org-protocol" entry (file
"~/workarea/personal/orgfiles/refile.org")
               "* TODO Review %c\n%U\n" :immediate-finish t)
              ("m" "Meeting" entry (file
"~/workarea/personal/orgfiles/refile.org")
               "* MEETING with %? :MEETING:\n%U" :clock-in t :clock-resume t)
              ("p" "Phone call" entry (file
"~/workarea/personal/orgfiles/refile.org")
               "* PHONE %? :PHONE:\n%U" :clock-in t :clock-resume t)
              ("h" "Habit" entry (file
"~/workarea/personal/orgfiles/refile.org")
               "* NEXT %?\n%U\n%a\nSCHEDULED: %(format-time-string
\"<%Y-%m-%d %a .+1d/3d>\")\n:PROPERTIES:\n:STYLE:
habit\n:REPEAT_TO_STATE: NEXT\n:END:\n"))))

Anyone have any ideas on how I can correct this problem?  The elisp in
those top four functions from the profile is beyond me.

-j



-- 
-------------------------------------------------------------
Jamil Egdemir
unclejamil@gmail.com
http://www.power-quant.com
(631) 338-3170 (cell)
-------------------------------------------------------------

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: slow capture templates
  2014-05-22  7:07 slow capture templates jamil egdemir
@ 2014-05-22  8:49 ` Bastien
  2014-05-22 15:51   ` jamil egdemir
  0 siblings, 1 reply; 8+ messages in thread
From: Bastien @ 2014-05-22  8:49 UTC (permalink / raw)
  To: jamil egdemir; +Cc: emacs-orgmode

Hi Jamil,

jamil egdemir <unclejamil@gmail.com> writes:

> Anyone have any ideas on how I can correct this problem?

Nope -- but in the meantime, can you try with the latest Org version
from the Git master branch?

~$ git clone git://orgmode.org/org-mode.git
~$ cd org-mode
~$ make

then load the correct location in your .emacs config file.

-- 
 Bastien

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: slow capture templates
  2014-05-22  8:49 ` Bastien
@ 2014-05-22 15:51   ` jamil egdemir
  2014-05-22 16:34     ` Bastien
  0 siblings, 1 reply; 8+ messages in thread
From: jamil egdemir @ 2014-05-22 15:51 UTC (permalink / raw)
  To: emacs-orgmode

Bastien,

I've pulled the latest org from git and added it to my load-path:

;; to make sure we're using the latest org checkout from git:
(add-to-list 'load-path "~/home/jegdemir/buildarea/org-mode/lisp")
(add-to-list 'load-path "~/home/jegdemir/buildarea/org-mode/contrib/lisp" t)

and now when I evaluate org-version in my *scratch* I get:

(org-version)"8.2.6"

so it seems I'm tracking with development now.

I reran the profiler with org instrumented:

org-get-x-clipboard                                           6
   62.326623797  10.387770632
org-get-x-clipboard-compat                                    6
   62.326477761  10.387746293
org-make-link-string                                          1
   0.026009872   0.026009872
org-image-file-name-regexp                                    1
   0.025920266   0.025920266
org-clock-in                                                  1
   0.004433664   0.004433664
org-mode-flyspell-verify                                      1
   0.002293867   0.002293867
org-indent-refresh-maybe                                      18
   0.001712022   9.511...e-05
org-switch-to-buffer-other-window                             2
   0.001558158   0.000779079
org-clock-find-position                                       1
   0.001489784   0.001489784
org-mode                                                      1
   0.001480635   0.001480635

I have also tried the capture templates with and without X
since the profile indicated that the largest
consumers of time were dealing with the clipboard.  Sure enough
the capture templates are greased lightning quick when run in emacs w/o X:

org-capture                                                   1
   1.161324914   1.161324914
org-capture-select-template                                   1
   1.1253895489  1.1253895489
org-mks                                                       1
   1.125358958   1.125358958
org-clock-in                                                  1
   0.030630571   0.030630571
org-clock-find-position                                       1
   0.025617154   0.025617154
org-indent-line                                               3
   0.0251875609  0.0083958536
org-in-item-p                                                 6
   0.0249584120  0.0041597353
org-list-context                                              6
   0.024542436   0.004090406
org-resolve-clocks                                            1
   0.002721156   0.002721156
org-find-open-clocks                                          3
   0.0025130990  0.0008376996
org-capture-fill-template                                     1
   0.002402191   0.002402191
org-capture-place-template                                    1
   0.002357772   0.002357772
org-capture-place-entry                                       1
   0.001994248   0.001994248
org-mode                                                      1
   0.001423784   0.001423784
org-indent-refresh-maybe                                      14
   0.001286477   9.189...e-05
<..snip..>

So it seems there is a connection with X.

-jamil

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: slow capture templates
  2014-05-22 15:51   ` jamil egdemir
@ 2014-05-22 16:34     ` Bastien
  2014-05-22 21:25       ` Fwd: " jamil egdemir
  0 siblings, 1 reply; 8+ messages in thread
From: Bastien @ 2014-05-22 16:34 UTC (permalink / raw)
  To: jamil egdemir; +Cc: emacs-orgmode

Hi Jamil,

jamil egdemir <unclejamil@gmail.com> writes:

> I've pulled the latest org from git and added it to my load-path:

You also need to "make" or "make autoloads".

> ;; to make sure we're using the latest org checkout from git:
> (add-to-list 'load-path "~/home/jegdemir/buildarea/org-mode/lisp")
> (add-to-list 'load-path "~/home/jegdemir/buildarea/org-mode/contrib/lisp" t)
>
> and now when I evaluate org-version in my *scratch* I get:
>
> (org-version)"8.2.6"

Please check M-x org-version RET, not just M-: (org-version) RET as it
gives more information.

> So it seems there is a connection with X.

Mhh...

`org-get-x-clipboard-compat' does not do anything fancy -- perhaps you
can check whether you observe the slowliness with other Emacs features
using the clipboard?

-- 
 Bastien

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Fwd: slow capture templates
  2014-05-22 16:34     ` Bastien
@ 2014-05-22 21:25       ` jamil egdemir
  2014-05-22 22:34         ` Nick Dokos
  0 siblings, 1 reply; 8+ messages in thread
From: jamil egdemir @ 2014-05-22 21:25 UTC (permalink / raw)
  To: emacs-orgmode

Bastien,

My apologies.  I should have been more explicit on the installation.
I followed the instructions at

http://orgmode.org/manual/Installation.html

which included the 'make autoloads' where make in this case is
actually GNU make pulled down from their packages as opposed to the
OpenBSD make.

Using M-x org-version RET I get:
Org-mode version 8.2.6 (release_8.2.6-1 @
/home/jegdemir/share/emacs/24.4.50/lisp/org/)

and so it appears the checked out org is being loaded.

In an attempt to follow you suggestion,  I fired up a few calls to
x-get-selection in my *scratch* but didn't find anything exciting:

;; let's try this with UTF8_STRING:
(x-get-selection nil 'UTF8_STRING)#("(x-get-selection value
'UTF8_STRING)" 0 35 (fontified nil) 35 36 (fontified nil
rear-nonsticky t))
(x-get-selection 'PRIMARY 'UTF8_STRING)##("rear" 0 4 (fontified t))
(x-get-selection 'SECONDARY 'UTF8_STRING)nil
(x-get-selection 'CLIPBOARD 'UTF8_STRING)#("resume" 0 6
(foreign-selection UTF8_STRING))

;; and with COMPOUND_TEXT:
(x-get-selection nil 'COMPOUND_TEXT)#("immediate" 0 9
(foreign-selection COMPOUND_TEXT))
(x-get-selection 'PRIMARY 'COMPOUND_TEXT)#("immediate" 0 9
(foreign-selection COMPOUND_TEXT))
(x-get-selection 'SECONDARY 'COMPOUND_TEXT)nil
(x-get-selection 'CLIPBOARD 'COMPOUND_TEXT)#("#(\"resume\" 0 6
(foreign-selection COMPOUND_TEXT))" 0 2 (fontified t) 2 10 (fontified
t face font-lock-string-face) 10 34 (fontified t) 34 47 (fontified t)
47 49 (fontified t))

I was hoping this would expose something since the two function calls
in org-eventually boil down to x-get-selection (I think) but no dice.
I also tried 'STRING and 'TEXT as arguments in the x-get-selection...
results were the same and execution time was snappy.

I also tried the following:

- close and restart emacs
- switched to *scratch* buffer
- instrumented X (along with org) by calling M-x
elp-instrument-package RET org RET and M-x elp-instrument-package RET
x RET
- executed (org-capture) in scratch with C-x C-e with point at the end
of the form

The resulting profile from elp immediately after last step:

org-get-x-clipboard                                           6
   115.30243587  19.217072645
org-get-x-clipboard-compat                                    6
   115.30235814  19.217059690
x-get-selection                                               24
   115.30194600  4.8042477502
x-get-selection-internal                                      24
   115.30104917  4.8042103823
org-clock-in                                                  1
   1.162223352   1.162223352
org-resolve-clocks                                            1
   1.158297155   1.158297155
org-find-open-clocks                                          3
   1.1580858859  0.3860286286
org-indent-add-properties                                     16
   0.420800437   0.0263000273
org-indent-initialize-agent                                   3
   0.4196886359  0.139896212
org-indent-initialize-buffer                                  2
   0.4195824059  0.2097912029
org-at-item-p                                                 3131
   0.2143426759  6.845...e-05
org-list-in-valid-context-p                                   329
   0.1737325780  0.0005280625
org-in-block-p                                                329
   0.1715975809  0.0005215731
org-between-regexps-p                                         2619
   0.1176125040  4.490...e-05
org-get-indentation                                           2814
   0.0492611860  1.750...e-05
org-mode                                                      3
   0.041698319   0.0138994396

and after looking at the source for x-get-selection you find that the
first thing it does is call x-get-selection-internal with appears to
map to something in xselect.c.  This happens inside select.el.gz...

Looking at the definitions of the capture templates I'm using I'm not
sure if I understand why the call is being made in the first place if
the capture template does not contain %x.  Not that I think this would
solve my deeper problem but it does seem like a good idea to check the
template before pulling the clipboard contents as a matter of course.

In any case it seems unintentional to me that using a capture template
should induce 6 calls to org-get-x-clipboard and 24 calls to
x-get-selection.

BTW, Thanks for the help B.

-jamil

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: Fwd: slow capture templates
  2014-05-22 21:25       ` Fwd: " jamil egdemir
@ 2014-05-22 22:34         ` Nick Dokos
  2014-05-23  5:35           ` Bastien
  0 siblings, 1 reply; 8+ messages in thread
From: Nick Dokos @ 2014-05-22 22:34 UTC (permalink / raw)
  To: emacs-orgmode

jamil egdemir <unclejamil@gmail.com> writes:

> Using M-x org-version RET I get:
> Org-mode version 8.2.6 (release_8.2.6-1 @
> /home/jegdemir/share/emacs/24.4.50/lisp/org/)
>

...and which OS and which X are you using?

> In an attempt to follow you suggestion,  I fired up a few calls to
> x-get-selection in my *scratch* but didn't find anything exciting:
> ...
>
> I was hoping this would expose something since the two function calls
> in org-eventually boil down to x-get-selection (I think) but no dice.
> I also tried 'STRING and 'TEXT as arguments in the x-get-selection...
> results were the same and execution time was snappy.

So calling it by hand is fast, but calling it through org-capture is
extremely slow. Can you run an instrumented x-get-selection by hand and
see *how* fast the fast case is? On my system, I get 2.8ms per call, so
the ratio between that and your slow x-get-selection (admittedly a
meaningless number but that's why I wanted your fast value) is 150 or
so. I tried to come up with a theory here, but I must admit I'm baffled.

> ...
> x-get-selection                                               24
>    115.30194600  4.8042477502
> x-get-selection-internal                                      24
>    115.30104917  4.8042103823
> ...
> Looking at the definitions of the capture templates I'm using I'm not
> sure if I understand why the call is being made in the first place if
> the capture template does not contain %x.  Not that I think this would
> solve my deeper problem but it does seem like a good idea to check the
> template before pulling the clipboard contents as a matter of course.
>

That's probably true, but they *are* supposed to be fairly fast calls,
so a little inefficiency might not be too important. Besides, you
wouldn't have known that you have a problem with X selections if org
were more efficient :-)

> In any case it seems unintentional to me that using a capture template
> should induce 6 calls to org-get-x-clipboard and 24 calls to
> x-get-selection.
>

org-capture-fill-template can call org-get-x-clipboard from 4 to 6 times
and org-get-x-clipboard can call x-get-selection from 1 to 4 times, so
x-get-selection can be called from 4 to 24 times in each capture - you
got the worst-case scenario: 24 is the maximum. In my case, I had 4
calls to org-get-x-clipboard and 11 calls to x-get-selection. And at 3ms
per call, even 24 calls is probably insignificant - but not at 5s a call!

Nick

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: Fwd: slow capture templates
  2014-05-22 22:34         ` Nick Dokos
@ 2014-05-23  5:35           ` Bastien
  2014-05-23  6:07             ` Nick Dokos
  0 siblings, 1 reply; 8+ messages in thread
From: Bastien @ 2014-05-23  5:35 UTC (permalink / raw)
  To: Nick Dokos; +Cc: emacs-orgmode

Hi Nick,

Nick Dokos <ndokos@gmail.com> writes:

> ...and which OS and which X are you using?

The OS is: x86_64-unknown-openbsd5.4

-- 
 Bastien

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: Fwd: slow capture templates
  2014-05-23  5:35           ` Bastien
@ 2014-05-23  6:07             ` Nick Dokos
  0 siblings, 0 replies; 8+ messages in thread
From: Nick Dokos @ 2014-05-23  6:07 UTC (permalink / raw)
  To: emacs-orgmode

Bastien <bzg@gnu.org> writes:

> Hi Nick,
>
> Nick Dokos <ndokos@gmail.com> writes:
>
>> ...and which OS and which X are you using?
>
> The OS is: x86_64-unknown-openbsd5.4

Ah, right - thanks! I googled a bit and found this:

   http://lists.gnu.org/archive/html/help-gnu-emacs/2013-10/msg00124.html

Maybe it helps?

-- 
Nick

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, other threads:[~2014-05-23  6:08 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-05-22  7:07 slow capture templates jamil egdemir
2014-05-22  8:49 ` Bastien
2014-05-22 15:51   ` jamil egdemir
2014-05-22 16:34     ` Bastien
2014-05-22 21:25       ` Fwd: " jamil egdemir
2014-05-22 22:34         ` Nick Dokos
2014-05-23  5:35           ` Bastien
2014-05-23  6:07             ` Nick Dokos

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/emacs/org-mode.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).