Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1eCBNQ-0006xs-0f for pgsql-performance@arkaria.postgresql.org; Tue, 07 Nov 2017 21:25:44 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84_2) (envelope-from ) id 1eCBNP-0002Z6-BP for pgsql-performance@arkaria.postgresql.org; Tue, 07 Nov 2017 21:25:43 +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 1eCBNO-0002Yw-N3 for pgsql-performance@postgresql.org; Tue, 07 Nov 2017 21:25:42 +0000 Received: from mail-lf0-x22b.google.com ([2a00:1450:4010:c07::22b]) by makus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.84_2) (envelope-from ) id 1eCBNL-0005Bq-GZ for pgsql-performance@postgresql.org; Tue, 07 Nov 2017 21:25:41 +0000 Received: by mail-lf0-x22b.google.com with SMTP id g70so728851lfl.3 for ; Tue, 07 Nov 2017 13:25:39 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:in-reply-to:references:from:date:message-id:subject:to :cc; bh=zyf5Qx1jg/Lz2U77lezRWCwjNogAQB3AtJV3uryIh1Y=; b=G5XWzY2G8Dh+9WVNCjHb+8NzeWX1wm9LK+5prNk05x0rJeIjCYTlIybaniS8OHSHtK G5PpCqhiT5mD5/vwmnfnYvEdWhJGKRW3RDhFCyhro6eBWCL7vQB7jdftRkFsKeVkHRg2 6sTLGggG2aWTIxo9e8K6jeQg60sACvHctT7oR4u9uVdhIjN1l0rvlfoFdZG1n3h6mAFu omQ6rxYUQLadRFuPeOYISpdXMfo8mbN3e9XFcofxXaVgPe7Z4UevBQjGJGifuFQTvYTx 0X/HWSsumUhVWH3/d6HWFtZxQmWxfWwiVVQzrgDmg6TO0e8cgxYP1k00eKC0PPxrOhzZ 4mFg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to:cc; bh=zyf5Qx1jg/Lz2U77lezRWCwjNogAQB3AtJV3uryIh1Y=; b=eJHLuOGXjIEaHZVxFfo4Au0Z/7t80po0V2m43/HcJgmT2lfdaVmvAVyY+j+/f1rr/3 Hady9yJQIhZiOa7AMX7EFpIQU1hUBJMpKd8QEJ9L9suqxbRPhVbkAeNZOUqN9cF8N7c3 gspH/HZPu8wygVHeh2wJsOS3MzBYq4MIxlZpePxp5d38rFeZ57PjeT7mz4GZgWoM2dFh Vd+tbfdyf2xjHnlafzE9szZf9S0CizlnTjkG3cDxAgrTaciniuISWwFqxn3HLdGtJGac MYN7bXOaR1W1doTZtQk1zTNvQoRKLjV186mXa2Hy+BqIqkBTAfFq4vZ8rvGs48v5P3bl qgTA== X-Gm-Message-State: AJaThX4GRF4orUsLJQLwpy/yxXz1cAE3AXnqMDA2L6Ie1IIlS6hkayi1 GacfBjeS+I3JCbM2cnSh0PvcCZhtUzaKUVdHxmo= X-Google-Smtp-Source: AGs4zMZRMz0SfHefMOJgzW1m+2ZLJWZcoplNy5AsezA676sIGthjZeZ4O8o32Joxy8W78F06eZ6XbN6Sn/Z6n2VTELc= X-Received: by 10.25.44.139 with SMTP id s133mr43124lfs.122.1510089937366; Tue, 07 Nov 2017 13:25:37 -0800 (PST) MIME-Version: 1.0 Received: by 10.25.74.202 with HTTP; Tue, 7 Nov 2017 13:25:36 -0800 (PST) In-Reply-To: <20171107194517.pabhi4czbtiasb2f@alap3.anarazel.de> References: <20171107151108.3jtmta4xrgmuyrqf@alap3.anarazel.de> <20171107194517.pabhi4czbtiasb2f@alap3.anarazel.de> From: =?UTF-8?Q?Ulf_Lohbr=C3=BCgge?= Date: Tue, 7 Nov 2017 22:25:36 +0100 Message-ID: Subject: Re: Slow execution of SET ROLE, SET search_path and RESET ROLE To: Andres Freund Cc: pgsql-performance@postgresql.org Content-Type: multipart/alternative; boundary="001a11411a9e4bb66d055d6b3692" List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-performance Precedence: bulk Sender: pgsql-performance-owner@postgresql.org --001a11411a9e4bb66d055d6b3692 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable 2017-11-07 20:45 GMT+01:00 Andres Freund : > On 2017-11-07 18:48:14 +0100, Ulf Lohbr=C3=BCgge wrote: > > Hi, > > > > 2017-11-07 16:11 GMT+01:00 Andres Freund : > > > > > Hi, > > > > > > On 2017-11-07 11:11:36 +0100, Ulf Lohbr=C3=BCgge wrote: > > > > I'm using PostgreSQL 9.5.9 on Debian and experience slow execution = of > > > some > > > > basic SET statements. > > > > > > > > I created about 1600 roles and use that setup for a multi tenancy > > > > application: > > > > > > Hm. How often do you drop/create these roles? How many other > > > roles/groups is one role a member of? > > > > > > > I create between 10-40 roles per day. > > Could you VACUUM (VERBOSE, FREEZE) that table and report the output? Do > you ever delete roles? > Which table do you mean exactly? pg_catalog.pg_authid? Sorry, forgot to write that: I delete about 2-3 roles per day. > > > Can you manually reproduce the problem? What times do you get if you > > > manually run the statement? > > > > > > > Unfortunately not. Every time I manually execute "SET ROLE ..." the > > statement is pretty fast. I created a simple SQL file that contains the > > following statements: > > > > --snip-- > > SET ROLE tenant382; > > SET ROLE tenant1337; > > SET ROLE tenant2; > > -- repeat the lines above 100k times > > --snap-- > > > > When I execute those statements via 'time psql < set-roles.sql', the ca= ll > > lasts 138,7 seconds. So 300k "SET ROLE" statements result in 0,46ms per > > call on average. > > And most of that is going to be roundtrip time. Hm. Could it be that > you're just seeing the delays when pgbouncer establishes new pooling > connections and you're attributing that to SET ROLE in your app? > I stopped using pgbouncer when I solely started using role 'admin' with "SET ROLE" statements. I use a connection pool (HikariCP) that renews connections after 30 minutes. I couldn't find a pattern yet when those slow statements occur. Does using a few thousands roles and schemata in postgres scale well? I only found some theoretical descriptions of multi tenancy setups with postgres while googling. Using tabulator in psql cli is pretty slow, mainly because pg_table_is_visible() is being called for many entries in pg_class. Cheers, Ulf --001a11411a9e4bb66d055d6b3692 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
2017= -11-07 20:45 GMT+01:00 Andres Freund <andres@anarazel.de>:<= br>
On 2017-11-07 18:48:14 +0100, Ulf Lohbr=C3=BCgge wrote:
> Hi,
>
> 2017-11-07 16:11 GMT+01:00 Andres Freund <andres@anarazel.de>:
>
> > Hi,
> >
> > On 2017-11-07 11:11:36 +0100, Ulf Lohbr=C3=BCgge wrote:
> > > I'm using PostgreSQL 9.5.9 on Debian and experience slow= execution of
> > some
> > > basic SET statements.
> > >
> > > I created about 1600 roles and use that setup for a multi te= nancy
> > > application:
> >
> > Hm. How often do you drop/create these roles?=C2=A0 How many othe= r
> > roles/groups is one role a member of?
> >
>
> I create between 10-40 roles per day.

Could you VACUUM (VERBOSE, FREEZE) that table and report the output?= =C2=A0 Do
you ever delete roles?
<= br>
Which table do you mean exactly?=C2=A0pg_catalog.pg_authid?

Sorry, forgot to write that: I delete about 2-3 rol= es per day.
=C2=A0
> > Can you manually reproduce the problem? What times do you get if = you
> > manually run the statement?
> >
>
> Unfortunately not. Every time I manually execute "SET ROLE ...&qu= ot; the
> statement is pretty fast. I created a simple SQL file that contains th= e
> following statements:
>
> --snip--
> SET ROLE tenant382;
> SET ROLE tenant1337;
> SET ROLE tenant2;
> -- repeat the lines above 100k times
> --snap--
>
> When I execute those statements via 'time psql < set-roles.sql&= #39;, the call
> lasts 138,7 seconds. So 300k "SET ROLE" statements result in= 0,46ms per
> call on average.

And most of that is going to be roundtrip time. Hm. Could it be that=
you're just seeing the delays when pgbouncer establishes new pooling connections and you're attributing that to SET ROLE in your app?

I stopped using pgbouncer when I solely start= ed using role 'admin' with "SET ROLE" statements. I use a= connection pool (HikariCP) that renews connections after 30 minutes. I cou= ldn't find a pattern yet when those slow statements occur.
Does using a few thousands roles and schemata in postgres scal= e well? I only found some theoretical descriptions of multi tenancy setups = with postgres while googling.
Using tabulator in psql cli is pret= ty slow, mainly because=C2=A0pg_table_is_visible() is being called for many= entries in pg_class.

Cheers,
Ulf
<= /div>
--001a11411a9e4bb66d055d6b3692--