Session gets removed when refresh_token request gets cancelled.

[leoMehlig]

Bug report

We've noticed that in our watchOS app, the user sometimes gets logged out. Looking at the logs, it appears that sometimes the refresh_token request fails with -999 cancelled after which the session gets deleted.

Looking at the code, I think .cancelled should be included in defaultRetryableURLErrorCodes (RetryableError.swift:22), but maybe it was left out on purpose.

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

System information

• OS: watchOS
• Version of supabase-swift: 2.6.1

Additional context

Logs from our QA:

[DEBUG] : [12 Apr 10:30:23.102 +0200] : [4.1.4:1650-beta] : [WatchStructuredApp.runAppRefresh():55] : [Structured] Finished sync with result: fullSync
[DEBUG] : [12 Apr 10:30:23.107 +0200] : [4.1.4:1650-beta] : [WatchStructuredApp.runAppRefresh():56] : [Structured] Reloading widget timelines
[DEBUG] : [12 Apr 10:30:23.116 +0200] : [4.1.4:1650-beta] : [WatchStructuredApp.runAppRefresh():58] : [Structured] Start fetching tasks once
[DEBUG] : [12 Apr 10:30:23.123 +0200] : [4.1.4:1650-beta] : [WatchStructuredApp.runAppRefresh():60] : [Structured] Finished fetching tasks once
[DEBUG] : [12 Apr 10:30:23.127 +0200] : [4.1.4:1650-beta] : [WatchStructuredApp.runAppRefresh():61] : [Structured] Finished app refresh
[DEBUG] : [12 Apr 11:15:00.706 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:15:00Z [debug] [Auth] [Auth/SessionManager.session():45] begin
context: ["client_id": 2]
[DEBUG] : [12 Apr 11:15:01.798 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:15:01Z [debug] [Auth] [Auth/SessionManager.session():55] session expired
context: ["client_id": 2]
[DEBUG] : [12 Apr 11:15:01.807 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:15:01Z [debug] [Auth] [Auth/SessionManager.refreshSession(_:):67] begin
context: ["client_id": 2, "refresh_token": P_mduGsd_p3W6Z3mPGEUXQ, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357]
[DEBUG] : [12 Apr 11:15:01.812 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:15:01Z [debug] [Auth] [Auth/SessionManager.refreshSession(_:):74] Refresh task started
context: ["client_id": 2, "refresh_token": P_mduGsd_p3W6Z3mPGEUXQ, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357]
[INFO] : [12 Apr 11:15:01.817 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:15:01Z [verbose] [Helpers] [Helpers/LoggerInterceptor.intercept(_:next:):25] Request: POST https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token
Body: {
  "refresh_token" : "P_mduGsd_p3W6Z3mPGEUXQ"
}
context: ["requestID": 07DC3883-D2A4-45DD-A4DA-27BC4D6FD604, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357, "refresh_token": P_mduGsd_p3W6Z3mPGEUXQ]
[DEBUG] : [12 Apr 11:18:58.602 +0200] : [4.1.4:1650-beta] : [WatchStructuredApp.runWatchConnectivityUpdate():138] : [Structured] Running Watch connectivty refresh
[ERROR] : [12 Apr 11:18:58.631 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:18:58Z [error] [Helpers] [Helpers/LoggerInterceptor.intercept(_:next:):44] Response: Failure Error Domain=NSURLErrorDomain Code=-999 "cancelled" UserInfo={_NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>, NSLocalizedDescription=cancelled, _kCFStreamErrorCodeKey=89, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>",
    "LocalDataPDTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>",
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>"
), NSErrorFailingURLStringKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token, _kCFStreamErrorDomainKey=1, NSErrorFailingURLKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token}
context: ["refresh_token": P_mduGsd_p3W6Z3mPGEUXQ, "requestID": 07DC3883-D2A4-45DD-A4DA-27BC4D6FD604, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357]
[DEBUG] : [12 Apr 11:18:58.638 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:18:58Z [debug] [Auth] [Auth/SessionManager.refreshSession(_:):101] Refresh token failed with error: Error Domain=NSURLErrorDomain Code=-999 "cancelled" UserInfo={_NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>, NSLocalizedDescription=cancelled, _kCFStreamErrorCodeKey=89, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>",
    "LocalDataPDTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>",
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>"
), NSErrorFailingURLStringKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token, _kCFStreamErrorDomainKey=1, NSErrorFailingURLKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token}
context: ["refresh_token": P_mduGsd_p3W6Z3mPGEUXQ, "client_id": 2, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357]
[DEBUG] : [12 Apr 11:18:58.643 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:18:58Z [debug] [Auth] [Auth/SessionManager.refreshSession(_:):78] Refresh task ended
context: ["refresh_token": P_mduGsd_p3W6Z3mPGEUXQ, "client_id": 2, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357]
[DEBUG] : [12 Apr 11:18:58.646 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:18:58Z [debug] [Auth] [Auth/SessionManager.refreshSession(_:):67] error: Error Domain=NSURLErrorDomain Code=-999 "cancelled" UserInfo={_NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>, NSLocalizedDescription=cancelled, _kCFStreamErrorCodeKey=89, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>",
    "LocalDataPDTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>",
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>"
), NSErrorFailingURLStringKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token, _kCFStreamErrorDomainKey=1, NSErrorFailingURLKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token}
context: ["refresh_token": P_mduGsd_p3W6Z3mPGEUXQ, "client_id": 2, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357]
[DEBUG] : [12 Apr 11:18:58.651 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:18:58Z [debug] [Auth] [Auth/SessionManager.refreshSession(_:):67] end
context: ["refresh_token": P_mduGsd_p3W6Z3mPGEUXQ, "client_id": 2, "refresh_id": DBAD3F2E-26B2-40E0-BA27-3A8BD2A35357]
[DEBUG] : [12 Apr 11:18:58.655 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:18:58Z [debug] [Auth] [Auth/SessionManager.session():45] error: Error Domain=NSURLErrorDomain Code=-999 "cancelled" UserInfo={_NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>, NSLocalizedDescription=cancelled, _kCFStreamErrorCodeKey=89, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<9>",
    "LocalDataPDTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>",
    "LocalDataTask <E3281BD5-53E3-4DF2-AF2B-D6ADD071D8DD>.<1>"
), NSErrorFailingURLStringKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token, _kCFStreamErrorDomainKey=1, NSErrorFailingURLKey=https://<redacted>.supabase.co/auth/v1/token?grant_type=refresh_token}
context: ["client_id": 2]
[DEBUG] : [12 Apr 11:18:58.660 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:18:58Z [debug] [Auth] [Auth/SessionManager.session():45] end
context: ["client_id": 2]
[INFO] : [12 Apr 11:18:58.665 +0200] : [4.1.4:1650-beta] : [SyncManager.handleSyncCancellation():1120] : [StructuredDB] Sync was stopped
[DEBUG] : [12 Apr 11:19:04.045 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:19:04Z [debug] [Auth] [Auth/SessionManager.session():45] begin
context: ["client_id": 2]
[ERROR] : [12 Apr 11:19:04.063 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:19:04Z [error] [Auth] [Auth/SessionStorage.live(clientID:):59] Failed to retrieve session: errSecItemNotFound: The item cannot be found.
[DEBUG] : [12 Apr 11:19:04.069 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:19:04Z [debug] [Auth] [Auth/SessionManager.session():47] session missing
context: ["client_id": 2]
[DEBUG] : [12 Apr 11:19:04.073 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:19:04Z [debug] [Auth] [Auth/SessionManager.session():45] error: sessionMissing
context: ["client_id": 2]
[DEBUG] : [12 Apr 11:19:04.077 +0200] : [4.1.4:1650-beta] : [SyncServer.log():611] : [StructuredDB] 2025-04-12T09:19:04Z [debug] [Auth] [Auth/SessionManager.session():45] end
context: ["client_id": 2]
[ERROR] : [12 Apr 11:19:04.081 +0200] : [4.1.4:1650-beta] : [SyncManager.sync():711] : [StructuredDB] User is not logged in.

[grdsdev]

Hey @leoMehlig thanks for reporting this.

I've added a check for the cancellation error in #712

Ideally I have to better structure this, as there may be other cases where session shouldn't be removed.

[leoMehlig]

Amazing! Thanks a lot @grdsdev.