Add detailed JWT debug logging for admin endpoints
Some checks are pending
Backend CI / test (push) Waiting to run
Backend CI / build (push) Blocked by required conditions
Deploy Mnemo Cards / Deploy Backend (push) Waiting to run
Deploy Mnemo Cards / Deploy Web App (push) Blocked by required conditions
Deploy Mnemo Cards / Final Verification (push) Blocked by required conditions

- Changed stderr to print for visibility in logs
- Added signature mismatch debugging
- Added expiry time debugging
This commit is contained in:
Dmitry 2025-12-12 00:54:21 +03:00
parent 221ae2a049
commit 24b584d835
2 changed files with 48 additions and 23 deletions

View file

@ -1,5 +1,3 @@
import 'dart:io';
import 'package:mnemo_cards_backend/api/v2/jwt_service.dart'; import 'package:mnemo_cards_backend/api/v2/jwt_service.dart';
import 'package:mnemo_cards_backend/user/user_manager.dart'; import 'package:mnemo_cards_backend/user/user_manager.dart';
import 'package:shelf/shelf.dart'; import 'package:shelf/shelf.dart';
@ -91,13 +89,17 @@ Middleware authorizeV2(UserManager userManager, JwtService jwtService) {
// Shelf normalizes headers to lowercase, so we check 'authorization' // Shelf normalizes headers to lowercase, so we check 'authorization'
final authHeader = request.headers['authorization']; final authHeader = request.headers['authorization'];
// Debug logging for admin endpoints - use stderr to ensure it's visible final isAdminEndpoint = normalizedPath.startsWith('/admin/');
if (normalizedPath.startsWith('/admin/')) {
stderr.writeln('[AUTH DEBUG] Path: $normalizedPath'); // Debug logging for admin endpoints
stderr.writeln('[AUTH DEBUG] Authorization header present: ${authHeader != null}'); if (isAdminEndpoint) {
print('[AUTH DEBUG] Path: $normalizedPath');
print('[AUTH DEBUG] Authorization header present: ${authHeader != null}');
if (authHeader != null) { if (authHeader != null) {
stderr.writeln('[AUTH DEBUG] Authorization header length: ${authHeader.length}'); print('[AUTH DEBUG] Authorization header length: ${authHeader.length}');
stderr.writeln('[AUTH DEBUG] Authorization header starts with Bearer: ${authHeader.startsWith('Bearer ')}'); print('[AUTH DEBUG] Authorization header starts with Bearer: ${authHeader.startsWith('Bearer ')}');
} else {
print('[AUTH DEBUG] All headers: ${request.headers}');
} }
} }
@ -117,25 +119,36 @@ Middleware authorizeV2(UserManager userManager, JwtService jwtService) {
final token = authHeader.substring(7); // Remove "Bearer " prefix final token = authHeader.substring(7); // Remove "Bearer " prefix
// Debug logging for admin endpoints - use stderr // Debug logging for admin endpoints
if (normalizedPath.startsWith('/admin/')) { if (isAdminEndpoint) {
stderr.writeln('[AUTH DEBUG] Verifying token for path: $normalizedPath'); print('[AUTH DEBUG] Verifying token for path: $normalizedPath');
stderr.writeln('[AUTH DEBUG] Token length: ${token.length}'); print('[AUTH DEBUG] Token length: ${token.length}');
stderr.writeln('[AUTH DEBUG] Token preview: ${token.length > 50 ? token.substring(0, 50) + "..." : token}'); print('[AUTH DEBUG] Token preview: ${token.length > 50 ? token.substring(0, 50) + "..." : token}');
} }
final userId = jwtService.verifyAccessToken(token); final isAdminPath = isAdminEndpoint;
final userId = jwtService.verifyAccessToken(token, debug: isAdminPath);
if (userId == null) { if (userId == null) {
// Additional debug info for admin endpoints // Additional debug info for admin endpoints
if (normalizedPath.startsWith('/admin/')) { if (isAdminPath) {
stderr.writeln('[AUTH DEBUG] Token verification failed for path: $normalizedPath'); print('[AUTH DEBUG] Token verification failed for path: $normalizedPath');
// Try to extract payload to see what's wrong // Try to extract payload to see what's wrong
try { try {
final payload = jwtService.extractPayload(token); final payload = jwtService.extractPayload(token);
stderr.writeln('[AUTH DEBUG] Extracted payload: $payload'); print('[AUTH DEBUG] Extracted payload: $payload');
if (payload != null) {
final exp = payload['exp'] as int?;
if (exp != null) {
final expiryTime = DateTime.fromMillisecondsSinceEpoch(exp * 1000);
print('[AUTH DEBUG] Token expires at: $expiryTime');
print('[AUTH DEBUG] Current time: ${DateTime.now()}');
print('[AUTH DEBUG] Is expired: ${DateTime.now().isAfter(expiryTime)}');
}
print('[AUTH DEBUG] Token type: ${payload['type']}');
}
} catch (e) { } catch (e) {
stderr.writeln('[AUTH DEBUG] Could not extract payload: $e'); print('[AUTH DEBUG] Could not extract payload: $e');
} }
} }
return Response( return Response(
@ -145,8 +158,8 @@ Middleware authorizeV2(UserManager userManager, JwtService jwtService) {
); );
} }
if (normalizedPath.startsWith('/admin/')) { if (isAdminPath) {
stderr.writeln('[AUTH DEBUG] Token verified successfully, userId: $userId'); print('[AUTH DEBUG] Token verified successfully, userId: $userId');
} }
// Get user from database // Get user from database

View file

@ -63,10 +63,11 @@ class JwtService {
} }
/// Verify access token and return user ID /// Verify access token and return user ID
String? verifyAccessToken(String token) { String? verifyAccessToken(String token, {bool debug = false}) {
try { try {
final payload = _verifySimpleJwt(token); final payload = _verifySimpleJwt(token, debug: debug);
if (payload == null) { if (payload == null) {
if (debug) print('[JWT DEBUG] _verifySimpleJwt returned null');
return null; return null;
} }
@ -75,17 +76,20 @@ class JwtService {
if (exp != null) { if (exp != null) {
final expiryTime = DateTime.fromMillisecondsSinceEpoch(exp * 1000); final expiryTime = DateTime.fromMillisecondsSinceEpoch(exp * 1000);
if (DateTime.now().isAfter(expiryTime)) { if (DateTime.now().isAfter(expiryTime)) {
if (debug) print('[JWT DEBUG] Token expired at $expiryTime, now: ${DateTime.now()}');
return null; return null;
} }
} }
// Check token type // Check token type
if (payload['type'] != 'access') { if (payload['type'] != 'access') {
if (debug) print('[JWT DEBUG] Wrong token type: ${payload['type']}');
return null; return null;
} }
return payload['userId']?.toString(); return payload['userId']?.toString();
} catch (e) { } catch (e) {
if (debug) print('[JWT DEBUG] Exception in verifyAccessToken: $e');
return null; return null;
} }
} }
@ -142,10 +146,11 @@ class JwtService {
} }
/// Verify a simple JWT /// Verify a simple JWT
Map<String, dynamic>? _verifySimpleJwt(String token) { Map<String, dynamic>? _verifySimpleJwt(String token, {bool debug = false}) {
try { try {
final parts = token.split('.'); final parts = token.split('.');
if (parts.length != 3) { if (parts.length != 3) {
if (debug) print('[JWT DEBUG] Invalid token format: ${parts.length} parts');
return null; return null;
} }
@ -160,6 +165,12 @@ class JwtService {
final expectedSignatureB64 = base64UrlEncode(expectedSignature); final expectedSignatureB64 = base64UrlEncode(expectedSignature);
if (signatureB64 != expectedSignatureB64) { if (signatureB64 != expectedSignatureB64) {
if (debug) {
print('[JWT DEBUG] Signature mismatch!');
print('[JWT DEBUG] Got signature: $signatureB64');
print('[JWT DEBUG] Expected signature: $expectedSignatureB64');
print('[JWT DEBUG] Secret key length: ${_secretKey.length}');
}
return null; // Invalid signature return null; // Invalid signature
} }
@ -167,6 +178,7 @@ class JwtService {
final payloadJson = utf8.decode(base64Url.decode(payloadB64)); final payloadJson = utf8.decode(base64Url.decode(payloadB64));
return jsonDecode(payloadJson) as Map<String, dynamic>; return jsonDecode(payloadJson) as Map<String, dynamic>;
} catch (e) { } catch (e) {
if (debug) print('[JWT DEBUG] Exception during verification: $e');
return null; return null;
} }
} }