Re: kqueue

On Thu, Sep 15, 2016 at 11:11 PM, Thomas Munro <
thomas(dot)munro(at)enterprisedb(dot)com> wrote:

> On Thu, Sep 15, 2016 at 11:04 AM, Thomas Munro
> <thomas(dot)munro(at)enterprisedb(dot)com> wrote:
> > On Thu, Sep 15, 2016 at 10:48 AM, Keith Fiske <keith(at)omniti(dot)com> wrote:
> >> Thomas Munro brought up in #postgresql on freenode needing someone to
> test a
> >> patch on a larger FreeBSD server. I've got a pretty decent machine
> (3.1Ghz
> >> Quad Core Xeon E3-1220V3, 16GB ECC RAM, ZFS mirror on WD Red HDD) so
> offered
> >> to give it a try.
> >>
> >> Bench setup was:
> >> pgbench -i -s 100 -d postgres
> >>
> >> I ran this against 96rc1 instead of HEAD like most of the others in this
> >> thread seem to have done. Not sure if that makes a difference and can
> re-run
> >> if needed.
> >> With higher concurrency, this seems to cause decreased performance. You
> can
> >> tell which of the runs is the kqueue patch by looking at the path to
> >> pgbench.
> >
> > Thanks Keith. So to summarise, you saw no change with 1 client, but
> > with 4 clients you saw a significant drop in performance (~93K TPS ->
> > ~80K TPS), and a smaller drop for 64 clients (~72 TPS -> ~68K TPS).
> > These results seem to be a nail in the coffin for this patch for now.
> >
> > Thanks to everyone who tested. I might be back in a later commitfest
> > if I can figure out why and how to fix it.
>
> Ok, here's a version tweaked to use EVFILT_PROC for postmaster death
> detection instead of the pipe, as Tom Lane suggested in another
> thread[1].
>
> The pipe still exists and is used for PostmasterIsAlive(), and also
> for the race case where kevent discovers that the PID doesn't exist
> when you try to add it (presumably it died already, but we want to
> defer the report of that until you call EventSetWait, so in that case
> we stick the traditional pipe into the kqueue set as before so that
> it'll fire a readable-because-EOF event then).
>
> Still no change measurable on my laptop. Keith, would you be able to
> test this on your rig and see if it sucks any less than the last one?
>
> [1] https://www.postgresql.org/message-id/13774.1473972000%40sss.pgh.pa.us
>
> --
> Thomas Munro
> http://www.enterprisedb.com
>

Ran benchmarks on unaltered 96rc1 again just to be safe. Those are first.
Decided to throw a 32 process test in there as well to see if there's
anything going on between 4 and 64

~/pgsql96rc1/bin/pgbench -i -s 100 -d pgbench -p 5496

[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 1 -c 1 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1543809
latency average: 0.039 ms
tps = 25729.749474 (including connections establishing)
tps = 25731.006414 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 1 -c 1 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1548340
latency average: 0.039 ms
tps = 25796.928387 (including connections establishing)
tps = 25798.275891 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 1 -c 1 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1535072
latency average: 0.039 ms
tps = 25584.182830 (including connections establishing)
tps = 25585.487246 (excluding connections establishing)

[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 4 -c 4 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 4
number of threads: 4
duration: 60 s
number of transactions actually processed: 5621013
latency average: 0.043 ms
tps = 93668.594248 (including connections establishing)
tps = 93674.730914 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 4 -c 4 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 4
number of threads: 4
duration: 60 s
number of transactions actually processed: 5659929
latency average: 0.042 ms
tps = 94293.572928 (including connections establishing)
tps = 94300.500395 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 4 -c 4 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 4
number of threads: 4
duration: 60 s
number of transactions actually processed: 5649572
latency average: 0.042 ms
tps = 94115.854165 (including connections establishing)
tps = 94123.436211 (excluding connections establishing)

[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 32 -c 32 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 5196336
latency average: 0.369 ms
tps = 86570.696138 (including connections establishing)
tps = 86608.648579 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 32 -c 32 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 5202443
latency average: 0.369 ms
tps = 86624.724577 (including connections establishing)
tps = 86664.848857 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 32 -c 32 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 5198412
latency average: 0.369 ms
tps = 86637.730825 (including connections establishing)
tps = 86668.706105 (excluding connections establishing)

[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 64 -c 64 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4790285
latency average: 0.802 ms
tps = 79800.369679 (including connections establishing)
tps = 79941.243428 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 64 -c 64 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4852921
latency average: 0.791 ms
tps = 79924.873678 (including connections establishing)
tps = 80179.182200 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1/bin/pgbench -T 60 -j 64 -c 64 -M
prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4672965
latency average: 0.822 ms
tps = 77871.911528 (including connections establishing)
tps = 77961.614345 (excluding connections establishing)

~/pgsql96rc1_kqueue_v6/bin/pgbench -i -s 100 -d pgbench -p 5496

Ran more than 3 times on occasion since results were coming out differently
by larger than expected values sometimes. Probably just something else
running on the server at the time.

Again, no real noticeable difference for single process
For 4 processes, things are mostly the same and only very, very slightly
lower, which is better than before.
For thirty-two processes, I saw a slight increase in performance for v6.
But, again, for 64 the results were slightly worse. Although the last run
did almost match, most runs were lower. They're better than they were last
time, but still not as good as the unchanged 96rc1

I can try running against HEAD if you'd like.

SINGLE
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 1
-c 1 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1508745
latency average: 0.040 ms
tps = 25145.524948 (including connections establishing)
tps = 25146.433564 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 1
-c 1 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1346454
latency average: 0.045 ms
tps = 22440.692798 (including connections establishing)
tps = 22441.527989 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 1
-c 1 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1426906
latency average: 0.042 ms
tps = 23781.710780 (including connections establishing)
tps = 23782.523744 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 1
-c 1 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1546252
latency average: 0.039 ms
tps = 25770.468513 (including connections establishing)
tps = 25771.352027 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 1
-c 1 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 1
number of threads: 1
duration: 60 s
number of transactions actually processed: 1542366
latency average: 0.039 ms
tps = 25705.706274 (including connections establishing)
tps = 25706.577285 (excluding connections establishing)

FOUR
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 4
-c 4 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 4
number of threads: 4
duration: 60 s
number of transactions actually processed: 5606159
latency average: 0.043 ms
tps = 93435.464767 (including connections establishing)
tps = 93442.716270 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 4
-c 4 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 4
number of threads: 4
duration: 60 s
number of transactions actually processed: 5602564
latency average: 0.043 ms
tps = 93375.528201 (including connections establishing)
tps = 93381.999147 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 4
-c 4 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 4
number of threads: 4
duration: 60 s
number of transactions actually processed: 5608675
latency average: 0.043 ms
tps = 93474.081114 (including connections establishing)
tps = 93481.634509 (excluding connections establishing)

THIRTY-TWO
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 32
-c 32 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 5273952
latency average: 0.364 ms
tps = 87855.483112 (including connections establishing)
tps = 87880.762662 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 32
-c 32 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 5294039
latency average: 0.363 ms
tps = 88126.254862 (including connections establishing)
tps = 88151.282371 (excluding connections establishing)
[keith(at)corpus ~]$
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 32
-c 32 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 5279444
latency average: 0.364 ms
tps = 87867.500628 (including connections establishing)
tps = 87891.856414 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 32
-c 32 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 5286405
latency average: 0.363 ms
tps = 88049.742194 (including connections establishing)
tps = 88077.409809 (excluding connections establishing)

SIXTY-FOUR
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 64
-c 64 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4426565
latency average: 0.867 ms
tps = 72142.306576 (including connections establishing)
tps = 72305.201516 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 64
-c 64 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4070048
latency average: 0.943 ms
tps = 66587.264608 (including connections establishing)
tps = 66711.820878 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 64
-c 64 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4478535
latency average: 0.857 ms
tps = 72768.961061 (including connections establishing)
tps = 72930.488922 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 64
-c 64 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4051086
latency average: 0.948 ms
tps = 66540.741821 (including connections establishing)
tps = 66601.943062 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 64
-c 64 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4374049
latency average: 0.878 ms
tps = 72093.025134 (including connections establishing)
tps = 72271.145559 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v6/bin/pgbench -T 60 -j 64
-c 64 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 64
number of threads: 64
duration: 60 s
number of transactions actually processed: 4762663
latency average: 0.806 ms
tps = 79372.610362 (including connections establishing)
tps = 79535.601194 (excluding connections establishing)

As a sanity check I went back and ran the pgbench from the v5 patch to see
if it was still lower. It is. So v6 seems to have a slight improvement in
some cases.

[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v5/bin/pgbench -T 60 -j 32
-c 32 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 4618814
latency average: 0.416 ms
tps = 76960.608378 (including connections establishing)
tps = 76981.609781 (excluding connections establishing)
[keith(at)corpus ~]$ /home/keith/pgsql96rc1_kqueue_v5/bin/pgbench -T 60 -j 32
-c 32 -M prepared -S -p 5496 pgbench
starting vacuum...end.
transaction type: <builtin: select only>
scaling factor: 100
query mode: prepared
number of clients: 32
number of threads: 32
duration: 60 s
number of transactions actually processed: 4649745
latency average: 0.413 ms
tps = 77491.094077 (including connections establishing)
tps = 77525.443941 (excluding connections establishing)