quick status in main navigation bar slows down trac dramatically

[hippo]

I'm using Trac with Trac Mercurial? backend and Bitten. It turns out that enabling "quick status in main navigation bar" increases page generation time from about 3 seconds to 15(!) seconds. The most killing thing is getting page generation time increased for all page (e.g wiki, tickets or admin page). I can live with such huge times for "Builds Status" page (though this could be filed as a separate ticket), but it's absolutely unacceptable for each page. It should be noted, that underlying mercurial repository is rather big with about 7000 changesets and about 3000 files. The trac and bitten is running on apache-2.2.14 on Intel Xeon @2.80GHz.

It seems, that bitten is rescanning the whole repository every time it is asked to display the quick status instead of retrieving the status from cache.

I can attach a profile, made with cProfile, if it is required.

[osimons]

I keep this feature turned off myself, so haven't really noticed. However, I think it was enabled on trac.edgewall.org and may be part of the performance issues there.

I'll apply any performance-enhancing fix for this feature.

[mpotter@…]

I too have noticed this performance hit and thus have been running with this feature disabled. I am not using ​TracMercurial but just the base SVN.

[hippo]

Replying to mpotter@…:

I too have noticed this performance hit and thus have been running with this feature disabled. I am not using ​TracMercurial but just the base SVN.

Well, I have a Trac with SVN backend too. But the performance penalty with svn is not so evident as with mercurial (although this could be just because my svn repository is much smaller than my mercurial one).

[dfraser]

The quick_status code in trunk/bitten/bitten/web_ui.py calls collect_changes which iterates through each revision of the repository, and aborts if it receives more than one revision (so that it can check multiple build results for the latest revision). It may be that the mercurial logic here is different to svn and fetches a lot more information from the repository (in the call to node.get_history) - having a quick look at the mercurial plugin it seems to call walkchangerevs from mercurial.cmdutil.py...

This could potentially be avoided by just querying for the current latest revision for a particular path, and checking for builds on that revision (which is what the effect is anyway)

[dfraser]

Looking in slightly more detail - the plugin ​seems to end up passing pats=None and opts={'rev': ['%s:0']} (where %s is the current revision), which triggers the slow_path branch of walkchangerevs. By the time this yields anything, it has already retrieved all revisions of the repository.

Unfortunately it's not that easy to fix this directly in bitten as there isn't a function in the ​trac version control API to just get the latest revision of a node - you can give a limit to the get_history function, but the mercurial backend doesn't do anything with this. There's a get_previous function, but in both backends this just defaults back to get_history (and we want get_current anyway)

So it seems to me this would require a quick special-casing of the first revision in the mercurial backend and then adding a limit=1 argument in bitten.

I'm inclined to push this out of the 0.6 milestone unless someone comes up with a solution...

[mpotter@…]

Maybe I'm off base in this approach, but trying to code a "global build status" as just an SQL query I came up with the following. This appears reasonably fast from what I can tell. Maybe there are some more optimizations that can be done to improve its performance. Basically from the output of this query:

• If there exists any record with a status='F'
  • Global Status is 'Fail'
• Else if there exists any record with a status of 'I', 'P' or NULL
  • Global Status is 'In Progress'
• Else All records should have a status of 'S', and thus
  • Global Status is 'Success'

SELECT
   MAX(nc.rev) AS 'Max Rev',
   bb.status AS 'Status'
   -- , bc.name AS 'Config'
   -- , bp.id AS 'Platform ID'
   -- , bp.name AS 'Platform'
   -- , bc.path AS 'Path'
FROM bitten_config bc
   JOIN bitten_platform bp
       ON     bc.active
          AND bc.name = bp.config
   LEFT JOIN bitten_build bb
       ON     bb.platform = bp.id
   LEFT JOIN node_change nc
       ON     nc.rev = bb.rev
WHERE nc.rev <= IFNULL(bc.max_rev,999999)
  AND nc.rev >= IFNULL(bc.min_rev,0)
  AND nc.path LIKE bc.path || '%'
GROUP BY bc.name, bp.id

[dfraser]

Replying to mpotter@…:

Maybe I'm off base in this approach, but trying to code a "global build status" as just an SQL query I came up with the following. This appears reasonably fast from what I can tell. Maybe there are some more optimizations that can be done to improve its performance. Basically from the output of this query:

• If there exists any record with a status='F'
  • Global Status is 'Fail'
• Else if there exists any record with a status of 'I', 'P' or NULL
  • Global Status is 'In Progress'
• Else All records should have a status of 'S', and thus
  • Global Status is 'Success'

SELECT
   MAX(nc.rev) AS 'Max Rev',
   bb.status AS 'Status'
   -- , bc.name AS 'Config'
   -- , bp.id AS 'Platform ID'
   -- , bp.name AS 'Platform'
   -- , bc.path AS 'Path'
FROM bitten_config bc
   JOIN bitten_platform bp
       ON     bc.active
          AND bc.name = bp.config
   LEFT JOIN bitten_build bb
       ON     bb.platform = bp.id
   LEFT JOIN node_change nc
       ON     nc.rev = bb.rev
WHERE nc.rev <= IFNULL(bc.max_rev,999999)
  AND nc.rev >= IFNULL(bc.min_rev,0)
  AND nc.path LIKE bc.path || '%'
GROUP BY bc.name, bp.id

Ah, querying the database directly is a good idea. What's actually slowing the current system down is trying to work out what the maximum revision on the current path is. Unfortunately revisions are not necessarily ordered alphabetically in all version control systems (many use hashes), so there is a function on the version control API which allows you to order revisions.

I'm not sure if the node_change.rev field is the same as the version control revision number or not - if it's guaranteed to be ordered then we could use something similar to this to work out the most recent change on the path.

Also I'm not sure if the query above would work correctly in the case that a build has not yet been initiated for the latest revision, so it seems simpler to me to work out the latest revision and then query the builds.

[osimons]

Just adding some notes that spring to mind, as I haven't looked at the details.

1. I think that the little red/green build status was a major performance killer for the main Trac site. Lots of revisions for many configs and platforms make this a very expensive thing to figure out as it currently is done. It needs to improve, and thanks for looking into it.

2. Mercurial makes it even worse, as Mercurial changesets and nodes are not cached by Trac. Every repository request is delegated to Mercurial itself.

The second point makes the idea to use SQL somewhat less attractive, and adds another issue we need to resolve to get Bitten to work nicely with any repository connector available for Trac.

[mpotter@…]

Replying to dfraser:

Ah, querying the database directly is a good idea. What's actually slowing the current system down is trying to work out what the maximum revision on the current path is. Unfortunately revisions are not necessarily ordered alphabetically in all version control systems (many use hashes),

Thought so, therefore change the SELECT MAX(nc.rev) AS 'Max Rev', to SELECT MAX(r.time), nc.rev AS 'Max Rev', and add a LEFT JOIN revision r ON nc.rev = r.rev; thus pulling the "most recent" revision instead of the "highest revision number".

Also I'm not sure if the query above would work correctly in the case that a build has not yet been initiated for the latest revision, so it seems simpler to me to work out the latest revision and then query the builds.

I did not test for that, but I did think about it. I think what I wrote would work since I LEFT JOIN bitten_build; thus one would get a 'Status' of NULL.

Replying to osimons:

2. Mercurial makes it even worse, as Mercurial changesets and nodes are not cached by Trac. Every repository request is delegated to Mercurial itself.

The second point makes the idea to use SQL somewhat less attractive, and adds another issue we need to resolve to get Bitten to work nicely with any repository connector available for Trac.

So you are saying that with Mercurial there is no information in the 'node_change' or 'revision' tables? Ack.

[osimons]

This is one of the remaining issues marked for 0.6. I have no good ideas for solving it that is efficient and general. As it now stands, I see 3 options:

1. Document our way out of it. At least the option is disabled by default, and we could add a bit of text both in Option doc and in UI to warn against its limitations.
2. Remove the feature completely.
3. Redo the logic and simplify what is queried, if possible. Like make it into a status for "last 10 completed builds" or something - red if any of last 10 failed. Or some other variation that restricts our interest to build + config information (ie. Bitten data only).

Votes or comments?

[hippo]

Replying to osimons:

This is one of the remaining issues marked for 0.6. I have no good ideas for solving it that is efficient and general. As it now stands, I see 3 options:

1. Document our way out of it. At least the option is disabled by default, and we could add a bit of text both in Option doc and in UI to warn against its limitations.
2. Remove the feature completely.
3. Redo the logic and simplify what is queried, if possible. Like make it into a status for "last 10 completed builds" or something - red if any of last 10 failed. Or some other variation that restricts our interest to build + config information (ie. Bitten data only).

Votes or comments?

I don't like 2) completely. This is a very nice feature and I always enable it for subversion repositories.

As a temporary solution 1) is ok, while moving this bug to the 0.7 milestone.

[dfraser]

Replying to osimons:

This is one of the remaining issues marked for 0.6. I have no good ideas for solving it that is efficient and general. As it now stands, I see 3 options:

1. Document our way out of it. At least the option is disabled by default, and we could add a bit of text both in Option doc and in UI to warn against its limitations.

+1 - this is definitely the simplest and easiest thing to do...

2. Remove the feature completely.

-1 - it's still a useful feature that works fine in the standard case; to prevent people turning it on seems overkill.

3. Redo the logic and simplify what is queried, if possible. Like make it into a status for "last 10 completed builds" or something - red if any of last 10 failed. Or some other variation that restricts our interest to build + config information (ie. Bitten data only).

+1 for 0.7 - this is the way to make it work more generally, but I really don't see the need to do this before 0.6 if we do the docs suggested in 1. above

Votes or comments?

[osimons]

I've updated the documentation for the option in [884:885], so rescheduling any fix for next major milestone.

[mpotter@…]

Another approach: Instead of putting this time-burden on the user every time a Trac page is rendered, put this time-burden on the slave-results handler and the build-scheduler. Basically:

• When new build-results are posted from a slave that complete a build, or changes are made to the build-queue due to a check-in or configuration change:
  • Run the existing status finding code, storing the results somewhere.
• When rendering a Trac page, to get the quick-status only requires fetching the previously stored value.

It may be possible to improve the status finding code based off of context. (e.g. A Build-complete can move the status from In-Progress, but cannot move the status from Fail or from Success. A new check-in can move the status from Fail or from Success, but cannot move the status from In-Progress.)

[anonymous]

Replying to mpotter@…:

Another approach: Instead of putting this time-burden on the user every time a Trac page is rendered, put this time-burden on the slave-results handler and the build-scheduler. Basically:

• When new build-results are posted from a slave that complete a build, or changes are made to the build-queue due to a check-in or configuration change:

Another case: When a user Invalidates a build.

Alas this looks like it may put the time-burden on the user. However, from context it maybe a quick check:

• If the current status is In-Progress, then no change.
• If this build was for a head revision,
  • then status moves to In-Progress,
  • else no-change.