Item11156: TablePlugin makes rdiff extremely slow on topics w/> 100 revs

First let me say I am not sure if this is a bug or a feature request.

My users still prefer the "Sequential" (rdiff type="history") view over the new pick your revision view.

This started with a complaint it was slow, but then turned into a complaint that it wasn't working.

This gets very slow with over 100 revisions, and times out after 200 revisions.

That is fare we have lots 10 years of history.

So we tried to limit the revisions using "rev1" and "rev2". However this had no effect on performance.

I am am not great with perl but it looks to me like the whole history is pulled regardless of the request.

I think that is a performance bug, but it may also be a feature request in that it would be nice to be able to do this through the UI also, instead of telling users to filter using URL. I think the best option would be to remove "Sequential" from bottom bar. And make "History" a render style.

-- JacobChamplin - 29 Sep 2011

Do you use RcsLite or RcsWrap, also are you using perl acceleration like mod_perl, fastcgi or fcgid?

-- GeorgeClark - 29 Sep 2011

RcsWrap, no perl acceleration.

-- JacobChamplin - 29 Sep 2011

I just tried RcsLite, and saw no performance difference. Its the system "rdiff" command that is taking so long, I can see it running using 100% of one core (is there a multicore rdiff?) for over 5 minutes.

-- JacobChamplin - 29 Sep 2011

Unfortuantly I can't send you the page but the ",v" file is only 497K I can't believe the its an IO issue.

-- JacobChamplin - 29 Sep 2011

What is your server timeout set to? Here locally on a test machine I've run an rdiff?type=history on a very large WikiUsers topic - 1700+ revisions, 510K rcs,v file. It takes a couple of minutes to run, but it does eventually return.

-- GeorgeClark - 29 Sep 2011

I don't know why ours is so slow, but I am sick of receiving messages. If you don't want to look into just close.

-- JacobChamplin - 04 Jan 2012

I'm not sure how to recreate this - it's really difficult to fix something without a good testcase. I have a couple of more questions, then instead of closing, remove your name from the "WaitingFor" field in the form - that will stop the messages. Change it to my name so I'll see that you've replied.

• If you use the "rlog data/web/YourSlowTopic.txt ... is that reasonably quick to respond?
• time rlog data/Main/WebStatistics.txt on my system takes around 3 seconds for 10,000 revisions
• time sudo -u apache ./view -topic WebStatistics ... is around 8 seconds
• Comparing rdiff and compare on that 10,000 rev topic on my laptop
  • time sudo -u apache ./rdiff -topic Main/WebStatistics -rev1 962 -rev2 963 was 51 seconds
  • time sudo -u apache ./compare -topic Main/WebStatistics -rev1 962 -rev2 963 was about 58 seconds
• Are you familiar with nytprof - it can profile perl to give a report on where the time is being spent.

-- GeorgeClark - 04 Jan 2012

Ah ... one more suggestion - try the command with the following in the URL:

bin/rdiff/YourWeb/YourSlowTopic?rev1=123;rev2=124;debugenableplugins=EmptyPlugin

That will disable all plugins. Sometimes plugins can really cause issues when rendered in a diff.

If this makes a big difference, you can add plugins to the list to enable one at a time until the slowdown occurrs. debugenableplugins=EmptyPlugin,TablePlugin and so on.

-- GeorgeClark - 04 Jan 2012

My 244 revision topic

• "Sequential" from web page: 233.875s
• time rlog: 0.034s
• time ./view: 0.268s
• time ./rdiff -rev1 1 -rev2 244: 0.272s
• time ./compare -rev1 1 -rev2 244: 0.377s
• URL "?type=history;debugenableplugins=EmptyPlugin": 9.959s

So It does seem to be something with plugins. No pluggins are used explicitly on that page. ActionTrackerPlugin is installed. RenderListPlugin, TinyMCEPlugin, and WysiwygPlugin are turned off from default install.

-- JacobChamplin - 06 Jan 2012

Probably the first thing to try is to add ?type=history;debugenableplugins=EmptyPlugin,ActionTrackerPlugin to see if that plugin is triggering the slowdown. If there are a large number of action macros in the old revisions, I could see that a sequential history might cause a lot of processing.

If that's confirmed, assign this to ActionTrackerPlugin and suggest that it be disabled for context=diff.

-- GeorgeClark - 06 Jan 2012

Nope doesn't appear to be ActionTrackerPlugin, with it enabled it rendered in 8.394 seconds

It took me so long to get back to you because I wanted to try enabling every plugin one at a time. I finally found it, ?type=history;debugenableplugins=EmptyPlugin,TablePlugin is what causes the slowness. Which makes sense this page has no ActionTrackerPlugin usuage but lots of TablePlugin usuage.

-- JacobChamplin - 13 Jan 2012

Hi Jacob, your followup is very much appreciated, hopefully we have enough to go on now to reproduce.

Re-titled the bug (was "rdiff type=history slow for > 100 revisions times out with > 200 revisions, giving rev range doesn't help") and set to new. Also assigned CompareRevisionsAddOn because, although filed against rdiff, we should see that any fix addresses the problem in both rdiff & compare.

-- PaulHarvey - 14 Jan 2012

Do you expect or need the TablePlugin rendering to be useful in the history output, or is the default table rendering provided by the core Foswiki render sufficient. A simple fix for this would be for the TablePlugin to turn itself off in the diff context and allow the core render to do the formatting. Or in other words, with TablePlugin disabled, is the rendered history acceptable to you.

-- GeorgeClark - 14 Jan 2012

I don't want to speak for everyone, but in our case yes having TablePlugin disabled is fine for history. Would be nice if that was configurable per plugin. Maybe it is I just haven't discovered how yet.

-- JacobChamplin - 17 Jan 2012

Deferring for 1.2.

-- GeorgeClark - 05 Apr 2012

Commenting is disabled while not logged in