speed issues

classic Classic list List threaded Threaded
11 messages Options
Reply | Threaded
Open this post in threaded view
|

speed issues

mhoenicka
Hi,

I'm using planner-mode to manage my projects in a research lab. I  
couldn't live without it, but I can't ignore speed problems which keep  
getting more and more pressing as my projects advance. I press C-c C-p  
each morning to update my HTML task list (see  
http://www.mhoenicka.de/software/hacks/tasklist.html) and to publish  
the changed planner pages to HTML. This process takes approx. 10  
minutes these days. I can live with that, although my box (a Pentium 4  
2.4GHz 768MB RAM) is essentially locked due to the modest hardware,  
but it's just not convenient.

Usually only half a dozen pages need to be published every day. The  
sizes are approx. one or two printed page using the HTML output, so  
this shouldn't be a problem. I reckon the problem is in generating the  
index. Currently there are approx. 1100 muse pages. As far as I  
understand, generating the index requires planner to peek into each  
file to collect the data for the calendar-based index, whereas the  
page-based index should just require a directory listing. OTOH my  
taskmm add-on (see http://www.mhoenicka.de/software/hacks/taskmm.html)  
also traverses all non-day muse files to collect the backlinks. This  
Perl script takes approx. 3 seconds to finish. So what does Emacs do  
in the remaining 10 minutes?

My platform is a Windows XP box running NTEmacs 23.1.1. I use Cygwin  
bash as a shell although I'm not sure if publishing planner projects  
involves any shell commands.

What are my options besides doing the obvious (ditch the box and get  
recent hardware)?

regards,
Markus

--
Markus Hoenicka
http://www.mhoenicka.de
AQ score 38



_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

Ottaway, Jim
>>>>> Markus Hoenicka <[hidden email]> writes:
> I'm using planner-mode to manage my projects in a research lab. I  
> couldn't live without it, but I can't ignore speed problems which keep  
> getting more and more pressing as my projects advance. I press C-c C-p  
> each morning to update my HTML task list (see  
> http://www.mhoenicka.de/software/hacks/tasklist.html) and to publish  
> the changed planner pages to HTML. This process takes approx. 10  
> minutes these days. I can live with that, although my box (a Pentium 4  
> 2.4GHz 768MB RAM) is essentially locked due to the modest hardware,  
> but it's just not convenient.

> [...]

> What are my options besides doing the obvious (ditch the box and get  
> recent hardware)?

You could try profiling the planner package to see what is taking up all
of that time:

Before you do the update

M-x elp-instrument-package [RET]
planner [RET]

Then

C-c C-p to do the update

Then

M-x elp-results [RET]



Yours sincerely,
--
Jim Ottaway


_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

mhoenicka
"Ottaway, Jim" <[hidden email]> was heard to say:

> You could try profiling the planner package to see what is taking up all
> of that time:
>

Hi Jim,

thanks for making me aware of these profiling commands. This is just  
what I was looking for.

The results are a bit strange though. Planner itself barely takes a  
couple of seconds. Therefore I also instrumented the muse package,  
which does the publishing after all. This is what I get (only the top  
35 or so entries are shown here):

muse-publish-markup-region                       4           880.836    
     220.209
muse-publish-markup                              16          880.82    
     55.05125
muse-project-publish-default                     1           444.809    
     444.809
muse-project-publish                             1           444.809    
     444.809
muse-project-publish-file                        979         444.433    
     0.4539662921
muse-project-publish-file-default                979         443.916    
     0.4534382022
muse-publish-file                                979          
443.46500000  0.4529775280
muse-publish-markup-buffer                       3           441.934    
     147.31133333
muse-publish-markup-link                         985          
440.15099999  0.4468538071
muse-publish-insert-url                          985          
440.07399999  0.4467756345
muse-publish-url                                 985          
440.01299999  0.4467137055
muse-publish-markup-tag                          96          439.84    
     4.5816666666
muse-publish-classify-url                        985          
439.54599999  0.4462395939
muse-project-link-page                           985          
439.48399999  0.4461766497
muse-publish-mark-up-tag                         1           438.902    
     438.902
muse-project-file-alist                          988          
438.41499999  0.4437398785
muse-project-file-entries                        988          
438.38299999  0.4437074898
muse-project-page-file                           985          
437.97699999  0.4446467005
muse-page-name                                   968252      
39.713999999  4.10...e-005
muse-style-element                               102748      2.053      
     1.99...e-005
muse-project-applicable-styles                   1964        
1.1910000000  0.0006064154
muse-find-markup-element                         13277        
0.9800000000  7.38...e-005
planner-update-task                              1           0.938      
     0.938
planner-index-as-string                          1           0.938      
     0.938
planner-update-task-basic                        1           0.938      
     0.938
planner-lower-task-priority                      1           0.938      
     0.938
muse-publish-lisp-tag                            28          0.938      
     0.0334999999
muse-eval-lisp                                   28          0.938      
     0.0334999999
muse-project-resolve-link                        985          
0.7230000000  0.0007340101
muse-collect-alist                               985          
0.7180000000  0.0007289340
planner-find-file                                1           0.469      
     0.469
planner-jump-to-linked-task-basic                1           0.469      
     0.469
planner-save-buffers                             1           0.469      
     0.469
planner-jump-to-linked-task                      1           0.469      
     0.469
muse-index-as-string                             1           0.469      
     0.469
planner-list-daily-files                         1           0.453      
     0.453
planner-file-alist                               1           0.453      
     0.453

What intrigues me is that a bunch of muse publishing functions like  
muse-project-publish-file are called 979 times, which is the number of  
muse files in my project. That is, muse spends approx. 7 minutes in  
files which don't need to be published at all. If I look at the  
timestamps in my output directory, I can verify that muse updates only  
those files which were actually modified, e.g. two files in the test  
shown above. Is this some problem of my particular setup, or is  
planner/muse supposed to work this way?

I'll appreciate any hints how to speed this up. 'Course I'll be happy  
to provide further debug information if needed.

regards,
Markus


--
Markus Hoenicka
http://www.mhoenicka.de
AQ score 38



_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

Ottaway, Jim
>>>>> Markus Hoenicka <[hidden email]> writes:
> "Ottaway, Jim" <[hidden email]> was heard to say:
>> You could try profiling the planner package to see what is taking up all
>> of that time:
>>
> thanks for making me aware of these profiling commands. This is just  
> what I was looking for.

> The results are a bit strange though. Planner itself barely takes a  
> couple of seconds. Therefore I also instrumented the muse package,  
> which does the publishing after all. This is what I get (only the top  
> 35 or so entries are shown here):

This one looks a bit suspicious:

> muse-publish-mark-up-tag       1           438.902    438.902

Do you have a <markup function=...> tag in a file somewhere with a
function that takes a long time?

> What intrigues me is that a bunch of muse publishing functions like
> muse-project-publish-file are called 979 times, which is the number of
> muse files in my project. That is, muse spends approx. 7 minutes in
> files which don't need to be published at all. If I look at the
> timestamps in my output directory, I can verify that muse updates only
> those files which were actually modified, e.g. two files in the test
> shown above. Is this some problem of my particular setup, or is
> planner/muse supposed to work this way?

Yes, it is supposed to work this way: muse-publish-file does the check
to see if FILE is newer than the published file, so it gets called
no matter what, but nothing is done if FILE is not newer [unless FORCE
is non-nil].

Yours sincerely,
--
Jim Ottaway


_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

mhoenicka
"Ottaway, Jim" <[hidden email]> was heard to say:

> This one looks a bit suspicious:
>
>> muse-publish-mark-up-tag       1           438.902    438.902
>
> Do you have a <markup function=...> tag in a file somewhere with a
> function that takes a long time?

No, there's only the obligatory <markup>..</markup> pseudo-element in  
index.muse:

<markup>
<lisp>(planner-index-as-string t t)</lisp>
</markup>

I would actually expect that generating the index takes a while, as  
we're looking at approx. 1000 files.

> Yes, it is supposed to work this way: muse-publish-file does the check
> to see if FILE is newer than the published file, so it gets called
> no matter what, but nothing is done if FILE is not newer [unless FORCE
> is non-nil].
>

So it takes Emacs approx. half a second to decide whether or not a  
file needs to be published? I didn't look at the source code yet, but  
this looks a bit suspicious to me.

I guess I'll try to repeat the profiling on a FreeBSD box at home,  
just to rule out any Windows or Cygwin-specific issues. I'll be back  
with the results later tonight.

regards,
Markus



--
Markus Hoenicka
http://www.mhoenicka.de
AQ score 38



_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

Ottaway, Jim

>>>>> markus hoenicka@mhoenicka de <[hidden email]> writes:

>> Yes, it is supposed to work this way: muse-publish-file does the check
>> to see if FILE is newer than the published file, so it gets called
>> no matter what, but nothing is done if FILE is not newer [unless FORCE
>> is non-nil].
>>
> So it takes Emacs approx. half a second to decide whether or not a  
> file needs to be published? I didn't look at the source code yet, but  
> this looks a bit suspicious to me.

Me too, now you mention it.

But remember that that's an average time, and also that it includes any
time taken by functions called by muse-publish-file.

I.e., to see if it is inefficient you'd have to try it when no files
need publishing.

Yours sincerely,
--
Jim Ottaway


_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

mhoenicka
Ottaway, Jim writes:
 > > So it takes Emacs approx. half a second to decide whether or not a  
 > > file needs to be published? I didn't look at the source code yet, but  
 > > this looks a bit suspicious to me.
 >
 > Me too, now you mention it.
 >

Ok, here goes. These are the results on a 1.7GHz Centrino Notebook
with 1GB of memory running FreeBSD 8.0-STABLE. The test data were a
backup of the files I use at work, so its like 10 files less but
otherwise the same.

The first run took approx. 4 min to complete, as all files needed
publishing. The ELP output of the second run with just one modified
file looks like this, with only those functions that take longer than
a second shown here:

muse-publish-markup                              11          18.625703     1.6932457272
muse-publish-markup-region                       3           18.551402     6.1838006666
muse-project-publish                             1           12.532707     12.532707
muse-project-publish-default                     1           12.532433     12.532433
muse-project-publish-file                        966         12.406346999  0.0128430093
muse-project-publish-file-default                966         11.158744999  0.0115514958
muse-publish-file                                966         11.097747999  0.0114883519
muse-publish-markup-buffer                       2           9.623259      4.8116295
muse-publish-markup-tag                          82          9.1936850000  0.1121181097
muse-publish-mark-up-tag                         1           9.017514      9.017514
muse-publish-markup-link                         589         7.8443390000  0.0133180628
muse-style-element                               67687       7.7524080000  0.0001145331
muse-publish-insert-url                          589         7.4865610000  0.0127106298
muse-publish-url                                 589         7.4511330000  0.0126504804
muse-publish-classify-url                        589         5.6892740000  0.0096592088
muse-publish-link-page                           589         5.6759699999  0.0096366213
muse-project-link-page                           589         5.6693740000  0.0096254227
muse-find-markup-element                         7959        3.1845389999  0.0004001179
muse-project-page-file                           589         2.8212049999  0.0047898217
muse-collect-alist                               589         2.5992269999  0.0044129490
muse-project-resolve-link                        589         1.3908080000  0.0023613039
muse-style                                       73190       1.2080370000  1.650...e-05
muse-project-applicable-styles                   1555        1.1961229999  0.0007692109
muse-project-of-file                             591         1.0742109999  0.0018176159

So, instead of 10 min it doesn't even take 20 seconds. Is it safe to
conclude that the file-newer-than-file-p implementation on NTEmacs is
somewhat flawed? This is the only platform-dependent function which I
can see in the muse-publish-file body. Here on FreeBSD it takes:

file-newer-than-file-p                           965         0.0586679999  6.079...e-05

I'll check tomorrow what it says on NTEmacs.

regards,
Markus

--
Markus Hoenicka
http://www.mhoenicka.de
AQ score 38

_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

mhoenicka
In reply to this post by mhoenicka
Markus Hoenicka <[hidden email]> was heard to say:

> So it takes Emacs approx. half a second to decide whether or not a  
> file needs to be published? I didn't look at the source code yet,  
> but this looks a bit suspicious to me.
>

This is what I get on my WinXP box:

file-newer-than-file-p  978         4.6200000000  0.0047239263

This function is almost two orders of magnitudes slower than on  
FreeBSD, but this doesn't explain the huge difference of the overall  
processing time. I'll continue profiling to find the culprit.

regards,
Markus

--
Markus Hoenicka
http://www.mhoenicka.de
AQ score 38



_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

mhoenicka
Markus Hoenicka <[hidden email]> was heard to say:

> This function is almost two orders of magnitudes slower than on
> FreeBSD, but this doesn't explain the huge difference of the overall
> processing time. I'll continue profiling to find the culprit.
>

And now for something really interesting. I've used Cygwin's Emacs  
this time. I've shunned this app so far due to some oddities, but it's  
probably time to move on. Again, only the top 25 are shown here:

muse-project-publish-default                     1           13.543    
     13.543
muse-project-publish                             1           13.543    
     13.543
muse-project-publish-file                        979          
12.747999999  0.0130214504
muse-project-publish-file-default                979          
12.124000000  0.0123840653
muse-publish-file                                979          
11.808000000  0.0120612870
muse-publish-markup                              16          11.284    
     0.70525
muse-publish-markup-region                       4            
11.225999999  2.8064999999
muse-publish-markup-buffer                       3           5.817      
     1.939
muse-publish-markup-tag                          141         5.654      
     0.0400992907
muse-publish-mark-up-tag                         1           5.487      
     5.487
muse-write-file                                  3           4.711      
     1.5703333333
muse-publish-markup-link                         999          
4.5740000000  0.0045785785
muse-publish-insert-url                          999          
4.3810000000  0.0043853853
muse-publish-url                                 999          
4.3140000000  0.0043183183
muse-publish-classify-url                        999          
3.1959999999  0.0031991991
muse-project-link-page                           999          
3.0549999999  0.0030580580
muse-style-element                               105046      
2.1749999999  2.070...e-05
muse-project-page-file                           1005        
1.5009999999  0.0014935323
muse-project-file-alist                          1009        
1.4019999999  0.0013894945
muse-find-markup-element                         13917        
1.3379999999  9.614...e-05
muse-project-applicable-styles                   1978        
1.0109999999  0.0005111223
muse-project-determine-last-mod                  1010        
0.9740000000  0.0009643564
muse-project-resolve-link                        999          
0.9500000000  0.0009509509
muse-publish-escape-specials-in-string           4995        
0.6490000000  0.0001299299
file-newer-than-file-p                           978          
0.5850000000  0.0005981595

As you can see, GNU Emacs is even faster on Cygwin than on my FreeBSD  
box, the older hardware notwithstanding. I conclude that my speed  
problems are neither planner's nor muse's fault, but are caused by  
speed issues of the native Windows port of GNU Emacs.

Thanks again for getting me on the right track in the first place.

regards,
Markus




--
Markus Hoenicka
http://www.mhoenicka.de
AQ score 38



_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

Ottaway, Jim
>>>>> Markus Hoenicka <[hidden email]> writes:

> Markus Hoenicka <[hidden email]> was heard to say:
>> This function is almost two orders of magnitudes slower than on
>> FreeBSD, but this doesn't explain the huge difference of the overall
>> processing time. I'll continue profiling to find the culprit.
>>

> And now for something really interesting. I've used Cygwin's Emacs  
> this time. I've shunned this app so far due to some oddities, but it's  
> probably time to move on. Again, only the top 25 are shown here:

> [...]

> file-newer-than-file-p        978          0.5850000000  0.0005981595

> As you can see, GNU Emacs is even faster on Cygwin than on my FreeBSD  
> box, the older hardware notwithstanding. I conclude that my speed  
> problems are neither planner's nor muse's fault, but are caused by  
> speed issues of the native Windows port of GNU Emacs.

> Thanks again for getting me on the right track in the first place.

Well it looks as though that is the culprit then.

I suppose if you wanted to carry on with the non-Cygwin Emacs you could
bypass the file-newer-than-file-p business by doing something elaborate
to maintain a persistent list of modified pages: use before-save-hook to
write out a list of modified pages to a file,
muse-before-project-publish-hook to read the list in , and a customized
:published-project option for the project [instead of
muse-project-publish-default] which only publishes the files in the
modified list.

Something like that...


Yours sincerely,
--
Jim Ottaway


_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss
Reply | Threaded
Open this post in threaded view
|

Re: speed issues

mhoenicka
Ottaway, Jim writes:
 > I suppose if you wanted to carry on with the non-Cygwin Emacs you could
 > bypass the file-newer-than-file-p business by doing something elaborate
 > to maintain a persistent list of modified pages: use before-save-hook to
 > write out a list of modified pages to a file,
 > muse-before-project-publish-hook to read the list in , and a customized
 > :published-project option for the project [instead of
 > muse-project-publish-default] which only publishes the files in the
 > modified list.
 >

My main gripe with Cygwin Emacs (running in an X11 window) is its lack
of file drag&drop. If I decide to stick with the native port, I'll
probably just run a script which calls Cygwin Emacs to batch-process
my project files. I usually do this only once in the morning, so this
wouldn't be a big deal.

regards,
Markus

--
Markus Hoenicka
http://www.mhoenicka.de
AQ score 38

_______________________________________________
Planner-el-discuss mailing list
[hidden email]
https://mail.gna.org/listinfo/planner-el-discuss