salman/igny8
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

logging

Browse Source
This commit is contained in:
alorig
2025-11-09 23:50:19 +05:00
parent 98e900da73
commit bee6a68718
5 changed files with 96 additions and 79 deletions
Download Patch File Download Diff File Expand all files Collapse all files

6
backend/igny8_core/ai/ai_core.py
View File

@@ -269,6 +269,7 @@ class AICore:
'cost': cost, 'cost': cost,
'error': None, 'error': None,
'api_id': api_id, 'api_id': api_id,
'duration': request_duration, # Add duration tracking
} }
else: else:
error_msg = 'No content in OpenAI response' error_msg = 'No content in OpenAI response'
@@ -315,8 +316,9 @@ class AICore:
} }
except Exception as e: except Exception as e:
error_msg = f'Unexpected error: {str(e)}' error_msg = f'Unexpected error: {str(e)}'
print(f"[AI][{function_name}][Error] {error_msg}") logger.error(f"[AI][{function_name}][Error] {error_msg}", exc_info=True)
logger.error(error_msg, exc_info=True) if tracker:
tracker.error('UnexpectedError', error_msg, e)
return { return {
'content': None, 'content': None,
'error': error_msg, 'error': error_msg,

33
backend/igny8_core/ai/tracker.py
View File

@@ -238,12 +238,15 @@ class ConsoleStepTracker:
self.current_phase = None self.current_phase = None
# Debug: Verify DEBUG_MODE is enabled # Debug: Verify DEBUG_MODE is enabled
import sys
if DEBUG_MODE: if DEBUG_MODE:
print(f"[DEBUG] ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is ENABLED", flush=True) init_msg = f"[DEBUG] ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is ENABLED"
logger.info(f"ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is ENABLED") logger.info(init_msg)
print(init_msg, flush=True, file=sys.stdout)
else: else:
print(f"[WARNING] ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is DISABLED", flush=True) init_msg = f"[WARNING] ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is DISABLED"
logger.warning(f"ConsoleStepTracker initialized for '{function_name}' - DEBUG_MODE is DISABLED") logger.warning(init_msg)
print(init_msg, flush=True, file=sys.stdout)
def _log(self, phase: str, message: str, status: str = 'info'): def _log(self, phase: str, message: str, status: str = 'info'):
"""Internal logging method that checks DEBUG_MODE""" """Internal logging method that checks DEBUG_MODE"""
@@ -256,15 +259,17 @@ class ConsoleStepTracker:
if status == 'error': if status == 'error':
log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] [ERROR] {message}" log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] [ERROR] {message}"
# Use logger.error for errors so they're always visible
logger.error(log_msg)
elif status == 'success': elif status == 'success':
log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] ✅ {message}" log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] ✅ {message}"
logger.info(log_msg)
else: else:
log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] {message}" log_msg = f"[{timestamp}] [{self.function_name}] [{phase_label}] {message}"
logger.info(log_msg)
# Print and flush immediately to ensure console output # Also print to stdout for immediate visibility (works in Celery worker logs)
print(log_msg, flush=True) print(log_msg, flush=True, file=sys.stdout)
# Also log to Python logger for better visibility
logger.info(log_msg)
self.steps.append({ self.steps.append({
'timestamp': timestamp, 'timestamp': timestamp,
@@ -300,8 +305,9 @@ class ConsoleStepTracker:
self._log('DONE', f"{message} (Duration: {duration:.2f}s)", status='success') self._log('DONE', f"{message} (Duration: {duration:.2f}s)", status='success')
if DEBUG_MODE: if DEBUG_MODE:
import sys import sys
print(f"[{self.function_name}] === AI Task Complete ===", flush=True) complete_msg = f"[{self.function_name}] === AI Task Complete ==="
logger.info(f"[{self.function_name}] === AI Task Complete ===") logger.info(complete_msg)
print(complete_msg, flush=True, file=sys.stdout)
def error(self, error_type: str, message: str, exception: Exception = None): def error(self, error_type: str, message: str, exception: Exception = None):
"""Log error with standardized format""" """Log error with standardized format"""
@@ -312,9 +318,10 @@ class ConsoleStepTracker:
if DEBUG_MODE and exception: if DEBUG_MODE and exception:
import sys import sys
import traceback import traceback
print(f"[{self.function_name}] [ERROR] Stack trace:", flush=True) error_trace_msg = f"[{self.function_name}] [ERROR] Stack trace:"
traceback.print_exc() logger.error(error_trace_msg, exc_info=exception)
logger.error(f"[{self.function_name}] [ERROR] Stack trace:", exc_info=exception) print(error_trace_msg, flush=True, file=sys.stdout)
traceback.print_exc(file=sys.stdout)
def retry(self, attempt: int, max_attempts: int, reason: str = ""): def retry(self, attempt: int, max_attempts: int, reason: str = ""):
"""Log retry attempt""" """Log retry attempt"""

21
backend/igny8_core/modules/system/integration_views.py
View File

@@ -961,15 +961,30 @@ class IntegrationSettingsViewSet(viewsets.ViewSet):
'meta': response_meta 'meta': response_meta
}) })
elif task_state == 'FAILURE': elif task_state == 'FAILURE':
# Try to get error from task.info meta first (this is where run_ai_task sets it)
if not error_message and isinstance(task_info, dict):
error_message = task_info.get('error') or task_info.get('message', '')
error_type = task_info.get('error_type', 'UnknownError')
# Also check if message contains error info
if not error_message and 'message' in task_info:
msg = task_info.get('message', '')
if msg and 'Error:' in msg:
error_message = msg.replace('Error: ', '')
# Use extracted error_message if available, otherwise try to get from error_info # Use extracted error_message if available, otherwise try to get from error_info
if not error_message: if not error_message:
error_info = task_info error_info = task_info
if isinstance(error_info, Exception): if isinstance(error_info, Exception):
error_message = str(error_info) error_message = str(error_info)
elif isinstance(error_info, dict): elif isinstance(error_info, dict):
error_message = error_info.get('error', str(error_info)) error_message = error_info.get('error') or error_info.get('message', '') or str(error_info)
else: elif error_info:
error_message = str(error_info) if error_info else 'Task failed' error_message = str(error_info)
# Final fallback - ensure we always have an error message
if not error_message or error_message.strip() == '':
error_message = f'Task execution failed - check Celery worker logs for task {task_id}'
error_type = 'ExecutionError'
response_meta = { response_meta = {
'error': error_message, 'error': error_message,

108
frontend/src/components/debug/ResourceDebugOverlay.tsx
View File

@@ -128,70 +128,60 @@ export default function ResourceDebugOverlay({ enabled }: ResourceDebugOverlayPr
headers['Authorization'] = `Bearer ${token}`; headers['Authorization'] = `Bearer ${token}`;
} }
const response = await nativeFetch.call(window, `${API_BASE_URL}/v1/system/request-metrics/${requestId}/`, { // Silently handle 404s and other errors - metrics might not exist for all requests
method: 'GET', try {
headers, const response = await nativeFetch.call(window, `${API_BASE_URL}/v1/system/request-metrics/${requestId}/`, {
credentials: 'include', // Include session cookies for authentication method: 'GET',
}); headers,
credentials: 'include', // Include session cookies for authentication
if (response.ok) { });
const data = await response.json();
// Only log in debug mode to reduce console noise if (response.ok) {
if (import.meta.env.DEV) { const data = await response.json();
console.debug('Fetched metrics for request:', requestId, data); // Only log in debug mode to reduce console noise
} if (import.meta.env.DEV) {
metricsRef.current = [...metricsRef.current, data]; console.debug('Fetched metrics for request:', requestId, data);
setMetrics([...metricsRef.current]);
} else if (response.status === 401) {
// Token might be expired - try to refresh and retry once
try {
await useAuthStore.getState().refreshToken();
const newToken = useAuthStore.getState().token;
if (newToken) {
const retryHeaders: HeadersInit = {
'Content-Type': 'application/json',
'Authorization': `Bearer ${newToken}`,
};
const retryResponse = await nativeFetch.call(window, `${API_BASE_URL}/v1/system/request-metrics/${requestId}/`, {
method: 'GET',
headers: retryHeaders,
credentials: 'include',
});
if (retryResponse.ok) {
const data = await retryResponse.json();
metricsRef.current = [...metricsRef.current, data];
setMetrics([...metricsRef.current]);
return;
}
} }
} catch (refreshError) { metricsRef.current = [...metricsRef.current, data];
// Refresh failed - user needs to re-login setMetrics([...metricsRef.current]);
console.warn('Token refresh failed, user may need to re-authenticate'); } else if (response.status === 401) {
} // Token might be expired - try to refresh and retry once
// Silently ignore 401 errors - user might not be authenticated try {
} else if (response.status === 404) { await useAuthStore.getState().refreshToken();
// Metrics not found - could be race condition, retry once after short delay const newToken = useAuthStore.getState().token;
if (retryCount === 0) { if (newToken) {
// First attempt failed, retry once after 200ms (middleware might still be storing) const retryHeaders: HeadersInit = {
setTimeout(() => fetchRequestMetrics(requestId, 1), 200); 'Content-Type': 'application/json',
'Authorization': `Bearer ${newToken}`,
};
const retryResponse = await nativeFetch.call(window, `${API_BASE_URL}/v1/system/request-metrics/${requestId}/`, {
method: 'GET',
headers: retryHeaders,
credentials: 'include',
});
if (retryResponse.ok) {
const data = await retryResponse.json();
metricsRef.current = [...metricsRef.current, data];
setMetrics([...metricsRef.current]);
return;
}
}
} catch (refreshError) {
// Refresh failed - silently ignore
}
// Silently ignore 401 errors - user might not be authenticated
} else if (response.status === 404) {
// Metrics not found - silently ignore (metrics might not exist for all requests)
return;
} else {
// Other errors - silently ignore
return; return;
} }
// Second attempt also failed - metrics truly not available } catch (error) {
// This is expected: metrics expired (5min TTL), request wasn't tracked, or middleware error // Silently ignore all fetch errors (network errors, etc.)
// Silently ignore - no need to log or show error // Metrics are optional and not critical for functionality
return;
} else {
// Only log non-404/401 errors (500, 403, etc.)
console.warn('Failed to fetch metrics:', response.status, response.statusText, 'for request:', requestId);
}
} catch (error) {
// Only log non-network errors
if (error instanceof TypeError && error.message.includes('fetch')) {
// Network error - silently ignore
return; return;
} }
console.error('Failed to fetch request metrics:', error);
}
}; };
// Calculate page load time // Calculate page load time

7
frontend/src/hooks/useProgressModal.ts
View File

@@ -346,11 +346,14 @@ export function useProgressModal(): UseProgressModalReturn {
} }
} else if (response.state === 'FAILURE') { } else if (response.state === 'FAILURE') {
const meta = response.meta || {}; const meta = response.meta || {};
const errorMsg = meta.error || 'Task failed'; // Try multiple error message sources
const errorMsg = meta.error || meta.message || response.error || 'Task failed - exception details unavailable';
const errorType = meta.error_type || 'Error';
setProgress({ setProgress({
percentage: 0, percentage: 0,
message: `Error: ${errorMsg}`, message: errorMsg.includes('exception details unavailable') ? errorMsg : `Error: ${errorMsg}`,
status: 'error', status: 'error',
details: meta.error_type ? `${errorType}: ${errorMsg}` : errorMsg,
}); });
// Update step logs from failure response // Update step logs from failure response