Re: B-Tree support function number 3 (strxfrm() optimization)

On 31 March 2014 06:51, Peter Geoghegan <pg(at)heroku(dot)com> wrote:
> On Wed, Mar 26, 2014 at 8:08 PM, Peter Geoghegan <pg(at)heroku(dot)com> wrote:
>> The API I envisage is a new support function 3 that operator class
>> authors may optionally provide.
>
> I've built a prototype patch, attached, that extends SortSupport and
> tuplesort to support "poor man's normalized keys". All the regression
> tests pass, so while it's just a proof of concept, it is reasonably
> well put together for one. The primary shortcoming of the prototype
> (the main reason why I'm calling it a prototype rather than just a
> patch) is that it isn't sufficiently generalized (i.e. it only works
> for the cases currently covered by SortSupport - not B-Tree index
> builds, or B-Tree scanKeys). There is no B-Tree support function
> number 3 in the patch. I didn't spend too long on this.
>
> I'm pretty happy with the results for in-memory sorting of text (my
> development system uses 'en_US.UTF8', so please assume that any costs
> involved are for runs that use that collation). With the dellstore2
> sample database [1] restored to my local development instance, the
> following example demonstrates just how much the technique can help
> performance.
>
> With master:
>
> pg(at)hamster:~/sort-tests$ cat sort.sql
> select * from (select * from customers order by firstname offset 100000) d;
> pg(at)hamster:~/sort-tests$ pgbench -f sort.sql -n -T 100
> transaction type: Custom query
> scaling factor: 1
> query mode: simple
> number of clients: 1
> number of threads: 1
> duration: 100 s
> number of transactions actually processed: 819
> latency average: 122.100 ms
> tps = 8.186197 (including connections establishing)
> tps = 8.186522 (excluding connections establishing)
>
> With patch applied (requires initdb for new text SortSupport pg_proc entry):
>
> pg(at)hamster:~/sort-tests$ cat sort.sql
> select * from (select * from customers order by firstname offset 100000) d;
> pg(at)hamster:~/sort-tests$ pgbench -f sort.sql -n -T 100
> transaction type: Custom query
> scaling factor: 1
> query mode: simple
> number of clients: 1
> number of threads: 1
> duration: 100 s
> number of transactions actually processed: 2525
> latency average: 39.604 ms
> tps = 25.241723 (including connections establishing)
> tps = 25.242447 (excluding connections establishing)

As another data point, I ran the same benchmark, but I don't appear to
yield the same positive result. An initdb was done for each rebuild,
my system uses en_GB.UTF-8 (if that's relevant) and I used your same
sort.sql...

With master:

thom(at)swift ~/Development $ pgbench -f sort.sql -n -T 100 ds2
transaction type: Custom query
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
duration: 100 s
number of transactions actually processed: 421479
latency average: 0.237 ms
tps = 4214.769601 (including connections establishing)
tps = 4214.906079 (excluding connections establishing)

With patch applied:

thom(at)swift ~/Development $ pgbench -f sort.sql -n -T 100 ds2
transaction type: Custom query
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
duration: 100 s
number of transactions actually processed: 412405
latency average: 0.242 ms
tps = 4124.047237 (including connections establishing)
tps = 4124.177437 (excluding connections establishing)

And with 4 runs (TPS):

Master: 4214.906079 / 4564.532623 / 4152.784608 / 4152.578297 (avg: 4271)
Patched: 4124.177437 / 3777.561869 / 3777.561869 / 2484.220475 (avg: 3481)

I'm not sure what's causing the huge variation. I ran 5 minute benchmarks too:

Master:

thom(at)swift ~/Development $ pgbench -f sort.sql -n -T 300 ds2
transaction type: Custom query
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
duration: 300 s
number of transactions actually processed: 1092221
latency average: 0.275 ms
tps = 3640.733002 (including connections establishing)
tps = 3640.784628 (excluding connections establishing)

Patched:

thom(at)swift ~/Development $ pgbench -f sort.sql -n -T 300 ds2
transaction type: Custom query
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
duration: 300 s
number of transactions actually processed: 1068239
latency average: 0.281 ms
tps = 3560.794946 (including connections establishing)
tps = 3560.835076 (excluding connections establishing)

And per-second results for the first 30 seconds:

Master:

progress: 1.0 s, 2128.8 tps, lat 0.464 ms stddev 0.084
progress: 2.0 s, 2138.9 tps, lat 0.464 ms stddev 0.015
progress: 3.0 s, 2655.6 tps, lat 0.374 ms stddev 0.151
progress: 4.0 s, 2214.0 tps, lat 0.448 ms stddev 0.080
progress: 5.0 s, 2171.1 tps, lat 0.457 ms stddev 0.071
progress: 6.0 s, 2131.6 tps, lat 0.466 ms stddev 0.035
progress: 7.0 s, 3811.2 tps, lat 0.260 ms stddev 0.177
progress: 8.0 s, 2139.6 tps, lat 0.464 ms stddev 0.017
progress: 9.0 s, 7989.7 tps, lat 0.124 ms stddev 0.091
progress: 10.0 s, 8509.7 tps, lat 0.117 ms stddev 0.062
progress: 11.0 s, 3131.3 tps, lat 0.317 ms stddev 0.177
progress: 12.0 s, 9362.1 tps, lat 0.106 ms stddev 0.006
progress: 13.0 s, 5831.0 tps, lat 0.170 ms stddev 0.137
progress: 14.0 s, 4949.3 tps, lat 0.201 ms stddev 0.156
progress: 15.0 s, 2136.9 tps, lat 0.464 ms stddev 0.028
progress: 16.0 s, 3918.3 tps, lat 0.253 ms stddev 0.177
progress: 17.0 s, 4102.7 tps, lat 0.242 ms stddev 0.122
progress: 18.0 s, 2997.6 tps, lat 0.331 ms stddev 0.151
progress: 19.0 s, 2139.1 tps, lat 0.464 ms stddev 0.034
progress: 20.0 s, 3189.5 tps, lat 0.311 ms stddev 0.173
progress: 21.0 s, 2120.7 tps, lat 0.468 ms stddev 0.030
progress: 22.0 s, 3197.7 tps, lat 0.311 ms stddev 0.182
progress: 23.0 s, 2115.3 tps, lat 0.469 ms stddev 0.034
progress: 24.0 s, 2129.0 tps, lat 0.466 ms stddev 0.031
progress: 25.0 s, 2190.7 tps, lat 0.453 ms stddev 0.106
progress: 26.0 s, 2118.6 tps, lat 0.468 ms stddev 0.031
progress: 27.0 s, 2136.8 tps, lat 0.464 ms stddev 0.018
progress: 28.0 s, 5160.7 tps, lat 0.193 ms stddev 0.156
progress: 29.0 s, 2312.5 tps, lat 0.429 ms stddev 0.107
progress: 30.0 s, 2145.9 tps, lat 0.463 ms stddev 0.038
progress: 31.0 s, 2107.6 tps, lat 0.471 ms stddev 0.071

Patched:

progress: 1.0 s, 2136.2 tps, lat 0.463 ms stddev 0.084
progress: 2.0 s, 2153.3 tps, lat 0.461 ms stddev 0.035
progress: 3.0 s, 2336.0 tps, lat 0.425 ms stddev 0.112
progress: 4.0 s, 2144.8 tps, lat 0.463 ms stddev 0.037
progress: 5.0 s, 2171.7 tps, lat 0.457 ms stddev 0.041
progress: 6.0 s, 2161.9 tps, lat 0.459 ms stddev 0.036
progress: 7.0 s, 2143.1 tps, lat 0.463 ms stddev 0.019
progress: 8.0 s, 2148.4 tps, lat 0.462 ms stddev 0.032
progress: 9.0 s, 2142.1 tps, lat 0.463 ms stddev 0.028
progress: 10.0 s, 2133.6 tps, lat 0.465 ms stddev 0.032
progress: 11.0 s, 2138.3 tps, lat 0.464 ms stddev 0.020
progress: 12.0 s, 2578.7 tps, lat 0.385 ms stddev 0.149
progress: 13.0 s, 2455.6 tps, lat 0.404 ms stddev 0.119
progress: 14.0 s, 2909.5 tps, lat 0.341 ms stddev 0.170
progress: 15.0 s, 2133.7 tps, lat 0.465 ms stddev 0.025
progress: 16.0 s, 2876.9 tps, lat 0.345 ms stddev 0.160
progress: 17.0 s, 2167.1 tps, lat 0.458 ms stddev 0.038
progress: 18.0 s, 3623.4 tps, lat 0.274 ms stddev 0.181
progress: 19.0 s, 2476.3 tps, lat 0.401 ms stddev 0.137
progress: 20.0 s, 2166.9 tps, lat 0.458 ms stddev 0.030
progress: 21.0 s, 3150.0 tps, lat 0.315 ms stddev 0.176
progress: 22.0 s, 2220.3 tps, lat 0.447 ms stddev 0.084
progress: 23.0 s, 2131.3 tps, lat 0.466 ms stddev 0.030
progress: 24.0 s, 2154.2 tps, lat 0.461 ms stddev 0.047
progress: 25.0 s, 2122.5 tps, lat 0.468 ms stddev 0.040
progress: 26.0 s, 2202.2 tps, lat 0.451 ms stddev 0.079
progress: 27.0 s, 2150.6 tps, lat 0.461 ms stddev 0.039
progress: 28.0 s, 2156.1 tps, lat 0.460 ms stddev 0.027
progress: 29.0 s, 2152.1 tps, lat 0.461 ms stddev 0.028
progress: 30.0 s, 2235.4 tps, lat 0.444 ms stddev 0.071

--
Thom