Slow performance with auth.uid() and RPCs #8733

nthouliss · 2022-08-31T02:21:51Z

nthouliss
Aug 31, 2022

Hi all,

I had a few questions around the auth.uid() helper provided by Supabase, what exactly does it do and what is the best way to test queries that are using it? The reason that I’m asking these questions is because we had to make some RPCs to implement some changes to our application, this change also resulted in increased Postgres API requests from our application (which was intended). Everything was working well in our stage environment so we rolled to production. On our production database, CPU utilisation rose to 99% at peak time, even with a XL database add-on. We only have about 10,000 users total and maybe only 300 on at peak time.

First we investigated our RPC queries using pgMustard which was really useful for optimising with indexing but RPC query times were still slow and CPU utilisation still high.

We spent most of the day adding indexes where we could, however our network request response times when using RPCs were still tremendously high (all other Postgrest requests from the Supabase client were performing well) even once CPU had freed up and was around 30%.

For example when using the following RPC:

create or replace function total_storage_rpc() 
returns int
language plpgsql
as $$
begin
return (select
  (select sum((metadata ->> 'size')::int) as size
  from storage.objects bucket
  where bucket.owner = auth.uid()
  and bucket.bucket_id = 'user-assets'));
end;

The network delay waiting for the server response was 10.24 seconds:

It was a tremendous delay for a query that was not very complicated, and if our RLS queries has been contributing to this time then we’d expect to see this delay on all our queries not just those using RPCs.

However, when we were testing our queries with explain analyze and putting them into pgMustard, we’d mostly been replacing the auth.uid() helper method, since there wasn’t any guidance that we could find about performance testing with this helper. We figured that we could re-write the query and see it’s impact in performance first in stage and then in production.

We added a variable to the RPC and then set it as the auth.uid() helper. This is what we changed the RPC to:

create or replace function total_storage_rpc()
returns int
language plpgsql
as $$
declare asset_owner uuid := auth.uid();
begin
return (select
 (select sum((metadata ->> 'size')::int) as size
 from storage.objects bucket
 where bucket.owner = asset_owner
 and bucket.bucket_id = 'user-assets'));
end;

First we tested in stage to be sure it worked and there was a very small improvement on network time, but it worked so we rolled it to production.

The network delay when waiting for server response reduced significantly from 10.24 seconds to 381.39 milliseconds:

With this performance improvement we decided to declare the auth.uid() helper into a variable for all out RPCs and saw significant improvements for all of them.

One RPC saw a reduction from 59 seconds to 251.28 milliseconds and another RPC decreased from 10.04 seconds to 555.98 milliseconds. After these improvements our CPU utilisation also decreased and now at peak times is around 30% and at its lowest is 7%, whereas before our lowest utilisation average was 30% and maxing out to 99%.

Why is the auth.uid() helper method slow when used in RPCs and is this documented anywhere?

I was hoping as well that there could be a guide around using explain analyze with Supabase helper methods, this would have really helped with finding this issue and would be really useful for everyday use, even with regular queries.

If it were possible it would be really useful to be able to trace requests through the system to know where they are being bogged down. This way it would be better to know where things are being held up in live traffic.

Are there any resources that could be recommended to better enhance performance and observability on Supabase?

steve-chavez · 2022-08-31T22:05:43Z

steve-chavez
Aug 31, 2022
Maintainer

From a glance, in the first version of your function the auth.uid is being called for every row while in the second version the auth.uid value is cached in your variable - only called once.

Could you share the EXPLAIN execution plans of both versions?

auth.uid() is defined here.

create or replace function auth.uid() 
returns uuid 
language sql stable
as $$
  select 
  	coalesce(
		nullif(current_setting('request.jwt.claim.sub', true), ''),
		(nullif(current_setting('request.jwt.claims', true), '')::jsonb ->> 'sub')
	)::uuid
$$;

5 replies

nthouliss Sep 1, 2022
Author

From a glance, in the first version of your function the auth.uid is being called for every row while in the second version the auth.uid value is cached in your variable - only called once.

Does this have implications that we should be aware of? We use auth.uid() in where clauses in our RLS policies and they don't seem to have this performance issue whereas on RPCs it's quite a difference (granted I'm not sure how to test for this on RLS, I only have what I've observed on the network). Sorry if this is an obvious answer, but I think I need further clarification.

I went back to pgMustard to grab the results from my explain analyze statements and the history seems to have cleared. I'll reach out to pgMustard about it but I did re-do the explain analyze between the two functions. I'll clarify as well that we haven't touched the storage.object table at all from the defaults that Supabase has set.

The old function (no declare statement):

[{"Plan":{"Node Type":"Result","Parallel Aware":false,"Async Capable":false,"Startup Cost":0,"Total Cost":0.26,"Plan Rows":1,"Plan Width":4,"Actual Startup Time":348.764,"Actual Total Time":348.765,"Actual Rows":1,"Actual Loops":1,"Output":["total_storage_rpc()"],"Shared Hit Blocks":13908,"Shared Read Blocks":0,"Shared Dirtied Blocks":0,"Shared Written Blocks":0,"Local Hit Blocks":0,"Local Read Blocks":0,"Local Dirtied Blocks":0,"Local Written Blocks":0,"Temp Read Blocks":0,"Temp Written Blocks":0},"Query Identifier":3096056772487703000,"Planning":{"Shared Hit Blocks":0,"Shared Read Blocks":0,"Shared Dirtied Blocks":0,"Shared Written Blocks":0,"Local Hit Blocks":0,"Local Read Blocks":0,"Local Dirtied Blocks":0,"Local Written Blocks":0,"Temp Read Blocks":0,"Temp Written Blocks":0},"Planning Time":0.113,"Triggers":[],"Execution Time":349.056}]

The new function (declare statement):

[{"Plan":{"Node Type":"Result","Parallel Aware":false,"Async Capable":false,"Startup Cost":0,"Total Cost":0.26,"Plan Rows":1,"Plan Width":4,"Actual Startup Time":3.219,"Actual Total Time":3.22,"Actual Rows":1,"Actual Loops":1,"Output":["total_storage_rpc()"],"Shared Hit Blocks":279,"Shared Read Blocks":0,"Shared Dirtied Blocks":0,"Shared Written Blocks":0,"Local Hit Blocks":0,"Local Read Blocks":0,"Local Dirtied Blocks":0,"Local Written Blocks":0,"Temp Read Blocks":0,"Temp Written Blocks":0},"Query Identifier":3096056772487703000,"Planning":{"Shared Hit Blocks":0,"Shared Read Blocks":0,"Shared Dirtied Blocks":0,"Shared Written Blocks":0,"Local Hit Blocks":0,"Local Read Blocks":0,"Local Dirtied Blocks":0,"Local Written Blocks":0,"Temp Read Blocks":0,"Temp Written Blocks":0},"Planning Time":0.113,"Triggers":[],"Execution Time":3.525}]

These were both run using explain analyze like this in the SQL Editor:

explain (analyze, buffers, verbose, format json)
select total_storage_rpc();

I was mostly reaching out on the discussions page to provide some feedback on what would have made this endevour easier for us, such as a guide for performance testing helper statements like auth.uid() (still not sure if we're doing this right in the SQL editor), better tracing, and more resources or recommendations on performance improvements with Supabase or Postgres (even from external sources).

There's a lot to find on the internet but it's hard to know if some practices are outdated, no longer recommended, or just bad practice and having Supabase guides/recommendations is more reassuring.

steve-chavez Sep 1, 2022
Maintainer

We use auth.uid() in where clauses in our RLS policies and they don't seem to have this performance issue whereas on RPCs it's quite a difference

Likely has to do with the postgres planner optimizing regular SQL queries while it couldn't do the same for the total_storage_rpc PLPGSQL function. But I don't have the full info at this point to determine this.

Do you have RLS policies defined in storage.objects? Could you share those?

Note that if you already have an RLS policy filtering on bucket.owner = auth.uid(), the query in the function would already include this conditional implicitly(since the function is SECURITY INVOKER by default).

nthouliss Sep 7, 2022
Author

Likely has to do with the postgres planner optimizing regular SQL queries while it couldn't do the same for the total_storage_rpc PLPGSQL function. But I don't have the full info at this point to determine this.

Should I be writing these RPCs in SQL function instead?

Do you have RLS policies defined in storage.objects? Could you share those?

I do have some RLS policies on storage.objects. I just shared the total_storage_rpc because I knew that it could be easily replicated against other Supabase projects. I think it might be a bit of a red-herring to go along the RLS policy path because these improvements were seen on RPCs that queried other tables. Is there any particular reason for needed to share the RLS policies, or what to look out for?

The policies are mostly restrictive, they prevent users with certain email domain from making modifying changes in the table and another restrictive policy uses that RPC to check that they are within their subscription limits for storage. The only other one gives the folder owner access rights.

If there's someway of running a test or explain analyze, I'm happy to pass on that data

steve-chavez Sep 7, 2022
Maintainer

Should I be writing these RPCs in SQL function instead?

You should prefer SQL overall since other languages are seen as black boxes for the query planner.

I believe you could have avoided the perf problem if the function was declared like this:

create or replace function total_storage_rpc() 
returns int as $$
select
  (select sum((metadata ->> 'size')::int) as size
  from storage.objects bucket
  where bucket.owner = auth.uid()
  and bucket.bucket_id = 'user-assets')
$$ 
language sql stable;

Notice that I've added stable there, this should allow the query planner to detect that auth.uid can be cached and only ran once. It would be great if you could test this to confirm.

Also note that total_storage_rpc doesn't really need plpgsql. Here you can see a list of reasons to use it, personally I only use plpgsql when I need dynamic SQL.

I was mostly reaching out on the discussions page to provide some feedback on what would have made this endevour easier for us, such as a guide for performance testing helper statements like auth.uid() (still not sure if we're doing this right in the SQL editor), better tracing, and more resources or recommendations on performance improvements with Supabase or Postgres (even from external sources).

Yes, absoultely. I think for now we can add a "best practices for writing functions" doc. I'll pass this feedback to the docs team.

nthouliss Sep 17, 2022
Author

Sorry, I've been very busy of the last couple weeks and haven't had the time to come back to this

Yes, absoultely. I think for now we can add a "best practices for writing functions" doc. I'll pass this feedback to the docs team.

This would be excellent, especially because I think a lot of people coming to Supabase don't necessarily have the experience to know what is considered best practice for functions and they seem to be recommended often.

I did add the SQL language RPC but the result still isn't as fast as using declare in my optimised function, still taking about 481ms to complete, compared to my 3ms.

[{"Plan":{"Node Type":"Result","Parallel Aware":false,"Async Capable":false,"Startup Cost":0,"Total Cost":0.26,"Plan Rows":1,"Plan Width":4,"Actual Startup Time":481.338,"Actual Total Time":481.339,"Actual Rows":1,"Actual Loops":1,"Output":["total_storage_rpc()"],"Shared Hit Blocks":22114,"Shared Read Blocks":0,"Shared Dirtied Blocks":0,"Shared Written Blocks":0,"Local Hit Blocks":0,"Local Read Blocks":0,"Local Dirtied Blocks":0,"Local Written Blocks":0,"Temp Read Blocks":0,"Temp Written Blocks":0},"Query Identifier":3096056772487703000,"Planning":{"Shared Hit Blocks":158,"Shared Read Blocks":0,"Shared Dirtied Blocks":0,"Shared Written Blocks":0,"Local Hit Blocks":0,"Local Read Blocks":0,"Local Dirtied Blocks":0,"Local Written Blocks":0,"Temp Read Blocks":0,"Temp Written Blocks":0},"Planning Time":2.165,"Triggers":[],"Execution Time":481.458}]

steve-chavez · 2023-04-25T20:07:21Z

steve-chavez
Apr 25, 2023
Maintainer

Hello, just circling back to this one.

I've found a solution for the RLS performance issue with auth.uid(). See https://github.com/orgs/supabase/discussions/9311#discussioncomment-5690939.

Basically we cache the auth.uid() value inside the RLS policy. It's similar to the caching you do in your plpgsql function.

1 reply

nthouliss May 1, 2023
Author

Thanks! This is good to know because we also leverage auth.uid() in our RLS queries. A lot of the the time we're querying against indexed columns so I'm not sure we'll see much of an optimisation but it's very useful to know 😄

megacherry · 2023-08-25T20:18:53Z

megacherry
Aug 25, 2023

Hi @steve-chavez ,

we also have problems with high CPU usage in our project.

We use only plpgsql functions with temporary tables in our project.

Do you think this is a big problem? If so, how can we improve the performance?

All our logic is in the database.

Thanks a lot in advance.
Andreas

0 replies

iddogino · 2024-09-25T17:23:59Z

iddogino
Sep 25, 2024

Was this ever solved / did anyone figure a more general solution? I am running into another performance issue with auth.uid() and trying to figure out if it's the same class of issues, or a new one - https://github.com/orgs/supabase/discussions/29518

1 reply

GaryAustin1 Sep 25, 2024
Collaborator

I can't comment on the original op. But for RLS you really need to surround all functions with a select as discussed here: https://supabase.com/docs/guides/database/postgres/row-level-security#call-functions-with-select

Supabase

Slow performance with auth.uid() and RPCs #8733

Uh oh!

nthouliss Aug 31, 2022

Replies: 4 comments · 7 replies

Uh oh!

Uh oh!

steve-chavez Aug 31, 2022 Maintainer

Uh oh!

nthouliss Sep 1, 2022 Author

Uh oh!

Uh oh!

steve-chavez Sep 1, 2022 Maintainer

Uh oh!

nthouliss Sep 7, 2022 Author

Uh oh!

steve-chavez Sep 7, 2022 Maintainer

Uh oh!

nthouliss Sep 17, 2022 Author

Uh oh!

Uh oh!

steve-chavez Apr 25, 2023 Maintainer

Uh oh!

nthouliss May 1, 2023 Author

Uh oh!

megacherry Aug 25, 2023

Uh oh!

iddogino Sep 25, 2024

Uh oh!

GaryAustin1 Sep 25, 2024 Collaborator

nthouliss
Aug 31, 2022

Replies: 4 comments 7 replies

steve-chavez
Aug 31, 2022
Maintainer

nthouliss Sep 1, 2022
Author

steve-chavez Sep 1, 2022
Maintainer

nthouliss Sep 7, 2022
Author

steve-chavez Sep 7, 2022
Maintainer

nthouliss Sep 17, 2022
Author

steve-chavez
Apr 25, 2023
Maintainer

nthouliss May 1, 2023
Author

megacherry
Aug 25, 2023

iddogino
Sep 25, 2024

GaryAustin1 Sep 25, 2024
Collaborator