Refactor Logging BIG

This commit is contained in:
alma 2026-01-07 10:49:57 +01:00
parent c1ab0d5f81
commit 9ee441773c
4 changed files with 139 additions and 89 deletions

View File

@ -2,6 +2,7 @@ import { NextRequest, NextResponse } from "next/server";
import { getServerSession } from "next-auth/next"; import { getServerSession } from "next-auth/next";
import { authOptions } from "@/app/api/auth/options"; import { authOptions } from "@/app/api/auth/options";
import { getCachedTasksData, cacheTasksData } from "@/lib/redis"; import { getCachedTasksData, cacheTasksData } from "@/lib/redis";
import { logger } from "@/lib/logger";
interface Task { interface Task {
id: string; id: string;
@ -22,13 +23,15 @@ interface Task {
async function getLeantimeUserId(email: string): Promise<number | null> { async function getLeantimeUserId(email: string): Promise<number | null> {
try { try {
if (!process.env.LEANTIME_TOKEN) { if (!process.env.LEANTIME_TOKEN) {
console.error('LEANTIME_TOKEN is not set in environment variables'); logger.error('[LEANTIME_TASKS] LEANTIME_TOKEN is not set in environment variables');
return null; return null;
} }
console.log('Fetching Leantime users for email:', email); logger.debug('[LEANTIME_TASKS] Fetching Leantime users', {
console.log('API URL:', process.env.LEANTIME_API_URL); emailHash: Buffer.from(email.toLowerCase()).toString('base64').slice(0, 12),
console.log('Token length:', process.env.LEANTIME_TOKEN.length); apiUrlPresent: !!process.env.LEANTIME_API_URL,
tokenLength: process.env.LEANTIME_TOKEN.length,
});
const headers: Record<string, string> = { const headers: Record<string, string> = {
'Content-Type': 'application/json', 'Content-Type': 'application/json',
@ -46,13 +49,12 @@ async function getLeantimeUserId(email: string): Promise<number | null> {
}); });
const responseText = await response.text(); const responseText = await response.text();
console.log('Raw Leantime response:', responseText);
if (!response.ok) { if (!response.ok) {
console.error('Failed to fetch Leantime users:', { logger.error('[LEANTIME_TASKS] Failed to fetch Leantime users', {
status: response.status, status: response.status,
statusText: response.statusText, statusText: response.statusText,
headers: Object.fromEntries(response.headers.entries()) headers: Object.fromEntries(response.headers.entries()),
}); });
return null; return null;
} }
@ -61,14 +63,14 @@ async function getLeantimeUserId(email: string): Promise<number | null> {
try { try {
data = JSON.parse(responseText); data = JSON.parse(responseText);
} catch (e) { } catch (e) {
console.error('Failed to parse Leantime response:', e); logger.error('[LEANTIME_TASKS] Failed to parse Leantime response', {
error: e instanceof Error ? e.message : String(e),
});
return null; return null;
} }
console.log('Leantime users response:', data);
if (!data.result || !Array.isArray(data.result)) { if (!data.result || !Array.isArray(data.result)) {
console.error('Invalid response format from Leantime users API'); logger.error('[LEANTIME_TASKS] Invalid response format from Leantime users API');
return null; return null;
} }
@ -76,14 +78,21 @@ async function getLeantimeUserId(email: string): Promise<number | null> {
const user = users.find((u: any) => u.username === email); const user = users.find((u: any) => u.username === email);
if (user) { if (user) {
console.log('Found Leantime user:', { id: user.id, username: user.username }); logger.debug('[LEANTIME_TASKS] Found Leantime user', {
id: user.id,
emailHash: Buffer.from(email.toLowerCase()).toString('base64').slice(0, 12),
});
} else { } else {
console.log('No Leantime user found for username:', email); logger.warn('[LEANTIME_TASKS] No Leantime user found for username', {
emailHash: Buffer.from(email.toLowerCase()).toString('base64').slice(0, 12),
});
} }
return user ? user.id : null; return user ? user.id : null;
} catch (error) { } catch (error) {
console.error('Error fetching Leantime user ID:', error); logger.error('[LEANTIME_TASKS] Error fetching Leantime user ID', {
error: error instanceof Error ? error.message : String(error),
});
return null; return null;
} }
} }
@ -103,20 +112,29 @@ export async function GET(request: NextRequest) {
if (!forceRefresh) { if (!forceRefresh) {
const cachedTasks = await getCachedTasksData(session.user.id); const cachedTasks = await getCachedTasksData(session.user.id);
if (cachedTasks) { if (cachedTasks) {
console.log(`Using cached tasks data for user ${session.user.id}`); logger.debug('[LEANTIME_TASKS] Using cached tasks data', {
userId: session.user.id,
taskCount: Array.isArray(cachedTasks) ? cachedTasks.length : undefined,
});
return NextResponse.json(cachedTasks); return NextResponse.json(cachedTasks);
} }
} }
console.log('Fetching tasks for user:', session.user.email); logger.debug('[LEANTIME_TASKS] Fetching tasks for user', {
emailHash: Buffer.from(session.user.email.toLowerCase()).toString('base64').slice(0, 12),
});
const userId = await getLeantimeUserId(session.user.email); const userId = await getLeantimeUserId(session.user.email);
if (!userId) { if (!userId) {
console.error('User not found in Leantime'); logger.error('[LEANTIME_TASKS] User not found in Leantime', {
emailHash: Buffer.from(session.user.email.toLowerCase()).toString('base64').slice(0, 12),
});
return NextResponse.json({ error: "User not found in Leantime" }, { status: 404 }); return NextResponse.json({ error: "User not found in Leantime" }, { status: 404 });
} }
console.log('Fetching tasks for Leantime user ID:', userId); logger.debug('[LEANTIME_TASKS] Fetching tasks for Leantime user ID', {
userId,
});
const headers: Record<string, string> = { const headers: Record<string, string> = {
'Content-Type': 'application/json', 'Content-Type': 'application/json',
'X-API-Key': process.env.LEANTIME_TOKEN! 'X-API-Key': process.env.LEANTIME_TOKEN!
@ -137,12 +155,14 @@ export async function GET(request: NextRequest) {
}); });
const responseText = await response.text(); const responseText = await response.text();
console.log('Tasks API response status:', response.status); logger.debug('[LEANTIME_TASKS] Tasks API response status', {
status: response.status,
});
if (!response.ok) { if (!response.ok) {
console.error('Failed to fetch tasks from Leantime:', { logger.error('[LEANTIME_TASKS] Failed to fetch tasks from Leantime', {
status: response.status, status: response.status,
statusText: response.statusText statusText: response.statusText,
}); });
throw new Error('Failed to fetch tasks from Leantime'); throw new Error('Failed to fetch tasks from Leantime');
} }
@ -151,33 +171,27 @@ export async function GET(request: NextRequest) {
try { try {
data = JSON.parse(responseText); data = JSON.parse(responseText);
} catch (e) { } catch (e) {
console.error('Failed to parse tasks response'); logger.error('[LEANTIME_TASKS] Failed to parse tasks response', {
error: e instanceof Error ? e.message : String(e),
});
throw new Error('Invalid response format from Leantime'); throw new Error('Invalid response format from Leantime');
} }
if (!data.result || !Array.isArray(data.result)) { if (!data.result || !Array.isArray(data.result)) {
console.error('Invalid response format from Leantime tasks API'); logger.error('[LEANTIME_TASKS] Invalid response format from Leantime tasks API');
throw new Error('Invalid response format from Leantime'); throw new Error('Invalid response format from Leantime');
} }
// Log only the number of tasks and their IDs // Log only the number of tasks and their IDs
console.log('Received tasks count:', data.result.length); logger.debug('[LEANTIME_TASKS] Received tasks summary', {
console.log('Task IDs:', data.result.map((task: any) => task.id)); count: data.result.length,
idsSample: data.result.slice(0, 20).map((task: any) => task.id),
});
const tasks = data.result const tasks = data.result
.filter((task: any) => { .filter((task: any) => {
// Log raw task data for debugging
console.log('Raw task data:', {
id: task.id,
headline: task.headline,
status: task.status,
type: task.type,
dependingTicketId: task.dependingTicketId
});
// Filter out any task (main or subtask) that has status Done (5) // Filter out any task (main or subtask) that has status Done (5)
if (task.status === 5) { if (task.status === 5) {
console.log(`Filtering out Done task ${task.id} (type: ${task.type || 'main'}, status: ${task.status})`);
return false; return false;
} }
@ -187,7 +201,6 @@ export async function GET(request: NextRequest) {
// Only show tasks where the user is the editor // Only show tasks where the user is the editor
const isUserEditor = taskEditorId === currentUserId; const isUserEditor = taskEditorId === currentUserId;
console.log(`Task ${task.id}: status=${task.status}, type=${task.type || 'main'}, parentId=${task.dependingTicketId || 'none'}, isUserEditor=${isUserEditor}`);
return isUserEditor; return isUserEditor;
}) })
.map((task: any) => ({ .map((task: any) => ({
@ -208,14 +221,19 @@ export async function GET(request: NextRequest) {
dependingTicketId: task.dependingTicketId || null // Added parent task reference dependingTicketId: task.dependingTicketId || null // Added parent task reference
})); }));
console.log(`Found ${tasks.length} tasks assigned to user ${userId}`); logger.debug('[LEANTIME_TASKS] Filtered tasks for user', {
userId,
count: tasks.length,
});
// Cache the results // Cache the results
await cacheTasksData(session.user.id, tasks); await cacheTasksData(session.user.id, tasks);
return NextResponse.json(tasks); return NextResponse.json(tasks);
} catch (error) { } catch (error) {
console.error('Error in tasks route:', error); logger.error('[LEANTIME_TASKS] Error in tasks route', {
error: error instanceof Error ? error.message : String(error),
});
return NextResponse.json( return NextResponse.json(
{ error: "Failed to fetch tasks" }, { error: "Failed to fetch tasks" },
{ status: 500 } { status: 500 }

View File

@ -1,6 +1,7 @@
import { NextResponse } from 'next/server'; import { NextResponse } from 'next/server';
import { env } from '@/lib/env'; import { env } from '@/lib/env';
import { getCachedNewsData, cacheNewsData } from '@/lib/redis'; import { getCachedNewsData, cacheNewsData } from '@/lib/redis';
import { logger } from '@/lib/logger';
// Helper function to clean HTML content // Helper function to clean HTML content
function cleanHtmlContent(text: string): string { function cleanHtmlContent(text: string): string {
@ -91,21 +92,26 @@ export async function GET(request: Request) {
// Also bypass cache if a non-default limit is explicitly requested // Also bypass cache if a non-default limit is explicitly requested
const bypassCache = forceRefresh || (url.searchParams.has('limit') && limit !== '100'); const bypassCache = forceRefresh || (url.searchParams.has('limit') && limit !== '100');
console.log(`News API request: limit=${limit}, forceRefresh=${forceRefresh}, bypassCache=${bypassCache}`); logger.debug('[NEWS] Request received', {
limit,
forceRefresh,
bypassCache,
});
// Try to get data from cache if not forcing refresh // Try to get data from cache if not forcing refresh
if (!bypassCache) { if (!bypassCache) {
const cachedNews = await getCachedNewsData(limit); const cachedNews = await getCachedNewsData(limit);
if (cachedNews) { if (cachedNews) {
console.log(`Using cached news data (${cachedNews.length} articles)`); logger.debug('[NEWS] Using cached news data', {
limit,
count: cachedNews.length,
});
return NextResponse.json(cachedNews); return NextResponse.json(cachedNews);
} }
} }
console.log(`Fetching news from FastAPI server with limit=${limit}...`);
const apiUrl = `${env.NEWS_API_URL}/news?limit=${limit}`; const apiUrl = `${env.NEWS_API_URL}/news?limit=${limit}`;
console.log(`Full API URL: ${apiUrl}`); logger.debug('[NEWS] Fetching from backend', { apiUrl });
const response = await fetch(apiUrl, { const response = await fetch(apiUrl, {
method: 'GET', method: 'GET',
@ -117,10 +123,13 @@ export async function GET(request: Request) {
}); });
if (!response.ok) { if (!response.ok) {
console.error(`News API error: ${response.status} ${response.statusText}`); logger.error('[NEWS] Backend API error', {
status: response.status,
statusText: response.statusText,
});
const contentType = response.headers.get('content-type'); const contentType = response.headers.get('content-type');
if (contentType && !contentType.includes('application/json')) { if (contentType && !contentType.includes('application/json')) {
console.error('News API returned non-JSON response'); logger.error('[NEWS] Backend returned non-JSON response');
return NextResponse.json( return NextResponse.json(
{ error: 'News API returned invalid response format', status: response.status }, { error: 'News API returned invalid response format', status: response.status },
{ status: 502 } { status: 502 }
@ -135,15 +144,21 @@ export async function GET(request: Request) {
let articles; let articles;
try { try {
articles = await response.json(); articles = await response.json();
console.log(`News API returned ${articles.length} articles with limit=${limit}`); logger.debug('[NEWS] Backend response summary', {
console.log(`First article: ${JSON.stringify(articles[0])}`); limit,
console.log(`API URL used: ${apiUrl}`); count: articles.length,
});
if (articles.length < parseInt(limit) && articles.length > 0) { if (articles.length < parseInt(limit) && articles.length > 0) {
console.log(`WARNING: API returned fewer articles (${articles.length}) than requested (${limit}). This suggests a backend limit.`); logger.debug('[NEWS] Backend returned fewer articles than requested', {
requested: limit,
actual: articles.length,
});
} }
} catch (error) { } catch (error) {
console.error('Failed to parse news API response:', error); logger.error('[NEWS] Failed to parse backend response', {
error: error instanceof Error ? error.message : 'Unknown error',
});
return NextResponse.json( return NextResponse.json(
{ error: 'Failed to parse news API response', details: error instanceof Error ? error.message : 'Unknown error' }, { error: 'Failed to parse news API response', details: error instanceof Error ? error.message : 'Unknown error' },
{ status: 502 } { status: 502 }
@ -161,14 +176,19 @@ export async function GET(request: Request) {
url: article.url url: article.url
})); }));
console.log(`Formatted and returning ${formattedNews.length} news articles`); logger.debug('[NEWS] Returning formatted news', {
count: formattedNews.length,
limit,
});
// Cache the results // Cache the results
await cacheNewsData(formattedNews, limit); await cacheNewsData(formattedNews, limit);
return NextResponse.json(formattedNews); return NextResponse.json(formattedNews);
} catch (error) { } catch (error) {
console.error('News API error:', error); logger.error('[NEWS] Route error', {
error: error instanceof Error ? error.message : 'Unknown error',
});
return NextResponse.json( return NextResponse.json(
{ error: 'Failed to fetch news', details: error instanceof Error ? error.message : 'Unknown error' }, { error: 'Failed to fetch news', details: error instanceof Error ? error.message : 'Unknown error' },
{ status: 500 } { status: 500 }

View File

@ -2,6 +2,7 @@ import { getServerSession } from "next-auth";
import { authOptions } from "@/app/api/auth/options"; import { authOptions } from "@/app/api/auth/options";
import { NextResponse } from "next/server"; import { NextResponse } from "next/server";
import { getCachedMessagesData, cacheMessagesData } from "@/lib/redis"; import { getCachedMessagesData, cacheMessagesData } from "@/lib/redis";
import { logger } from "@/lib/logger";
// Helper function to get user token using admin credentials // Helper function to get user token using admin credentials
async function getUserToken(baseUrl: string) { async function getUserToken(baseUrl: string) {
@ -52,18 +53,20 @@ export async function GET(request: Request) {
if (!forceRefresh) { if (!forceRefresh) {
const cachedMessages = await getCachedMessagesData(session.user.id); const cachedMessages = await getCachedMessagesData(session.user.id);
if (cachedMessages) { if (cachedMessages) {
console.log(`Using cached messages data for user ${session.user.id}`); logger.debug("[ROCKET_CHAT] Using cached messages data", {
userId: session.user.id,
});
return NextResponse.json(cachedMessages); return NextResponse.json(cachedMessages);
} }
} }
const baseUrl = process.env.NEXT_PUBLIC_IFRAME_PAROLE_URL?.split('/channel')[0]; const baseUrl = process.env.NEXT_PUBLIC_IFRAME_PAROLE_URL?.split('/channel')[0];
if (!baseUrl) { if (!baseUrl) {
console.error('Failed to get Rocket.Chat base URL'); logger.error('[ROCKET_CHAT] Failed to get Rocket.Chat base URL');
return NextResponse.json({ error: 'Server configuration error' }, { status: 500 }); return NextResponse.json({ error: 'Server configuration error' }, { status: 500 });
} }
console.log('Using Rocket.Chat base URL:', baseUrl); logger.debug('[ROCKET_CHAT] Using Rocket.Chat base URL', { baseUrl });
// Step 1: Use admin token to authenticate // Step 1: Use admin token to authenticate
const adminHeaders = { const adminHeaders = {
@ -75,7 +78,9 @@ export async function GET(request: Request) {
// Step 2: Get the current user's Rocket.Chat ID // Step 2: Get the current user's Rocket.Chat ID
const username = session.user.email.split('@')[0]; const username = session.user.email.split('@')[0];
if (!username) { if (!username) {
console.error('No username found in session email'); logger.error('[ROCKET_CHAT] No username found in session email', {
email: session.user.email,
});
return NextResponse.json({ messages: [] }, { status: 200 }); return NextResponse.json({ messages: [] }, { status: 200 });
} }
@ -86,15 +91,17 @@ export async function GET(request: Request) {
}); });
if (!usersResponse.ok) { if (!usersResponse.ok) {
console.error('Failed to get users list:', usersResponse.status); logger.error('[ROCKET_CHAT] Failed to get users list', {
status: usersResponse.status,
});
return NextResponse.json({ messages: [] }, { status: 200 }); return NextResponse.json({ messages: [] }, { status: 200 });
} }
const usersData = await usersResponse.json(); const usersData = await usersResponse.json();
console.log('Users list response:', { logger.debug('[ROCKET_CHAT] Users list summary', {
success: usersData.success, success: usersData.success,
count: usersData.count, count: usersData.count,
usersCount: usersData.users?.length usersCount: usersData.users?.length,
}); });
// Find the current user in the list // Find the current user in the list
@ -103,13 +110,16 @@ export async function GET(request: Request) {
); );
if (!currentUser) { if (!currentUser) {
console.error('User not found in users list'); logger.error('[ROCKET_CHAT] User not found in users list', {
username,
email: session.user.email,
});
return NextResponse.json({ messages: [] }, { status: 200 }); return NextResponse.json({ messages: [] }, { status: 200 });
} }
console.log('Found Rocket.Chat user:', { logger.debug('[ROCKET_CHAT] Found user', {
username: currentUser.username, username: currentUser.username,
id: currentUser._id id: currentUser._id,
}); });
// Step 3: Create a token for the current user // Step 3: Create a token for the current user
@ -122,9 +132,13 @@ export async function GET(request: Request) {
}); });
if (!createTokenResponse.ok) { if (!createTokenResponse.ok) {
console.error('Failed to create user token:', createTokenResponse.status); logger.error('[ROCKET_CHAT] Failed to create user token', {
status: createTokenResponse.status,
});
const errorText = await createTokenResponse.text(); const errorText = await createTokenResponse.text();
console.error('Create token error details:', errorText); logger.error('[ROCKET_CHAT] Create token error details (truncated)', {
bodyPreview: errorText.substring(0, 200),
});
return NextResponse.json({ messages: [] }, { status: 200 }); return NextResponse.json({ messages: [] }, { status: 200 });
} }
@ -144,16 +158,20 @@ export async function GET(request: Request) {
}); });
if (!subscriptionsResponse.ok) { if (!subscriptionsResponse.ok) {
console.error('Failed to get subscriptions:', subscriptionsResponse.status); logger.error('[ROCKET_CHAT] Failed to get subscriptions', {
status: subscriptionsResponse.status,
});
const errorText = await subscriptionsResponse.text(); const errorText = await subscriptionsResponse.text();
console.error('Subscriptions error details:', errorText); logger.error('[ROCKET_CHAT] Subscriptions error details (truncated)', {
bodyPreview: errorText.substring(0, 200),
});
return NextResponse.json({ messages: [] }, { status: 200 }); return NextResponse.json({ messages: [] }, { status: 200 });
} }
const subscriptionsData = await subscriptionsResponse.json(); const subscriptionsData = await subscriptionsResponse.json();
if (!subscriptionsData.success || !Array.isArray(subscriptionsData.update)) { if (!subscriptionsData.success || !Array.isArray(subscriptionsData.update)) {
console.error('Invalid subscriptions response structure'); logger.error('[ROCKET_CHAT] Invalid subscriptions response structure');
return NextResponse.json({ messages: [] }, { status: 200 }); return NextResponse.json({ messages: [] }, { status: 200 });
} }
@ -167,18 +185,10 @@ export async function GET(request: Request) {
return ['d', 'c', 'p'].includes(sub.t); return ['d', 'c', 'p'].includes(sub.t);
}); });
console.log('Filtered user subscriptions:', { logger.debug('[ROCKET_CHAT] Filtered user subscriptions', {
userId: currentUser._id, userId: currentUser._id,
username: currentUser.username, username: currentUser.username,
totalSubscriptions: userSubscriptions.length, totalSubscriptions: userSubscriptions.length,
subscriptionDetails: userSubscriptions.map((sub: any) => ({
type: sub.t,
name: sub.fname || sub.name,
rid: sub.rid,
alert: sub.alert,
unread: sub.unread,
userMentions: sub.userMentions
}))
}); });
const messages: any[] = []; const messages: any[] = [];
@ -217,15 +227,19 @@ export async function GET(request: Request) {
); );
if (!messagesResponse.ok) { if (!messagesResponse.ok) {
console.error(`Failed to get messages for room ${subscription.name}:`, messagesResponse.status); logger.error('[ROCKET_CHAT] Failed to get messages for room', {
roomName: subscription.name,
status: messagesResponse.status,
});
continue; continue;
} }
const messageData = await messagesResponse.json(); const messageData = await messagesResponse.json();
console.log(`Messages for room ${subscription.fname || subscription.name}:`, { logger.debug('[ROCKET_CHAT] Messages for room', {
roomName: subscription.fname || subscription.name,
success: messageData.success, success: messageData.success,
count: messageData.count, count: messageData.count,
hasMessages: messageData.messages?.length > 0 hasMessages: messageData.messages?.length > 0,
}); });
if (messageData.success && messageData.messages?.length > 0) { if (messageData.success && messageData.messages?.length > 0) {
@ -337,7 +351,10 @@ export async function GET(request: Request) {
} }
} }
} catch (error) { } catch (error) {
console.error(`Error fetching messages for room ${subscription.name}:`, error); logger.error('[ROCKET_CHAT] Error fetching messages for room', {
roomName: subscription.name,
error: error instanceof Error ? error.message : String(error),
});
continue; continue;
} }
} }
@ -358,7 +375,9 @@ export async function GET(request: Request) {
return NextResponse.json(finalResponse); return NextResponse.json(finalResponse);
} catch (error) { } catch (error) {
console.error('Error fetching messages:', error); logger.error('[ROCKET_CHAT] Error fetching messages', {
error: error instanceof Error ? error.message : String(error),
});
return NextResponse.json({ error: 'Failed to fetch messages' }, { status: 500 }); return NextResponse.json({ error: 'Failed to fetch messages' }, { status: 500 });
} }
} }

View File

@ -12,14 +12,7 @@ const clientId = process.env.MICROSOFT_CLIENT_ID;
const clientSecret = process.env.MICROSOFT_CLIENT_SECRET; const clientSecret = process.env.MICROSOFT_CLIENT_SECRET;
const redirectUri = process.env.MICROSOFT_REDIRECT_URI; const redirectUri = process.env.MICROSOFT_REDIRECT_URI;
// Log configuration for debugging // NOTE: In production we do not log Microsoft OAuth configuration to avoid noise and potential leakage.
console.log('Microsoft OAuth Configuration:', {
tenantId,
authorizeUrl: MICROSOFT_AUTHORIZE_URL,
tokenUrl: MICROSOFT_TOKEN_URL,
clientIdFirstChars: clientId ? clientId.substring(0, 5) + '...' : 'undefined',
redirectUri
});
// Required scopes for IMAP and SMTP access // Required scopes for IMAP and SMTP access
const REQUIRED_SCOPES = [ const REQUIRED_SCOPES = [