Skip to content

Supabase Realtime Subscript Fails With Undefined Error (Possibly: Auth error: tenant 'realtime-dev' not found #746

Closed
Closed
Supabase Realtime Subscript Fails With Undefined Error (Possibly: Auth error: tenant 'realtime-dev' not found#746
Labels
bugSomething isn't working
@ghost

Description

@ghost
ghost
opened on Nov 20, 2023

Bug report

  • I confirm this is a bug with Supabase, not with my own application.
  • I confirm I have searched the Docs, GitHub Discussions, and Discord.

Describe the bug

On the latest Supabase CLI (1.112.0) with the latest Supabase.js (2.38.4) (albeit, which is not using the latest realtime, since the latest CLI is only using public.ecr.aws/supabase/realtime:v2.25.27, but a PR is already there to bump this) when attempting to create a realtime subscription, I get the following error:

Screenshot 2023-11-19 at 7 14 18 PM

Sample Code

// note: subscriptionID is just a random, `v4()` from the `uuid` npm package
const subscription = supabase
        .channel(subscriptionID)
        .on("postgres_changes", {
            event: "*",
            schema: "public",
            table: "users",
            filter: `id=eq.${user.id}`,
          },
          async () => await realtimeCallback())
        .subscribe((status, err) => handleLog({
          status, err
        }));

Detailed Logs

Subscription Error Logs

These logs appear as soon as I attempt to create a realtime subscription (omitting the startup logs in the next section):

2023-11-19 19:12:12 00:12:12.851 [warning] Replica region not found, defaulting to Realtime.Repo
2023-11-19 19:12:12 00:12:12.854 [debug] QUERY OK source="tenants" db=0.7ms queue=1.1ms idle=1308.1ms
2023-11-19 19:12:12 SELECT t0."id", t0."name", t0."external_id", t0."jwt_secret", t0."postgres_cdc_default", t0."max_concurrent_users", t0."max_events_per_second", t0."max_bytes_per_second", t0."max_channels_per_client", t0."max_joins_per_second", t0."suspend", t0."inserted_at", t0."updated_at" FROM "tenants" AS t0 WHERE (t0."external_id" = $1) ["realtime-dev"]
2023-11-19 19:12:12 00:12:12.854 project=realtime-dev external_id=realtime-dev [error] Auth error: tenant `realtime-dev` not found
2023-11-19 19:12:13 00:12:13.862 project=realtime-dev external_id=realtime-dev [error] Auth error: tenant `realtime-dev` not found
2023-11-19 19:12:14 00:12:14.871 project=realtime-dev external_id=realtime-dev [error] Auth error: tenant `realtime-dev` not found
2023-11-19 19:12:15 00:12:15.883 project=realtime-dev external_id=realtime-dev [error] Auth error: tenant `realtime-dev` not found

Start-up Logs

These are the logs before attempting to create a realtime subscription (I'll omit these in the previous section of logs for brevity):

2023-11-19 19:06:31 00:06:31.400 [info] Migrations already up
2023-11-19 19:06:31 00:06:31.951 [debug] QUERY OK db=1.5ms queue=120.6ms idle=0.0ms
2023-11-19 19:06:31 begin []
2023-11-19 19:06:31 00:06:31.987 [debug] QUERY OK source="tenants" db=8.0ms
2023-11-19 19:06:31 SELECT t0."id", t0."name", t0."external_id", t0."jwt_secret", t0."postgres_cdc_default", t0."max_concurrent_users", t0."max_events_per_second", t0."max_bytes_per_second", t0."max_channels_per_client", t0."max_joins_per_second", t0."suspend", t0."inserted_at", t0."updated_at" FROM "tenants" AS t0 WHERE (t0."external_id" = $1) ["realtime-dev-tenant"]
2023-11-19 19:06:32 00:06:32.009 [debug] QUERY OK source="extensions" db=0.9ms
2023-11-19 19:06:32 DELETE FROM "extensions" AS e0 WHERE (e0."tenant_external_id" = $1) ["realtime-dev-tenant"]
2023-11-19 19:06:32 00:06:32.011 [debug] QUERY OK db=0.4ms
2023-11-19 19:06:32 DELETE FROM "tenants" WHERE "id" = $1 [<<54, 209, 49, 175, 43, 250, 64, 46, 133, 27, 16, 111, 45, 177, 27, 149>>]
2023-11-19 19:06:32 00:06:32.025 [debug] QUERY OK db=0.2ms
2023-11-19 19:06:32 INSERT INTO "tenants" ("external_id","jwt_secret","max_bytes_per_second","max_channels_per_client","max_concurrent_users","max_events_per_second","max_joins_per_second","name","suspend","inserted_at","updated_at","id") VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12) ["realtime-dev-tenant", "iNjicxc4+llvc9wovDvqymwfnj9teWMlyOIbJ8Fh6j2WNU8CIJ2ZgjR6MUIKqSmeDmvpsKLsZ9jgXJmQPpwL8w==", 100000, 100, 200, 100, 100, "realtime-dev-tenant", false, ~N[2023-11-20 00:06:32], ~N[2023-11-20 00:06:32], <<67, 92, 208, 132, 244, 191, 64, 183, 156, 75, 126, 149, 221, 211, 255, 167>>]
2023-11-19 19:06:32 00:06:32.031 [debug] QUERY OK db=4.7ms
2023-11-19 19:06:32 INSERT INTO "extensions" ("settings","tenant_external_id","type","inserted_at","updated_at","id") VALUES ($1,$2,$3,$4,$5,$6) [%{"db_host" => "WduM1JTp+Ah9s/HVBIpbqg==", "db_name" => "sWBpZNdjggEPTQVlI52Zfw==", "db_password" => "sWBpZNdjggEPTQVlI52Zfw==", "db_port" => "+enMDFi1J/3IrrquHHwUmA==", "db_user" => "sWBpZNdjggEPTQVlI52Zfw==", "ip_version" => 4, "poll_interval_ms" => 100, "poll_max_changes" => 100, "poll_max_record_bytes" => 1048576, "publication" => "supabase_realtime", "region" => "us-east-1", "slot_name" => "supabase_realtime_replication_slot"}, "realtime-dev-tenant", "postgres_cdc_rls", ~N[2023-11-20 00:06:32], ~N[2023-11-20 00:06:32], <<144, 72, 61, 67, 242, 123, 67, 26, 155, 233, 101, 224, 169, 201, 135, 109>>]
2023-11-19 19:06:32 00:06:32.031 [debug] QUERY OK db=0.7ms
2023-11-19 19:06:32 commit []
2023-11-19 19:06:32 00:06:32.032 [debug] QUERY OK db=0.1ms idle=87.5ms
2023-11-19 19:06:32 begin []
2023-11-19 19:06:32 00:06:32.034 [debug] QUERY OK db=1.9ms
2023-11-19 19:06:32 drop publication if exists supabase_realtime []
2023-11-19 19:06:32 00:06:32.035 [debug] QUERY OK db=0.8ms
2023-11-19 19:06:32 drop table if exists public.test_tenant; []
2023-11-19 19:06:32 00:06:32.044 [debug] QUERY OK db=8.0ms
2023-11-19 19:06:32 create table public.test_tenant (
2023-11-19 19:06:32         id SERIAL PRIMARY KEY,
2023-11-19 19:06:32         details text
2023-11-19 19:06:32         ); []
2023-11-19 19:06:32 00:06:32.044 [debug] QUERY OK db=0.1ms
2023-11-19 19:06:32 grant all on table public.test_tenant to anon; []
2023-11-19 19:06:32 00:06:32.044 [debug] QUERY OK db=0.0ms
2023-11-19 19:06:32 grant all on table public.test_tenant to postgres; []
2023-11-19 19:06:32 00:06:32.044 [debug] QUERY OK db=0.0ms
2023-11-19 19:06:32 grant all on table public.test_tenant to authenticated; []
2023-11-19 19:06:32 00:06:32.044 [debug] QUERY OK db=0.1ms
2023-11-19 19:06:32 create publication supabase_realtime for table public.test_tenant []
2023-11-19 19:06:32 00:06:32.046 [debug] QUERY OK db=1.8ms
2023-11-19 19:06:32 commit []
2023-11-19 19:06:33 00:06:33.155 [notice]     :alarm_handler: {:set, {:system_memory_high_watermark, []}}
2023-11-19 19:06:33 00:06:33.199 [info] Elixir.Realtime.SignalHandler is being initialized...
2023-11-19 19:06:33 00:06:33.199 [notice] SYN[realtime@127.0.0.1] Adding node to scope <Elixir.Realtime.Tenants.Connect>
2023-11-19 19:06:33 00:06:33.199 [notice] SYN[realtime@127.0.0.1] Creating tables for scope <Elixir.Realtime.Tenants.Connect>
2023-11-19 19:06:33 00:06:33.199 [notice] SYN[realtime@127.0.0.1|registry<Elixir.Realtime.Tenants.Connect>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.199 [notice] SYN[realtime@127.0.0.1|pg<Elixir.Realtime.Tenants.Connect>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.199 [notice] SYN[realtime@127.0.0.1] Adding node to scope <users>
2023-11-19 19:06:33 00:06:33.200 [notice] SYN[realtime@127.0.0.1] Creating tables for scope <users>
2023-11-19 19:06:33 00:06:33.200 [notice] SYN[realtime@127.0.0.1|registry<users>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.200 [notice] SYN[realtime@127.0.0.1|pg<users>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.200 [notice] SYN[realtime@127.0.0.1] Adding node to scope <Elixir.RegionNodes>
2023-11-19 19:06:33 00:06:33.200 [notice] SYN[realtime@127.0.0.1] Creating tables for scope <Elixir.RegionNodes>
2023-11-19 19:06:33 00:06:33.200 [notice] SYN[realtime@127.0.0.1|registry<Elixir.RegionNodes>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.200 [notice] SYN[realtime@127.0.0.1|pg<Elixir.RegionNodes>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.200 [warning] Replica region not found, defaulting to Realtime.Repo
2023-11-19 19:06:33 00:06:33.213 [info] Running RealtimeWeb.Endpoint with cowboy 2.10.0 at :::4000 (http)
2023-11-19 19:06:33 00:06:33.213 [info] Access RealtimeWeb.Endpoint at http://realtime.fly.dev
2023-11-19 19:06:33 00:06:33.214 [notice] SYN[realtime@127.0.0.1] Adding node to scope <Elixir.PostgresCdcStream>
2023-11-19 19:06:33 00:06:33.214 [notice] SYN[realtime@127.0.0.1] Creating tables for scope <Elixir.PostgresCdcStream>
2023-11-19 19:06:33 00:06:33.214 [notice] SYN[realtime@127.0.0.1|registry<Elixir.PostgresCdcStream>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.214 [notice] SYN[realtime@127.0.0.1|pg<Elixir.PostgresCdcStream>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.217 [notice] SYN[realtime@127.0.0.1] Adding node to scope <Elixir.Extensions.PostgresCdcRls>
2023-11-19 19:06:33 00:06:33.217 [notice] SYN[realtime@127.0.0.1] Creating tables for scope <Elixir.Extensions.PostgresCdcRls>
2023-11-19 19:06:33 00:06:33.217 [notice] SYN[realtime@127.0.0.1|registry<Elixir.Extensions.PostgresCdcRls>] Discovering the cluster
2023-11-19 19:06:33 00:06:33.217 [notice] SYN[realtime@127.0.0.1|pg<Elixir.Extensions.PostgresCdcRls>] Discovering the cluster
2023-11-19 19:06:36 00:06:36.201 [debug] Tzdata polling for update.
2023-11-19 19:06:36 00:06:36.350 [info] tzdata release in place is from a file last modified Fri, 22 Oct 2021 02:20:47 GMT. Release file on server was last modified Tue, 28 Mar 2023 20:25:39 GMT.
2023-11-19 19:06:36 00:06:36.350 [debug] Tzdata downloading new data from https://data.iana.org/time-zones/tzdata-latest.tar.gz
2023-11-19 19:06:36 00:06:36.420 [debug] Tzdata data downloaded. Release version 2023c.
2023-11-19 19:06:36 00:06:36.748 [info] Tzdata has updated the release from 2021e to 2023c
2023-11-19 19:06:36 00:06:36.748 [debug] Tzdata deleting ETS table for version 2021e
2023-11-19 19:06:36 00:06:36.749 [debug] Tzdata deleting ETS table file for version 2021e

To Reproduce

Not entirely sure. We can give temporary repo access to someone at supabase (just don't want it public). Here are the project details:

  • Next.js 14.0.2 (app router, not pages router, but the realtime subscription is created in the browser by prefixing "use client" at the top of the file)
  • React 18

Expected behavior

  • the error that is occuring to output into the callback (just so I can debug without having to file a bug report as early, hopefully saving the Supabase team time and resources)
  • a subscription should occur

Screenshots

See above.

System information

  • OS: macOS 13.3 (22E252)
  • Browser: Chrome Version 119.0.6045.159 (Official Build) (arm64)
  • Version of supabase-js: 2.38.4 (with CLI version 1.112.0)
  • Version of Node.js: 18.17.1

Additional context

As I mention above, I'll happily give the Supabase team access to our repo if you have trouble reproducing, it's not super sensitive, but enough so that I don't want to make the repo public.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions