Re: Slow execution of SET ROLE, SET search_path and RESET ROLE

Hi,

2017-11-07 16:11 GMT+01:00 Andres Freund <andres(at)anarazel(dot)de>:

> Hi,
>
> On 2017-11-07 11:11:36 +0100, Ulf Lohbrügge 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.

The roles tenant1 to tenant1600 are not members of any other roles. Only
the role 'admin' is member of many roles (tenant1 to tenant1600).

>
>
> > My application solely uses the role 'admin' to connect to the database.
> > When performing sql statements for a specific tenant (e.g. tenant1337), a
> > connection with user 'admin' is established and the following commands
> are
> > executed:
> >
> > SET ROLE 1337;
> > SET search_path = tenant1337;
> >
> > Then the application uses that connection to perform various statements
> in
> > the database.
>
> Just to be sure: You realize bad application code could escape from
> that, right?
>

Yes, I do. :)
My application executes all statements via an ORM tool (Hibernate). But
evil code could still get the plain DB-Connection and execute "SET ROLE
..." statements. My application used to connect as tenant1 to tenant1600
but that lead to a vast amount of postgresql connections (even with
pgbouncer).

>
>
> > My application is a web service that approximately executes some hundred
> > statements per second.
> >
> > I set "log_min_duration_statement = 200ms" and I get about 2k to 4k lines
> > per day with statements like "SET ROLE"", "SET search_path ..." and
> "RESET
> > ROLE":
> >
> > --snip--
> > 2017-11-07 09:44:30 CET [27760]: [3-1] user=admin,db=mydb LOG: duration:
> > 901.591 ms execute <unnamed>: SET ROLE "tenant762"
> > 2017-11-07 09:44:30 CET [27659]: [4-1] user=admin,db=mydb LOG: duration:
> > 1803.971 ms execute <unnamed>: SET ROLE "tenant392"
>
> That is weird.
>
>
> > Besides those peaks in statement duration, my application performs (i.e.
> > has acceptable response times) most of the time.
> >
> > Is there anything I can do to improve performance here?
> > Any help is greatly appreciated!
>
> 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 call
lasts 138,7 seconds. So 300k "SET ROLE" statements result in 0,46ms per
call on average.

Cheers,
Ulf