create new tag
, view all tags
Related topics: DatabaseForPreferences PrefsDotPm AddValuesToPreferenceVariable MetadataSucks MetaDataSucksMeasurement StepByStepRenderingOrder DatabaseForAccessControl SimplifyInternalMetaDataHandling MetaDataDefinition DatabaseForMETA MegaTWiki

Part 1: Profile by time


Following my assertions about the performance issues behind moving structural metadata and access control out of the topic file in the MetaDataSucks topic, I decided to make some actual measurements. Its all very well hypothesising, but lets get some hard facts.

I used the Devel::DProf tool to measure the times and calls for the 'view' operation. I chose 'view' because it was non-interactive and is the most common activity in a wiki.

The topic that was viewed was %TWIKIWEB%.WebHome.


The output can be presented in many ways and I spent an interesting hour going over many of them. The nested call graph is particularly valuable in showing the flow of control.

However I want to present here an abstraction - a grep of just key parts of the TWiki library modules, since they show some interesting and critical points. Please note the highlighted figures

Total Elapsed Time = 1.682254 Seconds
User+System Time = 0.542254 Seconds
%Time ExcliSec CumulS #Calls sec/call Csec/c Name
25.4 0.000 0.138 10 0.0000 0.0138 TWiki::Prefs::getPrefsFromTopic
20.1 0.000 0.109 3 0.0000 0.0365 TWiki::Prefs::BEGIN
5.53 0.000 0.030 1 0.0000 0.0299 TWiki::Store::initialize
5.53 0.010 0.030 7 0.0014 0.0043 TWiki::Store::BEGIN
3.69 0.010 0.020 3 0.0033 0.0066 TWiki::Store::RcsWrap::BEGIN
3.69 0.020 0.020 109 0.0002 0.0002 TWiki::Prefs::prvAddToPrefsList
3.69 0.010 0.020 30 0.0003 0.0007 TWiki::Prefs::getPreferencesValue
3.50 0.010 0.019 11 0.0009 0.0017 TWiki::Store::readTopic
1.84 0.010 0.010 13 0.0008 0.0008 TWiki::Store::readFile
1.84 0.010 0.010 3 0.0033 0.0033 TWiki::Store::RcsFile::BEGIN
1.84 0.000 0.010 7 0.0000 0.0014 TWiki::Prefs::getPreferencesFlag
1.84 0.000 0.010 7 0.0000 0.0014 TWiki::Func::getPreferencesFlag
1.84 0.000 0.010 11 0.0000 0.0009 TWiki::Store::readTopicRaw
- 0.000 -0.000 1 0.0000 - TWiki::Store::saveFile
- 0.000 -0.000 1 0.0000 - TWiki::Func::getUrlHost
- 0.000 -0.000 1 0.0000 - TWiki::Access::initializeAccess
- 0.000 -0.000 1 0.0000 - TWiki::Func::getPubUrlPath
- 0.000 -0.000 1 0.0000 - TWiki::Store::readWebTopic
- 0.000 -0.000 1 0.0000 - TWiki::Func::getDataDir
- 0.000 -0.000 1 0.0000 - TWiki::Func::saveFile
- 0.000 -0.000 3 0.0000 - TWiki::Access::prvGetWebTopicName
- 0.000 -0.000 3 0.0000 - TWiki::Access::prvGetUserList
- 0.000 -0.000 1 0.0000 - TWiki::Meta::BEGIN
- 0.000 -0.000 2 0.0000 - TWiki::Func::getCgiQuery
- 0.000 -0.000 2 0.0000 - TWiki::Store::topicExists
- 0.000 -0.000 2 0.0000 - TWiki::Func::BEGIN
- 0.000 -0.000 2 0.0000 - TWiki::Access::BEGIN
- 0.000 -0.000 1 0.0000 - TWiki::Access::prvGetUsersOfGroup
- 0.000 -0.000 2 0.0000 - TWiki::Store::convert2metaFormat
- 0.000 -0.000 11 0.0000 - TWiki::Meta::count
- 0.000 -0.000 13 0.0000 - TWiki::Meta::new
- 0.000 -0.000 13 0.0000 - TWiki::Store::normalizeWebTopicNam
- 0.000 -0.000 1 0.0000 - TWiki::Access::userIsInGroup
- 0.000 -0.000 1 0.0000 - TWiki::Access::checkAccessPermissi
- 0.000 -0.000 17 0.0000 - TWiki::Func::extractNameValuePair
- 0.000 -0.000 56 0.0000 - TWiki::Meta::_key
- 0.000 -0.000 19 0.0000 - TWiki::Meta::findOne
- 0.000 -0.000 6 0.0000 - TWiki::Func::getPreferencesValue
- 0.000 -0.000 37 0.0000 - TWiki::Meta::put
- 0.000 -0.000 253 0.0000 - TWiki::Meta::restoreValue
- 0.000 -0.001 1 0.0000 - TWiki::Func::readTopic
- 0.000 -0.001 37 0.0000 - TWiki::Meta::_keyValue2Hash
- 0.000 -0.001 13 0.0000 - TWiki::Meta::read
- 0.000 -0.001 11 0.0000 - TWiki::Store::_extractMetaData


  • My machine is fast and lightly loaded so that there is not adequate resolution of the times.
  • Ignore the elapsed time - DProf added to that as it wrote records to disk
    • Conversely, this does not measure the cost of writing to the network.
  • Only subroutine call-return is instrumented.
    • Manual debug shows the loops at Meta.pm around like 296 and Prefs.pm around lines 161 and 167 are very intense as a pattern is applied to every line of the topics.

  • I was surprise to see that thirteen topics were read.
    • TWiki::Store::normalizeWebTopicName and the subsequent TWiki::Meta::read indicate this
    • Some of those are tracing WebPrefs, SitePrefs and UserPrefs and the Groups and TwikiAdminGroup for access control but I can't account for the others, though I suspect some may be the Plugin settings pages
      • I need to put in debug statements to find out which topics are being parsed.
      • Moving access control to a DB will eliminate some of those and shorten others, but settings for LOGO and WEBBGCOLOR and SMILEY and COPYRIGHT and so forth are still in the Preferences files.
        • This may be a justification for putting _ALL preferences ina DB.
  • The 25% in getPrefsFromTopic is cumulative, that is the time includes all of the nested calls to other routines.
  • The low times for getPreferenceValue and checkAccessPermission are because the preferences have already been read in.
    • This could mislead one into thinking that access control is not an expensive operation. It is, its cost is hidden in getPreferenceValue

  • Presumably the readTopicRaw is for finding the META data.
  • Moving the META statements out to a DB will reduce some of the reads and line-by-line scans
    • It seems that even though only the metadata in the topic being viewed is actually used, the code structure means the WebPrefs, SitePrefs and UserPrefs and Groups files don't need the meta data extracted.


  1. Identifying when META data is really needed may be of benefit.
  2. The procesing of Settings (aka Preferences) is very expensive
  3. Ultimately, all preferences should be in a DB and not in the topics.
    • Having preferences as text in topics is convenient and helped boot-strap TWiki, but as the above table shows, it proves expensive.
    • Some GUI interface similar to that used in MegaTwiki is needed to manipulate the settings in the DB.
      Where are you when we need you? Can your code be abstracted and re-used or is it tightly bound to MegaTwiki?

  • Moving access control and META data out of the topics is a good structuring move but the performance benefits might not be significant unless the server is heavily loaded.
  • META data will be easy to extract and put into a per-web flat file DB using perl and extracted using a RE.
  • The code flow should be reviewed to eliminate useless access of META data before changes to the META data storage are made.

-- AntonAylward - 04 May 2003

I think you are making a good case for moving

  • Plugin settings
  • Preference settings
  • User info
  • and similar...
into a DB. I don't think the case for separating out the meta data (META:FIELD, META:TABLE, META:TOPICPARENT, etc.) is strong.

-- ThomasWeigert - 04 May 2003

However, there is another, more important time sink. This information is recomputed at any topic read again, due to the nature of CGI scripts. I guess modperl would solve this problem by providing persistent state across topic views?

-- ThomasWeigert - 04 May 2003

The case for moving META data out is discussed in SimplifyInternalMetaDataHandling and MetaDataSucks, and is not an issue of eprformance but of good design and separation of functionality. Even putting it in a %TOPIC%.meta file would would achevie this. As JohnTalintyre points out in SimplifyInternalMetaDataHandling, the code is all "object" so the actual META store is irreelvant. John's point also makes it clear that this also means the factoring out of the META store will be straight forward.

      The existing meta code is OO based and it would be relatively 
      easy to have one implementation for databases and one for the 
      file format. That said it wouldn't be difficult to convert from 
      database form to file format and back again.

Having factored it out we can make new measurements to examine the impact and make new observations about the code to determine structural inefficiencies. As Kernighan and Plauger point out in their seminal book "SoftwareTools", algorithms and structure have more effect on performance and efficiency than code tricks.

At the moment, and this is the case I'm making with MartinCleaver in MetaDataSucks, everything all in one file confuses the processing. There is a high degree of coupling - of the most evil form, ContentCoupling. The principles of good design that grew up with StructuredProgramming in the 1970s have not been invalidated over the years, even if, as a find as a project manager, programmers are not being taught many of these principles in the community colleges.

While I do recommend mod_perl, I don't think that we can force it on end users and I don't think that having code that requires it - as ThomasWeigert suggests, is a good move.

Factoring out the META data from the body of the topic that is to be rendered will, in due course, simplify other code paths.

I also think Thomas misses a key point about what is and isn't persisitent data. If I'm walking though a sereis of topics, clicking on links:

  • The META data of each topic is unique to that topic
  • The topic level access control information is unique to that topic
  • If the thread takes me across webs, the access control information is unique to each web.

While having a database server that caches this for a community of users may help, the complexity may not warent it.

As an example, consider the Squid cache I have.

  • Any page I view might have MY usename displayed in it
    • So that cache entry is not valid for another user
  • Any page I view many have settings from my home page expanded in it
    • See above

Persistent stores are not that straightforward!

-- AntonAylward - 05 May 2003

Independent of that I think you misunderstand my point above, let me ask you the following... What is better, the concept of the registry data base in MS Windows, or the concept of resource forks in MacOS? Anybody who had to upgrade the OS on both of these machines will be quite clear on the answer, I would venture...

The point is, things are not as absolute and clearcut as you make them seem to be.

-- ThomasWeigert - 05 May 2003

Thomas, please take this discussion to MetadataSucks or SimplifyInternalMetaDataHandling wher ther is greater context about both the function and the justification.

-- AntonAylward - 05 May 2003

I moved ThomasWeigert's question to MetadataSucks so I could ask a follow-up question.

-- RandyKramer - 06 May 2003

Part 2: A trace of TWiki.TWikiVariables

See DatabaseForAccessControl. Realy this should be there.

OK so I've gone off and addressed preferneces instead of metadata, but my excuse is that Thomas made a good point. Moving metadata to a DB may be easy and help with the partitioning and move to a more "object" model and allow the topic body to be "pre-formeted" in many cases, but its not where the big performace hit is.

To look deeper I ran a trace by adding debug statements.

My first attempt was on =WebHome-, but the inclusion of the site map table produced too much data. It also made it clear that some things are very, very wrong with the way preferences and access control are handled and makes the performance problems inherent in the curent implementation very clear. I suspect that if I were to profile WebHome then instead of 25% we would be seeing over 50%.

To get something manageable, I used WebPreferences. The raw debug.txt file is attached, albeint under another name as I did many runs.

Pleae note: in the attachement, my %MAINWEB% is "Sys"

Many things are clear from this.

Everything gets parsed, needed or not

Obviously the Site, Web, Topic and User preferences get parsed up front. We can see that in TWiki::Prefs::initializePrefs(). However some these get parsed again, redundantly. I'll discuss that in a moment.

The plugins also get parsed. TWiki::Plugins::initialize() inspects INSTALLEDPLUGINS, DISABLEDPLUGINS and discovered plugins and scans their settings in %TWIKIWEB%/pluginname.txt. It does this regardless of whether they are used or not.

Checking Access Permissions causes stuff to be re-parsed

Big ouch! No caching. See below.

There is No Caching

A simple change on the way to the OO version of TWiki (where we can call it class data vs object data) would be to cache the settings obtained from each call to TWiki::Prefs::getPrefsFromTopic(). At the moment, each call triggers a TWiki::Store::readFile() for the topic.

In the example trace there are reducnat calls to the various WebPreferences topics. For a topic that did searches and includes or like WebHome, processed the site map, there would be a lot more.

Access Permissions

I can understand the call to TWiki::Access::checkAccessPermissions("view", guest, ... topic="TWikiVariables", web="TWiki") towards the end of the trace, just after the skins have been read. I can't understand the earlier call TWiki::Access::checkAccessPermissions("view", guest, ... topic="SmiliesPlugin", web="TWiki"). Why this plugin and no other? I don't see any acces cotnrol statements in it.


Once again I want to raise the idea of seperating out access control from other settings. This will allow us to re-order code in the CGI scrips such as bin/view to check access control first and so avoid a lot of other processing.

Moving settings out of the topics has a number aspects.

  1. The code to process settings on a per site, web and topic basis will be straight forward. Simple DB HASH files.
  2. Converting the current settings will be strainght forward -- extract them using GREP and build the DB HASH file. A simple perl script can do that.
  3. Making the topics "look right" by haveing a %SETTING{}% that pulls the value out of the DB. The same perl script can patch that up. See my example in DatabaseForPreferences
  4. A Settings Editor. The code for this might not be too heavy, but definign the how and where and when might lead to complications.
    • A setting that allows settings to be altered might be needed
    • Seperatating out access control
      • An access control setting that allows the access control to be altered.

Extracting Settings

The example I gave in DatabaseForPreferences is

    <-- TWikiPreferences -->
    * Set HTTP_EQUIV_ON_VIEW = %SET{ scope="site" key="HTTP_EQUIV_ON_VIEW"   }%
    <-- WebPreferences -->
    %SET{ scope="web" key="WEBBGCOLOR" format="   * Set $key = $value"  }%

or even better if you just want the seetings with no comment

    %SET{ scope="web" key="WEB*" regex="on" format="   * Set $key = $value"  }%

-- AntonAylward - 13 May 2003

One comment with respect to the redundant rereading of the various preference topics: much of this is eliminated by my recent refactoring of PrefsDotPm, which doesn't seem to have made it onto twiki.org yet, but is in CVS. My analysis indicates that the only topics that are being read twice now are those for other webs -- it seems to read them once into their own namespace and a second time into the "primary" settings namespace with the "Web.blah" prefix. With the new setup it should be simple to cache preferences topics, even across requests with ModPerl, although logic would be necessary to update the persistent cache when new settings are saved to any topic that can contain them. Having a simple hash of "web.topic" -> preferences set and a hook in topic save to update the cache and re-cascade changed settings would do it. I'll implement that soonish, I think.

-- WalterMundt - 13 Feb 2004

I tried to run Devel::DProf myself to see what the performance looked like with my recent changes, and found that it doesn't seem to work properly in the case where a plugin that is not present is listed under INSTALLEDPLUGINS. What happens is that after the eval that tries to load in the plugin fails, and the function which calls it returns, execution seems to silently stop. DProf writes out the profiling data up to there and is then confused as to why none of the functions on the stack at that point ever exited. I'm not really sure how to resolve this, other than not having this case when using the profiler.

-- WalterMundt - 13 Feb 2004

I had problems before when debugging Plugins. I found it helped to do an explicit use statement in TWiki.pm for the plugins I was debugging. I must admit to not fully understand the way different loads and symbol resolutions work in Perl, but this might help.

I've kept wondering about caching preferences, especially with ModPerl, which as you state above would need update mechanism. If this is done it would be good to see:

  1. Support no cache - I'd suggest this as default (less to go wrong)
  2. Support cache
  3. Run with cache and no cache and highlight any differences.

In my experience caches always cause problems! From a ModPerl point of view I wondered about caching frequently accessed topics, but was never sure what a clean and fast mechanism would be for cache invalidation - doing messaging via files seemed almost as inefficient as the topic read.

-- JohnTalintyre - 13 Feb 2004

When you're doing ModPerl, cache invalidation is actually easier, because all requests run in the same multithreaded Perl interpreter process. Because they share global variables (reason caching is practical to begin with), those same global variables may be used to deal with cache invalidation. As I outlined above, if a TWiki::Store::saveNew call notifies TWiki::Prefs that a topic has changed, then the appropriate preferences cache can be updated immediately based on the new topic text (possibly passed along with the notification directly from the TWiki::Store). Of course, if we're considering doing widespread caching, it would probably be best to set up a generic topic-change-callback system in TWiki::Store that allows any other component to register interest in topic changes.

-- WalterMundt - 13 Feb 2004

Topic attachments
I Attachment History Action Size Date Who Comment
Texttxt trace.txt r1 manage 37.3 K 2003-05-13 - 15:47 AntonAylward Trace of TWiki.TWikivariables
Edit | Attach | Watch | Print version | History: r13 < r12 < r11 < r10 < r9 | Backlinks | Raw View | Raw edit | More topic actions
Topic revision: r13 - 2006-07-22 - WillNorris
  • Learn about TWiki  
  • Download TWiki
This site is powered by the TWiki collaboration platform Powered by Perl Hosted by OICcam.com Ideas, requests, problems regarding TWiki? Send feedback. Ask community in the support forum.
Copyright © 1999-2018 by the contributing authors. All material on this collaboration platform is the property of the contributing authors.