Re: [PERFORM] Slow execution of SET ROLE, SET search_path and RESET ROLE - Mailing list pgsql-performance

From Ulf Lohbrügge
Subject Re: [PERFORM] Slow execution of SET ROLE, SET search_path and RESET ROLE
Date
Msg-id CABZYQR+GE7mV7qiTFGO3EqxdqV_TmSQyzY3ghSE1OfHabZcG7g@mail.gmail.com
Whole thread Raw
In response to Re: [PERFORM] Slow execution of SET ROLE, SET search_path and RESETROLE  (Andres Freund <andres@anarazel.de>)
List pgsql-performance
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ü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

pgsql-performance by date:

Previous
From: Andres Freund
Date:
Subject: Re: [PERFORM] Slow execution of SET ROLE, SET search_path and RESETROLE
Next
From: Andres Freund
Date:
Subject: Re: [PERFORM] Slow execution of SET ROLE, SET search_path and RESETROLE