Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1b7fcy-0005oW-MH for pgsql-hackers@arkaria.postgresql.org; Tue, 31 May 2016 09:06:20 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84_2) (envelope-from ) id 1b7fcy-0003YM-5I for pgsql-hackers@arkaria.postgresql.org; Tue, 31 May 2016 09:06:20 +0000 Received: from makus.postgresql.org ([2001:4800:1501:1::229]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1b7fct-0003Ug-OP for pgsql-hackers@postgresql.org; Tue, 31 May 2016 09:06:16 +0000 Received: from forward5h.cmail.yandex.net ([87.250.230.20]) by makus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1b7fcp-0002R8-Ep for pgsql-hackers@postgresql.org; Tue, 31 May 2016 09:06:14 +0000 Received: from smtp1h.mail.yandex.net (smtp1h.mail.yandex.net [84.201.187.144]) by forward5h.cmail.yandex.net (Yandex) with ESMTP id 098F0211C6; Tue, 31 May 2016 12:06:05 +0300 (MSK) Received: from smtp1h.mail.yandex.net (localhost [127.0.0.1]) by smtp1h.mail.yandex.net (Yandex) with ESMTP id 3F9AA1340F6D; Tue, 31 May 2016 12:06:05 +0300 (MSK) Received: by smtp1h.mail.yandex.net (nwsmtp/Yandex) with ESMTPSA id TasVzQrjq2-64jmJBW1; Tue, 31 May 2016 12:06:04 +0300 (using TLSv1 with cipher ECDHE-RSA-AES128-SHA (128/128 bits)) (Client certificate not present) X-Yandex-Suid-Status: 1 0,1 0,1 0 Content-Type: multipart/alternative; boundary="Apple-Mail=_313BCFBA-38AE-49B6-8EE5-E34F253CABE0" Mime-Version: 1.0 (Mac OS X Mail 9.3 \(3124\)) Subject: Re: 9.4 -> 9.5 regression with queries through pgbouncer on RHEL 6 From: Vladimir Borodin In-Reply-To: <910CBF45-90EB-44D6-9640-22638C2F26F7@simply.name> Date: Tue, 31 May 2016 12:06:03 +0300 Cc: PostgreSQL-development , pgbouncer-general@lists.pgfoundry.org Message-Id: References: <26239E39-A838-4611-B7BA-0E96D2DF3253@simply.name> <910CBF45-90EB-44D6-9640-22638C2F26F7@simply.name> To: Andres Freund X-Mailer: Apple Mail (2.3124) X-Pg-Spam-Score: -2.6 (--) List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-hackers Precedence: bulk Sender: pgsql-hackers-owner@postgresql.org --Apple-Mail=_313BCFBA-38AE-49B6-8EE5-E34F253CABE0 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 > 27 =D0=BC=D0=B0=D1=8F 2016 =D0=B3., =D0=B2 19:57, Vladimir Borodin = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0=B0): >=20 > -performance > +hackers >=20 >> 25 =D0=BC=D0=B0=D1=8F 2016 =D0=B3., =D0=B2 17:33, Vladimir Borodin = > =D0=BD=D0=B0=D0=BF=D0=B8=D1=81= =D0=B0=D0=BB(=D0=B0): >>=20 >> Hi all. >>=20 >> We have found that queries through PgBouncer 1.7.2 (with transaction = pooling) to local PostgreSQL are almost two times slower in 9.5.3 than = in 9.4.8 on RHEL 6 hosts (all packages are updated to last versions). = Meanwhile the problem can=E2=80=99t be reproduced i.e. on Ubuntu 14.04 = (also fully-updated). >>=20 >> Here is how the results look like for 9.4, 9.5 and 9.6. All are built = from latest commits on yesterday in >> * REL9_4_STABLE (a0cc89a28141595d888d8aba43163d58a1578bfb), >> * REL9_5_STABLE (e504d915bbf352ecfc4ed335af934e799bf01053), >> * master (6ee7fb8244560b7a3f224784b8ad2351107fa55d). >>=20 >> All of them are build on the host where testing is done (with stock = gcc versions). Sysctls, pgbouncer config and everything we found are the = same, postgres configs are default, PGDATA is in tmpfs. All numbers are = reproducible, they are stable between runs. >>=20 >> Shortly: >>=20 >> OS PostgreSQL version TPS = Avg. latency >> RHEL 6 9.4 44898 = 1.425 ms >> RHEL 6 9.5 26199 = 2.443 ms >> RHEL 6 9.5 43027 = 1.487 ms >> Ubuntu 14.04 9.4 67458 = 0.949 ms >> Ubuntu 14.04 9.5 64065 = 0.999 ms >> Ubuntu 14.04 9.6 64350 = 0.995 ms >=20 > The results above are not really fair, pgbouncer.ini was a bit = different on Ubuntu host (application_name_add_host was disabled). Here = are the right results with exactly the same configuration: >=20 > OS PostgreSQL version TPS = Avg. latency > RHEL 6 9.4 44898 = 1.425 ms > RHEL 6 9.5 26199 = 2.443 ms > RHEL 6 9.5 43027 = 1.487 ms > Ubuntu 14.04 9.4 45971 = 1.392 ms > Ubuntu 14.04 9.5 40282 = 1.589 ms > Ubuntu 14.04 9.6 45410 = 1.409 ms >=20 > It can be seen that there is a regression for 9.5 in Ubuntu also, but = not so significant. We first thought that the reason is = 38628db8d8caff21eb6cf8d775c0b2d04cf07b9b (Add memory barriers for = PgBackendStatus.st _changecount protocol), = but in that case the regression should also be seen in 9.6 also. >=20 > There also was a bunch of changes in FE/BE communication (like = 387da18874afa17156ee3af63766f17efb53c4b9 or = 98a64d0bd713cb89e61bef6432befc4b7b5da59e) and that may answer the = question of regression in 9.5 and normal results in 9.6. Probably the = right way to find the answer is to do bisect. I=E2=80=99ll do it but if = some more diagnostics information can help, feel free to ask about it. Yep, bisect confirms that the first bad commit in REL9_5_STABLE is = 387da18874afa17156ee3af63766f17efb53c4b9. Full output is attached. And bisect for master branch confirms that the situation became much = better after 98a64d0bd713cb89e61bef6432befc4b7b5da59e. Output is also = attached. On Ubuntu performance degradation is ~15% and on RHEL it is ~100%. I = don=E2=80=99t know what is the cause for different numbers on RHEL and = Ubuntu but certainly there is a regression when pgbouncer is connected = to postgres through localhost. When I try to connect pgbouncer to = postgres through unix-socket performance is constantly bad on all = postgres versions. Both servers are for testing but I can easily provide you SSH access = only to Ubuntu host if necessary. I can also gather more diagnostics if = needed. >=20 >>=20 >> You could see that the difference between major versions on Ubuntu is = not significant, but on RHEL 9.5 is 70% slower than 9.4 and 9.6. >>=20 >> Below are more details. >>=20 >> RHEL 6: >>=20 >> postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg94' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 2693962 >> latency average: 1.425 ms >> tps =3D 44897.461518 (including connections establishing) >> tps =3D 44898.763258 (excluding connections establishing) >> postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg95' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 1572014 >> latency average: 2.443 ms >> tps =3D 26198.928627 (including connections establishing) >> tps =3D 26199.803363 (excluding connections establishing) >> postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg96' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 2581645 >> latency average: 1.487 ms >> tps =3D 43025.676995 (including connections establishing) >> tps =3D 43027.038275 (excluding connections establishing) >> postgres@pgload05g ~ $ >>=20 >> Ubuntu 14.04 (the same hardware): >>=20 >> postgres@pgloadpublic02:~$ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg94' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 2758348 >> latency average: 1.392 ms >> tps =3D 45970.634737 (including connections establishing) >> tps =3D 45971.531098 (excluding connections establishing) >> postgres@pgloadpublic02:~$ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg95' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 2417009 >> latency average: 1.589 ms >> tps =3D 40282.003641 (including connections establishing) >> tps =3D 40282.855938 (excluding connections establishing) >> postgres@pgloadpublic02:~$ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg96' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 2724666 >> latency average: 1.409 ms >> tps =3D 45409.308603 (including connections establishing) >> tps =3D 45410.152406 (excluding connections establishing) >> postgres@pgloadpublic02:~$ >>=20 >> In both tests (RHEL and Ubuntu) the bottleneck is performance of = singe CPU core which is 100% consumed by PgBouncer. If pgbench connects = to postgres directly I get the following (expected) numbers: >>=20 >> postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D5432' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 10010710 >> latency average: 0.384 ms >> tps =3D 166835.937859 (including connections establishing) >> tps =3D 166849.730224 (excluding connections establishing) >> postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D5433' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 13373890 >> latency average: 0.287 ms >> tps =3D 222888.311289 (including connections establishing) >> tps =3D 222951.470125 (excluding connections establishing) >> postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D5434' >> transaction type: SELECT only >> scaling factor: 100 >> query mode: simple >> number of clients: 64 >> number of threads: 64 >> duration: 60 s >> number of transactions actually processed: 12989816 >> latency average: 0.296 ms >> tps =3D 216487.458399 (including connections establishing) >> tps =3D 216548.069976 (excluding connections establishing) >> postgres@pgload05g ~ $ >>=20 >> Compilation options look almost the same: >> # RHEL 6 >> CFLAGS =3D -Wall -Wmissing-prototypes -Wpointer-arith = -Wdeclaration-after-statement -Wendif-labels -Wmissing-format-attribute = -Wformat-security -fno-strict-aliasing -fwrapv -g -O2 >> # Ubuntu >> CFLAGS =3D -Wall -Wmissing-prototypes -Wpointer-arith = -Wdeclaration-after-statement -Wendif-labels -Wmissing-format-attribute = -Wformat-security -fno-strict-aliasing -fwrapv = -fexcess-precision=3Dstandard -g -O2 >>=20 >> Attached are a simple script to deploy the testing environment = (PgBouncer should be installed) and pgbouncer config. I could provide = any other needed information like backtraces or perf reports or anything = else. >>=20 >> >> >>=20 >> -- >> May the force be with you=E2=80=A6 >> https://simply.name >=20 >=20 > -- > May the force be with you=E2=80=A6 > https://simply.name -- May the force be with you=E2=80=A6 https://simply.name --Apple-Mail=_313BCFBA-38AE-49B6-8EE5-E34F253CABE0 Content-Type: multipart/mixed; boundary="Apple-Mail=_CEE8060D-BCDA-45F5-86C7-8139A631137F" --Apple-Mail=_CEE8060D-BCDA-45F5-86C7-8139A631137F Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8
27 =D0=BC=D0=B0=D1=8F 2016 =D0=B3., =D0=B2 19:57, Vladimir = Borodin <root@simply.name> =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0= =BB(=D0=B0):

-performance
+hackers

25 = =D0=BC=D0=B0=D1=8F 2016 =D0=B3., =D0=B2 17:33, Vladimir Borodin <root@simply.name> = =D0=BD=D0=B0=D0=BF=D0=B8=D1=81=D0=B0=D0=BB(=D0=B0):

Hi all.

We have found that queries through = PgBouncer 1.7.2 (with transaction pooling) to local PostgreSQL are = almost two times slower in 9.5.3 than in 9.4.8 on RHEL 6 hosts (all = packages are updated to last versions). Meanwhile the problem can=E2=80=99= t be reproduced i.e. on Ubuntu 14.04 (also fully-updated).

Here is how the results = look like for 9.4, 9.5 and 9.6. All are built from latest commits on = yesterday in
* REL9_4_STABLE = (a0cc89a28141595d888d8aba43163d58a1578bfb),
= * REL9_5_STABLE = (e504d915bbf352ecfc4ed335af934e799bf01053),
= * master = (6ee7fb8244560b7a3f224784b8ad2351107fa55d).

All of them are build on the host where = testing is done (with stock gcc versions). Sysctls, pgbouncer config and = everything we found are the same, postgres configs are default, PGDATA = is in tmpfs. All numbers are reproducible, they are stable between = runs.

Shortly:

OS PostgreSQL = version = TPS = Avg. latency
RHEL 6 = 9.4 = 44898 1.425 ms
RHEL 6 9.5 = 26199 2.443 ms
RHEL 6 = 9.5 = 43027 1.487 ms
Ubuntu 14.04 9.4 = 67458 = 0.949 ms
Ubuntu 14.04 9.5 = 64065 0.999 ms
Ubuntu = 14.04 = 9.6 = 64350 0.995 = ms

The results above are not really fair, pgbouncer.ini was a = bit different on Ubuntu host (application_name_add_host was disabled). = Here are the right results with exactly the same = configuration:

OS PostgreSQL = version = TPS = Avg. latency
RHEL 6 = 9.4 = 44898 1.425 ms
RHEL 6 9.5 = 26199 2.443 ms
RHEL 6 = 9.5 = 43027 1.487 ms
Ubuntu 14.04 9.4 = 45971 = 1.392 ms
Ubuntu 14.04 9.5 = 40282 1.589 ms
Ubuntu = 14.04 = 9.6 = 45410 1.409 = ms

It can be seen that there is a regression for 9.5 in Ubuntu = also, but not so significant. We first thought that the reason = is 38628db8d8caff21eb6cf8d775c0b2d04cf07b9b (Add memory barriers = for PgBackendStatus.st_changecount protocol), but in that = case the regression should also be seen in 9.6 also.

There also was a bunch = of changes in FE/BE communication (like = 387da18874afa17156ee3af63766f17efb53c4b9 or = 98a64d0bd713cb89e61bef6432befc4b7b5da59e) and that may answer the = question of regression in 9.5 and normal results in 9.6. Probably the = right way to find the answer is to do bisect. I=E2=80=99ll do it but if = some more diagnostics information can help, feel free to ask about = it.

Yep, bisect confirms that the first bad commit in = REL9_5_STABLE is 387da18874afa17156ee3af63766f17efb53c4b9. Full = output is attached.
And bisect for master branch confirms that = the situation became much better after = 98a64d0bd713cb89e61bef6432befc4b7b5da59e. Output is also = attached.

On Ubuntu performance = degradation is ~15% and on RHEL it is ~100%. I don=E2=80=99t know what = is the cause for different numbers on RHEL and Ubuntu but certainly = there is a regression when pgbouncer is connected to postgres through = localhost. When I try to connect pgbouncer to postgres through = unix-socket performance is constantly bad on all postgres = versions.

Both servers are for = testing but I can easily provide you SSH access only to Ubuntu host if = necessary. I can also gather more diagnostics if needed.

= --Apple-Mail=_CEE8060D-BCDA-45F5-86C7-8139A631137F Content-Disposition: attachment; filename=bisect95.out Content-Type: application/octet-stream; name="bisect95.out" Content-Transfer-Encoding: 7bit root@pgload05g ~/postgresql # cat bisect_test.sh #!/bin/bash su - postgres -c "/usr/lib/postgresql/9.5/bin/pg_ctl -D /dev/shm/pg/9.5/ stop -m fast" >/dev/null 2>&1 || true rm -rf /dev/shm/pg/9.5/* make clean >/dev/null || exit 125 ./configure --prefix=/usr/lib/postgresql/9.5 --enable-debug >/dev/null || exit 125 make -j 32 >/dev/null 2>&1 || exit 125 make install >/dev/null || exit 125 make -j 32 -C contrib >/dev/null 2>&1 || exit 125 make -C contrib install >/dev/null || exit 125 su - postgres -c "/usr/lib/postgresql/9.5/bin/initdb -D /dev/shm/pg/9.5/" >/dev/null 2>&1 || exit 125 echo "local all all trust" >/dev/shm/pg/9.5/pg_hba.conf echo "host all all 127.0.0.1/32 trust" >>/dev/shm/pg/9.5/pg_hba.conf echo "host all all ::1/128 trust" >>/dev/shm/pg/9.5/pg_hba.conf su - postgres -c '/usr/lib/postgresql/9.5/bin/pg_ctl -D /dev/shm/pg/9.5/ -o "-p 5433" start' >/dev/null 2>&1 || exit 125 sleep 3 su - postgres -c "/usr/lib/postgresql/9.5/bin/pgbench -i -s 100 'host=localhost port=6432 dbname=pg95'" >/dev/null 2>&1 || exit 125 sleep 3 TPS=`su - postgres -c "/usr/lib/postgresql/9.5/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n 'host=localhost port=6432 dbname=pg95'" | awk '/excluding connections establishing/ {print $3}' | cut -f1 -d\.` REV=`git rev-parse --short HEAD` echo "$REV $TPS" >>/tmp/bisect.log if [ "$TPS" -gt 55000 ]; then exit 0 else exit 1 fi root@pgload05g ~/postgresql # git branch REL9_4_STABLE * REL9_5_STABLE master root@pgload05g ~/postgresql # git pull Already up-to-date. root@pgload05g ~/postgresql # git bisect start HEAD a24c104 Bisecting: 1338 revisions left to test after this (roughly 10 steps) [0badb069bc9f590dbc1306ccbd51e99ed81f228c] pg_ctl: change default shutdown mode from 'smart' to 'fast' root@pgload05g ~/postgresql # git bisect run ./bisect_test.sh running ./bisect_test.sh Bisecting: 669 revisions left to test after this (roughly 9 steps) [606c0123d627b37d5ac3f7c2c97cd715dde7842f] Reduce btree scan overhead for < and > strategies running ./bisect_test.sh Bisecting: 334 revisions left to test after this (roughly 8 steps) [1c993b3aceb7e0ccf32b59280b266b1f4f7b077e] Reword CREATE POLICY parameter descriptions running ./bisect_test.sh Bisecting: 167 revisions left to test after this (roughly 7 steps) [ee4ddcb38a0abfdb8f7302bbc332a1cb92888ed1] Fix targetRelation initializiation in prepsecurity running ./bisect_test.sh Bisecting: 83 revisions left to test after this (roughly 6 steps) [2c75531a6cc49a56afbd5619c36b3daccbe243fa] In the SSL test suite, use a root CA cert that won't expire (so quickly) running ./bisect_test.sh Bisecting: 41 revisions left to test after this (roughly 5 steps) [4fe384bd858671d40d311ca68cc9b80f4c683a3e] Process 'die' interrupts while reading/writing from the client socket. running ./bisect_test.sh Bisecting: 20 revisions left to test after this (roughly 4 steps) [21fe4e2b6e701234afb77fa92e192546d51a5962] Release notes for 9.4.1, 9.3.6, 9.2.10, 9.1.15, 9.0.19. running ./bisect_test.sh Bisecting: 10 revisions left to test after this (roughly 3 steps) [2b3a8b20c2da9f39ffecae25ab7c66974fbc0d3b] Be more careful to not lose sync in the FE/BE protocol. running ./bisect_test.sh Bisecting: 5 revisions left to test after this (roughly 3 steps) [507627f5b5c009aa95c04254614778c6263a3dc2] Rephrase the documentation on pg_receivexlog --synchronous option. running ./bisect_test.sh Bisecting: 2 revisions left to test after this (roughly 2 steps) [778d498c7d9099c784f14199a319ec2a84d91191] Fix breakage in GEODEBUG debug code. running ./bisect_test.sh Bisecting: 0 revisions left to test after this (roughly 1 step) [4f85fde8eb860f263384fffdca660e16e77c7f76] Introduce and use infrastructure for interrupt processing during client reads. running ./bisect_test.sh Bisecting: 0 revisions left to test after this (roughly 0 steps) [387da18874afa17156ee3af63766f17efb53c4b9] Use a nonblocking socket for FE/BE communication and block using latches. running ./bisect_test.sh 387da18874afa17156ee3af63766f17efb53c4b9 is the first bad commit commit 387da18874afa17156ee3af63766f17efb53c4b9 Author: Andres Freund Date: Tue Feb 3 22:03:48 2015 +0100 Use a nonblocking socket for FE/BE communication and block using latches. This allows to introduce more elaborate handling of interrupts while reading from a socket. Currently some interrupt handlers have to do significant work from inside signal handlers, and it's very hard to correctly write code to do so. Generic signal handler limitations, combined with the fact that we can't safely jump out of a signal handler while reading from the client have prohibited implementation of features like timeouts for idle-in-transaction. Additionally we use the latch code to wait in a couple places where we previously only had waiting code on windows as other platforms just busy looped. This can increase the number of systemcalls happening during FE/BE communication. Benchmarks so far indicate that the impact isn't very high, and there's room for optimization in the latch code. The chance of cleaning up the usage of latches gives us, seem to outweigh the risk of small performance regressions. This commit theoretically can't used without the next patch in the series, as WaitLatchOrSocket is not defined to be fully signal safe. As we already do that in some cases though, it seems better to keep the commits separate, so they're easier to understand. Author: Andres Freund Reviewed-By: Heikki Linnakangas :040000 040000 dbfcf3cc32e4c6c64dc8540a1f3913fb7f19eeb5 e66d116eb69f76071ce0d864b85dca3b73d17f9e M src bisect run success root@pgload05g ~/postgresql # cat /tmp/bisect.log 0badb06 36523 606c012 71388 1c993b3 74150 ee4ddcb 36710 2c75531 35458 4fe384b 36848 21fe4e2 73805 2b3a8b2 74067 507627f 73929 778d498 74068 4f85fde 36982 387da18 35763 root@pgload05g ~/postgresql # --Apple-Mail=_CEE8060D-BCDA-45F5-86C7-8139A631137F Content-Transfer-Encoding: 7bit Content-Type: text/html; charset=us-ascii
--Apple-Mail=_CEE8060D-BCDA-45F5-86C7-8139A631137F Content-Disposition: attachment; filename=bisect96.out Content-Type: application/octet-stream; name="bisect96.out" Content-Transfer-Encoding: 7bit root@pgload05g ~/tmp/postgresql # git branch * master root@pgload05g ~/tmp/postgresql # git rev-parse HEAD 2195c5afaabd4d794c8bbf1bf10d8e4fe54b6145 root@pgload05g ~/tmp/postgresql # cat bisect_test.sh #!/bin/bash su - postgres -c "/usr/lib/postgresql/9.6/bin/pg_ctl -D /dev/shm/pg/9.6/ stop -m fast" >/dev/null 2>&1 || true rm -rf /dev/shm/pg/9.6/* ./configure --prefix=/usr/lib/postgresql/9.6 --enable-debug >/dev/null || exit 125 make clean >/dev/null || exit 125 make -j 32 >/dev/null 2>&1 || exit 125 make install >/dev/null || exit 125 make -j 32 -C contrib >/dev/null 2>&1 || exit 125 make -C contrib install >/dev/null || exit 125 su - postgres -c "/usr/lib/postgresql/9.6/bin/initdb -D /dev/shm/pg/9.6/" >/dev/null 2>&1 || exit 125 echo "local all all trust" >/dev/shm/pg/9.6/pg_hba.conf echo "host all all 127.0.0.1/32 trust" >>/dev/shm/pg/9.6/pg_hba.conf echo "host all all ::1/128 trust" >>/dev/shm/pg/9.6/pg_hba.conf su - postgres -c '/usr/lib/postgresql/9.6/bin/pg_ctl -D /dev/shm/pg/9.6/ -o "-p 5434" start' >/dev/null 2>&1 || exit 125 sleep 3 su - postgres -c "/usr/lib/postgresql/9.6/bin/pgbench -i -s 100 'host=localhost port=6432 dbname=pg96'" >/dev/null 2>&1 || exit 125 sleep 3 TPS=`su - postgres -c "/usr/lib/postgresql/9.5/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n 'host=localhost port=6432 dbname=pg96'" | awk '/excluding connections establishing/ {print $3}' | cut -f1 -d\.` REV=`git rev-parse --short HEAD` echo "$REV $TPS" >>/tmp/bisect96.log if [ "$TPS" -lt 55000 ]; then exit 0 else exit 1 fi root@pgload05g ~/tmp/postgresql # git bisect run ./bisect_test.sh running ./bisect_test.sh Bisecting: 455 revisions left to test after this (roughly 9 steps) [7caaeaf3607fae91318f24debce3dc017ca299a3] Link libpq after libpgfeutils to satisfy Windows linker. running ./bisect_test.sh Bisecting: 227 revisions left to test after this (roughly 8 steps) [9def031bd2821f35b5f506260d922482648a8bb0] Add more tests for commit_timestamp feature running ./bisect_test.sh Bisecting: 113 revisions left to test after this (roughly 7 steps) [e01157500f26342bf4f067a4eb1e45ab9a3cd410] Include portability/mem.h into fd.c for MAP_FAILED. running ./bisect_test.sh Bisecting: 56 revisions left to test after this (roughly 6 steps) [61d2ebdbf9155d80f83281d8c5729c8f8f0949bc] Fix a typo running ./bisect_test.sh Bisecting: 28 revisions left to test after this (roughly 5 steps) [b6afae71aaf6d2df76d0a0a77c8b630220a01ec1] Use %option bison-bridge in psql/pgbench lexers. running ./bisect_test.sh Bisecting: 14 revisions left to test after this (roughly 4 steps) [384dfbde19330541f7fb487f9352949aa06c812e] Fix unsafe use of strtol() on a non-null-terminated Text datum. running ./bisect_test.sh Bisecting: 6 revisions left to test after this (roughly 3 steps) [92b7902deb3155f6975f33e8b6c8be4d9d066172] Clean up some Coverity complaints about commit 0bf3ae88af330496. running ./bisect_test.sh Bisecting: 6 revisions left to test after this (roughly 3 steps) [98a64d0bd713cb89e61bef6432befc4b7b5da59e] Introduce WaitEventSet API. running ./bisect_test.sh Bisecting: 1 revision left to test after this (roughly 1 step) [326d73c86fda407a810675c3b5a48e0a0cc992f5] Second attempt at fixing MSVC build for 68ab8e8ba4a471d9. running ./bisect_test.sh Bisecting: 0 revisions left to test after this (roughly 0 steps) [72e2d21c1249b674496f97cd6009c0bda62f6b4d] Combine win32 and unix latch implementations. running ./bisect_test.sh 98a64d0bd713cb89e61bef6432befc4b7b5da59e is the first bad commit commit 98a64d0bd713cb89e61bef6432befc4b7b5da59e Author: Andres Freund Date: Mon Mar 21 09:56:39 2016 +0100 Introduce WaitEventSet API. Commit ac1d794 ("Make idle backends exit if the postmaster dies.") introduced a regression on, at least, large linux systems. Constantly adding the same postmaster_alive_fds to the OSs internal datastructures for implementing poll/select can cause significant contention; leading to a performance regression of nearly 3x in one example. This can be avoided by using e.g. linux' epoll, which avoids having to add/remove file descriptors to the wait datastructures at a high rate. Unfortunately the current latch interface makes it hard to allocate any persistent per-backend resources. Replace, with a backward compatibility layer, WaitLatchOrSocket with a new WaitEventSet API. Users can allocate such a Set across multiple calls, and add more than one file-descriptor to wait on. The latter has been added because there's upcoming postgres features where that will be helpful. In addition to the previously existing poll(2), select(2), WaitForMultipleObjects() implementations also provide an epoll_wait(2) based implementation to address the aforementioned performance problem. Epoll is only available on linux, but that is the most likely OS for machines large enough (four sockets) to reproduce the problem. To actually address the aforementioned regression, create and use a long-lived WaitEventSet for FE/BE communication. There are additional places that would benefit from a long-lived set, but that's a task for another day. Thanks to Amit Kapila, who helped make the windows code I blindly wrote actually work. Reported-By: Dmitry Vasilyev Discussion: CAB-SwXZh44_2ybvS5Z67p_CDz=XFn4hNAD=CnMEF+QqkXwFrGg@mail.gmail.com 20160114143931.GG10941@awork2.anarazel.de :100755 100755 c10d9549a40951293f16ff058bf077bcddd0bb99 24655dc09614ee72f882abad90a0d071a1e5f51e M configure :100644 100644 47d0f584deda36025cdf0f83252e5976986531e9 c564a7695fa917e664f5c5676c8dc95468fad4e5 M configure.in :040000 040000 3e57535f13f005a4b8e4e606cab91b1f93cad048 b9d1d96a88cd9cfd0ad0a6f98cd36938762bfb57 M src bisect run success root@pgload05g ~/tmp/postgresql # cat /tmp/bisect96.log 65c5fcd 35783 7caaeaf 71532 9def031 36279 e011575 36386 61d2ebd 35791 b6afae7 35288 384dfbd 71557 98a64d0 70223 326d73c 35029 72e2d21 33649 root@pgload05g ~/tmp/postgresql # --Apple-Mail=_CEE8060D-BCDA-45F5-86C7-8139A631137F Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8



You could see that the = difference between major versions on Ubuntu is not significant, but on = RHEL 9.5 is 70% slower than 9.4 and 9.6.

Below are more details.

RHEL 6:

postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg94'
transaction type: SELECT = only
scaling factor: 100
query = mode: simple
number of clients: 64
number of threads: 64
duration: 60 = s
number of transactions actually processed: = 2693962
latency average: 1.425 ms
tps =3D 44897.461518 (including connections = establishing)
tps =3D 44898.763258 (excluding = connections establishing)
postgres@pgload05g ~ $ = /usr/lib/postgresql/9.4/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n = 'host=3Dlocalhost port=3D6432 dbname=3Dpg95'
transaction type: SELECT only
scaling = factor: 100
query mode: simple
number of clients: 64
number of threads: = 64
duration: 60 s
number of = transactions actually processed: 1572014
latency = average: 2.443 ms
tps =3D 26198.928627 (including = connections establishing)
tps =3D 26199.803363 = (excluding connections establishing)
postgres@pgload05g ~ $ /usr/lib/postgresql/9.4/bin/pgbench -U = postgres -T 60 -j 64 -c 64 -S -n 'host=3Dlocalhost port=3D6432 = dbname=3Dpg96'
transaction type: SELECT = only
scaling factor: 100
query = mode: simple
number of clients: 64
number of threads: 64
duration: 60 = s
number of transactions actually processed: = 2581645
latency average: 1.487 ms
tps =3D 43025.676995 (including connections = establishing)
tps =3D 43027.038275 (excluding = connections establishing)
postgres@pgload05g ~ = $

Ubuntu 14.04 = (the same hardware):

postgres@pgloadpublic02:~$ = /usr/lib/postgresql/9.4/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n = 'host=3Dlocalhost port=3D6432 dbname=3Dpg94'
transaction type: SELECT = only
scaling factor: 100
query mode: simple
number of clients: = 64
number = of threads: 64
duration: 60 s
number of transactions actually processed: = 2758348
latency average: 1.392 ms
tps =3D 45970.634737 (including connections = establishing)
tps =3D 45971.531098 (excluding connections = establishing)
postgres@pgloadpublic02:~$ = /usr/lib/postgresql/9.4/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n = 'host=3Dlocalhost port=3D6432 dbname=3Dpg95'
transaction type: SELECT = only
scaling factor: 100
query mode: simple
number of clients: = 64
number = of threads: 64
duration: 60 s
number of transactions actually processed: = 2417009
latency average: 1.589 ms
tps =3D 40282.003641 (including connections = establishing)
tps =3D 40282.855938 (excluding connections = establishing)
postgres@pgloadpublic02:~$ = /usr/lib/postgresql/9.4/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n = 'host=3Dlocalhost port=3D6432 dbname=3Dpg96'
transaction type: SELECT = only
scaling factor: 100
query mode: simple
number of clients: = 64
number = of threads: 64
duration: 60 s
number of transactions actually processed: = 2724666
latency average: 1.409 ms
tps =3D 45409.308603 (including connections = establishing)
tps =3D 45410.152406 (excluding connections = establishing)
postgres@pgloadpublic02:~$

In both tests (RHEL and Ubuntu) the = bottleneck is performance of singe CPU core which is 100% consumed by = PgBouncer. If pgbench connects to postgres directly I get the following = (expected) numbers:

postgres@pgload05g ~ $ = /usr/lib/postgresql/9.4/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n = 'host=3Dlocalhost port=3D5432'
transaction type: = SELECT only
scaling factor: 100
query mode: simple
number of clients: = 64
number of threads: 64
duration: 60 s
number of transactions = actually processed: 10010710
latency average: 0.384 = ms
tps =3D 166835.937859 (including connections = establishing)
tps =3D 166849.730224 (excluding = connections establishing)
postgres@pgload05g ~ $ = /usr/lib/postgresql/9.4/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n = 'host=3Dlocalhost port=3D5433'
transaction type: = SELECT only
scaling factor: 100
query mode: simple
number of clients: = 64
number of threads: 64
duration: 60 s
number of transactions = actually processed: 13373890
latency average: 0.287 = ms
tps =3D 222888.311289 (including connections = establishing)
tps =3D 222951.470125 (excluding = connections establishing)
postgres@pgload05g ~ $ = /usr/lib/postgresql/9.4/bin/pgbench -U postgres -T 60 -j 64 -c 64 -S -n = 'host=3Dlocalhost port=3D5434'
transaction type: = SELECT only
scaling factor: 100
query mode: simple
number of clients: = 64
number of threads: 64
duration: 60 s
number of transactions = actually processed: 12989816
latency average: 0.296 = ms
tps =3D 216487.458399 (including connections = establishing)
tps =3D 216548.069976 (excluding = connections establishing)
postgres@pgload05g ~ = $

Compilation = options look almost the same:
# = RHEL 6
CFLAGS =3D -Wall -Wmissing-prototypes = -Wpointer-arith -Wdeclaration-after-statement -Wendif-labels = -Wmissing-format-attribute -Wformat-security -fno-strict-aliasing = -fwrapv -g -O2
# Ubuntu
CFLAGS =3D -Wall -Wmissing-prototypes -Wpointer-arith = -Wdeclaration-after-statement -Wendif-labels -Wmissing-format-attribute = -Wformat-security -fno-strict-aliasing -fwrapv = -fexcess-precision=3Dstandard -g -O2

Attached are a = simple script to deploy the testing environment (PgBouncer should be = installed) and pgbouncer config. I could provide any other needed = information like backtraces or perf reports or anything else.

<pgbouncer.ini>
<deploy.sh>

--
May the force be with you=E2=80=A6
<= div class=3D"" style=3D"font-family: Helvetica; font-size: 12px; = font-style: normal; font-variant-ligatures: normal; = font-variant-position: normal; font-variant-caps: normal; = font-variant-numeric: normal; font-variant-alternates: normal; = font-variant-east-asian: normal; font-weight: normal; letter-spacing: = normal; line-height: normal; orphans: auto; text-align: start; = text-indent: 0px; text-transform: none; white-space: normal; widows: = auto; word-spacing: 0px; -webkit-text-stroke-width: 0px;">https://simply.name



--
May the force be with you=E2=80=A6
<= div class=3D"" style=3D"font-family: Helvetica; font-size: 12px; = font-style: normal; font-variant-ligatures: normal; = font-variant-position: normal; font-variant-caps: normal; = font-variant-numeric: normal; font-variant-alternates: normal; = font-variant-east-asian: normal; font-weight: normal; letter-spacing: = normal; line-height: normal; orphans: auto; text-align: start; = text-indent: 0px; text-transform: none; white-space: normal; widows: = auto; word-spacing: 0px; -webkit-text-stroke-width: 0px;">https://simply.name


--
May the force be with you=E2=80=A6
https://simply.name

= --Apple-Mail=_CEE8060D-BCDA-45F5-86C7-8139A631137F-- --Apple-Mail=_313BCFBA-38AE-49B6-8EE5-E34F253CABE0--