supabase-kt icon indicating copy to clipboard operation
supabase-kt copied to clipboard

[Bug]: Resubscribe fails when access token is expired

Open sproctor opened this issue 8 months ago • 14 comments

General Info

  • [x] I checked for similar bug report
  • [x] I am using the latest version
  • [x] I checked the troubleshooting page for similar problems

Version(s)

3.0.14

Kotlin Target(s) and their respective versions

JVM 21, Android 15

What happened? (include your code)

Resumed app and immediately started subscriptions. Connected to realtime socket before sessionStatus was updated. RealtimeChannelImpl attempts to join with expired token and gets: Received message without event: RealtimeMessage(topic=realtime:db-changes, event=phx_reply, payload={"status":"error","response":{"reason":"Token has expired 59 seconds ago"}}, ref=null)

val channel = supabase.realtime.channel("db-changes")
try {
  tables.forEach { table ->
      channel.postgresChangeFlow<PostgresAction>(schema = "public") {
        this.table = table
        filter(FilterOperation("account_id", FilterOperator.EQ, accountId))
    }
          .onEach {
              syncTable(table)
          }
          .launchIn(this)
  }
  channel.subscribe(true)
  launch {
      supabase.realtime.status.collectLatest { status ->
          syncAllTables()
      }
  }
  awaitCancellation()
} catch (e: Exception) {
  logger.i(e) { "subscription cancelled" }
  throw e
} finally {
  withContext(NonCancellable) {
      channel.unsubscribe()
      supabase.realtime.removeChannel(channel)
  }
}

Steps To Reproduce (optional)

  1. Get access token
  2. put app in background
  3. Wait until access token expires
  4. Resume app and start subscriptions before access token can be updated

Relevant log output (optional)


sproctor avatar Apr 18 '25 17:04 sproctor

So reading your thread from #892, the problem is that the session is refreshed, but realtime is connecting and subscribing to channels before the new token is saved/used?

jan-tennert avatar Apr 18 '25 17:04 jan-tennert

That's right. The channel gets an error response that is ignored. I made a few attempts at fixing the issue that broke some tests, I'm pasting the one that seems to work. I'm sure you can come up with something better. My idea was to resend the join message after a timeout.

My changes are in RealtimeChannelImpl.subscribe():

    if(blockUntilSubscribed) {
        val retryJob = CoroutineScope(defaultDispatcher).launch {
            delay(7.seconds)
            Realtime.logger.i { "Timed out waiting for channel join response. Resending request." }
            realtimeImpl.send(
                RealtimeMessage(topic, RealtimeChannel.CHANNEL_EVENT_JOIN, joinConfigObject, null)
            )
        }
        status.first { it == RealtimeChannel.Status.SUBSCRIBED }
        retryJob.cancel()
    }

This doesn't handle the case if blockUntilSubscribed is false. Maybe just launch something that does the check asynchronously there.

sproctor avatar Apr 18 '25 17:04 sproctor

It might make more sense to check if the access token is valid and wait for a new access token.

I could just timeout the subscribe method myself. that actually might make the most sense.

sproctor avatar Apr 18 '25 18:04 sproctor

What I'm wondering is, why there is even an expired token. The Auth plugin has some special logic for Android, if AuthConfig#enableLifecycleCallbacks is enabled, the Auth plugin sets the SessionStatus to Initializing when the app goes into background, so that the application doesn't mistakenly use an expired token after it comes back again. If that were the case you could just put supabase.auth.awaitInitialization() before your realtime code, which waits for Auth to update the status to Authenticated with a confirmed valid token. (Or any other status, but no Authenticated with an expired token). Also did you try printing the sessionStatus directly before connecting?

jan-tennert avatar Apr 18 '25 18:04 jan-tennert

I am printing sessionStatus as it changes, and it's Initializing at that point. It looks like Realtime has a cached access token that isn't cleared when the device goes to sleep and it's using that on reconnect. I'll add an awaitInitialization, I also added a timeout to subscribe to retry after a certain amount of time.

sproctor avatar Apr 18 '25 19:04 sproctor

t looks like Realtime has a cached access token that isn't cleared when the device goes to sleep and it's using that on reconnect.

Oh yea, forgot that I added a caching mechanism recently https://github.com/supabase-community/supabase-kt/blob/4fd0c66812f55c6d093282a64cea615e3a35e8ff/Realtime/src/commonMain/kotlin/io/github/jan/supabase/realtime/RealtimeChannelImpl.kt#L50 Maybe I'll revisit that.

Using awaitInitialization() will probably be the way to go

jan-tennert avatar Apr 18 '25 19:04 jan-tennert

#907 and this could both be resolved by reconnecting on access token errors. Adding awaitInitialization() before the subscribe seems to have fixed this issue, but then I hit #907 once. I added some more debug messages to my app and I hope to have a clearer picture of what's happening there later this week.

sproctor avatar Apr 21 '25 14:04 sproctor

Yea, but #907 isn't inherently a realtime issue, the issue in #907 is that the application is trying to use Supabase in the background, which is by default disabled, and token refreshes are only done when the app is in the foreground (and there is no reason to do otherwise if your app hasn't any background features). If you disable that via enableLifecycleCallbacks = false, the auto refresh mechanism is still in place but it seems like something is happening to the coroutine scope after going to the background, which causes the token to expire. Hard to pin point the problem without logs, but I'll try to look into it.

We can also look into adding token expiration as a reason for rejoining channels, but it shouldn't even come to that.

jan-tennert avatar Apr 21 '25 15:04 jan-tennert

My listener on the sessionStatus was accidentally disabled when I hit a bug similar to #907. I don't have lifecycle callbacks disabled. Maybe I hit a completely different bug.

I added a 10 second timeout around .subscribe(). That got triggered this morning without any error message. I'm enabling sending of debug level logs to see if I can get to the root of that.

sproctor avatar Apr 21 '25 15:04 sproctor

https://github.com/supabase-community/supabase-kt/blob/4fd0c66812f55c6d093282a64cea615e3a35e8ff/Auth/src/commonMain/kotlin/io/github/jan/supabase/auth/AuthImpl.kt#L426

This should use the adjusted refresh time.

It would be nice if token expiry issues in channels could set Realtime to reconnect. I think that would fix my issues.

sproctor avatar Apr 25 '25 11:04 sproctor

This should use the adjusted refresh time.

Sure, that we can change

It would be nice if token expiry issues in channels could set Realtime to reconnect. I think that would fix my issues.

@grdsdev how do the other libs handle this? If the client gets a token expiry error in realtime, do they try to rejoin the channels?

jan-tennert avatar Apr 25 '25 11:04 jan-tennert

Hi @jan-tennert the JS lib does rejoin in case of channel error.

Check in: https://github.com/supabase/realtime-js/blob/master/src/RealtimeChannel.ts#L191

On error, it schedules a rejoin.

grdsdev avatar May 02 '25 08:05 grdsdev

It's been a few months of usage here. I've added the awaitInitialization, but I'm still occasionally getting hangs while subscribing. Unfortunately, I haven't found a way to consistently reproduce it. I've mitigated this with a timeout/retry function. It seems like the client isn't handling the the subscription error leading to this hang.

sproctor avatar Sep 18 '25 12:09 sproctor

I'm going to extend the rejoining mechanism in 3.2.4, let me know if that changes anything

jan-tennert avatar Sep 19 '25 08:09 jan-tennert