supabase / cli

Supabase CLI. Manage postgres migrations, run Supabase locally, deploy edge functions. Postgres backups. Generating types from your database schema.
https://supabase.com/docs/reference/cli/about
MIT License
1.07k stars 209 forks source link

Significant Delay in Query Execution with Supabase Locally #2576

Closed tharakadesilva closed 3 months ago

tharakadesilva commented 3 months ago

Describe the bug

When running Supabase locally using the CLI (v1.187.3), there's a significant delay between the actual query execution time and the observed time in the application. For instance, an update query that takes 0.140 ms to execute (according to EXPLAIN ANALYZE) is taking about 72 seconds in the application.

Additional Notes:

To Reproduce Steps to reproduce the behavior:

  1. Set up a local Supabase instance using CLI v1.187.3
  2. Run supabase start
  3. Execute a simple update query in your application
  4. Observe the time taken for the query execution

Expected behavior

The query execution time in the application should be close to the actual execution time reported by EXPLAIN ANALYZE (milliseconds, not seconds).

Screenshots ~If applicable, add screenshots to help explain your problem.~

System information Rerun the failing command with --create-ticket flag.

        SERVICE IMAGE      │      LOCAL       │ LINKED
  ─────────────────────────┼──────────────────┼─────────
    supabase/postgres      │ 15.1.1.61        │ -
    supabase/gotrue        │ v2.151.0         │ -
    postgrest/postgrest    │ v12.2.0          │ -
    supabase/realtime      │ v2.29.15         │ -
    supabase/storage-api   │ v1.0.6           │ -
    supabase/edge-runtime  │ v1.55.0          │ -
    supabase/studio        │ 20240701-05dfbec │ -
    supabase/postgres-meta │ v0.83.2          │ -
    supabase/logflare      │ 1.4.0            │ -
    supabase/supavisor     │ 1.1.56           │ -

Additional context If applicable, add any other context about the problem here.


Code Sample:

const handleSave = useCallback(async () => {
  try {
    const startTime2 = performance.now();
    console.log("Start time (User): ", startTime2);
    const {
      data: { user },
    } = await supabase.auth.getUser();
    const endTime2 = performance.now();
    console.log("End time (User): ", endTime2);
    console.log("Time taken (User): ", endTime2 - startTime2);

    if (!user) {
      console.log("No user found");
      return;
    }

    const startTime = performance.now();
    console.log("Start time: ", startTime);
    const { data, error } = await supabase
      .from("profiles")
      .update({ preferred_name: value.trim() })
      .eq("id", user.id)
      .select();
    const endTime = performance.now();
    console.log("End time: ", endTime);
    console.log("Time taken: ", endTime - startTime);
    console.log(data);
    console.log(error);
  } catch (error) {
    console.log(error);
  }
}, []);

Console Output of Above:

 LOG  Start time (User):  4787866.071666
 LOG  End time (User):  4816994.7515
 LOG  Time taken (User):  29128.679833999835
 LOG  Start time:  4816995.05275
 LOG  End time:  4889937.893708
 LOG  Time taken:  72942.84095800016
 LOG  [{"avatar_url": null, "id": "ed007d8a-c34f-4c66-8199-d919c5b35f69", "preferred_name": "Tharaka De Silva", "updated_at": "2024-07-29T21:35:51.337524+00:00"}]
 LOG  null

EXPLAIN ANALYZE Query:

explain analyze
update profiles
set preferred_name = 'Raka'
where id = 'ed007d8a-c34f-4c66-8199-d919c5b35f69';

Result:

| QUERY PLAN                                                                                                                    |
| ----------------------------------------------------------------------------------------------------------------------------- |
| Update on profiles  (cost=0.15..8.17 rows=0 width=0) (actual time=0.075..0.075 rows=0 loops=1)                                |
|   ->  Index Scan using profiles_pkey on profiles  (cost=0.15..8.17 rows=1 width=38) (actual time=0.007..0.008 rows=1 loops=1) |
|         Index Cond: (id = 'ed007d8a-c34f-4c66-8199-d919c5b35f69'::uuid)                                                       |
| Planning Time: 0.189 ms                                                                                                       |
| Execution Time: 0.140 ms                                                                                                      |
tharakadesilva commented 3 months ago

Sorry folks, this was me not using a useEffect when loading some data and that was causing some stress on the database 😓. Once I fixed my bad code, things are working as expected again.