Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1b6L54-0007bL-Gt for pgsql-hackers@arkaria.postgresql.org; Fri, 27 May 2016 16:57:51 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84_2) (envelope-from ) id 1b6L54-0004dp-3a for pgsql-hackers@arkaria.postgresql.org; Fri, 27 May 2016 16:57:50 +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 1b6L52-0004di-VK for pgsql-hackers@postgresql.org; Fri, 27 May 2016 16:57:49 +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 1b6L4u-0007eL-Hb for pgsql-hackers@postgresql.org; Fri, 27 May 2016 16:57:47 +0000 Received: from smtp2h.mail.yandex.net (smtp2h.mail.yandex.net [84.201.187.145]) by forward5h.cmail.yandex.net (Yandex) with ESMTP id 0171E211CF; Fri, 27 May 2016 19:57:35 +0300 (MSK) Received: from smtp2h.mail.yandex.net (localhost [127.0.0.1]) by smtp2h.mail.yandex.net (Yandex) with ESMTP id 845091700364; Fri, 27 May 2016 19:57:35 +0300 (MSK) Received: by smtp2h.mail.yandex.net (nwsmtp/Yandex) with ESMTPSA id IiISMRYAUL-vYuiEI8v; Fri, 27 May 2016 19:57:34 +0300 (using TLSv1 with cipher ECDHE-RSA-AES128-SHA (128/128 bits)) (Client certificate not present) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=simply.name; s=mail; t=1464368254; bh=jYIFULIBGB7Ev56SHh8E+cbciDANBaeDK5YjG/V5w0I=; h=From:Content-Type:Message-Id:Mime-Version:Subject:Date:References: To:In-Reply-To:X-Mailer; b=3cw4XfIW24IFUbtslMsmMn9kAQvmosEGipjlklLo0QvZ/YlignhATDgcTLWy5Mr8v tWw6n6OUYD2dPQi1BfcwkRIrP/SfR/jX5ePOROFFztEsS4JolAn9PFvxnTSCNFBm1J YBSyV+vZx5JxW/nhSEw+1XWRarvEu7hO0AN0N2Gs= Authentication-Results: smtp2h.mail.yandex.net; dkim=pass header.i=@simply.name X-Yandex-Suid-Status: 1 0,1 0 From: Vladimir Borodin Content-Type: multipart/alternative; boundary="Apple-Mail=_9A9BD984-83C5-4516-A32B-3C0151CC2B73" Message-Id: <910CBF45-90EB-44D6-9640-22638C2F26F7@simply.name> 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 Date: Fri, 27 May 2016 19:57:34 +0300 References: <26239E39-A838-4611-B7BA-0E96D2DF3253@simply.name> To: PostgreSQL-development , pgbouncer-general@lists.pgfoundry.org In-Reply-To: <26239E39-A838-4611-B7BA-0E96D2DF3253@simply.name> X-Mailer: Apple Mail (2.3124) X-Pg-Spam-Score: -2.7 (--) 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=_9A9BD984-83C5-4516-A32B-3C0151CC2B73 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 -performance +hackers > 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 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. >=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 -- May the force be with you=E2=80=A6 https://simply.name --Apple-Mail=_9A9BD984-83C5-4516-A32B-3C0151CC2B73 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 -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=99t 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.


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
https://simply.name



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

= --Apple-Mail=_9A9BD984-83C5-4516-A32B-3C0151CC2B73--