[PATCH 2 of 2] [WIP] parsers: use base-16 trie for faster node->rev mapping

[Bryan O'Sullivan]

On Mon, Mar 26, 2012 at 6:34 PM, Greg Ward <greg at gerg.ca> wrote:
>
> Anyways, I got some results this time.


Hi Greg,

Thanks for taking the time to measure results in your environment. I
refreshed and reposted the patches yesterday. The major difference now
is that the lazy index parser caches its results. In my measurements,
this makes it much faster for small revlog accesses to either the tip
revision or a few numeric indices, and almost exactly the same as the
eager index parser for bulk accesses.

Do you have any details of the repo you measured in? Is it something I
could clone and try myself?

Here are my measurements of the same commands on a linux-2.6 repo,
using a 64-bit Python 2.7 build on OS X, with both new patches
applied.

> test 1: hg tip
>  unpatched: 0:00.89 s elapsed, 39304 kB max
>  patched:   0:00.58 s elapsed, 21360 kB max

unpatched: 0.44 s, 138.6 MB
patched: 0.14 s, 35.4 MB

> test 2: hg log -v -r 50000 --style custom.style
>  [my custom.style uses {file_adds}, {file_mods}, and {file_dels},
>   forcing manifest reads]
>  unpatched: 0:01.48 s elapsed, 68788 kB max
>  patched:   0:00.93 s elapsed, 37684 kB max

I emulated this using "hg log -r 50000 --debug".

unpatched: 0.91 s, 267.1 MB
patched: 0.33 s, 77.5 MB

> test 3: hg log -v -r 2978b0d97fcf --style custom.style
>  [same changeset as -r 50000]
>  unpatched: 0:01.68 s elapsed, 68832 kB max
>  patched:   0:01.25 s elapsed, 37744 kB max

Emulated with "856afed070aa".

unpatched: 1.01 s, 267.1 MB
patched: 0.59 s, 172.8 MB

> test 4: hg log -v -r 2978b0d97fcfa2d5e6a251120772c8ff6b50f6f8 --style custom.style
>  [same again, this time no need for prefix lookup]
>  unpatched: 0:01.48 s elapsed, 68792 kB max
>  patched:   0:00.93 s elapsed, 37680 kB max

unpatched: 0.92 s, 267.1 MB
patched: 0.33 s, 77.5 MB

> test 5: hg diff -c 128362
>  [big merge:  2525 files changed, 143973 insertions(+), 85114 deletions(-)]
>  unpatched: 0:16.00 s elapsed, 78644 kB max
>  patched:   0:17.15 s elapsed, 63884 kB max

I used rev 7a6c4ccf5654 in the kernel repo for this.

unpatched: 0.71 s, 250.9 MB
patched: 0.35 s, 79.7 MB

> perfheads:
>
>  unpatched: wall 0.120259 comb 0.120000 user 0.120000 sys 0.000000 (best of 76)
>
>  patched:   wall 0.241573 comb 0.240000 user 0.240000 sys 0.000000 (best of 41)

unpatched: wall 0.109537 comb 0.110000 user 0.110000 sys 0.000000 (best of 90)
patched: wall 0.118316 comb 0.110000 user 0.110000 sys 0.000000 (best of 82)

> perflog:
>
>  unpatched: wall 63.324580 comb 60.710000 user 59.600000 sys 1.110000 (best of 3)
>  patched:   wall 65.194923 comb 64.070000 user 63.040000 sys 1.030000 (best of 3)

unpatched: wall 55.200150 comb 55.000000 user 54.700000 sys 0.300000 (best of 3)
patched: wall 54.219291 comb 54.030000 user 53.750000 sys 0.280000 (best of 3)

> perfindex:
>
>  unpatched: wall 0.180053 comb 0.170000 user 0.150000 sys 0.020000 (best of 52)
>  patched:   wall 0.021411 comb 0.020000 user 0.000000 sys 0.020000 (best of 139)

The numbers reported for this look bogus for me: 6 microseconds.
Haven't investigated why yet, but I suspect it's because the revlog's
node->rev cache isn't invalidated between runs.

> perfrevlog .hg/store/00changelog.i:
>
>  unpatched: wall 0.609125 comb 0.610000 user 0.540000 sys 0.070000 (best of 14)
>  patched:   wall 0.276779 comb 0.290000 user 0.220000 sys 0.070000 (best of 36)

unpatched: wall 0.583637 comb 0.560000 user 0.470000 sys 0.090000 (best of 15)
patched: wall 0.316487 comb 0.280000 user 0.210000 sys 0.070000 (best of 20)

> perfrevlog .hg/store/00manifest.i:
>
>  unpatched: wall 24.790400 comb 23.620000 user 21.070000 sys 2.550000 (best of 3)
>  patched:   wall 24.157500 comb 23.670000 user 21.220000 sys 2.450000 (best of 3)

unpatched: wall 57.159712 comb 48.860000 user 43.450000 sys 5.410000 (best of 3)
patched: wall 55.174832 comb 48.540000 user 43.390000 sys 5.150000 (best of 3)

New benchmarks from Matt:

perfnodelookup 33333:

unpatched: wall 0.309029 comb 0.300000 user 0.260000 sys 0.040000 (best of 25)
patched: wall 0.042455 comb 0.040000 user 0.020000 sys 0.020000 (best of 58)

perfnodelookup b9b9d908209022:

unpatched: wall 0.317325 comb 0.310000 user 0.260000 sys 0.050000 (best of 25)
patched: wall 0.042200 comb 0.040000 user 0.030000 sys 0.010000 (best of 63)

perfnodelookup b9b9d9082090229558496d24c0efaacc244facae:

unpatched: wall 0.310132 comb 0.310000 user 0.250000 sys 0.060000 (best of 25)
patched: wall 0.040877 comb 0.040000 user 0.030000 sys 0.010000 (best of 67)