diff --git a/package.json b/package.json index 386a6506..5b352846 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "impro", - "version": "0.20.106", + "version": "0.20.107", "type": "module", "scripts": { "start": "rm -rf \"${BUILD_DIR:-build}\" && NODE_ENV=development eleventy --serve", diff --git a/src/js/api.js b/src/js/api.js index da182c7d..2578e0bc 100644 --- a/src/js/api.js +++ b/src/js/api.js @@ -7,6 +7,7 @@ import { getCurrentTimestamp, unique, } from "/js/utils.js"; +import { logAuthEvent } from "/js/errorLogs.js"; import { linkToLogin } from "/js/navigation.js"; import { PUBLIC_SERVICE_ENDPOINT_URL, @@ -156,12 +157,18 @@ export class Api { } catch (error) { // Handle token refresh error if ( - error instanceof RefreshTokenError || - error instanceof OauthRefreshTokenError + this.onTokenRefreshError && + (error instanceof RefreshTokenError || + error instanceof OauthRefreshTokenError) ) { console.error("Token refresh error", error); const did = this.isAuthenticated ? (this.session.did ?? null) : null; - await this.onTokenRefreshError?.(did); + logAuthEvent("token-refresh-error", { + did, + request: path, + message: error.message, + }); + await this.onTokenRefreshError(did); window.location.href = linkToLogin(); await new Promise(() => {}); } diff --git a/src/js/app.js b/src/js/app.js index f0b2144c..504677f4 100644 --- a/src/js/app.js +++ b/src/js/app.js @@ -59,6 +59,7 @@ import { ProfileHoverCardService } from "/js/profileHoverCardService.js"; import { InteractionHandlers } from "/js/interactionHandlers.js"; import { hapticsImpactLight } from "/js/haptics.js"; import { isNative } from "/js/utils.js"; +import { getStoredAuthKeys, logAuthEvent } from "/js/errorLogs.js"; import { effect, untrack } from "/js/signals.js"; import { dispatchNativeRefreshEnded } from "/js/nativeRefresh.js"; import { NOTIFICATIONS_PAGE_SIZE } from "/js/config.js"; @@ -104,6 +105,10 @@ export async function main() { await auth.ensureCurrentScopes(); const session = await auth.getSession(); + logAuthEvent("boot", { + did: session?.did ?? null, + storedAuthKeys: getStoredAuthKeys(), + }); const appViewConfig = getAppViewConfig(); function createApi(opts = {}) { diff --git a/src/js/auth.js b/src/js/auth.js index 8e28c6e0..74abb8d4 100644 --- a/src/js/auth.js +++ b/src/js/auth.js @@ -5,6 +5,7 @@ import { InvalidAuthUrlError, } from "/js/oauth.js"; import { isDev, isNative, TimeoutError, withTimeout } from "/js/utils.js"; +import { getStoredAuthKeys, logAuthEvent } from "/js/errorLogs.js"; import { linkToLogin, validateReturnToParam } from "/js/navigation.js"; export class RefreshTokenError extends Error { @@ -115,6 +116,7 @@ export class BasicAuthSession { this.save(); return await this.fetch(url, options); } else { + logAuthEvent("basic-refresh-failed", { status: refreshRes.status }); throw new RefreshTokenError(refreshRes); } } @@ -311,6 +313,7 @@ export class Auth { } logout(did = null) { + logAuthEvent("logout", { did, stack: new Error().stack }); return this.provider.logout(did); } @@ -361,6 +364,7 @@ export class Auth { const accounts = await this.listAccounts(); const current = await this.provider.getSession(); const isCurrent = current?.did === did; + logAuthEvent("remove-account", { did, isCurrent }); if (isCurrent) { const other = accounts.find((account) => account.did !== did); if (other) { @@ -379,6 +383,9 @@ export class Auth { async requireAuth() { const session = await this.provider.getSession(); if (!session) { + logAuthEvent("require-auth-no-session", { + storedAuthKeys: getStoredAuthKeys(), + }); window.location.href = linkToLogin(); return new Promise(() => {}); } @@ -422,6 +429,7 @@ export class Auth { ); if (missing.length === 0) return; console.warn("OAuth scopes are out of date, forcing re-auth:", missing); + logAuthEvent("scopes-out-of-date", { did: session.did, missing }); try { await this.logout(); } catch (error) { @@ -436,6 +444,7 @@ export class Auth { if (!params.has(FORCE_LOGOUT_QUERY_PARAM)) { return; } + logAuthEvent("force-logout-param", {}); try { await this.logout(); } catch (error) { diff --git a/src/js/errorLogs.js b/src/js/errorLogs.js index fd955878..ca9315db 100644 --- a/src/js/errorLogs.js +++ b/src/js/errorLogs.js @@ -129,3 +129,50 @@ export function enableErrorLogs() { showMessage(args.map(formatArg).join(" ")); }; } + +const AUTH_DEBUG_FLAG_KEY = "debug-auth"; +const AUTH_DEBUG_LOG_KEY = "debug-auth-log"; +const AUTH_DEBUG_LOG_MAX_ENTRIES = 200; + +function isAuthDebugEnabled() { + try { + return localStorage.getItem(AUTH_DEBUG_FLAG_KEY) === "true"; + } catch { + return false; + } +} + +export function readAuthDebugLog() { + try { + return JSON.parse(localStorage.getItem(AUTH_DEBUG_LOG_KEY)) ?? []; + } catch { + return []; + } +} + +// Persisted to localStorage because most logout paths redirect, wiping the console. +export function logAuthEvent(event, details) { + if (!isAuthDebugEnabled()) return; + const entry = { + time: new Date().toISOString(), + event, + path: window.location.pathname, + ...details, + }; + console.info("[auth-debug]", entry); + try { + const entries = [...readAuthDebugLog(), entry].slice( + -AUTH_DEBUG_LOG_MAX_ENTRIES, + ); + localStorage.setItem(AUTH_DEBUG_LOG_KEY, JSON.stringify(entries)); + } catch (error) { + console.warn("Failed to persist auth debug log", error); + } +} + +export function getStoredAuthKeys() { + return Object.keys(localStorage).filter( + (key) => + key.startsWith("oauth_") || key === "accessJwt" || key === "refreshJwt", + ); +} diff --git a/src/js/oauth.js b/src/js/oauth.js index 21b83f19..a9b27c85 100644 --- a/src/js/oauth.js +++ b/src/js/oauth.js @@ -1,5 +1,6 @@ import { HandleNotFoundError } from "/js/atproto.js"; import { KVIndexedDB } from "/js/utils.js"; +import { logAuthEvent } from "/js/errorLogs.js"; export { HandleNotFoundError } from "/js/atproto.js"; @@ -400,6 +401,11 @@ export class Session { signal: AbortSignal.timeout(Session.refreshTimeoutMs), }); } catch (error) { + logAuthEvent("oauth-refresh-network-error", { + did: this.sessionData.did, + retryCount, + message: error.message, + }); if (retryCount < maxRetries) { await new Promise((resolve) => setTimeout(resolve, backoffMs)); return await this.refreshToken({ retryCount: retryCount + 1 }); @@ -409,6 +415,14 @@ export class Session { } if (!response.ok) { + logAuthEvent("oauth-refresh-failed", { + did: this.sessionData.did, + retryCount, + status: response.status, + error: response.data?.error ?? null, + errorDescription: response.data?.error_description ?? null, + expiresAt: new Date(this.sessionData.expiresAt).toISOString(), + }); if (response.status >= 500) { if (retryCount < maxRetries) { await new Promise((resolve) => setTimeout(resolve, backoffMs)); @@ -421,12 +435,18 @@ export class Session { } // invalid_grant can mean another tab rotated the refresh token, so re-check storage and adopt if so if (response.status === 400 && response.data?.error === "invalid_grant") { - if (this.adoptRotatedSession(usedRefreshToken)) return; + if (this.adoptRotatedSession(usedRefreshToken)) { + logAuthEvent("oauth-refresh-adopted-rotated", { attempt: 1 }); + return; + } // attempt twice with delay await new Promise((resolve) => setTimeout(resolve, Session.concurrentRefreshRecoveryMs), ); - if (this.adoptRotatedSession(usedRefreshToken)) return; + if (this.adoptRotatedSession(usedRefreshToken)) { + logAuthEvent("oauth-refresh-adopted-rotated", { attempt: 2 }); + return; + } } const body = response.data ? JSON.stringify(response.data) @@ -788,6 +808,7 @@ export class OauthClient { async revoke(did = null) { const targetDid = did ?? localStorage.getItem(CURRENT_DID_KEY); + logAuthEvent("oauth-revoke", { did: targetDid }); if (!targetDid) return; await this._sendRevokeRequest(targetDid); localStorage.removeItem(SESSION_KEY_PREFIX + targetDid); diff --git a/src/js/push/pushNotificationService.js b/src/js/push/pushNotificationService.js index 23503505..37c2f369 100644 --- a/src/js/push/pushNotificationService.js +++ b/src/js/push/pushNotificationService.js @@ -258,9 +258,7 @@ export class PushNotificationService { async _apiForAccount(did) { const session = await this.auth.getSession(did); - return session - ? new Api(session, { onLogout: (did) => this.auth.logout(did) }) - : null; + return session ? new Api(session) : null; } async unregisterAccount(did) { diff --git a/src/js/views/settings.view.js b/src/js/views/settings.view.js index 73ca8555..aab26146 100644 --- a/src/js/views/settings.view.js +++ b/src/js/views/settings.view.js @@ -13,6 +13,7 @@ import "/js/components/context-menu.js"; import "/js/components/context-menu-item.js"; import { confirmModal } from "/js/modals/confirm.modal.js"; import { showToast } from "/js/toasts.js"; +import { logAuthEvent } from "/js/errorLogs.js"; import { Signal } from "/js/signals.js"; import { avatarPlaceholderTemplate, @@ -347,6 +348,7 @@ export default async function settingsView({ ) { return; } + logAuthEvent("user-sign-out", {}); if (pushNotificationService?.isEnabled) { await pushNotificationService.disable(); } diff --git a/tests/unit/specs/api.test.js b/tests/unit/specs/api.test.js index b96b6145..cdd91405 100644 --- a/tests/unit/specs/api.test.js +++ b/tests/unit/specs/api.test.js @@ -449,6 +449,23 @@ describe("token refresh failure", () => { ); assert.deepEqual(capturedHrefs.at(-1), "/login"); }); + + it("rethrows without redirecting when no handler is provided", async () => { + const capturedHrefs = mockWindowLocation(""); + const refreshError = new TokenRefreshError("refresh failed"); + const session = { + serviceEndpoint: "https://test.example.com", + did: "did:plc:testuser", + handle: "alice.bsky.social", + fetch: async () => { + throw refreshError; + }, + }; + const api = new Api(session); + + await assert.rejects(() => api.request("com.example.method"), refreshError); + assert.deepEqual(capturedHrefs, []); + }); }); describe("service DID in requests", () => { diff --git a/tests/unit/specs/errorLogs.test.js b/tests/unit/specs/errorLogs.test.js index a3836643..48964a59 100644 --- a/tests/unit/specs/errorLogs.test.js +++ b/tests/unit/specs/errorLogs.test.js @@ -1,6 +1,10 @@ -import { describe, it, beforeEach, afterEach } from "node:test"; +import { describe, it, beforeEach, afterEach, mock } from "node:test"; import assert from "node:assert/strict"; -import { enableErrorLogs } from "/js/errorLogs.js"; +import { + enableErrorLogs, + logAuthEvent, + readAuthDebugLog, +} from "/js/errorLogs.js"; describe("errorLogs overlay", () => { const originalWarn = console.warn; @@ -55,3 +59,45 @@ describe("errorLogs overlay", () => { assert.deepEqual(entries()[0].dataset.logLevel, "error"); }); }); + +describe("auth debug log", () => { + beforeEach(() => { + localStorage.clear(); + mock.method(console, "info", () => {}); + }); + + afterEach(() => { + localStorage.clear(); + mock.restoreAll(); + }); + + it("does nothing when the flag is not set", () => { + logAuthEvent("logout", { did: "did:plc:alice" }); + assert.deepEqual(readAuthDebugLog(), []); + }); + + it("persists entries when the flag is set", () => { + localStorage.setItem("debug-auth", "true"); + logAuthEvent("logout", { did: "did:plc:alice" }); + logAuthEvent("boot", { did: null }); + const entries = readAuthDebugLog(); + assert.deepEqual( + entries.map((entry) => [entry.event, entry.did]), + [ + ["logout", "did:plc:alice"], + ["boot", null], + ], + ); + assert(entries[0].time); + }); + + it("caps the number of stored entries", () => { + localStorage.setItem("debug-auth", "true"); + for (let i = 0; i < 205; i++) { + logAuthEvent("event", { index: i }); + } + const entries = readAuthDebugLog(); + assert.equal(entries.length, 200); + assert.equal(entries[0].index, 5); + }); +});