Issue #2559 resolved

Serious performance degradation using workbench "Branch" filter

Steve Spencer
created an issue

I've just switched my team to Mercurial and have a well structured clean repository of around 8 years development.

Clones with null take up around 200mb. Until last week it only had one branch ("default") with 38000 revisions (we only imported trunk from Svn). Plus several daily anonymous branches from normal team work on default.

This week we've started using named branches for features. We've got around 5 such named branches, each with around 5 commits, plus some merges from default to feature.

I want to avoid accidental reintegration of features (merging B into A instead of A into B). This happened already on day 1, and is impossible to fix - backout means you can't subsequently re-integrate.

So my current advice is to use the Branch filter to the branch you're working in. And to use a custom script to routinely merge from default (dev) into feature.

This way someone working on default can't accidentally right-click and merge from feature, thinking they are simply merging two heads in default.

(I'm interested in any other ideas for how to solve this - possibly a central repo hook - but I appreciate this isn't the place for such a discussion).

However, the moment you change " Show all " to "default" (or any other named branch), the workbench slows down by a couple of orders of magnitude. Refreshing takes many seconds instead of near-instantaneous, for example. Navigating through update/merge dialogs is equally slow (presumably it's refreshing the window).

I've tried disabling all extensions, nuking any custom settings, and changing the log from 500 to 100, restarting each time, to no effect.

Executing this in cmd is instantaneous: hg log -l 100 -b default > nul

This is a commercial repository so I can't share anything sensitive. Is there anything I can do to log or profile what the workbench is doing to help diagnose?

Using 2.7.2 on Win7 x64 on a top-end i7 with 32gb and repo on SSD.

Comments (11)

  1. Yuya Nishihara

    Can you time hg log -G -l 100 -b default > nul ?

    TortoiseHg needs to build revision graph, which may take further time than liner access (without -G option.)

  2. Steve Spencer reporter

    Here are a range of timings (very rough). Looks like more of the problem is in hg itself.

    1000 limit:

    hg log -G -l 1000 > nul ~0.25 secs hg log -G -l 1000 -b default > nul ~3.2 secs THg switch to Branch: default ~4.5 secs THg switch to Branch: Show all ~0.6 secs

    100 limit:

    hg log -G -l 100 > nul ~0.1 secs hg log -G -l 100 -b default > nul ~3.0 secs THg switch to Branch: default ~4.5 secs THg switch to Branch: Show all ~0.4 secs

    Clearly there is a major delay when choosing to filter by branch in "hg log -G". And there's little benefit in reducing from the default limit (500).

    There's a lesser performance problem in THg itself when filtering by branch. But the main issue is hg. Should I post this elsewhere?

    I'll attach the log from "hg log -G -l 100" with identifying information blanked out.

  3. Yuya Nishihara

    Thanks for the detail.

    Found out that ctx.branch() causes this performance problem. The culprit in our code is the loop to build branch colors:

    https://bitbucket.org/tortoisehg/thg/src/82c2dd50c45e/tortoisehg/hgqt/graph.py#cl-121

    It issues bunch of getparents() requests, and if branch filtering is enabled, each request involves ctx.branch() call.

    https://bitbucket.org/tortoisehg/thg/src/82c2dd50c45e/tortoisehg/hgqt/graph.py#cl-89

    We should build color map lazily.

    FWIW, it can be avoided by enabling "Include all ancestors".

  4. Steve Spencer reporter

    I presume you are referring to the lesser problem in THg itself. The additional ~1.5 seconds introduced by thg over the hg command performance.

    Where is "Include all ancestors"?

    Should I file the greater performance problem in "hg" itself, separately?

  5. Yuya Nishihara

    TortoiseHg's graph handling is based on hg's, but they're different now. I found that our problem is different from hg log -G's, even though both seem to be slow because of ctx.branch() calls.

    ctx.branch() isn't fast by design, so TortoiseHg shouldn't call it too much. I have experimental patch for this problem, which saves ~8sec in kernel mirror repo.

    Where is "Include all ancestors"?

    It's listed in the pull-down menu of the "Branch" filter.

  6. Steve Spencer reporter

    Yuya, thanks for the tip. "Include all ancestors" solves it entirely.

    And in fact it's probably what we want in practice - it shows up a couple of places where bad merges (wrong direction, integrating a feature branch early) happened by mistake.

    Now if only it was persistent... :-)

    I'd be happy to try the patch for you if you gave me some pointers. But I'm using the installed stable build currently.

    I won't cross-post to hg issue tracker, since equivalent "hg log" performance isn't actually a problem for us.

  7. Yuya Nishihara

    graph: build color table incrementally (fixes #2559)

    If branch filter is enabled, getparents() is very slow because it needs to read revlog entry. So revision_grapher should not look up all ancestors at once.

    Quick benchmark result:

    # 301198 revisions in default branch
    repo = hg.repository(ui.ui(), 'linux-2.6-hg')
    grapher = graph.revision_grapher(repo, branch=...)
    for i in xrange(100):
        grapher.next()
    
    branch=None (no filter):  2.6sec -> 0.6sec
    branch='default'       : 10.9sec -> 0.7sec
    

    → <<cset ab5497e48198>>

    NOTE: this will be included in TortoiseHg 2.9, not 2.8.2

  8. Log in to comment