Add detailed logging to auth flow on backend and iOS

backend/src/middleware/auth.ts

@@ -8,8 +8,11 @@ export async function requireAuth(
   res: Response,
   next: NextFunction
 ): Promise<void> {
+  const tag = `[requireAuth] ${req.method} ${req.path}`;
+
   // 1. Session-based auth (web frontend)
   if (req.session?.user) {
+    console.log(`${tag} -> session auth OK (user: ${req.session.user.id})`);
     req.user = req.session.user as AuthenticatedUser;
     return next();
   }
@@ -18,17 +21,24 @@ export async function requireAuth(
   const authHeader = req.headers.authorization;
   if (authHeader?.startsWith('Bearer ')) {
     const token = authHeader.slice(7);
+    console.log(`${tag} -> Bearer token present (first 20 chars: ${token.slice(0, 20)}…)`);
     try {
-      // Verify the backend-signed JWT locally — no IDP network call needed.
       req.user = verifyBackendJwt(token);
+      console.log(`${tag} -> JWT auth OK (user: ${req.user.id})`);
       return next();
     } catch (err) {
       const message = err instanceof Error ? err.message : String(err);
+      console.warn(`${tag} -> JWT verification failed: ${message}`);
       res.status(401).json({ error: `Unauthorized: ${message}` });
       return;
     }
   }
 
+  if (authHeader) {
+    console.warn(`${tag} -> Authorization header present but not a Bearer token: "${authHeader.slice(0, 30)}…"`);
+  } else {
+    console.warn(`${tag} -> No session and no Authorization header`);
+  }
   res.status(401).json({ error: 'Unauthorized' });
 }
 

backend/src/routes/auth.routes.ts

@@ -50,21 +50,24 @@ router.get("/login", async (req, res) => {
     await ensureOIDC();
 
     const redirectUri = req.query.redirect_uri as string | undefined;
+    console.log(`[auth/login] initiated (redirect_uri: ${redirectUri ?? '(web flow)'})`);
     const session = createAuthSession(redirectUri);
 
     if (redirectUri) {
       // Native app flow: store session by state so /auth/token can retrieve it
       // without relying on the browser cookie jar.
       storeNativeSession(session);
+      console.log(`[auth/login] native session stored (state: ${session.state})`);
     } else {
       // Web flow: store session in the cookie-backed server session as before.
       req.session.oidc = session;
     }
 
     const authorizationUrl = getAuthorizationUrl(session, redirectUri);
+    console.log(`[auth/login] redirecting to IDP`);
     res.redirect(authorizationUrl);
   } catch (error) {
-    console.error("Login error:", error);
+    console.error("[auth/login] error:", error);
     res.status(500).json({ error: "Failed to initiate login" });
   }
 });
@@ -129,24 +132,33 @@ router.post("/token", async (req, res) => {
     await ensureOIDC();
 
     const { code, state, redirect_uri } = req.body;
+    console.log(`[auth/token] received (state: ${state}, redirect_uri: ${redirect_uri}, code present: ${!!code})`);
 
     if (!code || !state || !redirect_uri) {
-      res.status(400).json({ error: "Missing required parameters: code, state, redirect_uri" });
+      const missing = ['code', 'state', 'redirect_uri'].filter(k => !req.body[k]);
+      console.warn(`[auth/token] missing parameters: ${missing.join(', ')}`);
+      res.status(400).json({ error: `Missing required parameters: ${missing.join(', ')}` });
       return;
     }
 
     const oidcSession = popNativeSession(state);
     if (!oidcSession) {
+      console.warn(`[auth/token] no session found for state "${state}" — known states: [${[...nativeOidcSessions.keys()].join(', ')}]`);
       res.status(400).json({ error: "OIDC session not found or expired. Initiate login again." });
       return;
     }
+    console.log(`[auth/token] session found, exchanging code with IDP`);
 
     const tokenSet = await exchangeNativeCode(code, oidcSession.codeVerifier, redirect_uri);
+    console.log(`[auth/token] IDP code exchange OK (access_token present: ${!!tokenSet.access_token}, id_token present: ${!!tokenSet.id_token})`);
+
     const user = await getUserInfo(tokenSet);
+    console.log(`[auth/token] user resolved (id: ${user.id}, email: ${user.email})`);
     await syncUser(user);
 
     // Mint a backend JWT. The iOS app stores this and sends it as Bearer <token>.
     const backendJwt = signBackendJwt(user);
+    console.log(`[auth/token] backend JWT minted for user ${user.id}`);
 
     res.json({
       access_token: backendJwt,
@@ -156,7 +168,7 @@ router.post("/token", async (req, res) => {
     });
   } catch (error) {
     const message = error instanceof Error ? error.message : String(error);
-    console.error("Token exchange error:", error);
+    console.error("[auth/token] error:", error);
     res.status(500).json({ error: `Failed to exchange token: ${message}` });
   }
 });

ios/TimeTracker/TimeTracker/Core/Auth/AuthService.swift

@@ -1,6 +1,9 @@
 import Foundation
 import AuthenticationServices
 import CryptoKit
+import OSLog
+
+private let logger = Logger(subsystem: "com.timetracker.app", category: "AuthService")
 
 final class AuthService: NSObject {
     static let shared = AuthService()
@@ -29,6 +32,9 @@ final class AuthService: NSObject {
             throw AuthError.invalidURL
         }
         
+        logger.info("Starting login — auth URL: \(authURL.absoluteString)")
+        logger.info("Callback URL scheme: \(AppConfig.authCallbackURL)")
+        
         let callbackScheme = URL(string: AppConfig.authCallbackURL)?.scheme ?? "timetracker"
         
         // Use an ephemeral session — we only need the redirect URL back with the
@@ -40,8 +46,10 @@ final class AuthService: NSObject {
             if let error = error {
                 let authError: AuthError
                 if (error as? ASWebAuthenticationSessionError)?.code == .canceledLogin {
+                    logger.info("Login cancelled by user")
                     authError = .cancelled
                 } else {
+                    logger.error("ASWebAuthenticationSession error: \(error)")
                     authError = .failed(error.localizedDescription)
                 }
                 DispatchQueue.main.async {
@@ -55,6 +63,7 @@ final class AuthService: NSObject {
             }
             
             guard let callbackURL = callbackURL else {
+                logger.error("ASWebAuthenticationSession returned nil callbackURL")
                 DispatchQueue.main.async {
                     NotificationCenter.default.post(
                         name: .authError,
@@ -91,6 +100,7 @@ final class AuthService: NSObject {
               let code = components.queryItems?.first(where: { $0.name == "code" })?.value,
               let state = components.queryItems?.first(where: { $0.name == "state" })?.value
         else {
+            logger.error("Callback URL missing code or state: \(url.absoluteString)")
             DispatchQueue.main.async {
                 NotificationCenter.default.post(
                     name: .authError,
@@ -103,11 +113,13 @@ final class AuthService: NSObject {
         
         Task {
             do {
+                logger.info("Exchanging code for tokens (state: \(state), redirect_uri: \(AppConfig.authCallbackURL))")
                 let tokenResponse = try await exchangeCodeForTokens(
                     code: code,
                     state: state,
                     redirectUri: AppConfig.authCallbackURL
                 )
+                logger.info("Token exchange succeeded for user: \(tokenResponse.user.id)")
                 
                 await AuthManager.shared.handleTokenResponse(tokenResponse)
                 
@@ -115,6 +127,7 @@ final class AuthService: NSObject {
                     NotificationCenter.default.post(name: .authCallbackReceived, object: nil)
                 }
             } catch {
+                logger.error("Token exchange failed: \(error)")
                 DispatchQueue.main.async {
                     NotificationCenter.default.post(
                         name: .authError,
@@ -152,12 +165,17 @@ final class AuthService: NSObject {
             throw AuthError.failed("Invalid response")
         }
         
+        let bodyString = String(data: data, encoding: .utf8) ?? "(non-UTF8 body)"
+        logger.debug("POST /auth/token — status \(httpResponse.statusCode), body: \(bodyString)")
+        
         guard httpResponse.statusCode == 200 else {
             if let errorJson = try? JSONSerialization.jsonObject(with: data) as? [String: Any],
                let errorMessage = errorJson["error"] as? String {
+                logger.error("POST /auth/token — server error: \(errorMessage)")
                 throw AuthError.failed(errorMessage)
             }
-            throw AuthError.failed("Token exchange failed with status \(httpResponse.statusCode)")
+            logger.error("POST /auth/token — unexpected status \(httpResponse.statusCode): \(bodyString)")
+            throw AuthError.failed("Token exchange failed with status \(httpResponse.statusCode): \(bodyString)")
         }
         
         return try JSONDecoder().decode(TokenResponse.self, from: data)

ios/TimeTracker/TimeTracker/Core/Network/APIClient.swift

@@ -1,4 +1,7 @@
 import Foundation
+import OSLog
+
+private let logger = Logger(subsystem: "com.timetracker.app", category: "APIClient")
 
 actor APIClient {
     private let session: URLSession
@@ -43,9 +46,11 @@ actor APIClient {
         if authenticated {
             let token = await MainActor.run { AuthManager.shared.accessToken }
             guard let token = token else {
+                logger.warning("\(method.rawValue) \(endpoint) — no access token in keychain, throwing .unauthorized")
                 throw NetworkError.unauthorized
             }
             request.setValue("Bearer \(token)", forHTTPHeaderField: "Authorization")
+            logger.debug("\(method.rawValue) \(endpoint) — Authorization header set (token: \(token.prefix(20))…)")
         }
         
         if let body = body {
@@ -53,27 +58,29 @@ actor APIClient {
         }
         
         do {
+            logger.debug("\(method.rawValue) \(url.absoluteString) — sending request")
             let (data, response) = try await session.data(for: request)
             
             guard let httpResponse = response as? HTTPURLResponse else {
                 throw NetworkError.invalidResponse
             }
             
+            logger.debug("\(method.rawValue) \(endpoint) — status \(httpResponse.statusCode)")
+            
             if httpResponse.statusCode == 401 {
-                let message = try? decoder.decode(ErrorResponse.self, from: data).error
+                let serverMessage = (try? decoder.decode(ErrorResponse.self, from: data))?.error
-                await MainActor.run {
+                logger.error("\(method.rawValue) \(endpoint) — 401 Unauthorized. Server: \(serverMessage ?? "(no message)")")
-                    AuthManager.shared.clearAuth()
+                await MainActor.run { AuthManager.shared.clearAuth() }
-                }
+                throw NetworkError.httpError(statusCode: 401, message: serverMessage)
-                throw NetworkError.httpError(statusCode: 401, message: message)
             }
             
             guard (200...299).contains(httpResponse.statusCode) else {
-                let message = try? decoder.decode(ErrorResponse.self, from: data).error
+                let serverMessage = (try? decoder.decode(ErrorResponse.self, from: data))?.error
-                throw NetworkError.httpError(statusCode: httpResponse.statusCode, message: message)
+                logger.error("\(method.rawValue) \(endpoint) — HTTP \(httpResponse.statusCode). Server: \(serverMessage ?? "(no message)")")
+                throw NetworkError.httpError(statusCode: httpResponse.statusCode, message: serverMessage)
             }
             
             if data.isEmpty {
-                let empty: T? = nil
                 return try decoder.decode(T.self, from: "{}".data(using: .utf8)!)
             }
             
@@ -81,8 +88,10 @@ actor APIClient {
         } catch let error as NetworkError {
             throw error
         } catch let error as DecodingError {
+            logger.error("\(method.rawValue) \(endpoint) — decoding error: \(error)")
             throw NetworkError.decodingError(error)
         } catch {
+            logger.error("\(method.rawValue) \(endpoint) — network error: \(error)")
             throw NetworkError.networkError(error)
         }
     }
@@ -115,9 +124,11 @@ actor APIClient {
         if authenticated {
             let token = await MainActor.run { AuthManager.shared.accessToken }
             guard let token = token else {
+                logger.warning("\(method.rawValue) \(endpoint) — no access token in keychain, throwing .unauthorized")
                 throw NetworkError.unauthorized
             }
             request.setValue("Bearer \(token)", forHTTPHeaderField: "Authorization")
+            logger.debug("\(method.rawValue) \(endpoint) — Authorization header set (token: \(token.prefix(20))…)")
         }
         
         if let body = body {
@@ -125,27 +136,31 @@ actor APIClient {
         }
         
         do {
+            logger.debug("\(method.rawValue) \(url.absoluteString) — sending request")
             let (data, response) = try await session.data(for: request)
             
             guard let httpResponse = response as? HTTPURLResponse else {
                 throw NetworkError.invalidResponse
             }
             
+            logger.debug("\(method.rawValue) \(endpoint) — status \(httpResponse.statusCode)")
+            
             if httpResponse.statusCode == 401 {
-                let message = try? decoder.decode(ErrorResponse.self, from: data).error
+                let serverMessage = (try? decoder.decode(ErrorResponse.self, from: data))?.error
-                await MainActor.run {
+                logger.error("\(method.rawValue) \(endpoint) — 401 Unauthorized. Server: \(serverMessage ?? "(no message)")")
-                    AuthManager.shared.clearAuth()
+                await MainActor.run { AuthManager.shared.clearAuth() }
-                }
+                throw NetworkError.httpError(statusCode: 401, message: serverMessage)
-                throw NetworkError.httpError(statusCode: 401, message: message)
             }
             
             guard (200...299).contains(httpResponse.statusCode) else {
-                let message = try? decoder.decode(ErrorResponse.self, from: data).error
+                let serverMessage = (try? decoder.decode(ErrorResponse.self, from: data))?.error
-                throw NetworkError.httpError(statusCode: httpResponse.statusCode, message: message)
+                logger.error("\(method.rawValue) \(endpoint) — HTTP \(httpResponse.statusCode). Server: \(serverMessage ?? "(no message)")")
+                throw NetworkError.httpError(statusCode: httpResponse.statusCode, message: serverMessage)
             }
         } catch let error as NetworkError {
             throw error
         } catch {
+            logger.error("\(method.rawValue) \(endpoint) — network error: \(error)")
             throw NetworkError.networkError(error)
         }
     }