diff --git a/.vscode/settings.json b/.vscode/settings.json index 9309b7c2..ed546a7a 100644 --- a/.vscode/settings.json +++ b/.vscode/settings.json @@ -10,6 +10,7 @@ "confirmdialog", "contentful", "Contentful", + "customfield", "DATEADD", "daygrid", "dismissable", diff --git a/CLAUDE.md b/CLAUDE.md index 9ebd24d1..e552e5ee 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -98,26 +98,224 @@ lfx-v2-ui/ - **Protected routes middleware** handles selective authentication logic - **Custom login handler** at `/login` with URL validation and secure redirects - Authentication is handled by Auth0/Authelia with express-openid-connect middleware -- **Logging System**: Uses Pino for structured JSON logs with sensitive data redaction -- **Logger Helper Pattern**: All controller functions must use Logger helper methods: - - `Logger.start(req, 'operation_name', metadata)` - Returns startTime, logs at INFO - - `Logger.success(req, 'operation_name', startTime, metadata)` - Logs at INFO - - `Logger.error(req, 'operation_name', startTime, error, metadata)` - Logs at ERROR with 'err' field - - `Logger.warning(req, 'operation_name', message, metadata)` - Logs at WARN - - `Logger.validation(req, 'operation_name', errors, metadata)` - Logs at WARN -- **Error Logging Standard**: Always use `err` field for errors to leverage Pino's error serializer - - ✅ Correct: `req.log.error({ err: error, ...metadata }, 'message')` - - ✅ Correct: `serverLogger.error({ err: error }, 'message')` - - ✅ Correct: `Logger.error(req, 'operation', startTime, error, metadata)` - - ❌ Incorrect: `{ error: error.message }` or `{ error: error instanceof Error ? error.message : error }` - - Benefits: Complete stack traces (production/debug), clean single-line errors (development), proper AWS CloudWatch format - - Custom serializer: `/server/helpers/error-serializer.ts` - excludes verbose stacks in dev, includes in prod -- **Log Level Guidelines** (What to log at each level): - - **INFO**: Business operation completions (created, updated, deleted), successful data retrieval (fetched, retrieved) - - **WARN**: Error conditions leading to exceptions, data quality issues, user not found, fallback behaviors - - **DEBUG**: Internal operations, preparation steps (sanitizing, creating payload), intent statements (resolving, fetching), NATS lookups - - **ERROR**: System failures, unhandled exceptions, critical errors requiring immediate attention -- **Filtered URLs**: Health checks (/health, /api/health) and /.well-known URLs are not logged to reduce noise + +## Logging System + +### Architecture Overview + +- **Base Logger**: `serverLogger` created in `server.ts` - base Pino instance with all configuration +- **HTTP Logger**: `pinoHttp` middleware uses `serverLogger` as base, creates `req.log` for each request +- **Logger Service**: Singleton service (`logger.service.ts`) - unified interface for all application logging +- **Format**: Structured JSON logs with Pino for AWS CloudWatch compatibility + +### Logger Service Pattern (Primary Interface) + +**Import and Usage:** + +```typescript +import { logger } from './logger.service'; + +// In controllers/routes with request context: +const startTime = logger.startOperation(req, 'operation_name', metadata); +logger.success(req, 'operation_name', startTime, metadata); + +// In services/utilities without request context: +const startTime = logger.startOperation(undefined, 'nats_connect', metadata); +logger.success(undefined, 'nats_connect', startTime, metadata); +``` + +**Available Methods:** + +- `logger.startOperation(req|undefined, 'operation', metadata, options?)` → Returns startTime, logs at INFO (silent option available) +- `logger.success(req|undefined, 'operation', startTime, metadata)` → Logs at INFO with duration +- `logger.error(req|undefined, 'operation', startTime, error, metadata, options?)` → Logs at ERROR with 'err' field +- `logger.warning(req|undefined, 'operation', message, metadata)` → Logs at WARN +- `logger.validation(req|undefined, 'operation', errors[], metadata)` → Logs at ERROR with validation details +- `logger.debug(req|undefined, 'operation', message, metadata)` → Logs at DEBUG +- `logger.etag(req|undefined, 'operation', resourceType, resourceId, etag?, metadata)` → Logs ETag operations + +**When to Use Each Pattern:** + +- **Request-scoped** (pass `req`): Controllers, route handlers, service methods called from routes +- **Infrastructure** (pass `undefined`): NATS connections, Snowflake pool, server startup/shutdown, scheduled jobs + +### Error Logging Standard + +**Always use `err` field** for proper error serialization: + +```typescript +// ✅ CORRECT +logger.error(req, 'operation', startTime, error, metadata); +logger.error(undefined, 'operation', startTime, error, metadata); + +// ❌ INCORRECT +serverLogger.error({ error: error.message }, 'message'); // Don't use serverLogger directly +req.log.error({ error: error }, 'message'); // Should use logger service +{ + error: error.message; +} // Loses stack trace +``` + +**Benefits:** + +- Complete stack traces in production/debug +- Clean single-line errors in development +- Proper AWS CloudWatch format +- Custom serializer: `/server/helpers/error-serializer.ts` + +### Log Level Guidelines + +**INFO** - Business operation completions: + +- Successful data operations (created, updated, deleted, fetched) +- Important state changes +- Operation success with duration + +**WARN** - Recoverable issues: + +- Error conditions leading to exceptions +- Data quality issues, user not found +- Fallback behaviors, NATS failures with graceful handling + +**DEBUG** - Internal operations: + +- Preparation steps (sanitizing, creating payload) +- Internal lookups (NATS, database queries) +- Intent statements (resolving, fetching) +- Infrastructure operations (connections, pool state) + +**ERROR** - Critical failures: + +- System failures, unhandled exceptions +- Critical errors requiring immediate attention +- Operations that cannot continue + +### Features + +- **Deduplication**: Prevents duplicate logs for same operation (request-scoped only) +- **Duration Tracking**: Automatic calculation from startTime to completion +- **Request Correlation**: `request_id` field for tracing (when req provided) +- **Sensitive Data Redaction**: Automatic redaction of tokens, auth headers, cookies +- **AWS Trace ID**: Automatic capture from Lambda environment +- **Filtered URLs**: Health checks (`/health`, `/api/health`) and `/.well-known` not logged + +### Logging Architecture + +```text +server-logger.ts (breaks circular dependency) + └─ Creates and exports serverLogger (base Pino instance) + └─ Configuration: levels, serializers, formatters, redaction + +server.ts + ├─ Imports serverLogger from server-logger.ts + └─ Creates httpLogger (pinoHttp middleware) + └─ Uses serverLogger as base + └─ Attaches req.log to each request + +logger.service.ts + ├─ Imports serverLogger from server-logger.ts + └─ Singleton logger service + ├─ Request-scoped: uses req.log when req provided + ├─ Infrastructure: uses serverLogger when req = undefined + └─ Provides unified API for all logging +``` + +**Direct serverLogger Usage:** + +- ❌ **Never** call `serverLogger` directly from services/routes/controllers +- ✅ **Always** use `logger` service methods +- ℹ️ `serverLogger` only exists in `server-logger.ts` (created), `server.ts` (imported), and `logger.service.ts` (imported) + +### Common Logging Patterns + +**Controller/Route Handler Pattern:** + +```typescript +export const getUser = async (req: Request, res: Response, next: NextFunction) => { + const startTime = logger.startOperation(req, 'get_user', { userId: req.params.id }); + + try { + const user = await userService.getUserById(req, req.params.id); + + logger.success(req, 'get_user', startTime, { userId: user.id }); + return res.json(user); + } catch (error) { + logger.error(req, 'get_user', startTime, error, { userId: req.params.id }); + return next(error); + } +}; +``` + +**Service Method with Request Context:** + +```typescript +public async updateUser(req: Request, userId: string, data: UpdateData): Promise { + const startTime = logger.startOperation(req, 'update_user', { userId }); + + try { + // Validation + if (!data.email) { + logger.validation(req, 'update_user', ['Email required'], { userId }); + throw new ValidationError('Email required'); + } + + const user = await this.performUpdate(userId, data); + logger.success(req, 'update_user', startTime, { userId, updatedFields: Object.keys(data) }); + return user; + } catch (error) { + logger.error(req, 'update_user', startTime, error, { userId }); + throw error; + } +} +``` + +**Infrastructure Operation (No Request Context):** + +```typescript +public async connect(): Promise { + const startTime = logger.startOperation(undefined, 'db_connect', { host: this.config.host }); + + try { + await this.pool.connect(); + logger.success(undefined, 'db_connect', startTime, { poolSize: this.pool.size }); + } catch (error) { + logger.error(undefined, 'db_connect', startTime, error, { host: this.config.host }); + throw error; + } +} +``` + +**Internal Service Operation (Called from method with req):** + +```typescript +// Parent method has req +public async getProjectBySlug(req: Request, slug: string): Promise { + return this.fetchFromNats(req, slug); // Pass req down +} + +// Internal method receives req for logging correlation +private async fetchFromNats(req: Request, slug: string): Promise { + logger.debug(req, 'fetch_from_nats', 'Fetching project from NATS', { slug }); + // ... implementation +} +``` + +### Logging Checklist + +**Before logging:** + +- [ ] Using `logger` service, not `serverLogger` directly? +- [ ] Passing `req` if available, `undefined` if infrastructure? +- [ ] Using `err` field for errors (not `error`)? +- [ ] Appropriate log level (INFO/WARN/DEBUG/ERROR)? +- [ ] Operation name in snake_case? +- [ ] Sensitive data sanitized? + +**For operations with duration:** + +- [ ] Called `logger.startOperation()` and captured `startTime`? +- [ ] Calling `logger.success()` or `logger.error()` with `startTime`? +- [ ] Passing relevant metadata for debugging? - All shared types, interfaces, and constants are centralized in @lfx-one/shared package - **AI Service Integration**: Claude Sonnet 4 model via LiteLLM proxy for meeting agenda generation - **AI Environment Variables**: AI_PROXY_URL and AI_API_KEY required for AI functionality @@ -128,7 +326,7 @@ lfx-v2-ui/ - **License headers are required on all source files** - run `./check-headers.sh` to verify - **Pre-commit hooks enforce license headers** - commits will fail without proper headers - Always run yarn format from the root of the project to ensure formatting is done after you have made all your changes -- Always preprend "Generated with [Claude Code](https://claude.ai/code)" if you assisted with the code +- Always prepend "Generated with [Claude Code](https://claude.ai/code)" if you assisted with the code - Do not nest ternary expressions - Always run yarn lint before yarn build to validate your linting - The JIRA project key for this is LFXV2. All tickets associated to this repo should generally be in there. diff --git a/apps/lfx-one/src/app/modules/meetings/components/meeting-card/meeting-card.component.ts b/apps/lfx-one/src/app/modules/meetings/components/meeting-card/meeting-card.component.ts index 1b361b17..5e84bb44 100644 --- a/apps/lfx-one/src/app/modules/meetings/components/meeting-card/meeting-card.component.ts +++ b/apps/lfx-one/src/app/modules/meetings/components/meeting-card/meeting-card.component.ts @@ -473,7 +473,7 @@ export class MeetingCardComponent implements OnInit { private initAttachments(): Signal { return runInInjectionContext(this.injector, () => { - return toSignal(this.meetingService.getMeetingAttachments(this.meeting().uid).pipe(catchError(() => of([]))), { + return toSignal(this.meetingService.getMeetingAttachments(this.meetingInput().uid).pipe(catchError(() => of([]))), { initialValue: [], }); }); @@ -482,7 +482,7 @@ export class MeetingCardComponent implements OnInit { private initRecording(): void { runInInjectionContext(this.injector, () => { toSignal( - this.meetingService.getPastMeetingRecording(this.meeting().uid).pipe( + this.meetingService.getPastMeetingRecording(this.meetingInput().uid).pipe( catchError(() => of(null)), tap((recording) => this.recording.set(recording)) ), @@ -494,7 +494,7 @@ export class MeetingCardComponent implements OnInit { private initSummary(): void { runInInjectionContext(this.injector, () => { toSignal( - this.meetingService.getPastMeetingSummary(this.meeting().uid).pipe( + this.meetingService.getPastMeetingSummary(this.meetingInput().uid).pipe( catchError(() => of(null)), tap((summary) => this.summary.set(summary)) ), diff --git a/apps/lfx-one/src/server/controllers/analytics.controller.ts b/apps/lfx-one/src/server/controllers/analytics.controller.ts index fbc2e007..39648829 100644 --- a/apps/lfx-one/src/server/controllers/analytics.controller.ts +++ b/apps/lfx-one/src/server/controllers/analytics.controller.ts @@ -4,7 +4,7 @@ import { NextFunction, Request, Response } from 'express'; import { AuthenticationError, ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { OrganizationService } from '../services/organization.service'; import { ProjectService } from '../services/project.service'; import { UserService } from '../services/user.service'; @@ -30,7 +30,7 @@ export class AnalyticsController { * Get active weeks streak data for the authenticated user */ public async getActiveWeeksStreak(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_active_weeks_streak'); + const startTime = logger.startOperation(req, 'get_active_weeks_streak'); try { const userEmail = req.oidc?.user?.['email']; @@ -43,14 +43,14 @@ export class AnalyticsController { const response = await this.userService.getActiveWeeksStreak(userEmail); - Logger.success(req, 'get_active_weeks_streak', startTime, { + logger.success(req, 'get_active_weeks_streak', startTime, { total_weeks: response.totalWeeks, current_streak: response.currentStreak, }); res.json(response); } catch (error) { - Logger.error(req, 'get_active_weeks_streak', startTime, error); + logger.error(req, 'get_active_weeks_streak', startTime, error); next(error); } } @@ -60,7 +60,7 @@ export class AnalyticsController { * Get pull requests merged activity data for the authenticated user */ public async getPullRequestsMerged(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_pull_requests_merged'); + const startTime = logger.startOperation(req, 'get_pull_requests_merged'); try { const userEmail = req.oidc?.user?.['email']; @@ -73,14 +73,14 @@ export class AnalyticsController { const response = await this.userService.getPullRequestsMerged(userEmail); - Logger.success(req, 'get_pull_requests_merged', startTime, { + logger.success(req, 'get_pull_requests_merged', startTime, { total_days: response.totalDays, total_pull_requests: response.totalPullRequests, }); res.json(response); } catch (error) { - Logger.error(req, 'get_pull_requests_merged', startTime, error); + logger.error(req, 'get_pull_requests_merged', startTime, error); next(error); } } @@ -90,7 +90,7 @@ export class AnalyticsController { * Get code commits activity data for the authenticated user */ public async getCodeCommits(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_code_commits'); + const startTime = logger.startOperation(req, 'get_code_commits'); try { const userEmail = req.oidc?.user?.['email']; @@ -103,14 +103,14 @@ export class AnalyticsController { const response = await this.userService.getCodeCommits(userEmail); - Logger.success(req, 'get_code_commits', startTime, { + logger.success(req, 'get_code_commits', startTime, { total_days: response.totalDays, total_commits: response.totalCommits, }); res.json(response); } catch (error) { - Logger.error(req, 'get_code_commits', startTime, error); + logger.error(req, 'get_code_commits', startTime, error); next(error); } } @@ -120,7 +120,7 @@ export class AnalyticsController { * Get user's projects with activity data */ public async getMyProjects(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_my_projects'); + const startTime = logger.startOperation(req, 'get_my_projects'); try { // Get LF username from OIDC context @@ -134,14 +134,14 @@ export class AnalyticsController { const response = await this.userService.getMyProjects(lfUsername); - Logger.success(req, 'get_my_projects', startTime, { + logger.success(req, 'get_my_projects', startTime, { returned_projects: response.data.length, total_projects: response.totalProjects, }); res.json(response); } catch (error) { - Logger.error(req, 'get_my_projects', startTime, error); + logger.error(req, 'get_my_projects', startTime, error); next(error); } } @@ -152,7 +152,7 @@ export class AnalyticsController { * Query params: accountId (required) - Organization account ID, foundationSlug (required) - Foundation slug */ public async getCertifiedEmployees(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_certified_employees'); + const startTime = logger.startOperation(req, 'get_certified_employees'); try { const accountId = req.query['accountId'] as string | undefined; @@ -172,7 +172,7 @@ export class AnalyticsController { const response = await this.organizationService.getCertifiedEmployees(accountId, foundationSlug); - Logger.success(req, 'get_certified_employees', startTime, { + logger.success(req, 'get_certified_employees', startTime, { account_id: accountId, foundation_slug: foundationSlug, total_certifications: response.certifications, @@ -182,7 +182,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_certified_employees', startTime, error); + logger.error(req, 'get_certified_employees', startTime, error); next(error); } } @@ -193,7 +193,7 @@ export class AnalyticsController { * Query params: accountId (required) - Organization account ID, projectSlug (required) - Foundation project slug */ public async getMembershipTier(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_membership_tier'); + const startTime = logger.startOperation(req, 'get_membership_tier'); try { const accountId = req.query['accountId'] as string | undefined; @@ -213,7 +213,7 @@ export class AnalyticsController { const response = await this.organizationService.getMembershipTier(accountId, projectSlug); - Logger.success(req, 'get_membership_tier', startTime, { + logger.success(req, 'get_membership_tier', startTime, { account_id: accountId, project_slug: projectSlug, membership_tier: response.membershipTier, @@ -222,7 +222,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_membership_tier', startTime, error); + logger.error(req, 'get_membership_tier', startTime, error); next(error); } } @@ -233,7 +233,7 @@ export class AnalyticsController { * Query params: accountId (required) - Organization account ID, foundationSlug (required) - Foundation slug */ public async getOrganizationMaintainers(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_organization_maintainers'); + const startTime = logger.startOperation(req, 'get_organization_maintainers'); try { const accountId = req.query['accountId'] as string | undefined; @@ -253,7 +253,7 @@ export class AnalyticsController { const response = await this.organizationService.getOrganizationMaintainers(accountId, foundationSlug); - Logger.success(req, 'get_organization_maintainers', startTime, { + logger.success(req, 'get_organization_maintainers', startTime, { account_id: accountId, foundation_slug: foundationSlug, maintainers: response.maintainers, @@ -263,7 +263,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_organization_maintainers', startTime, error); + logger.error(req, 'get_organization_maintainers', startTime, error); next(error); } } @@ -274,7 +274,7 @@ export class AnalyticsController { * Query params: accountId (required) - Organization account ID, foundationSlug (required) - Foundation slug */ public async getOrganizationContributors(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_organization_contributors'); + const startTime = logger.startOperation(req, 'get_organization_contributors'); try { const accountId = req.query['accountId'] as string | undefined; @@ -294,7 +294,7 @@ export class AnalyticsController { const response = await this.organizationService.getOrganizationContributors(accountId, foundationSlug); - Logger.success(req, 'get_organization_contributors', startTime, { + logger.success(req, 'get_organization_contributors', startTime, { account_id: accountId, foundation_slug: foundationSlug, total_active_contributors: response.contributors, @@ -303,7 +303,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_organization_contributors', startTime, error); + logger.error(req, 'get_organization_contributors', startTime, error); next(error); } } @@ -314,7 +314,7 @@ export class AnalyticsController { * Query params: accountId (required) - Organization account ID, projectSlug (required) - Foundation project slug */ public async getTrainingEnrollments(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_training_enrollments'); + const startTime = logger.startOperation(req, 'get_training_enrollments'); try { const accountId = req.query['accountId'] as string | undefined; @@ -334,7 +334,7 @@ export class AnalyticsController { const response = await this.organizationService.getTrainingEnrollments(accountId, projectSlug); - Logger.success(req, 'get_training_enrollments', startTime, { + logger.success(req, 'get_training_enrollments', startTime, { account_id: accountId, project_slug: projectSlug, total_enrollments: response.totalEnrollments, @@ -343,7 +343,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_training_enrollments', startTime, error); + logger.error(req, 'get_training_enrollments', startTime, error); next(error); } } @@ -354,7 +354,7 @@ export class AnalyticsController { * Query params: accountId (required) - Organization account ID, foundationSlug (required) - Foundation slug */ public async getEventAttendanceMonthly(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_event_attendance_monthly'); + const startTime = logger.startOperation(req, 'get_event_attendance_monthly'); try { const accountId = req.query['accountId'] as string | undefined; @@ -374,7 +374,7 @@ export class AnalyticsController { const response = await this.organizationService.getEventAttendanceMonthly(accountId, foundationSlug); - Logger.success(req, 'get_event_attendance_monthly', startTime, { + logger.success(req, 'get_event_attendance_monthly', startTime, { account_id: accountId, foundation_slug: foundationSlug, total_attended: response.totalAttended, @@ -384,7 +384,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_event_attendance_monthly', startTime, error); + logger.error(req, 'get_event_attendance_monthly', startTime, error); next(error); } } @@ -395,7 +395,7 @@ export class AnalyticsController { * Query params: slug (required), entityType (required) * */ public async getProjectIssuesResolution(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_project_issues_resolution'); + const startTime = logger.startOperation(req, 'get_project_issues_resolution'); try { const slug = req.query['slug'] as string | undefined; @@ -422,7 +422,7 @@ export class AnalyticsController { const response = await this.projectService.getProjectIssuesResolution(slug, entityType); - Logger.success(req, 'get_project_issues_resolution', startTime, { + logger.success(req, 'get_project_issues_resolution', startTime, { slug, entity_type: entityType, total_days: response.totalDays, @@ -434,7 +434,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_project_issues_resolution', startTime, error); + logger.error(req, 'get_project_issues_resolution', startTime, error); next(error); } } @@ -445,7 +445,7 @@ export class AnalyticsController { * Query params: slug (required), entityType (required) * */ public async getProjectPullRequestsWeekly(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_project_pull_requests_weekly'); + const startTime = logger.startOperation(req, 'get_project_pull_requests_weekly'); try { const slug = req.query['slug'] as string | undefined; @@ -472,7 +472,7 @@ export class AnalyticsController { const response = await this.projectService.getProjectPullRequestsWeekly(slug, entityType); - Logger.success(req, 'get_project_pull_requests_weekly', startTime, { + logger.success(req, 'get_project_pull_requests_weekly', startTime, { slug, entity_type: entityType, total_weeks: response.totalWeeks, @@ -482,7 +482,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_project_pull_requests_weekly', startTime, error); + logger.error(req, 'get_project_pull_requests_weekly', startTime, error); next(error); } } @@ -493,7 +493,7 @@ export class AnalyticsController { * Query params: slug (required) - Foundation slug for filtering */ public async getContributorsMentored(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_contributors_mentored'); + const startTime = logger.startOperation(req, 'get_contributors_mentored'); try { const slug = req.query['slug'] as string | undefined; @@ -506,7 +506,7 @@ export class AnalyticsController { const response = await this.projectService.getContributorsMentored(slug); - Logger.success(req, 'get_contributors_mentored', startTime, { + logger.success(req, 'get_contributors_mentored', startTime, { slug, total_mentored: response.totalMentored, avg_weekly_new: response.avgWeeklyNew, @@ -515,7 +515,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_contributors_mentored', startTime, error); + logger.error(req, 'get_contributors_mentored', startTime, error); next(error); } } @@ -526,7 +526,7 @@ export class AnalyticsController { * Query params: slug (required), entityType (required) */ public async getUniqueContributorsWeekly(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_unique_contributors_weekly'); + const startTime = logger.startOperation(req, 'get_unique_contributors_weekly'); try { const slug = req.query['slug'] as string | undefined; @@ -553,7 +553,7 @@ export class AnalyticsController { const response = await this.projectService.getUniqueContributorsWeekly(slug, entityType); - Logger.success(req, 'get_unique_contributors_weekly', startTime, { + logger.success(req, 'get_unique_contributors_weekly', startTime, { slug, entity_type: entityType, total_weeks: response.totalWeeks, @@ -563,7 +563,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_unique_contributors_weekly', startTime, error); + logger.error(req, 'get_unique_contributors_weekly', startTime, error); next(error); } } @@ -574,7 +574,7 @@ export class AnalyticsController { * Query params: foundationSlug (required) */ public async getFoundationTotalProjects(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_foundation_total_projects'); + const startTime = logger.startOperation(req, 'get_foundation_total_projects'); try { const foundationSlug = req.query['foundationSlug'] as string | undefined; @@ -587,7 +587,7 @@ export class AnalyticsController { const response = await this.projectService.getFoundationTotalProjects(foundationSlug); - Logger.success(req, 'get_foundation_total_projects', startTime, { + logger.success(req, 'get_foundation_total_projects', startTime, { foundation_slug: foundationSlug, total_projects: response.totalProjects, monthly_data_points: response.monthlyData.length, @@ -595,7 +595,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_foundation_total_projects', startTime, error); + logger.error(req, 'get_foundation_total_projects', startTime, error); next(error); } } @@ -606,7 +606,7 @@ export class AnalyticsController { * Query params: foundationSlug (required) */ public async getFoundationTotalMembers(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_foundation_total_members'); + const startTime = logger.startOperation(req, 'get_foundation_total_members'); try { const foundationSlug = req.query['foundationSlug'] as string | undefined; @@ -619,7 +619,7 @@ export class AnalyticsController { const response = await this.projectService.getFoundationTotalMembers(foundationSlug); - Logger.success(req, 'get_foundation_total_members', startTime, { + logger.success(req, 'get_foundation_total_members', startTime, { foundation_slug: foundationSlug, total_members: response.totalMembers, monthly_data_points: response.monthlyData.length, @@ -627,7 +627,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_foundation_total_members', startTime, error); + logger.error(req, 'get_foundation_total_members', startTime, error); next(error); } } @@ -638,7 +638,7 @@ export class AnalyticsController { * Query params: foundationSlug (required) */ public async getFoundationSoftwareValue(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_foundation_software_value'); + const startTime = logger.startOperation(req, 'get_foundation_software_value'); try { const foundationSlug = req.query['foundationSlug'] as string | undefined; @@ -651,7 +651,7 @@ export class AnalyticsController { const response = await this.projectService.getFoundationSoftwareValue(foundationSlug); - Logger.success(req, 'get_foundation_software_value', startTime, { + logger.success(req, 'get_foundation_software_value', startTime, { foundation_slug: foundationSlug, total_value_millions: response.totalValue, top_projects_count: response.topProjects.length, @@ -659,7 +659,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_foundation_software_value', startTime, error); + logger.error(req, 'get_foundation_software_value', startTime, error); next(error); } } @@ -670,7 +670,7 @@ export class AnalyticsController { * Query params: foundationSlug (required) */ public async getFoundationMaintainers(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_foundation_maintainers'); + const startTime = logger.startOperation(req, 'get_foundation_maintainers'); try { const foundationSlug = req.query['foundationSlug'] as string | undefined; @@ -683,7 +683,7 @@ export class AnalyticsController { const response = await this.projectService.getFoundationMaintainers(foundationSlug); - Logger.success(req, 'get_foundation_maintainers', startTime, { + logger.success(req, 'get_foundation_maintainers', startTime, { foundation_slug: foundationSlug, avg_maintainers: response.avgMaintainers, trend_data_points: response.trendData.length, @@ -691,7 +691,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_foundation_maintainers', startTime, error); + logger.error(req, 'get_foundation_maintainers', startTime, error); next(error); } } @@ -702,7 +702,7 @@ export class AnalyticsController { * Query params: foundationSlug (required) */ public async getFoundationHealthScoreDistribution(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_foundation_health_score_distribution'); + const startTime = logger.startOperation(req, 'get_foundation_health_score_distribution'); try { const foundationSlug = req.query['foundationSlug'] as string | undefined; @@ -717,7 +717,7 @@ export class AnalyticsController { const totalProjects = Object.values(response).reduce((sum, count) => sum + count, 0); - Logger.success(req, 'get_foundation_health_score_distribution', startTime, { + logger.success(req, 'get_foundation_health_score_distribution', startTime, { foundation_slug: foundationSlug, total_projects: totalProjects, excellent: response.excellent, @@ -729,7 +729,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_foundation_health_score_distribution', startTime, error); + logger.error(req, 'get_foundation_health_score_distribution', startTime, error); next(error); } } @@ -740,7 +740,7 @@ export class AnalyticsController { * Query params: foundationSlug (required) */ public async getCompanyBusFactor(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_company_bus_factor'); + const startTime = logger.startOperation(req, 'get_company_bus_factor'); try { const foundationSlug = req.query['foundationSlug'] as string | undefined; @@ -753,7 +753,7 @@ export class AnalyticsController { const response = await this.organizationService.getCompanyBusFactor(foundationSlug); - Logger.success(req, 'get_company_bus_factor', startTime, { + logger.success(req, 'get_company_bus_factor', startTime, { foundation_slug: foundationSlug, top_companies_count: response.topCompaniesCount, top_companies_percentage: response.topCompaniesPercentage, @@ -761,7 +761,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_company_bus_factor', startTime, error); + logger.error(req, 'get_company_bus_factor', startTime, error); next(error); } } @@ -772,7 +772,7 @@ export class AnalyticsController { * Query params: slug (required), entityType (required) */ public async getHealthMetricsDaily(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_health_metrics_daily'); + const startTime = logger.startOperation(req, 'get_health_metrics_daily'); try { const slug = req.query['slug'] as string | undefined; @@ -799,7 +799,7 @@ export class AnalyticsController { const response = await this.projectService.getHealthMetricsDaily(slug, entityType); - Logger.success(req, 'get_health_metrics_daily', startTime, { + logger.success(req, 'get_health_metrics_daily', startTime, { slug, entity_type: entityType, total_days: response.totalDays, @@ -808,7 +808,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_health_metrics_daily', startTime, error); + logger.error(req, 'get_health_metrics_daily', startTime, error); next(error); } } @@ -819,7 +819,7 @@ export class AnalyticsController { * Query params: slug (required), entityType (required) */ public async getUniqueContributorsDaily(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_unique_contributors_daily'); + const startTime = logger.startOperation(req, 'get_unique_contributors_daily'); try { const slug = req.query['slug'] as string | undefined; @@ -846,7 +846,7 @@ export class AnalyticsController { const response = await this.projectService.getUniqueContributorsDaily(slug, entityType); - Logger.success(req, 'get_unique_contributors_daily', startTime, { + logger.success(req, 'get_unique_contributors_daily', startTime, { slug, entity_type: entityType, total_days: response.totalDays, @@ -855,7 +855,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_unique_contributors_daily', startTime, error); + logger.error(req, 'get_unique_contributors_daily', startTime, error); next(error); } } @@ -866,7 +866,7 @@ export class AnalyticsController { * Query params: slug (required), entityType (required) */ public async getHealthEventsMonthly(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_health_events_monthly'); + const startTime = logger.startOperation(req, 'get_health_events_monthly'); try { const slug = req.query['slug'] as string | undefined; @@ -893,7 +893,7 @@ export class AnalyticsController { const response = await this.projectService.getHealthEventsMonthly(slug, entityType); - Logger.success(req, 'get_health_events_monthly', startTime, { + logger.success(req, 'get_health_events_monthly', startTime, { slug, entity_type: entityType, total_months: response.totalMonths, @@ -902,7 +902,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_health_events_monthly', startTime, error); + logger.error(req, 'get_health_events_monthly', startTime, error); next(error); } } @@ -913,7 +913,7 @@ export class AnalyticsController { * Query params: slug (required), entityType (required) */ public async getCodeCommitsDaily(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_code_commits_daily'); + const startTime = logger.startOperation(req, 'get_code_commits_daily'); try { const slug = req.query['slug'] as string | undefined; @@ -940,7 +940,7 @@ export class AnalyticsController { const response = await this.projectService.getCodeCommitsDaily(slug, entityType); - Logger.success(req, 'get_code_commits_daily', startTime, { + logger.success(req, 'get_code_commits_daily', startTime, { slug, entity_type: entityType, total_days: response.totalDays, @@ -949,7 +949,7 @@ export class AnalyticsController { res.json(response); } catch (error) { - Logger.error(req, 'get_code_commits_daily', startTime, error); + logger.error(req, 'get_code_commits_daily', startTime, error); next(error); } } diff --git a/apps/lfx-one/src/server/controllers/committee.controller.ts b/apps/lfx-one/src/server/controllers/committee.controller.ts index 88a2d256..ee0ea001 100644 --- a/apps/lfx-one/src/server/controllers/committee.controller.ts +++ b/apps/lfx-one/src/server/controllers/committee.controller.ts @@ -5,7 +5,7 @@ import { CommitteeCreateData, CommitteeUpdateData, CreateCommitteeMemberRequest import { NextFunction, Request, Response } from 'express'; import { ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { CommitteeService } from '../services/committee.service'; /** @@ -18,20 +18,19 @@ export class CommitteeController { * GET /committees */ public async getCommittees(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_committees', { - query_params: Logger.sanitize(req.query as Record), + const startTime = logger.startOperation(req, 'get_committees', { + query_params: logger.sanitize(req.query as Record), }); try { const committees = await this.committeeService.getCommittees(req, req.query); - Logger.success(req, 'get_committees', startTime, { + logger.success(req, 'get_committees', startTime, { committee_count: committees.length, }); res.json(committees); } catch (error) { - Logger.error(req, 'get_committees', startTime, error); next(error); } } @@ -40,20 +39,19 @@ export class CommitteeController { * GET /committees/count */ public async getCommitteesCount(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_committees_count', { - query_params: Logger.sanitize(req.query as Record), + const startTime = logger.startOperation(req, 'get_committees_count', { + query_params: logger.sanitize(req.query as Record), }); try { const count = await this.committeeService.getCommitteesCount(req, req.query); - Logger.success(req, 'get_committees_count', startTime, { + logger.success(req, 'get_committees_count', startTime, { count, }); res.json({ count }); } catch (error) { - Logger.error(req, 'get_committees_count', startTime, error); next(error); } } @@ -63,16 +61,13 @@ export class CommitteeController { */ public async getCommitteeById(req: Request, res: Response, next: NextFunction): Promise { const { id } = req.params; - const startTime = Logger.start(req, 'get_committee_by_id', { + const startTime = logger.startOperation(req, 'get_committee_by_id', { committee_id: id, }); try { // Check if the committee ID is provided if (!id) { - // Log the error - Logger.error(req, 'get_committee_by_id', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'get_committee_by_id', @@ -88,7 +83,7 @@ export class CommitteeController { const committee = await this.committeeService.getCommitteeById(req, id); // Log the success - Logger.success(req, 'get_committee_by_id', startTime, { + logger.success(req, 'get_committee_by_id', startTime, { committee_id: id, committee_category: committee.category, }); @@ -96,11 +91,6 @@ export class CommitteeController { // Send the committee data to the client res.json(committee); } catch (error) { - // Log the error - Logger.error(req, 'get_committee_by_id', startTime, error, { - committee_id: id, - }); - // Send the error to the next middleware next(error); } @@ -110,8 +100,8 @@ export class CommitteeController { * POST /committees */ public async createCommittee(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'create_committee', { - committee_data: Logger.sanitize(req.body), + const startTime = logger.startOperation(req, 'create_committee', { + committee_data: logger.sanitize(req.body), }); try { @@ -120,7 +110,7 @@ export class CommitteeController { const newCommittee = await this.committeeService.createCommittee(req, committeeData); // Log the success - Logger.success(req, 'create_committee', startTime, { + logger.success(req, 'create_committee', startTime, { committee_id: newCommittee.uid, committee_category: newCommittee.category, }); @@ -128,9 +118,6 @@ export class CommitteeController { // Send the new committee data to the client res.status(201).json(newCommittee); } catch (error) { - // Log the error - Logger.error(req, 'create_committee', startTime, error); - // Send the error to the next middleware next(error); } @@ -141,16 +128,14 @@ export class CommitteeController { */ public async updateCommittee(req: Request, res: Response, next: NextFunction): Promise { const { id } = req.params; - const startTime = Logger.start(req, 'update_committee', { + const startTime = logger.startOperation(req, 'update_committee', { committee_id: id, - update_data: Logger.sanitize(req.body), + update_data: logger.sanitize(req.body), }); try { // Check if the committee ID is provided if (!id) { - Logger.error(req, 'update_committee', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'update_committee', @@ -170,16 +155,13 @@ export class CommitteeController { const updatedCommittee = await this.committeeService.updateCommittee(req, id, updateData); // Log the success - Logger.success(req, 'update_committee', startTime, { + logger.success(req, 'update_committee', startTime, { committee_id: id, }); // Send the updated committee data to the client res.json(updatedCommittee); } catch (error) { - Logger.error(req, 'update_committee', startTime, error, { - committee_id: id, - }); next(error); } } @@ -189,15 +171,13 @@ export class CommitteeController { */ public async deleteCommittee(req: Request, res: Response, next: NextFunction): Promise { const { id } = req.params; - const startTime = Logger.start(req, 'delete_committee', { + const startTime = logger.startOperation(req, 'delete_committee', { committee_id: id, }); try { // Check if the committee ID is provided if (!id) { - Logger.error(req, 'delete_committee', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'delete_committee', @@ -214,18 +194,13 @@ export class CommitteeController { await this.committeeService.deleteCommittee(req, id); // Log the success - Logger.success(req, 'delete_committee', startTime, { + logger.success(req, 'delete_committee', startTime, { committee_id: id, }); // Send the response to the client res.status(204).send(); } catch (error) { - // Log the error - Logger.error(req, 'delete_committee', startTime, error, { - committee_id: id, - }); - // Send the error to the next middleware next(error); } @@ -236,16 +211,14 @@ export class CommitteeController { */ public async getCommitteeMembers(req: Request, res: Response, next: NextFunction): Promise { const { id } = req.params; - const startTime = Logger.start(req, 'get_committee_members', { + const startTime = logger.startOperation(req, 'get_committee_members', { committee_id: id, - query_params: Logger.sanitize(req.query as Record), + query_params: logger.sanitize(req.query as Record), }); try { // Check if the committee ID is provided if (!id) { - Logger.error(req, 'get_committee_members', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'get_committee_members', @@ -262,7 +235,7 @@ export class CommitteeController { const members = await this.committeeService.getCommitteeMembers(req, id, req.query); // Log the success - Logger.success(req, 'get_committee_members', startTime, { + logger.success(req, 'get_committee_members', startTime, { committee_id: id, member_count: members.length, }); @@ -270,11 +243,6 @@ export class CommitteeController { // Send the members data to the client res.json(members); } catch (error) { - // Log the error - Logger.error(req, 'get_committee_members', startTime, error, { - committee_id: id, - }); - // Send the error to the next middleware next(error); } @@ -285,7 +253,7 @@ export class CommitteeController { */ public async getCommitteeMemberById(req: Request, res: Response, next: NextFunction): Promise { const { id, memberId } = req.params; - const startTime = Logger.start(req, 'get_committee_member_by_id', { + const startTime = logger.startOperation(req, 'get_committee_member_by_id', { committee_id: id, member_id: memberId, }); @@ -293,8 +261,6 @@ export class CommitteeController { try { // Check if the committee ID is provided if (!id) { - Logger.error(req, 'get_committee_member_by_id', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'get_committee_member_by_id', @@ -309,8 +275,6 @@ export class CommitteeController { // Check if the member ID is provided if (!memberId) { - Logger.error(req, 'get_committee_member_by_id', startTime, new Error('Missing member ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('memberId', 'Member ID is required', { operation: 'get_committee_member_by_id', @@ -327,7 +291,7 @@ export class CommitteeController { const member = await this.committeeService.getCommitteeMemberById(req, id, memberId); // Log the success - Logger.success(req, 'get_committee_member_by_id', startTime, { + logger.success(req, 'get_committee_member_by_id', startTime, { committee_id: id, member_id: memberId, }); @@ -335,12 +299,6 @@ export class CommitteeController { // Send the member data to the client res.json(member); } catch (error) { - // Log the error - Logger.error(req, 'get_committee_member_by_id', startTime, error, { - committee_id: id, - member_id: memberId, - }); - // Send the error to the next middleware next(error); } @@ -351,16 +309,14 @@ export class CommitteeController { */ public async createCommitteeMember(req: Request, res: Response, next: NextFunction): Promise { const { id } = req.params; - const startTime = Logger.start(req, 'create_committee_member', { + const startTime = logger.startOperation(req, 'create_committee_member', { committee_id: id, - member_data: Logger.sanitize(req.body), + member_data: logger.sanitize(req.body), }); try { // Check if the committee ID is provided if (!id) { - Logger.error(req, 'create_committee_member', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'create_committee_member', @@ -380,7 +336,7 @@ export class CommitteeController { const newMember = await this.committeeService.createCommitteeMember(req, id, memberData); // Log the success - Logger.success(req, 'create_committee_member', startTime, { + logger.success(req, 'create_committee_member', startTime, { committee_id: id, member_id: newMember.uid, }); @@ -388,11 +344,6 @@ export class CommitteeController { // Send the new member data to the client res.status(201).json(newMember); } catch (error) { - // Log the error - Logger.error(req, 'create_committee_member', startTime, error, { - committee_id: id, - }); - // Send the error to the next middleware next(error); } @@ -403,17 +354,15 @@ export class CommitteeController { */ public async updateCommitteeMember(req: Request, res: Response, next: NextFunction): Promise { const { id, memberId } = req.params; - const startTime = Logger.start(req, 'update_committee_member', { + const startTime = logger.startOperation(req, 'update_committee_member', { committee_id: id, member_id: memberId, - update_data: Logger.sanitize(req.body), + update_data: logger.sanitize(req.body), }); try { // Check if the committee ID is provided if (!id) { - Logger.error(req, 'update_committee_member', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'update_committee_member', @@ -428,8 +377,6 @@ export class CommitteeController { // Check if the member ID is provided if (!memberId) { - Logger.error(req, 'update_committee_member', startTime, new Error('Missing member ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('memberId', 'Member ID is required', { operation: 'update_committee_member', @@ -449,7 +396,7 @@ export class CommitteeController { const updatedMember = await this.committeeService.updateCommitteeMember(req, id, memberId, updateData); // Log the success - Logger.success(req, 'update_committee_member', startTime, { + logger.success(req, 'update_committee_member', startTime, { committee_id: id, member_id: memberId, }); @@ -457,11 +404,6 @@ export class CommitteeController { // Send the updated member data to the client res.json(updatedMember); } catch (error) { - // Log the error - Logger.error(req, 'update_committee_member', startTime, error, { - committee_id: id, - member_id: memberId, - }); next(error); } } @@ -471,7 +413,7 @@ export class CommitteeController { */ public async deleteCommitteeMember(req: Request, res: Response, next: NextFunction): Promise { const { id, memberId } = req.params; - const startTime = Logger.start(req, 'delete_committee_member', { + const startTime = logger.startOperation(req, 'delete_committee_member', { committee_id: id, member_id: memberId, }); @@ -479,8 +421,6 @@ export class CommitteeController { try { // Check if the committee ID is provided if (!id) { - Logger.error(req, 'delete_committee_member', startTime, new Error('Missing committee ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('id', 'Committee ID is required', { operation: 'delete_committee_member', @@ -495,8 +435,6 @@ export class CommitteeController { // Check if the member ID is provided if (!memberId) { - Logger.error(req, 'delete_committee_member', startTime, new Error('Missing member ID parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('memberId', 'Member ID is required', { operation: 'delete_committee_member', @@ -513,7 +451,7 @@ export class CommitteeController { await this.committeeService.deleteCommitteeMember(req, id, memberId); // Log the success - Logger.success(req, 'delete_committee_member', startTime, { + logger.success(req, 'delete_committee_member', startTime, { committee_id: id, member_id: memberId, }); @@ -521,12 +459,6 @@ export class CommitteeController { // Send the response to the client res.status(204).send(); } catch (error) { - // Log the error - Logger.error(req, 'delete_committee_member', startTime, error, { - committee_id: id, - member_id: memberId, - }); - // Send the error to the next middleware next(error); } diff --git a/apps/lfx-one/src/server/controllers/meeting.controller.ts b/apps/lfx-one/src/server/controllers/meeting.controller.ts index add31406..032335f1 100644 --- a/apps/lfx-one/src/server/controllers/meeting.controller.ts +++ b/apps/lfx-one/src/server/controllers/meeting.controller.ts @@ -6,15 +6,17 @@ import { CreateMeetingRegistrantRequest, CreateMeetingRequest, CreateMeetingRsvpRequest, + GenerateAgendaResponse, UpdateMeetingRegistrantRequest, UpdateMeetingRequest, } from '@lfx-one/shared/interfaces'; import { NextFunction, Request, Response } from 'express'; import { ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; import { addInvitedStatusToMeeting, addInvitedStatusToMeetings } from '../helpers/meeting.helper'; +import { logger } from '../services/logger.service'; import { validateUidParameter } from '../helpers/validation.helper'; +import { AiService } from '../services/ai.service'; import { MeetingService } from '../services/meeting.service'; /** @@ -22,13 +24,14 @@ import { MeetingService } from '../services/meeting.service'; */ export class MeetingController { private meetingService: MeetingService = new MeetingService(); + private aiService: AiService = new AiService(); /** * GET /meetings */ public async getMeetings(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_meetings', { - query_params: Logger.sanitize(req.query as Record), + const startTime = logger.startOperation(req, 'get_meetings', { + query_params: logger.sanitize(req.query as Record), }); try { @@ -72,7 +75,7 @@ export class MeetingController { }); // Log the success - Logger.success(req, 'get_meetings', startTime, { + logger.success(req, 'get_meetings', startTime, { meeting_count: meetings.length, regular_meeting_count: regularMeetings.length, v1_meeting_count: v1Meetings.length, @@ -81,8 +84,6 @@ export class MeetingController { // Send the meetings data to the client res.json(invitedMeetings); } catch (error) { - // Log the error - Logger.error(req, 'get_meetings', startTime, error); next(error); } } @@ -91,8 +92,8 @@ export class MeetingController { * GET /meetings/count */ public async getMeetingsCount(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_meetings_count', { - query_params: Logger.sanitize(req.query as Record), + const startTime = logger.startOperation(req, 'get_meetings_count', { + query_params: logger.sanitize(req.query as Record), }); try { @@ -100,15 +101,13 @@ export class MeetingController { const count = await this.meetingService.getMeetingsCount(req, req.query as Record); // Log the success - Logger.success(req, 'get_meetings_count', startTime, { + logger.success(req, 'get_meetings_count', startTime, { count, }); // Send the count to the client res.json({ count }); } catch (error) { - // Log the error - Logger.error(req, 'get_meetings_count', startTime, error); next(error); } } @@ -118,7 +117,7 @@ export class MeetingController { */ public async getMeetingById(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_meeting_by_id', { + const startTime = logger.startOperation(req, 'get_meeting_by_id', { meeting_uid: uid, }); @@ -138,7 +137,7 @@ export class MeetingController { const meeting = await this.meetingService.getMeetingById(req, uid); // Log the success - Logger.success(req, 'get_meeting_by_id', startTime, { + logger.success(req, 'get_meeting_by_id', startTime, { meeting_uid: uid, project_uid: meeting.project_uid, title: meeting.title, @@ -152,8 +151,8 @@ export class MeetingController { meeting.individual_registrants_count = registrants.length - committeeMembers; meeting.committee_members_count = committeeMembers; } catch (error) { - // Log the error - Logger.error(req, 'get_meeting_by_id', startTime, error, { + // Log the error for registrants fetch failure + logger.error(req, 'get_meeting_by_id', startTime, error, { meeting_uid: uid, }); } @@ -165,11 +164,6 @@ export class MeetingController { // Send the meeting data to the client res.json(meetingWithInvitedStatus); } catch (error) { - // Log the error - Logger.error(req, 'get_meeting_by_id', startTime, error, { - meeting_uid: uid, - }); - // Send the error to the next middleware next(error); } @@ -180,7 +174,7 @@ export class MeetingController { */ public async createMeeting(req: Request, res: Response, next: NextFunction): Promise { const meetingData: CreateMeetingRequest = req.body; - const startTime = Logger.start(req, 'create_meeting', { + const startTime = logger.startOperation(req, 'create_meeting', { project_uid: meetingData?.project_uid, title: meetingData?.title, start_time: meetingData?.start_time, @@ -194,7 +188,7 @@ export class MeetingController { const meeting = await this.meetingService.createMeeting(req, meetingData); // Log the success - Logger.success(req, 'create_meeting', startTime, { + logger.success(req, 'create_meeting', startTime, { meeting_id: meeting.uid, project_uid: meeting.project_uid, title: meeting.title, @@ -203,11 +197,6 @@ export class MeetingController { // Send the new meeting data to the client res.status(201).json(meeting); } catch (error) { - // Log the error - Logger.error(req, 'create_meeting', startTime, error, { - project_uid: req.body?.project_uid, - }); - // Send the error to the next middleware next(error); } @@ -220,7 +209,7 @@ export class MeetingController { const { uid } = req.params; const meetingData: UpdateMeetingRequest = req.body; const { editType } = req.query; - const startTime = Logger.start(req, 'update_meeting', { + const startTime = logger.startOperation(req, 'update_meeting', { meeting_uid: uid, project_uid: meetingData?.project_uid, start_time: meetingData?.start_time, @@ -245,7 +234,7 @@ export class MeetingController { const meeting = await this.meetingService.updateMeeting(req, uid, meetingData, editType as 'single' | 'future'); // Log the success - Logger.success(req, 'update_meeting', startTime, { + logger.success(req, 'update_meeting', startTime, { meeting_uid: uid, project_uid: meeting.project_uid, title: meeting.title, @@ -255,12 +244,6 @@ export class MeetingController { // Send the updated meeting data to the client res.json(meeting); } catch (error) { - // Log the error - Logger.error(req, 'update_meeting', startTime, error, { - meeting_uid: uid, - edit_type: editType, - }); - // Send the error to the next middleware next(error); } @@ -271,7 +254,7 @@ export class MeetingController { */ public async deleteMeeting(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'delete_meeting', { + const startTime = logger.startOperation(req, 'delete_meeting', { meeting_uid: uid, }); @@ -291,7 +274,7 @@ export class MeetingController { await this.meetingService.deleteMeeting(req, uid); // Log the success - Logger.success(req, 'delete_meeting', startTime, { + logger.success(req, 'delete_meeting', startTime, { meeting_uid: uid, status_code: 204, }); @@ -299,11 +282,6 @@ export class MeetingController { // Send the response to the client res.status(204).send(); } catch (error) { - // Log the error - Logger.error(req, 'delete_meeting', startTime, error, { - meeting_uid: uid, - }); - // Send the error to the next middleware next(error); } @@ -314,7 +292,7 @@ export class MeetingController { */ public async cancelOccurrence(req: Request, res: Response, next: NextFunction): Promise { const { uid, occurrenceId } = req.params; - const startTime = Logger.start(req, 'cancel_occurrence', { + const startTime = logger.startOperation(req, 'cancel_occurrence', { meeting_uid: uid, occurrence_id: occurrenceId, }); @@ -338,11 +316,6 @@ export class MeetingController { service: 'meeting_controller', }); - Logger.error(req, 'cancel_occurrence', startTime, validationError, { - meeting_uid: uid, - occurrence_id: occurrenceId, - }); - return next(validationError); } @@ -350,7 +323,7 @@ export class MeetingController { await this.meetingService.cancelOccurrence(req, uid, occurrenceId); // Log the success - Logger.success(req, 'cancel_occurrence', startTime, { + logger.success(req, 'cancel_occurrence', startTime, { meeting_uid: uid, occurrence_id: occurrenceId, status_code: 204, @@ -359,12 +332,6 @@ export class MeetingController { // Send the response to the client res.status(204).send(); } catch (error) { - // Log the error - Logger.error(req, 'cancel_occurrence', startTime, error, { - meeting_uid: uid, - occurrence_id: occurrenceId, - }); - // Send the error to the next middleware next(error); } @@ -378,7 +345,7 @@ export class MeetingController { const { include_rsvp } = req.query; const includeRsvp = include_rsvp === 'true'; - const startTime = Logger.start(req, 'get_meeting_registrants', { + const startTime = logger.startOperation(req, 'get_meeting_registrants', { meeting_uid: uid, include_rsvp: includeRsvp, }); @@ -398,7 +365,7 @@ export class MeetingController { // Get the meeting registrants const registrants = await this.meetingService.getMeetingRegistrants(req, uid, includeRsvp); - Logger.success(req, 'get_meeting_registrants', startTime, { + logger.success(req, 'get_meeting_registrants', startTime, { meeting_uid: uid, registrant_count: registrants.length, include_rsvp: includeRsvp, @@ -407,12 +374,6 @@ export class MeetingController { // Send the registrants data to the client res.json(registrants); } catch (error) { - // Log the error - Logger.error(req, 'get_meeting_registrants', startTime, error, { - meeting_uid: uid, - include_rsvp: includeRsvp, - }); - // Send the error to the next middleware next(error); } @@ -430,7 +391,7 @@ export class MeetingController { meeting_uid: uid, })) || []; - const startTime = Logger.start(req, 'add_meeting_registrants', { + const startTime = logger.startOperation(req, 'add_meeting_registrants', { meeting_uid: uid, registrant_count: registrantData.length, body_size: JSON.stringify(req.body).length, @@ -439,8 +400,6 @@ export class MeetingController { try { // Check if the meeting UID is provided if (!uid) { - Logger.error(req, 'add_meeting_registrants', startTime, new Error('Missing meeting UID parameter')); - const validationError = ServiceValidationError.forField('uid', 'Meeting UID is required', { operation: 'add_meeting_registrants', service: 'meeting_controller', @@ -453,8 +412,6 @@ export class MeetingController { // Check if the registrants data is provided and is an array if (!Array.isArray(registrantData) || !registrantData.length) { - Logger.error(req, 'add_meeting_registrants', startTime, new Error('No registrants provided')); - // Create a validation error const validationError = ServiceValidationError.forField('registrants', 'No registrants provided', { operation: 'add_meeting_registrants', @@ -476,8 +433,7 @@ export class MeetingController { 'add_meeting_registrants', uid, registrantData, - (registrant) => this.meetingService.addMeetingRegistrant(req, registrant), - (registrant) => registrant.email + (registrant) => this.meetingService.addMeetingRegistrant(req, registrant) ); // If the processing should return, return @@ -487,7 +443,7 @@ export class MeetingController { const batchResponse = this.createBatchResponse(results, registrantData, req, startTime, 'add_meeting_registrants', uid, (registrant) => registrant.email); // Log the success - Logger.success(req, 'add_meeting_registrants', startTime, { + logger.success(req, 'add_meeting_registrants', startTime, { meeting_uid: uid, total_count: registrantData.length, successful_count: batchResponse.summary.successful, @@ -507,12 +463,6 @@ export class MeetingController { // Send the batch response to the client res.status(statusCode).json(batchResponse); } catch (error) { - // Log the error - Logger.error(req, 'add_meeting_registrants', startTime, error, { - meeting_uid: uid, - registrant_count: registrantData.length, - }); - // Send the error to the next middleware next(error); } @@ -533,7 +483,7 @@ export class MeetingController { }, })) || []; - const startTime = Logger.start(req, 'update_meeting_registrants', { + const startTime = logger.startOperation(req, 'update_meeting_registrants', { meeting_uid: uid, registrant_count: updateData.length, body_size: JSON.stringify(req.body).length, @@ -542,8 +492,6 @@ export class MeetingController { try { // Check if the meeting UID is provided if (!uid) { - Logger.error(req, 'update_meeting_registrants', startTime, new Error('Missing meeting UID parameter')); - const validationError = ServiceValidationError.forField('uid', 'Meeting UID is required', { operation: 'update_meeting_registrants', service: 'meeting_controller', @@ -556,8 +504,6 @@ export class MeetingController { // Check if the update data is provided and is an array if (!Array.isArray(updateData) || !updateData.length) { - Logger.error(req, 'update_meeting_registrants', startTime, new Error('No registrants provided')); - const validationError = ServiceValidationError.forField('registrants', 'No registrants provided', { operation: 'update_meeting_registrants', service: 'meeting_controller', @@ -570,10 +516,6 @@ export class MeetingController { // Check if the registrant UIDs are provided if (updateData.some((update) => !update.uid)) { - Logger.error(req, 'update_meeting_registrants', startTime, new Error('Missing registrant UIDs for update'), { - provided_uids: updateData.map((update) => update.uid).filter(Boolean), - }); - const validationError = ServiceValidationError.forField('registrants.uid', 'One or more registrants are missing UID', { operation: 'update_meeting_registrants', service: 'meeting_controller', @@ -585,15 +527,8 @@ export class MeetingController { } // Process updates with fail-fast for 403 errors - const { results, shouldReturn } = await this.processRegistrantOperations( - req, - next, - startTime, - 'update_meeting_registrants', - uid, - updateData, - (update) => this.meetingService.updateMeetingRegistrant(req, uid, update.uid, update.changes), - (update) => update.uid + const { results, shouldReturn } = await this.processRegistrantOperations(req, next, startTime, 'update_meeting_registrants', uid, updateData, (update) => + this.meetingService.updateMeetingRegistrant(req, uid, update.uid, update.changes) ); // If the processing should return, return @@ -603,7 +538,7 @@ export class MeetingController { const batchResponse = this.createBatchResponse(results, updateData, req, startTime, 'update_meeting_registrants', uid, (update) => update.uid); // Log the success - Logger.success(req, 'update_meeting_registrants', startTime, { + logger.success(req, 'update_meeting_registrants', startTime, { meeting_uid: uid, total_count: updateData.length, successful_count: batchResponse.summary.successful, @@ -623,12 +558,6 @@ export class MeetingController { // Send the batch response to the client res.status(statusCode).json(batchResponse); } catch (error) { - // Log the error - Logger.error(req, 'update_meeting_registrants', startTime, error, { - meeting_uid: uid, - registrant_count: updateData.length, - }); - // Send the error to the next middleware next(error); } @@ -642,7 +571,7 @@ export class MeetingController { const { uid } = req.params; const registrantsUid: string[] = req.body || []; - const startTime = Logger.start(req, 'delete_meeting_registrants', { + const startTime = logger.startOperation(req, 'delete_meeting_registrants', { meeting_uid: uid, registrant_count: registrantsUid.length, body_size: JSON.stringify(req.body).length, @@ -651,8 +580,6 @@ export class MeetingController { try { // Check if the meeting UID is provided if (!uid) { - Logger.error(req, 'delete_meeting_registrants', startTime, new Error('Missing meeting UID parameter')); - const validationError = ServiceValidationError.forField('uid', 'Meeting UID is required', { operation: 'delete_meeting_registrants', service: 'meeting_controller', @@ -665,7 +592,6 @@ export class MeetingController { // Check if the registrant UIDs are provided if (!registrantsUid.length) { - Logger.error(req, 'delete_meeting_registrants', startTime, new Error('Empty registrant UIDs array')); const validationError = ServiceValidationError.forField('registrantUids', 'Empty registrant UIDs array', { operation: 'delete_meeting_registrants', service: 'meeting_controller', @@ -678,10 +604,6 @@ export class MeetingController { // Check if the registrant UIDs are provided and is an array if (!Array.isArray(registrantsUid) || !registrantsUid.length || !req.body.every((item: string) => typeof item === 'string')) { - Logger.error(req, 'delete_meeting_registrants', startTime, new Error('Empty registrant UIDs array'), { - provided_count: registrantsUid.length, - }); - const validationError = ServiceValidationError.forField('registrantUids', 'Array of registrant UIDs is required', { operation: 'delete_meeting_registrants', service: 'meeting_controller', @@ -701,8 +623,7 @@ export class MeetingController { 'delete_meeting_registrants', uid, registrantsUid, - (registrantUid) => this.meetingService.deleteMeetingRegistrant(req, uid, registrantUid).then(() => registrantUid), - (registrantUid) => registrantUid + (registrantUid) => this.meetingService.deleteMeetingRegistrant(req, uid, registrantUid).then(() => registrantUid) ); // If the processing should return, return @@ -720,7 +641,7 @@ export class MeetingController { ); // Log the success - Logger.success(req, 'delete_meeting_registrants', startTime, { + logger.success(req, 'delete_meeting_registrants', startTime, { meeting_uid: uid, total_count: registrantsUid.length, successful_count: batchResponse.summary.successful, @@ -740,12 +661,6 @@ export class MeetingController { // Send the batch response to the client res.status(statusCode).json(batchResponse); } catch (error) { - // Log the error - Logger.error(req, 'delete_meeting_registrants', startTime, error, { - meeting_uid: uid, - registrant_count: registrantsUid.length, - }); - // Send the error to the next middleware next(error); } @@ -756,7 +671,7 @@ export class MeetingController { */ public async resendMeetingInvitation(req: Request, res: Response, next: NextFunction): Promise { const { uid, registrantId } = req.params; - const startTime = Logger.start(req, 'resend_meeting_invitation', { + const startTime = logger.startOperation(req, 'resend_meeting_invitation', { meeting_uid: uid, registrant_id: registrantId, }); @@ -764,8 +679,6 @@ export class MeetingController { try { // Validate meeting ID parameter if (!uid) { - Logger.error(req, 'resend_meeting_invitation', startTime, new Error('Missing meeting ID parameter')); - const validationError = ServiceValidationError.forField('uid', 'Meeting ID is required', { operation: 'resend_meeting_invitation', service: 'meeting_controller', @@ -778,8 +691,6 @@ export class MeetingController { // Validate registrant ID parameter if (!registrantId) { - Logger.error(req, 'resend_meeting_invitation', startTime, new Error('Missing registrant ID parameter')); - const validationError = ServiceValidationError.forField('registrantId', 'Registrant ID is required', { operation: 'resend_meeting_invitation', service: 'meeting_controller', @@ -794,7 +705,7 @@ export class MeetingController { await this.meetingService.resendMeetingInvitation(req, uid, registrantId); // Log the success - Logger.success(req, 'resend_meeting_invitation', startTime, { + logger.success(req, 'resend_meeting_invitation', startTime, { meeting_uid: uid, registrant_id: registrantId, }); @@ -804,12 +715,6 @@ export class MeetingController { message: 'Invitation resent successfully', }); } catch (error) { - // Log the error - Logger.error(req, 'resend_meeting_invitation', startTime, error, { - meeting_uid: uid, - registrant_id: registrantId, - }); - // Send the error to the next middleware next(error); } @@ -822,7 +727,7 @@ export class MeetingController { const { uid } = req.params; const rsvpData: CreateMeetingRsvpRequest = req.body; - const startTime = Logger.start(req, 'create_meeting_rsvp', { + const startTime = logger.startOperation(req, 'create_meeting_rsvp', { meeting_uid: uid, registrant_id: rsvpData.registrant_id, response: rsvpData.response, @@ -858,15 +763,13 @@ export class MeetingController { const rsvp = await this.meetingService.createMeetingRsvp(req, uid, rsvpData); // Log success - Logger.success(req, 'create_meeting_rsvp', startTime, { + logger.success(req, 'create_meeting_rsvp', startTime, { rsvp_id: rsvp.id, }); // Send response res.json(rsvp); } catch (error) { - // Log error - Logger.error(req, 'create_meeting_rsvp', startTime, error); next(error); } } @@ -879,7 +782,7 @@ export class MeetingController { const { uid } = req.params; const { occurrenceId } = req.query; - const startTime = Logger.start(req, 'get_meeting_rsvp_by_username', { + const startTime = logger.startOperation(req, 'get_meeting_rsvp_by_username', { meeting_uid: uid, occurrence_id: occurrenceId, }); @@ -898,7 +801,7 @@ export class MeetingController { const rsvp = await this.meetingService.getMeetingRsvpByUsername(req, uid, occurrenceId as string | undefined); // Log success - Logger.success(req, 'get_meeting_rsvp_by_username', startTime, { + logger.success(req, 'get_meeting_rsvp_by_username', startTime, { found: !!rsvp, rsvp_id: rsvp?.id, occurrence_id: occurrenceId, @@ -907,8 +810,6 @@ export class MeetingController { // Send response res.json(rsvp); } catch (error) { - // Log error - Logger.error(req, 'get_meeting_rsvp_by_username', startTime, error); next(error); } } @@ -919,7 +820,7 @@ export class MeetingController { public async getMeetingRsvps(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_meeting_rsvps', { + const startTime = logger.startOperation(req, 'get_meeting_rsvps', { meeting_uid: uid, }); @@ -937,15 +838,13 @@ export class MeetingController { const rsvps = await this.meetingService.getMeetingRsvps(req, uid); // Log success - Logger.success(req, 'get_meeting_rsvps', startTime, { + logger.success(req, 'get_meeting_rsvps', startTime, { count: rsvps.length, }); // Send response res.json(rsvps); } catch (error) { - // Log error - Logger.error(req, 'get_meeting_rsvps', startTime, error); next(error); } } @@ -957,7 +856,7 @@ export class MeetingController { const { uid } = req.params; const attachmentData = req.body; - const startTime = Logger.start(req, 'create_meeting_attachment', { + const startTime = logger.startOperation(req, 'create_meeting_attachment', { meeting_uid: uid, type: attachmentData.type, name: attachmentData.name, @@ -990,7 +889,6 @@ export class MeetingController { } ); - Logger.error(req, 'create_meeting_attachment', startTime, validationError); return next(validationError); } @@ -1017,16 +915,13 @@ export class MeetingController { // Create attachment via LFX V2 API const attachment = await this.meetingService.createMeetingAttachment(req, uid, formData); - Logger.success(req, 'create_meeting_attachment', startTime, { + logger.success(req, 'create_meeting_attachment', startTime, { attachment_uid: attachment.uid, meeting_uid: uid, }); res.status(201).json(attachment); } catch (error) { - Logger.error(req, 'create_meeting_attachment', startTime, error, { - meeting_uid: uid, - }); next(error); } } @@ -1040,7 +935,7 @@ export class MeetingController { const { uid, attachmentId } = req.params; const { download } = req.query; - const startTime = Logger.start(req, 'get_meeting_attachment', { + const startTime = logger.startOperation(req, 'get_meeting_attachment', { meeting_uid: uid, attachment_id: attachmentId, download_mode: download === 'true' ? 'download' : 'inline', @@ -1066,7 +961,6 @@ export class MeetingController { path: req.path, }); - Logger.error(req, 'get_meeting_attachment', startTime, validationError); return next(validationError); } @@ -1083,14 +977,14 @@ export class MeetingController { filename = metadata.name || filename; contentType = metadata.mime_type || metadata.content_type || contentType; } catch (metadataError) { - Logger.warning(req, 'get_meeting_attachment_metadata', 'Failed to fetch metadata, using defaults', { + logger.warning(req, 'get_meeting_attachment_metadata', 'Failed to fetch metadata, using defaults', { meeting_uid: uid, attachment_id: attachmentId, error: metadataError instanceof Error ? metadataError.message : metadataError, }); } - Logger.success(req, 'get_meeting_attachment', startTime, { + logger.success(req, 'get_meeting_attachment', startTime, { meeting_uid: uid, attachment_id: attachmentId, status_code: 200, @@ -1110,10 +1004,6 @@ export class MeetingController { // Send the buffer directly res.status(200).send(attachmentData); } catch (error) { - Logger.error(req, 'get_meeting_attachment', startTime, error, { - meeting_uid: uid, - attachment_id: attachmentId, - }); next(error); } } @@ -1124,7 +1014,7 @@ export class MeetingController { public async deleteMeetingAttachment(req: Request, res: Response, next: NextFunction): Promise { const { uid, attachmentId } = req.params; - const startTime = Logger.start(req, 'delete_meeting_attachment', { + const startTime = logger.startOperation(req, 'delete_meeting_attachment', { meeting_uid: uid, attachment_id: attachmentId, }); @@ -1149,14 +1039,13 @@ export class MeetingController { path: req.path, }); - Logger.error(req, 'delete_meeting_attachment', startTime, validationError); return next(validationError); } // Delete attachment via LFX V2 API await this.meetingService.deleteMeetingAttachment(req, uid, attachmentId); - Logger.success(req, 'delete_meeting_attachment', startTime, { + logger.success(req, 'delete_meeting_attachment', startTime, { meeting_uid: uid, attachment_id: attachmentId, status_code: 204, @@ -1164,10 +1053,6 @@ export class MeetingController { res.status(204).send(); } catch (error) { - Logger.error(req, 'delete_meeting_attachment', startTime, error, { - meeting_uid: uid, - attachment_id: attachmentId, - }); next(error); } } @@ -1175,7 +1060,7 @@ export class MeetingController { public async getMeetingAttachmentMetadata(req: Request, res: Response, next: NextFunction): Promise { const { uid, attachmentId } = req.params; - const startTime = Logger.start(req, 'get_meeting_attachment_metadata', { + const startTime = logger.startOperation(req, 'get_meeting_attachment_metadata', { meeting_uid: uid, attachment_id: attachmentId, }); @@ -1200,14 +1085,13 @@ export class MeetingController { path: req.path, }); - Logger.error(req, 'get_meeting_attachment_metadata', startTime, validationError); return next(validationError); } // Get attachment metadata via LFX V2 API const metadata = await this.meetingService.getMeetingAttachmentMetadata(req, uid, attachmentId); - Logger.success(req, 'get_meeting_attachment_metadata', startTime, { + logger.success(req, 'get_meeting_attachment_metadata', startTime, { meeting_uid: uid, attachment_id: attachmentId, status_code: 200, @@ -1215,10 +1099,6 @@ export class MeetingController { res.status(200).json(metadata); } catch (error) { - Logger.error(req, 'get_meeting_attachment_metadata', startTime, error, { - meeting_uid: uid, - attachment_id: attachmentId, - }); next(error); } } @@ -1229,7 +1109,7 @@ export class MeetingController { public async getMeetingAttachments(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_meeting_attachments', { + const startTime = logger.startOperation(req, 'get_meeting_attachments', { meeting_uid: uid, }); @@ -1248,7 +1128,7 @@ export class MeetingController { // Get attachments via Query Service const attachments = await this.meetingService.getMeetingAttachments(req, uid); - Logger.success(req, 'get_meeting_attachments', startTime, { + logger.success(req, 'get_meeting_attachments', startTime, { meeting_uid: uid, attachment_count: attachments.length, status_code: 200, @@ -1256,9 +1136,6 @@ export class MeetingController { res.status(200).json(attachments); } catch (error) { - Logger.error(req, 'get_meeting_attachments', startTime, error, { - meeting_uid: uid, - }); next(error); } } @@ -1269,7 +1146,7 @@ export class MeetingController { public async getPastMeetingAttachments(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_past_meeting_attachments', { + const startTime = logger.startOperation(req, 'get_past_meeting_attachments', { past_meeting_uid: uid, }); @@ -1288,7 +1165,7 @@ export class MeetingController { // Get attachments via Query Service const attachments = await this.meetingService.getPastMeetingAttachments(req, uid); - Logger.success(req, 'get_past_meeting_attachments', startTime, { + logger.success(req, 'get_past_meeting_attachments', startTime, { past_meeting_uid: uid, attachment_count: attachments.length, status_code: 200, @@ -1296,9 +1173,55 @@ export class MeetingController { res.status(200).json(attachments); } catch (error) { - Logger.error(req, 'get_past_meeting_attachments', startTime, error, { - past_meeting_uid: uid, + next(error); + } + } + + /** + * POST /meetings/generate-agenda + * Generate meeting agenda using AI + */ + public async generateAgenda(req: Request, res: Response, next: NextFunction): Promise { + const startTime = logger.startOperation(req, 'generate_agenda', { + meeting_type: req.body['meetingType'], + has_context: !!req.body['context'], + }); + + try { + const { meetingType, title, projectName, context } = req.body; + + // Validate required fields + if (!meetingType || !title || !projectName) { + const validationError = ServiceValidationError.fromFieldErrors( + { + meetingType: !meetingType ? 'Meeting type is required' : [], + title: !title ? 'Title is required' : [], + projectName: !projectName ? 'Project name is required' : [], + }, + 'Agenda generation validation failed', + { + operation: 'generate_agenda', + service: 'meeting_controller', + path: req.path, + } + ); + + return next(validationError); + } + + const response: GenerateAgendaResponse = await this.aiService.generateMeetingAgenda(req, { + meetingType, + title, + projectName, + context, + }); + + logger.success(req, 'generate_agenda', startTime, { + estimated_duration: response.estimatedDuration, }); + + res.json(response); + } catch (error) { next(error); } } @@ -1309,14 +1232,13 @@ export class MeetingController { private async processRegistrantOperations( req: Request, next: NextFunction, - startTime: number, + _startTime: number, operationName: string, meetingUid: string, inputData: T[], - operation: (input: T) => Promise, - getIdentifier: (input: T, index?: number) => string + operation: (input: T) => Promise ): Promise<{ results: PromiseSettledResult[]; shouldReturn: boolean }> { - const helperStartTime = Logger.start(req, `${operationName}_batch_processing`, { + const helperStartTime = logger.startOperation(req, `${operationName}_batch_processing`, { meeting_uid: meetingUid, batch_size: inputData.length, }); @@ -1334,7 +1256,7 @@ export class MeetingController { results = [{ status: 'fulfilled', value: firstResult }]; } - Logger.success(req, `${operationName}_batch_processing`, helperStartTime, { + logger.success(req, `${operationName}_batch_processing`, helperStartTime, { meeting_uid: meetingUid, batch_size: inputData.length, successful: results.filter((r) => r.status === 'fulfilled').length, @@ -1346,18 +1268,6 @@ export class MeetingController { // Check if it's a 403 error - if so, fail fast // This will stop the processing if a 403 error is encountered if (error?.status === 403 || error?.statusCode === 403) { - Logger.error(req, `${operationName}_batch_processing`, helperStartTime, error, { - meeting_uid: meetingUid, - identifier: getIdentifier(inputData[0], 0), - fail_fast: true, - }); - - Logger.error(req, operationName, startTime, error, { - meeting_uid: meetingUid, - identifier: getIdentifier(inputData[0], 0), - fail_fast: true, - }); - // Send the error to the next middleware next(error); return { results: [], shouldReturn: true }; @@ -1385,7 +1295,7 @@ export class MeetingController { meetingUid: string, getIdentifier: (input: I, index?: number) => string ): BatchRegistrantOperationResponse { - const helperStartTime = Logger.start(req, `${operationName}_batch_response`, { + const helperStartTime = logger.startOperation(req, `${operationName}_batch_response`, { meeting_uid: meetingUid, total_results: results.length, }); @@ -1413,14 +1323,14 @@ export class MeetingController { }); // Log individual failure - Logger.error(req, operationName, startTime, error, { + logger.error(req, operationName, startTime, error, { meeting_uid: meetingUid, identifier: getIdentifier(inputData[index], index), }); } }); - Logger.success(req, `${operationName}_batch_response`, helperStartTime, { + logger.success(req, `${operationName}_batch_response`, helperStartTime, { meeting_uid: meetingUid, total: inputData.length, successful: successes.length, diff --git a/apps/lfx-one/src/server/controllers/organization.controller.ts b/apps/lfx-one/src/server/controllers/organization.controller.ts index 47196e65..d72db46a 100644 --- a/apps/lfx-one/src/server/controllers/organization.controller.ts +++ b/apps/lfx-one/src/server/controllers/organization.controller.ts @@ -4,8 +4,8 @@ import { NextFunction, Request, Response } from 'express'; import { ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; import { OrganizationService } from '../services/organization.service'; +import { logger } from '../services/logger.service'; /** * Controller for handling organization HTTP requests @@ -18,18 +18,14 @@ export class OrganizationController { */ public async searchOrganizations(req: Request, res: Response, next: NextFunction): Promise { const { query } = req.query; - const startTime = Logger.start(req, 'search_organizations', { + const startTime = logger.startOperation(req, 'search_organizations', { has_query: !!query, }); try { // Check if the search query is provided and is a string if (!query || typeof query !== 'string') { - Logger.error(req, 'search_organizations', startTime, new Error('Missing or invalid search query'), { - query_type: typeof query, - }); - - // Create a validation error + // Create a validation error - error handler will log const validationError = ServiceValidationError.forField('query', 'Search query is required and must be a string', { operation: 'search_organizations', service: 'organization_controller', @@ -44,15 +40,14 @@ export class OrganizationController { const suggestions = await this.organizationService.searchOrganizations(req, query); // Log the success - Logger.success(req, 'search_organizations', startTime, { + logger.success(req, 'search_organizations', startTime, { result_count: suggestions.length, }); // Send the results to the client res.json({ suggestions }); } catch (error) { - // Log the error - Logger.error(req, 'search_organizations', startTime, error); + // Error handler will log - just propagate next(error); } } diff --git a/apps/lfx-one/src/server/controllers/past-meeting.controller.ts b/apps/lfx-one/src/server/controllers/past-meeting.controller.ts index 3114da68..07f364a2 100644 --- a/apps/lfx-one/src/server/controllers/past-meeting.controller.ts +++ b/apps/lfx-one/src/server/controllers/past-meeting.controller.ts @@ -5,7 +5,7 @@ import { NextFunction, Request, Response } from 'express'; import { PastMeeting, PastMeetingRecording, PastMeetingSummary, UpdatePastMeetingSummaryRequest } from '@lfx-one/shared/interfaces'; import { isUuid } from '@lfx-one/shared/utils'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { validateUidParameter } from '../helpers/validation.helper'; import { MeetingService } from '../services/meeting.service'; @@ -19,8 +19,8 @@ export class PastMeetingController { * GET /past-meetings */ public async getPastMeetings(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_past_meetings', { - query_params: Logger.sanitize(req.query as Record), + const startTime = logger.startOperation(req, 'get_past_meetings', { + query_params: logger.sanitize(req.query as Record), }); try { @@ -47,7 +47,7 @@ export class PastMeetingController { ); // Log the success - Logger.success(req, 'get_past_meetings', startTime, { + logger.success(req, 'get_past_meetings', startTime, { meeting_count: meetings.length, regular_past_meeting_count: regularPastMeetings.length, v1_past_meeting_count: v1PastMeetings.length, @@ -57,7 +57,7 @@ export class PastMeetingController { res.json(meetings); } catch (error) { // Log the error - Logger.error(req, 'get_past_meetings', startTime, error); + logger.error(req, 'get_past_meetings', startTime, error); next(error); } } @@ -67,7 +67,7 @@ export class PastMeetingController { */ public async getPastMeetingParticipants(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_past_meeting_participants', { + const startTime = logger.startOperation(req, 'get_past_meeting_participants', { past_meeting_uid: uid, }); @@ -87,7 +87,7 @@ export class PastMeetingController { const participants = await this.meetingService.getPastMeetingParticipants(req, uid); // Log the success - Logger.success(req, 'get_past_meeting_participants', startTime, { + logger.success(req, 'get_past_meeting_participants', startTime, { past_meeting_uid: uid, participant_count: participants.length, }); @@ -96,7 +96,7 @@ export class PastMeetingController { res.json(participants); } catch (error) { // Log the error - Logger.error(req, 'get_past_meeting_participants', startTime, error, { + logger.error(req, 'get_past_meeting_participants', startTime, error, { past_meeting_uid: uid, }); @@ -110,7 +110,7 @@ export class PastMeetingController { */ public async getPastMeetingRecording(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_past_meeting_recording', { + const startTime = logger.startOperation(req, 'get_past_meeting_recording', { past_meeting_uid: uid, }); @@ -142,7 +142,7 @@ export class PastMeetingController { } // Log the success - Logger.success(req, 'get_past_meeting_recording', startTime, { + logger.success(req, 'get_past_meeting_recording', startTime, { past_meeting_uid: uid, recording_uid: recording.uid, recording_count: recording.recording_count, @@ -153,7 +153,7 @@ export class PastMeetingController { res.json(recording); } catch (error) { // Log the error - Logger.error(req, 'get_past_meeting_recording', startTime, error, { + logger.error(req, 'get_past_meeting_recording', startTime, error, { past_meeting_uid: uid, }); @@ -167,7 +167,7 @@ export class PastMeetingController { */ public async getPastMeetingSummary(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_past_meeting_summary', { + const startTime = logger.startOperation(req, 'get_past_meeting_summary', { past_meeting_uid: uid, }); @@ -199,7 +199,7 @@ export class PastMeetingController { } // Log the success - Logger.success(req, 'get_past_meeting_summary', startTime, { + logger.success(req, 'get_past_meeting_summary', startTime, { past_meeting_uid: uid, summary_uid: summary.uid, approved: summary.approved, @@ -210,7 +210,7 @@ export class PastMeetingController { res.json(summary); } catch (error) { // Log the error - Logger.error(req, 'get_past_meeting_summary', startTime, error, { + logger.error(req, 'get_past_meeting_summary', startTime, error, { past_meeting_uid: uid, }); @@ -224,7 +224,7 @@ export class PastMeetingController { */ public async getPastMeetingAttachments(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_past_meeting_attachments', { + const startTime = logger.startOperation(req, 'get_past_meeting_attachments', { past_meeting_uid: uid, }); @@ -244,7 +244,7 @@ export class PastMeetingController { const attachments = await this.meetingService.getPastMeetingAttachments(req, uid); // Log the success - Logger.success(req, 'get_past_meeting_attachments', startTime, { + logger.success(req, 'get_past_meeting_attachments', startTime, { past_meeting_uid: uid, attachment_count: attachments.length, }); @@ -253,7 +253,7 @@ export class PastMeetingController { res.json(attachments); } catch (error) { // Log the error - Logger.error(req, 'get_past_meeting_attachments', startTime, error, { + logger.error(req, 'get_past_meeting_attachments', startTime, error, { past_meeting_uid: uid, }); @@ -267,7 +267,7 @@ export class PastMeetingController { */ public async updatePastMeetingSummary(req: Request, res: Response, next: NextFunction): Promise { const { uid, summaryUid } = req.params; - const startTime = Logger.start(req, 'update_past_meeting_summary', { + const startTime = logger.startOperation(req, 'update_past_meeting_summary', { past_meeting_uid: uid, summary_uid: summaryUid, }); @@ -304,7 +304,7 @@ export class PastMeetingController { const updatedSummary = await this.meetingService.updatePastMeetingSummary(req, uid, summaryUid, body); // Log the success - Logger.success(req, 'update_past_meeting_summary', startTime, { + logger.success(req, 'update_past_meeting_summary', startTime, { past_meeting_uid: uid, summary_uid: summaryUid, }); @@ -313,7 +313,7 @@ export class PastMeetingController { res.json(updatedSummary); } catch (error) { // Log the error - Logger.error(req, 'update_past_meeting_summary', startTime, error, { + logger.error(req, 'update_past_meeting_summary', startTime, error, { past_meeting_uid: uid, summary_uid: summaryUid, }); @@ -333,7 +333,7 @@ export class PastMeetingController { req: Request, pastMeetingUid: string ): Promise<{ individual_registrants_count: number; committee_members_count: number; participant_count: number; attended_count: number }> { - const startTime = Logger.start(req, 'add_participant_counts', { + const startTime = logger.startOperation(req, 'add_participant_counts', { past_meeting_uid: pastMeetingUid, }); @@ -353,7 +353,7 @@ export class PastMeetingController { attended_count: attendedCount, // Count of people who actually attended }; - Logger.success(req, 'add_participant_counts', startTime, { + logger.success(req, 'add_participant_counts', startTime, { past_meeting_uid: pastMeetingUid, invited_count: invitedCount, attended_count: attendedCount, @@ -363,7 +363,7 @@ export class PastMeetingController { return result; } catch (error) { // Log error but don't fail - default to 0 counts - Logger.error(req, 'add_participant_counts', startTime, error, { + logger.error(req, 'add_participant_counts', startTime, error, { past_meeting_uid: pastMeetingUid, }); diff --git a/apps/lfx-one/src/server/controllers/profile.controller.ts b/apps/lfx-one/src/server/controllers/profile.controller.ts index 0b274690..016f9290 100644 --- a/apps/lfx-one/src/server/controllers/profile.controller.ts +++ b/apps/lfx-one/src/server/controllers/profile.controller.ts @@ -13,7 +13,7 @@ import { import { NextFunction, Request, Response } from 'express'; import { AuthenticationError, AuthorizationError, MicroserviceError, ResourceNotFoundError, ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { SupabaseService } from '../services/supabase.service'; import { UserService } from '../services/user.service'; import { getUsernameFromAuth } from '../utils/auth-helper'; @@ -30,15 +30,13 @@ export class ProfileController { * Uses NATS as the sole authoritative source for user metadata */ public async getCurrentUserProfile(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_current_user_profile'); + const startTime = logger.startOperation(req, 'get_current_user_profile'); try { // Get username from auth context const username = await getUsernameFromAuth(req); if (!username) { - Logger.error(req, 'get_current_user_profile', startTime, new Error('User not authenticated or username not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'get_current_user_profile', service: 'profile_controller', @@ -52,8 +50,6 @@ export class ProfileController { const oidcUser = req.oidc?.user; if (!oidcUser) { - Logger.error(req, 'get_current_user_profile', startTime, new Error('OIDC user data not available')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication data not available', { operation: 'get_current_user_profile', service: 'profile_controller', @@ -67,27 +63,20 @@ export class ProfileController { let natsUserData: UserMetadata | null = null; try { const natsResponse = await this.userService.getUserInfo(req, username); - req.log.info({ username, natsSuccess: natsResponse.success }, 'Fetched user metadata from NATS'); if (natsResponse.success && natsResponse.data) { natsUserData = natsResponse.data; } else { - req.log.warn( - { - username, - error: natsResponse.error, - }, - 'Failed to fetch user metadata from NATS' - ); + logger.warning(req, 'get_current_user_profile', 'Failed to fetch user metadata from NATS', { + username, + error: natsResponse.error, + }); } } catch (error) { - req.log.warn( - { - username, - err: error, - }, - 'Exception while fetching user metadata from NATS' - ); + logger.warning(req, 'get_current_user_profile', 'Exception while fetching user metadata from NATS', { + username, + err: error, + }); } // Construct UserProfile from OIDC token data @@ -107,7 +96,7 @@ export class ProfileController { profile: natsUserData, }; - Logger.success(req, 'get_current_user_profile', startTime, { + logger.success(req, 'get_current_user_profile', startTime, { user_id: userProfile.id, username, has_metadata: !!natsUserData, @@ -115,7 +104,6 @@ export class ProfileController { res.json(combinedProfile); } catch (error) { - Logger.error(req, 'get_current_user_profile', startTime, error); next(error); } } @@ -125,7 +113,7 @@ export class ProfileController { * Handles all user profile fields including personal info and profile details */ public async updateUserMetadata(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'update_user_metadata_nats', { + const startTime = logger.startOperation(req, 'update_user_metadata_nats', { request_body_keys: Object.keys(req.body), }); @@ -133,8 +121,6 @@ export class ProfileController { // Get the bearer token from the request (set by auth middleware) or OIDC access token const token = req.bearerToken || req.oidc?.accessToken?.access_token; if (!token) { - Logger.error(req, 'update_user_metadata_nats', startTime, new Error('No authentication token found')); - const validationError = ServiceValidationError.forField('token', 'Authentication token required', { operation: 'update_user_metadata_nats', service: 'profile_controller', @@ -147,8 +133,6 @@ export class ProfileController { // Get username from auth context for user_id const username = await getUsernameFromAuth(req); if (!username) { - Logger.error(req, 'update_user_metadata_nats', startTime, new Error('User not authenticated')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'update_user_metadata_nats', service: 'profile_controller', @@ -163,8 +147,6 @@ export class ProfileController { // Validate at least one field to update is provided if (!user_metadata) { - Logger.error(req, 'update_user_metadata_nats', startTime, new Error('No update data provided')); - const validationError = ServiceValidationError.forField('body', 'At least one field to update must be provided', { operation: 'update_user_metadata_nats', service: 'profile_controller', @@ -179,8 +161,6 @@ export class ProfileController { try { this.userService.validateUserMetadata(user_metadata); } catch (validationError) { - Logger.error(req, 'update_user_metadata_nats', startTime, validationError); - const error = ServiceValidationError.forField('user_metadata', validationError instanceof Error ? validationError.message : 'Invalid user metadata', { operation: 'update_user_metadata_nats', service: 'profile_controller', @@ -203,7 +183,7 @@ export class ProfileController { // Handle response if (response.success) { - Logger.success(req, 'update_user_metadata_nats', startTime, { + logger.success(req, 'update_user_metadata_nats', startTime, { user_id: username, updated_fields: response.updated_fields, }); @@ -214,8 +194,6 @@ export class ProfileController { updated_fields: response.updated_fields, }); } else { - Logger.error(req, 'update_user_metadata_nats', startTime, new Error(response.error || 'Update failed')); - // Create appropriate error based on error type let error: any; @@ -269,7 +247,6 @@ export class ProfileController { return next(error); } } catch (error) { - Logger.error(req, 'update_user_metadata_nats', startTime, error); next(error); } } @@ -278,14 +255,12 @@ export class ProfileController { * GET /api/profile/emails - Get current user's email management data */ public async getUserEmails(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_user_emails'); + const startTime = logger.startOperation(req, 'get_user_emails'); try { const username = await getUsernameFromAuth(req); if (!username) { - Logger.error(req, 'get_user_emails', startTime, new Error('User not authenticated or user ID not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'get_user_emails', service: 'profile_controller', @@ -298,8 +273,6 @@ export class ProfileController { const userId = await this.supabaseService.getUser(username); if (!userId) { - Logger.error(req, 'get_user_emails', startTime, new Error('User not found')); - const validationError = ServiceValidationError.forField('user_id', 'User not found', { operation: 'get_user_emails', service: 'profile_controller', @@ -311,7 +284,7 @@ export class ProfileController { const emailData = await this.supabaseService.getEmailManagementData(userId.id); - Logger.success(req, 'get_user_emails', startTime, { + logger.success(req, 'get_user_emails', startTime, { user_id: userId.id, email_count: emailData.emails.length, has_preferences: !!emailData.preferences, @@ -319,7 +292,6 @@ export class ProfileController { res.json(emailData); } catch (error) { - Logger.error(req, 'get_user_emails', startTime, error); next(error); } } @@ -328,7 +300,7 @@ export class ProfileController { * POST /api/profile/emails - Add new email for current user */ public async addUserEmail(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'add_user_email', { + const startTime = logger.startOperation(req, 'add_user_email', { request_body_keys: Object.keys(req.body), }); @@ -336,8 +308,6 @@ export class ProfileController { const username = await getUsernameFromAuth(req); if (!username) { - Logger.error(req, 'add_user_email', startTime, new Error('User not authenticated or user ID not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'add_user_email', service: 'profile_controller', @@ -350,8 +320,6 @@ export class ProfileController { const user = await this.supabaseService.getUser(username); if (!user) { - Logger.error(req, 'add_user_email', startTime, new Error('User not found')); - const validationError = ServiceValidationError.forField('user_id', 'User not found', { operation: 'add_user_email', service: 'profile_controller', @@ -364,8 +332,6 @@ export class ProfileController { const { email }: AddEmailRequest = req.body; if (!email || typeof email !== 'string') { - Logger.error(req, 'add_user_email', startTime, new Error('Invalid email address')); - const validationError = ServiceValidationError.forField('email', 'Valid email address is required', { operation: 'add_user_email', service: 'profile_controller', @@ -378,8 +344,6 @@ export class ProfileController { // Basic email validation const emailRegex = /^[^\s@]+@[^\s@]+\.[^\s@]+$/; if (!emailRegex.test(email)) { - Logger.error(req, 'add_user_email', startTime, new Error('Invalid email format')); - const validationError = ServiceValidationError.forField('email', 'Invalid email format', { operation: 'add_user_email', service: 'profile_controller', @@ -391,7 +355,7 @@ export class ProfileController { const newEmail = await this.supabaseService.addUserEmail(user.id, email); - Logger.success(req, 'add_user_email', startTime, { + logger.success(req, 'add_user_email', startTime, { user_id: user.id, email_id: newEmail.id, email: newEmail.email, @@ -399,7 +363,6 @@ export class ProfileController { res.status(201).json(newEmail); } catch (error) { - Logger.error(req, 'add_user_email', startTime, error); if (error instanceof Error && error.message.includes('already in use')) { const validationError = ServiceValidationError.forField('email', error.message, { operation: 'add_user_email', @@ -416,7 +379,7 @@ export class ProfileController { * DELETE /api/profile/emails/:emailId - Delete user email */ public async deleteUserEmail(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'delete_user_email', { + const startTime = logger.startOperation(req, 'delete_user_email', { email_id: req.params['emailId'], }); @@ -425,8 +388,6 @@ export class ProfileController { const emailId = req.params['emailId']; if (!username) { - Logger.error(req, 'delete_user_email', startTime, new Error('User not authenticated or user ID not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'delete_user_email', service: 'profile_controller', @@ -437,8 +398,6 @@ export class ProfileController { } if (!emailId) { - Logger.error(req, 'delete_user_email', startTime, new Error('Email ID is required')); - const validationError = ServiceValidationError.forField('email_id', 'Email ID is required', { operation: 'delete_user_email', service: 'profile_controller', @@ -451,8 +410,6 @@ export class ProfileController { const user = await this.supabaseService.getUser(username); if (!user) { - Logger.error(req, 'delete_user_email', startTime, new Error('User not found')); - const validationError = ServiceValidationError.forField('user_id', 'User not found', { operation: 'delete_user_email', service: 'profile_controller', @@ -464,14 +421,13 @@ export class ProfileController { await this.supabaseService.deleteUserEmail(emailId, user.id); - Logger.success(req, 'delete_user_email', startTime, { + logger.success(req, 'delete_user_email', startTime, { user_id: user.id, email_id: emailId, }); res.status(204).send(); } catch (error) { - Logger.error(req, 'delete_user_email', startTime, error); if (error instanceof Error && (error.message.includes('Cannot delete') || error.message.includes('last email'))) { const validationError = ServiceValidationError.forField('email_id', error.message, { operation: 'delete_user_email', @@ -488,7 +444,7 @@ export class ProfileController { * PUT /api/profile/emails/:emailId/primary - Set email as primary */ public async setPrimaryEmail(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'set_primary_email', { + const startTime = logger.startOperation(req, 'set_primary_email', { email_id: req.params['emailId'], }); @@ -497,8 +453,6 @@ export class ProfileController { const emailId = req.params['emailId']; if (!username) { - Logger.error(req, 'set_primary_email', startTime, new Error('User not authenticated or user ID not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'set_primary_email', service: 'profile_controller', @@ -509,8 +463,6 @@ export class ProfileController { } if (!emailId) { - Logger.error(req, 'set_primary_email', startTime, new Error('Email ID is required')); - const validationError = ServiceValidationError.forField('email_id', 'Email ID is required', { operation: 'set_primary_email', service: 'profile_controller', @@ -523,8 +475,6 @@ export class ProfileController { const user = await this.supabaseService.getUser(username); if (!user) { - Logger.error(req, 'set_primary_email', startTime, new Error('User not found')); - const validationError = ServiceValidationError.forField('user_id', 'User not found', { operation: 'set_primary_email', service: 'profile_controller', @@ -536,14 +486,13 @@ export class ProfileController { await this.supabaseService.setPrimaryEmail(user.id, emailId); - Logger.success(req, 'set_primary_email', startTime, { + logger.success(req, 'set_primary_email', startTime, { user_id: user.id, email_id: emailId, }); res.status(200).json({ message: 'Primary email updated successfully' }); } catch (error) { - Logger.error(req, 'set_primary_email', startTime, error); next(error); } } @@ -552,13 +501,12 @@ export class ProfileController { * GET /api/profile/email-preferences - Get user email preferences */ public async getEmailPreferences(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_email_preferences'); + const startTime = logger.startOperation(req, 'get_email_preferences'); try { const username = await getUsernameFromAuth(req); if (!username) { - Logger.error(req, 'get_email_preferences', startTime, new Error('User not authenticated or user ID not found')); const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'get_email_preferences', service: 'profile_controller', @@ -571,8 +519,6 @@ export class ProfileController { const user = await this.supabaseService.getUser(username); if (!user) { - Logger.error(req, 'get_email_preferences', startTime, new Error('User not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'get_email_preferences', service: 'profile_controller', @@ -584,14 +530,13 @@ export class ProfileController { const preferences = await this.supabaseService.getEmailPreferences(user.id); - Logger.success(req, 'get_email_preferences', startTime, { + logger.success(req, 'get_email_preferences', startTime, { user_id: user.id, has_preferences: !!preferences, }); res.json(preferences); } catch (error) { - Logger.error(req, 'get_email_preferences', startTime, error); next(error); } } @@ -600,7 +545,7 @@ export class ProfileController { * PUT /api/profile/email-preferences - Update user email preferences */ public async updateEmailPreferences(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'update_email_preferences', { + const startTime = logger.startOperation(req, 'update_email_preferences', { request_body_keys: Object.keys(req.body), }); @@ -608,8 +553,6 @@ export class ProfileController { const username = await getUsernameFromAuth(req); if (!username) { - Logger.error(req, 'update_email_preferences', startTime, new Error('User not authenticated or user ID not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'update_email_preferences', service: 'profile_controller', @@ -622,8 +565,6 @@ export class ProfileController { const user = await this.supabaseService.getUser(username); if (!user) { - Logger.error(req, 'update_email_preferences', startTime, new Error('User not found')); - const validationError = ServiceValidationError.forField('user_id', 'User not found', { operation: 'update_email_preferences', service: 'profile_controller', @@ -644,8 +585,6 @@ export class ProfileController { } if (Object.keys(updateData).length === 0) { - Logger.error(req, 'update_email_preferences', startTime, new Error('No valid fields provided for update')); - const validationError = ServiceValidationError.forField('request_body', 'No valid fields provided for update', { operation: 'update_email_preferences', service: 'profile_controller', @@ -657,14 +596,13 @@ export class ProfileController { const updatedPreferences = await this.supabaseService.updateEmailPreferences(user.id, updateData); - Logger.success(req, 'update_email_preferences', startTime, { + logger.success(req, 'update_email_preferences', startTime, { user_id: user.id, updated_fields: Object.keys(updateData), }); res.json(updatedPreferences); } catch (error) { - Logger.error(req, 'update_email_preferences', startTime, error); next(error); } } @@ -673,15 +611,13 @@ export class ProfileController { * GET /api/profile/developer - Get current user's developer token information */ public async getDeveloperTokenInfo(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_developer_token_info'); + const startTime = logger.startOperation(req, 'get_developer_token_info'); try { // Get user ID from auth context const userId = await getUsernameFromAuth(req); if (!userId) { - Logger.error(req, 'get_developer_token_info', startTime, new Error('User not authenticated or user ID not found')); - const validationError = ServiceValidationError.forField('user_id', 'User authentication required', { operation: 'get_developer_token_info', service: 'profile_controller', @@ -695,8 +631,6 @@ export class ProfileController { const bearerToken = req.bearerToken; if (!bearerToken) { - Logger.error(req, 'get_developer_token_info', startTime, new Error('No bearer token available')); - const validationError = ServiceValidationError.forField('token', 'No API token available for user', { operation: 'get_developer_token_info', service: 'profile_controller', @@ -712,7 +646,7 @@ export class ProfileController { type: 'Bearer', }; - Logger.success(req, 'get_developer_token_info', startTime, { + logger.success(req, 'get_developer_token_info', startTime, { user_id: userId, token_length: bearerToken.length, }); @@ -726,7 +660,6 @@ export class ProfileController { res.json(tokenInfo); } catch (error) { - Logger.error(req, 'get_developer_token_info', startTime, error); next(error); } } diff --git a/apps/lfx-one/src/server/controllers/project.controller.ts b/apps/lfx-one/src/server/controllers/project.controller.ts index 6cea7ed7..08479793 100644 --- a/apps/lfx-one/src/server/controllers/project.controller.ts +++ b/apps/lfx-one/src/server/controllers/project.controller.ts @@ -6,7 +6,7 @@ import { isUuid } from '@lfx-one/shared/utils'; import { NextFunction, Request, Response } from 'express'; import { ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { CommitteeService } from '../services/committee.service'; import { MeetingService } from '../services/meeting.service'; import { ProjectService } from '../services/project.service'; @@ -23,8 +23,8 @@ export class ProjectController { * GET /projects */ public async getProjects(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_projects', { - query_params: Logger.sanitize(req.query as Record), + const startTime = logger.startOperation(req, 'get_projects', { + query_params: logger.sanitize(req.query as Record), }); try { @@ -39,15 +39,13 @@ export class ProjectController { }) ); - Logger.success(req, 'get_projects', startTime, { + logger.success(req, 'get_projects', startTime, { project_count: projects.length, }); // Send the projects to the client res.json(projects); } catch (error) { - // Log the error - Logger.error(req, 'get_projects', startTime, error); next(error); } } @@ -57,17 +55,13 @@ export class ProjectController { */ public async searchProjects(req: Request, res: Response, next: NextFunction): Promise { const { q } = req.query; - const startTime = Logger.start(req, 'search_projects', { + const startTime = logger.startOperation(req, 'search_projects', { has_query: !!q, }); try { // Check if the search query is provided and is a string if (!q || typeof q !== 'string') { - Logger.error(req, 'search_projects', startTime, new Error('Missing or invalid search query'), { - query_type: typeof q, - }); - // Create a validation error const validationError = ServiceValidationError.forField('q', 'Search query is required and must be a string', { operation: 'search_projects', @@ -91,15 +85,13 @@ export class ProjectController { ); // Log the success - Logger.success(req, 'search_projects', startTime, { + logger.success(req, 'search_projects', startTime, { result_count: results.length, }); // Send the results to the client res.json(results); } catch (error) { - // Log the error - Logger.error(req, 'search_projects', startTime, error); next(error); } } @@ -109,15 +101,13 @@ export class ProjectController { */ public async getProjectBySlug(req: Request, res: Response, next: NextFunction): Promise { const { slug } = req.params; - const startTime = Logger.start(req, 'get_project_by_slug', { + const startTime = logger.startOperation(req, 'get_project_by_slug', { slug, }); try { // Check if the project slug is provided if (!slug) { - Logger.error(req, 'get_project_by_slug', startTime, new Error('Missing project slug parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('slug', 'Project slug is required', { operation: 'get_project_by_slug', @@ -141,7 +131,7 @@ export class ProjectController { const project = await this.projectService.getProjectBySlug(req, slug); // Log the success - Logger.success(req, 'get_project_by_slug', startTime, { + logger.success(req, 'get_project_by_slug', startTime, { slug, project_uid: project.uid, }); @@ -149,11 +139,6 @@ export class ProjectController { // Send the project to the client res.json(project); } catch (error) { - // Log the error - Logger.error(req, 'get_project_by_slug', startTime, error, { - slug, - }); - // Send the error to the next middleware next(error); } @@ -164,15 +149,13 @@ export class ProjectController { */ public async getProjectPermissions(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'get_project_permissions', { + const startTime = logger.startOperation(req, 'get_project_permissions', { uid, }); try { // Check if the project uid is provided if (!uid) { - Logger.error(req, 'get_project_permissions', startTime, new Error('Missing project uid parameter')); - // Create a validation error const validationError = ServiceValidationError.forField('uid', 'Project uid is required', { operation: 'get_project_permissions', @@ -188,7 +171,7 @@ export class ProjectController { const settings = await this.projectService.getProjectSettings(req, uid); // Log the success - Logger.success(req, 'get_project_permissions', startTime, { + logger.success(req, 'get_project_permissions', startTime, { uid, project_uid: settings.uid, }); @@ -196,11 +179,6 @@ export class ProjectController { // Send the permissions to the client res.json(settings); } catch (error) { - // Log the error - Logger.error(req, 'get_project_permissions', startTime, error, { - uid, - }); - // Send the error to the next middleware next(error); } @@ -211,15 +189,13 @@ export class ProjectController { */ public async addUserToProjectPermissions(req: Request, res: Response, next: NextFunction): Promise { const { uid } = req.params; - const startTime = Logger.start(req, 'add_user_project_permissions', { + const startTime = logger.startOperation(req, 'add_user_project_permissions', { uid, }); try { // Validate project uid if (!uid) { - Logger.error(req, 'add_user_project_permissions', startTime, new Error('Missing project uid parameter')); - const validationError = ServiceValidationError.forField('uid', 'Project uid is required', { operation: 'add_user_project_permissions', service: 'project_controller', @@ -234,8 +210,6 @@ export class ProjectController { // Validate required fields if (!userData.username || !userData.role) { - Logger.error(req, 'add_user_project_permissions', startTime, new Error('Missing required fields')); - const validationError = ServiceValidationError.forField('body', 'Username and role are required', { operation: 'add_user_project_permissions', service: 'project_controller', @@ -248,8 +222,6 @@ export class ProjectController { // Validate role value if (!['view', 'manage'].includes(userData.role)) { - Logger.error(req, 'add_user_project_permissions', startTime, new Error('Invalid role value')); - const validationError = ServiceValidationError.forField('role', 'Role must be either "view" or "manage"', { operation: 'add_user_project_permissions', service: 'project_controller', @@ -281,7 +253,7 @@ export class ProjectController { // The service will handle the email_to_sub -> email_to_username flow internally const result = await this.projectService.updateProjectPermissions(req, uid, 'add', userData.username, userData.role, manualUserInfo); - Logger.success(req, 'add_user_project_permissions', startTime, { + logger.success(req, 'add_user_project_permissions', startTime, { uid, username: userData.username, role: userData.role, @@ -290,9 +262,6 @@ export class ProjectController { res.status(201).json(result); } catch (error) { - Logger.error(req, 'add_user_project_permissions', startTime, error, { - uid, - }); next(error); } } @@ -302,7 +271,7 @@ export class ProjectController { */ public async updateUserPermissionRole(req: Request, res: Response, next: NextFunction): Promise { const { uid, username } = req.params; - const startTime = Logger.start(req, 'update_user_role_project_permissions', { + const startTime = logger.startOperation(req, 'update_user_role_project_permissions', { uid, username, }); @@ -310,8 +279,6 @@ export class ProjectController { try { // Validate parameters if (!uid) { - Logger.error(req, 'update_user_role_project_permissions', startTime, new Error('Missing project uid parameter')); - const validationError = ServiceValidationError.forField('uid', 'Project uid is required', { operation: 'update_user_role_project_permissions', service: 'project_controller', @@ -323,8 +290,6 @@ export class ProjectController { } if (!username) { - Logger.error(req, 'update_user_role_project_permissions', startTime, new Error('Missing username parameter')); - const validationError = ServiceValidationError.forField('username', 'Username is required', { operation: 'update_user_role_project_permissions', service: 'project_controller', @@ -339,8 +304,6 @@ export class ProjectController { // Validate required fields if (!roleData.role) { - Logger.error(req, 'update_user_role_project_permissions', startTime, new Error('Missing role field')); - const validationError = ServiceValidationError.forField('role', 'Role is required', { operation: 'update_user_role_project_permissions', service: 'project_controller', @@ -353,8 +316,6 @@ export class ProjectController { // Validate role value if (!['view', 'manage'].includes(roleData.role)) { - Logger.error(req, 'update_user_role_project_permissions', startTime, new Error('Invalid role value')); - const validationError = ServiceValidationError.forField('role', 'Role must be either "view" or "manage"', { operation: 'update_user_role_project_permissions', service: 'project_controller', @@ -367,7 +328,7 @@ export class ProjectController { const result = await this.projectService.updateProjectPermissions(req, uid, 'update', username, roleData.role); - Logger.success(req, 'update_user_role_project_permissions', startTime, { + logger.success(req, 'update_user_role_project_permissions', startTime, { uid, username, new_role: roleData.role, @@ -375,10 +336,6 @@ export class ProjectController { res.json(result); } catch (error) { - Logger.error(req, 'update_user_role_project_permissions', startTime, error, { - uid, - username, - }); next(error); } } @@ -388,7 +345,7 @@ export class ProjectController { */ public async removeUserFromProjectPermissions(req: Request, res: Response, next: NextFunction): Promise { const { uid, username } = req.params; - const startTime = Logger.start(req, 'remove_user_project_permissions', { + const startTime = logger.startOperation(req, 'remove_user_project_permissions', { uid, username, }); @@ -396,8 +353,6 @@ export class ProjectController { try { // Validate parameters if (!uid) { - Logger.error(req, 'remove_user_project_permissions', startTime, new Error('Missing project uid parameter')); - const validationError = ServiceValidationError.forField('uid', 'Project uid is required', { operation: 'remove_user_project_permissions', service: 'project_controller', @@ -409,8 +364,6 @@ export class ProjectController { } if (!username) { - Logger.error(req, 'remove_user_project_permissions', startTime, new Error('Missing username parameter')); - const validationError = ServiceValidationError.forField('username', 'Username is required', { operation: 'remove_user_project_permissions', service: 'project_controller', @@ -423,17 +376,13 @@ export class ProjectController { await this.projectService.updateProjectPermissions(req, uid, 'remove', username); - Logger.success(req, 'remove_user_project_permissions', startTime, { + logger.success(req, 'remove_user_project_permissions', startTime, { uid, username, }); res.status(204).send(); } catch (error) { - Logger.error(req, 'remove_user_project_permissions', startTime, error, { - uid, - username, - }); next(error); } } @@ -442,14 +391,12 @@ export class ProjectController { * GET /projects/pending-action-surveys - Get pending survey actions for the authenticated user */ public async getPendingActionSurveys(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_pending_action_surveys'); + const startTime = logger.startOperation(req, 'get_pending_action_surveys'); try { // Extract user email from OIDC const userEmail = req.oidc?.user?.['email']; if (!userEmail) { - Logger.error(req, 'get_pending_action_surveys', startTime, new Error('User email not found in OIDC context')); - const validationError = ServiceValidationError.forField('email', 'User email not found in authentication context', { operation: 'get_pending_action_surveys', service: 'project_controller', @@ -463,8 +410,6 @@ export class ProjectController { // Extract projectSlug from query parameters const projectSlug = req.query['projectSlug'] as string | undefined; if (!projectSlug) { - Logger.error(req, 'get_pending_action_surveys', startTime, new Error('Missing projectSlug parameter')); - const validationError = ServiceValidationError.forField('projectSlug', 'projectSlug query parameter is required', { operation: 'get_pending_action_surveys', service: 'project_controller', @@ -478,14 +423,13 @@ export class ProjectController { // Get pending surveys from service const pendingActions = await this.projectService.getPendingActionSurveys(userEmail, projectSlug); - Logger.success(req, 'get_pending_action_surveys', startTime, { + logger.success(req, 'get_pending_action_surveys', startTime, { project_slug: projectSlug, survey_count: pendingActions.length, }); res.json(pendingActions); } catch (error) { - Logger.error(req, 'get_pending_action_surveys', startTime, error); next(error); } } diff --git a/apps/lfx-one/src/server/controllers/public-meeting.controller.ts b/apps/lfx-one/src/server/controllers/public-meeting.controller.ts index 6e988153..d36d1524 100644 --- a/apps/lfx-one/src/server/controllers/public-meeting.controller.ts +++ b/apps/lfx-one/src/server/controllers/public-meeting.controller.ts @@ -8,10 +8,10 @@ import { NextFunction, Request, Response } from 'express'; import { ResourceNotFoundError, ServiceValidationError } from '../errors'; import { AuthorizationError } from '../errors/authentication.error'; -import { Logger } from '../helpers/logger'; import { addInvitedStatusToMeeting } from '../helpers/meeting.helper'; import { validateUidParameter } from '../helpers/validation.helper'; import { AccessCheckService } from '../services/access-check.service'; +import { logger } from '../services/logger.service'; import { MeetingService } from '../services/meeting.service'; import { ProjectService } from '../services/project.service'; import { generateM2MToken } from '../utils/m2m-token.util'; @@ -38,7 +38,7 @@ export class PublicMeetingController { v1 = true; } - const startTime = Logger.start(req, 'get_public_meeting_by_id', { + const startTime = logger.startOperation(req, 'get_public_meeting_by_id', { meeting_uid: id, v1, }); @@ -56,41 +56,29 @@ export class PublicMeetingController { const m2mToken = await this.setupM2MToken(req); // Get the meeting by ID using M2M token - Logger.start(req, 'get_public_meeting_by_id_fetch_meeting', { meeting_uid: id }); let meeting = await this.fetchMeetingWithM2M(req, id, v1 ? 'v1_meeting' : 'meeting', m2mToken); if (!meeting) { - // Log the error - Logger.error(req, 'get_public_meeting_by_id_fetch_meeting', startTime, new Error('Meeting not found')); - - // Throw a resource not found error + // Throw a resource not found error (error handler will log) throw new ResourceNotFoundError('Meeting', id, { operation: 'get_public_meeting_by_id', service: 'public_meeting_controller', path: `/meetings/${id}`, }); } - Logger.success(req, 'get_public_meeting_by_id_fetch_meeting', startTime, { meeting_uid: id }); // Fetch the project - Logger.start(req, 'get_public_meeting_by_id_fetch_project', { meeting_uid: id, project_uid: meeting.project_uid }); const project = await this.projectService.getProjectById(req, meeting.project_uid, false); if (!project) { - // Log the error - Logger.error(req, 'get_public_meeting_by_id_fetch_project', startTime, new Error('Project not found')); - - // Throw a resource not found error + // Throw a resource not found error (error handler will log) throw new ResourceNotFoundError('Project', meeting.project_uid, { operation: 'get_public_meeting_by_id', service: 'public_meeting_controller', path: `/projects/${meeting.project_uid}`, }); } - Logger.success(req, 'get_public_meeting_by_id_fetch_project', startTime, { meeting_uid: id, project_uid: project.uid }); // Fetch the registrants - Logger.start(req, 'get_public_meeting_by_id_fetch_registrants', { meeting_uid: id, project_uid: meeting.project_uid }); const registrants = v1 ? [] : await this.meetingService.getMeetingRegistrants(req, meeting.uid); - Logger.success(req, 'get_public_meeting_by_id_fetch_registrants', startTime, { meeting_uid: id, registrant_count: registrants.length }); const committeeMembers = registrants.filter((r) => r.type === 'committee').length ?? 0; meeting.individual_registrants_count = (registrants?.length ?? 0) - (committeeMembers ?? 0); meeting.committee_members_count = committeeMembers ?? 0; @@ -104,7 +92,7 @@ export class PublicMeetingController { } // Log the success - Logger.success(req, 'get_public_meeting_by_id', startTime, { meeting_uid: id, project_uid: meeting.project_uid, title: meeting.title }); + logger.success(req, 'get_public_meeting_by_id', startTime, { meeting_uid: id, project_uid: meeting.project_uid, title: meeting.title }); // Check if the meeting visibility is public and not restricted, if so, get join URL and return the meeting and project if (meeting.visibility === MeetingVisibility.PUBLIC && !meeting.restricted) { @@ -131,7 +119,7 @@ export class PublicMeetingController { // Check if the user has passed in a password, if so, check if it's correct const { password } = req.query; - if (!this.validateMeetingPassword(password as string, meeting.password as string, 'get_public_meeting_by_id', req, next, startTime)) { + if (!this.validateMeetingPassword(password as string, meeting.password as string, 'get_public_meeting_by_id', req, next)) { return; } @@ -142,22 +130,14 @@ export class PublicMeetingController { req.bearerToken = originalToken; } - Logger.start(req, 'get_public_meeting_by_id_check_organizer', { meeting_uid: id }); try { meeting = await this.accessCheckService.addAccessToResource(req, meeting, 'meeting', 'organizer'); - Logger.success(req, 'get_public_meeting_by_id_check_organizer', startTime, { - meeting_uid: id, - is_organizer: meeting.organizer, - }); } catch (error) { // If organizer check fails, log but continue with organizer = false - req.log.warn( - { - err: error, - meeting_uid: id, - }, - 'Failed to check organizer status, continuing with organizer = false' - ); + logger.warning(req, 'get_public_meeting_by_id', 'Failed to check organizer status, continuing with organizer = false', { + err: error, + meeting_uid: id, + }); meeting.organizer = false; } } else { @@ -168,12 +148,7 @@ export class PublicMeetingController { // Send the meeting and project data to the client res.json({ meeting, project: { name: project.name, slug: project.slug, logo_url: project.logo_url } }); } catch (error) { - // Log the error - Logger.error(req, 'get_public_meeting_by_id', startTime, error, { - meeting_uid: id, - }); - - // Send the error to the next middleware + // Error handler will log next(error); } } @@ -183,7 +158,7 @@ export class PublicMeetingController { const { id } = req.params; const { password } = req.query; const email: string = req.body.email ?? req.oidc.user?.['email'] ?? ''; - const startTime = Logger.start(req, 'post_meeting_join_url', { + const startTime = logger.startOperation(req, 'post_meeting_join_url', { meeting_uid: id, }); const v1 = !isUuid(id); @@ -205,7 +180,7 @@ export class PublicMeetingController { } // Check if the user has passed in a password, if so, check if it's correct - if (!this.validateMeetingPassword(password as string, meeting.password as string, 'post_meeting_join_url', req, next, startTime)) { + if (!this.validateMeetingPassword(password as string, meeting.password as string, 'post_meeting_join_url', req, next)) { return; } @@ -213,8 +188,6 @@ export class PublicMeetingController { if (!this.isWithinJoinWindow(meeting)) { const earlyJoinMinutes = meeting?.early_join_time_minutes ?? 10; - Logger.error(req, 'post_meeting_join_url', startTime, new Error('Meeting join not available yet')); - const validationError = ServiceValidationError.forField('timing', `You can join the meeting up to ${earlyJoinMinutes} minutes before the start time`, { operation: 'post_meeting_join_url', service: 'public_meeting_controller', @@ -228,7 +201,7 @@ export class PublicMeetingController { // Check that the user has access to the meeting by validating they were invited to the meeting // Restricted meetings require an email to be provided if (meeting.restricted) { - await this.restrictedMeetingCheck(req, next, email, id, startTime); + await this.restrictedMeetingCheck(req, next, email, id); } if (v1) { @@ -240,7 +213,7 @@ export class PublicMeetingController { const joinUrlData = await this.meetingService.getMeetingJoinUrl(req, id); // Log the success - Logger.success(req, 'post_meeting_join_url', startTime, { + logger.success(req, 'post_meeting_join_url', startTime, { meeting_uid: id, project_uid: meeting.project_uid, title: meeting.title, @@ -248,12 +221,7 @@ export class PublicMeetingController { res.json(joinUrlData); } catch (error) { - // Log the error - Logger.error(req, 'post_meeting_join_url', startTime, error, { - meeting_uid: id, - }); - - // Send the error to the next middleware + // Error handler will log next(error); } } @@ -266,7 +234,7 @@ export class PublicMeetingController { const registrantData: CreateMeetingRegistrantRequest = req.body; const meetingId = registrantData.meeting_uid; - const startTime = Logger.start(req, 'register_for_public_meeting', { + const startTime = logger.startOperation(req, 'register_for_public_meeting', { meeting_uid: meetingId, }); @@ -279,7 +247,6 @@ export class PublicMeetingController { path: req.path, }); - Logger.error(req, 'register_for_public_meeting', startTime, validationError); return next(validationError); } @@ -299,7 +266,6 @@ export class PublicMeetingController { } ); - Logger.error(req, 'register_for_public_meeting', startTime, validationError); return next(validationError); } @@ -325,11 +291,6 @@ export class PublicMeetingController { path: req.path, }); - Logger.error(req, 'register_for_public_meeting', startTime, authError, { - meeting_uid: meetingId, - visibility: meeting.visibility, - }); - return next(authError); } @@ -341,28 +302,20 @@ export class PublicMeetingController { path: req.path, }); - Logger.error(req, 'register_for_public_meeting', startTime, authError, { - meeting_uid: meetingId, - restricted: meeting.restricted, - }); - return next(authError); } // Add the registrant using M2M token const newRegistrant = await this.meetingService.addMeetingRegistrantWithM2M(req, registrantData, m2mToken); - Logger.success(req, 'register_for_public_meeting', startTime, { + logger.success(req, 'register_for_public_meeting', startTime, { meeting_uid: meetingId, registrant_uid: newRegistrant.uid, }); res.status(201).json(newRegistrant); } catch (error) { - Logger.error(req, 'register_for_public_meeting', startTime, error, { - meeting_uid: meetingId, - }); - + // Error handler will log next(error); } } @@ -371,21 +324,16 @@ export class PublicMeetingController { * Sets up M2M token for API calls */ private async setupM2MToken(req: Request): Promise { - const startTime = Logger.start(req, 'setup_m2m_token'); + const startTime = logger.startOperation(req, 'setup_m2m_token'); - try { - const m2mToken = await generateM2MToken(req); - req.bearerToken = m2mToken; + const m2mToken = await generateM2MToken(req); + req.bearerToken = m2mToken; - Logger.success(req, 'setup_m2m_token', startTime, { - has_token: !!m2mToken, - }); + logger.success(req, 'setup_m2m_token', startTime, { + has_token: !!m2mToken, + }); - return m2mToken; - } catch (error) { - Logger.error(req, 'setup_m2m_token', startTime, error); - throw error; - } + return m2mToken; } /** @@ -402,10 +350,8 @@ export class PublicMeetingController { /** * Validates meeting password */ - private validateMeetingPassword(password: string, meetingPassword: string, operation: string, req: Request, next: NextFunction, startTime: number): boolean { + private validateMeetingPassword(password: string, meetingPassword: string, operation: string, req: Request, next: NextFunction): boolean { if (!password || !validatePassword(password, meetingPassword)) { - Logger.error(req, operation, startTime, new Error('Invalid password parameter')); - const validationError = ServiceValidationError.forField('password', 'Invalid password', { operation, service: 'public_meeting_controller', @@ -426,38 +372,31 @@ export class PublicMeetingController { * @param m2mToken - Optional pre-generated M2M token (will be generated if not provided) */ private async fetchMeetingWithM2M(req: Request, id: string, meetingType: QueryServiceMeetingType = 'meeting', m2mToken?: string) { - const startTime = Logger.start(req, 'fetch_meeting_with_m2m', { + const startTime = logger.startOperation(req, 'fetch_meeting_with_m2m', { meeting_id: id, }); - try { - // Use provided token or generate a new one - if (m2mToken) { - req.bearerToken = m2mToken; - } else { - await this.setupM2MToken(req); - } - const meeting = await this.meetingService.getMeetingById(req, id, meetingType, false); + // Use provided token or generate a new one + if (m2mToken) { + req.bearerToken = m2mToken; + } else { + await this.setupM2MToken(req); + } + const meeting = await this.meetingService.getMeetingById(req, id, meetingType, false); - Logger.success(req, 'fetch_meeting_with_m2m', startTime, { - meeting_id: id, - meeting_uid: meeting.uid, - }); + logger.success(req, 'fetch_meeting_with_m2m', startTime, { + meeting_id: id, + meeting_uid: meeting.uid, + }); - return meeting; - } catch (error) { - Logger.error(req, 'fetch_meeting_with_m2m', startTime, error, { - meeting_id: id, - }); - throw error; - } + return meeting; } /** * Handles join URL logic for public meetings */ private async handleJoinUrlForPublicMeeting(req: Request, meeting: any, id: string): Promise { - const startTime = Logger.start(req, 'handle_join_url_for_public_meeting', { + const startTime = logger.startOperation(req, 'handle_join_url_for_public_meeting', { meeting_uid: id, }); @@ -465,12 +404,12 @@ export class PublicMeetingController { const joinUrlData = await this.meetingService.getMeetingJoinUrl(req, id); meeting.join_url = joinUrlData.join_url; - Logger.success(req, 'handle_join_url_for_public_meeting', startTime, { + logger.success(req, 'handle_join_url_for_public_meeting', startTime, { meeting_uid: id, has_join_url: !!joinUrlData.join_url, }); } catch (error) { - Logger.warning(req, 'handle_join_url_for_public_meeting', 'Failed to fetch join URL, continuing without it', { + logger.warning(req, 'handle_join_url_for_public_meeting', 'Failed to fetch join URL, continuing without it', { meeting_uid: id, has_token: !!req.bearerToken, err: error, @@ -494,19 +433,15 @@ export class PublicMeetingController { return now >= earliestJoinTime; } - private async restrictedMeetingCheck(req: Request, next: NextFunction, email: string, id: string, startTime: number): Promise { - const helperStartTime = Logger.start(req, 'restricted_meeting_check', { + private async restrictedMeetingCheck(req: Request, next: NextFunction, email: string, id: string): Promise { + const helperStartTime = logger.startOperation(req, 'restricted_meeting_check', { meeting_id: id, has_email: !!email, }); // Check that the user has access to the meeting by validating they were invited to the meeting if (!email) { - // Log the error - Logger.error(req, 'restricted_meeting_check', helperStartTime, new Error('Missing email parameter')); - Logger.error(req, 'post_meeting_join_url', startTime, new Error('Missing email parameter')); - - // Create a validation error + // Create a validation error (error handler will log) const validationError = ServiceValidationError.forField('email', 'Email is required', { operation: 'post_meeting_join_url', service: 'public_meeting_controller', @@ -525,14 +460,10 @@ export class PublicMeetingController { service: 'public_meeting_controller', path: `/meetings/${id}`, }); - Logger.error(req, 'restricted_meeting_check', helperStartTime, authError, { - email, - meeting_id: id, - }); throw authError; } - Logger.success(req, 'restricted_meeting_check', helperStartTime, { + logger.success(req, 'restricted_meeting_check', helperStartTime, { meeting_id: id, email, registrant_count: registrants.resources.length, diff --git a/apps/lfx-one/src/server/controllers/search.controller.ts b/apps/lfx-one/src/server/controllers/search.controller.ts index 09bf5333..a0094685 100644 --- a/apps/lfx-one/src/server/controllers/search.controller.ts +++ b/apps/lfx-one/src/server/controllers/search.controller.ts @@ -5,7 +5,7 @@ import { UserSearchParams } from '@lfx-one/shared/interfaces'; import { NextFunction, Request, Response } from 'express'; import { ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { SearchService } from '../services/search.service'; /** @@ -20,7 +20,7 @@ export class SearchController { */ public async searchUsers(req: Request, res: Response, next: NextFunction): Promise { const { name, type, tags } = req.query; - const startTime = Logger.start(req, 'search_users', { + const startTime = logger.startOperation(req, 'search_users', { has_name: !!name, has_type: !!type, has_tags: !!tags, @@ -29,11 +29,6 @@ export class SearchController { try { // Validate required parameters if ((!name || typeof name !== 'string') && (!tags || typeof tags !== 'string')) { - Logger.error(req, 'search_users', startTime, new Error('Missing or invalid name parameter'), { - name_type: typeof name, - tags_type: typeof tags, - }); - const validationError = ServiceValidationError.forField('name', 'Name or tags parameter is required and must be a string', { operation: 'search_users', service: 'search_controller', @@ -45,10 +40,6 @@ export class SearchController { } if (!type || typeof type !== 'string') { - Logger.error(req, 'search_users', startTime, new Error('Missing or invalid type parameter'), { - type_type: typeof type, - }); - const validationError = ServiceValidationError.forField('type', 'Type parameter is required and must be a string', { operation: 'search_users', service: 'search_controller', @@ -61,10 +52,6 @@ export class SearchController { // Validate type value if (!['committee_member', 'meeting_registrant'].includes(type)) { - Logger.error(req, 'search_users', startTime, new Error('Invalid type value'), { - provided_type: type, - }); - const validationError = ServiceValidationError.forField('type', 'Type must be either "committee_member" or "meeting_registrant"', { operation: 'search_users', service: 'search_controller', @@ -87,18 +74,13 @@ export class SearchController { // Perform the search const results = await this.searchService.searchUsers(req, searchParams); - Logger.success(req, 'search_users', startTime, { + logger.success(req, 'search_users', startTime, { result_count: results.results.length, has_more: results.has_more, }); res.json(results); } catch (error) { - Logger.error(req, 'search_users', startTime, error, { - name, - tags, - type, - }); next(error); } } diff --git a/apps/lfx-one/src/server/controllers/user.controller.ts b/apps/lfx-one/src/server/controllers/user.controller.ts index 8ea19f1a..7a8ded67 100644 --- a/apps/lfx-one/src/server/controllers/user.controller.ts +++ b/apps/lfx-one/src/server/controllers/user.controller.ts @@ -5,7 +5,7 @@ import { PersonaType } from '@lfx-one/shared/interfaces'; import { NextFunction, Request, Response } from 'express'; import { ServiceValidationError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { UserService } from '../services/user.service'; /** @@ -18,7 +18,7 @@ export class UserController { * GET /api/user/pending-actions - Get all pending actions for the authenticated user */ public async getPendingActions(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_pending_actions', { + const startTime = logger.startOperation(req, 'get_pending_actions', { persona: req.query['persona'], project_uid: req.query['projectUid'], }); @@ -27,8 +27,6 @@ export class UserController { // Extract user email from OIDC const userEmail = req.oidc?.user?.['email']; if (!userEmail) { - Logger.error(req, 'get_pending_actions', startTime, new Error('User email not found in OIDC context')); - const validationError = ServiceValidationError.forField('email', 'User email not found in authentication context', { operation: 'get_pending_actions', service: 'user_controller', @@ -42,8 +40,6 @@ export class UserController { // Extract and validate persona const persona = req.query['persona'] as PersonaType | undefined; if (!persona) { - Logger.error(req, 'get_pending_actions', startTime, new Error('Missing persona parameter')); - const validationError = ServiceValidationError.forField('persona', 'persona query parameter is required', { operation: 'get_pending_actions', service: 'user_controller', @@ -57,8 +53,6 @@ export class UserController { // Extract and validate projectUid const projectUid = req.query['projectUid'] as string | undefined; if (!projectUid) { - Logger.error(req, 'get_pending_actions', startTime, new Error('Missing projectUid parameter')); - const validationError = ServiceValidationError.forField('projectUid', 'projectUid query parameter is required', { operation: 'get_pending_actions', service: 'user_controller', @@ -72,8 +66,6 @@ export class UserController { // Extract and validate projectSlug (needed for Snowflake surveys query) const projectSlug = req.query['projectSlug'] as string | undefined; if (!projectSlug) { - Logger.error(req, 'get_pending_actions', startTime, new Error('Missing projectSlug parameter')); - const validationError = ServiceValidationError.forField('projectSlug', 'projectSlug query parameter is required', { operation: 'get_pending_actions', service: 'user_controller', @@ -87,7 +79,7 @@ export class UserController { // Get pending actions from service const pendingActions = await this.userService.getPendingActions(req, persona, projectUid, userEmail, projectSlug); - Logger.success(req, 'get_pending_actions', startTime, { + logger.success(req, 'get_pending_actions', startTime, { persona, project_uid: projectUid, project_slug: projectSlug, @@ -96,7 +88,6 @@ export class UserController { res.json(pendingActions); } catch (error) { - Logger.error(req, 'get_pending_actions', startTime, error); next(error); } } @@ -108,7 +99,7 @@ export class UserController { * @query projectUid - Required project UID to filter meetings */ public async getUserMeetings(req: Request, res: Response, next: NextFunction): Promise { - const startTime = Logger.start(req, 'get_user_meetings', { + const startTime = logger.startOperation(req, 'get_user_meetings', { project_uid: req.query['projectUid'], }); @@ -116,8 +107,6 @@ export class UserController { // Extract and validate projectUid const projectUid = req.query['projectUid'] as string | undefined; if (!projectUid) { - Logger.error(req, 'get_user_meetings', startTime, new Error('Missing projectUid parameter')); - const validationError = ServiceValidationError.forField('projectUid', 'projectUid query parameter is required', { operation: 'get_user_meetings', service: 'user_controller', @@ -131,8 +120,6 @@ export class UserController { // Extract user email from OIDC const userEmail = req.oidc?.user?.['email']; if (!userEmail) { - Logger.error(req, 'get_user_meetings', startTime, new Error('User email not found in OIDC context')); - const validationError = ServiceValidationError.forField('email', 'User email not found in authentication context', { operation: 'get_user_meetings', service: 'user_controller', @@ -147,14 +134,13 @@ export class UserController { const query = { tags_all: `project_uid:${projectUid}` }; const meetings = await this.userService.getUserMeetings(req, userEmail, projectUid, query); - Logger.success(req, 'get_user_meetings', startTime, { + logger.success(req, 'get_user_meetings', startTime, { project_uid: projectUid, meeting_count: meetings.length, }); res.json(meetings); } catch (error) { - Logger.error(req, 'get_user_meetings', startTime, error); next(error); } } diff --git a/apps/lfx-one/src/server/helpers/logger.ts b/apps/lfx-one/src/server/helpers/logger.ts deleted file mode 100644 index d7900b61..00000000 --- a/apps/lfx-one/src/server/helpers/logger.ts +++ /dev/null @@ -1,129 +0,0 @@ -// Copyright The Linux Foundation and each contributor to LFX. -// SPDX-License-Identifier: MIT - -import { SENSITIVE_FIELDS } from '@lfx-one/shared/constants'; -import { Request } from 'express'; - -/** - * Standardized request logging helper for consistent log formatting - */ -export class Logger { - /** - * Logs the start of an operation with timing - */ - public static start(req: Request, operation: string, metadata: Record = {}): number { - const startTime = Date.now(); - - req.log.info( - { - operation, - ...metadata, - request_id: req.id, - user_agent: req.get('User-Agent'), - ip_address: req.ip, - }, - `Starting ${operation.replace(/_/g, ' ')}` - ); - - return startTime; - } - - /** - * Logs successful completion of an operation - */ - public static success(req: Request, operation: string, startTime: number, metadata: Record = {}): void { - const duration = Date.now() - startTime; - - req.log.info( - { - operation, - duration, - status_code: metadata['status_code'] || 200, - ...metadata, - request_id: req.id, - }, - `Successfully completed ${operation.replace(/_/g, ' ')}` - ); - } - - /** - * Logs operation failure with error details - */ - public static error(req: Request, operation: string, startTime: number, error: unknown, metadata: Record = {}): void { - const duration = Date.now() - startTime; - - req.log.error( - { - operation, - duration, - err: error, - ...metadata, - request_id: req.id, - }, - `Failed to ${operation.replace(/_/g, ' ')}` - ); - } - - /** - * Logs validation errors specifically - */ - public static validation(req: Request, operation: string, validationErrors: any[], metadata: Record = {}): void { - req.log.warn( - { - operation, - validation_errors: validationErrors, - status_code: 400, - ...metadata, - request_id: req.id, - }, - `Validation failed for ${operation.replace(/_/g, ' ')}` - ); - } - - /** - * Logs ETag-related operations - */ - public static etag(req: Request, operation: string, resourceType: string, resourceId: string, etag?: string, metadata: Record = {}): void { - req.log.info( - { - operation, - resource_type: resourceType, - resource_id: resourceId, - etag, - ...metadata, - request_id: req.id, - }, - `ETag operation: ${operation.replace(/_/g, ' ')}` - ); - } - - /** - * Logs warning messages with operation context - */ - public static warning(req: Request, operation: string, message: string, metadata: Record = {}): void { - req.log.warn( - { - operation, - warning_message: message, - ...metadata, - request_id: req.id, - }, - `Warning during ${operation.replace(/_/g, ' ')}: ${message}` - ); - } - - /** - * Sanitizes sensitive data from metadata before logging - */ - public static sanitize(metadata: Record): Record { - const sanitized = { ...metadata }; - - Object.keys(sanitized).forEach((key) => { - if (SENSITIVE_FIELDS.some((field) => key.toLowerCase().includes(field))) { - sanitized[key] = '[REDACTED]'; - } - }); - - return sanitized; - } -} diff --git a/apps/lfx-one/src/server/helpers/validation.helper.ts b/apps/lfx-one/src/server/helpers/validation.helper.ts index 2bf5601e..4af7fbda 100644 --- a/apps/lfx-one/src/server/helpers/validation.helper.ts +++ b/apps/lfx-one/src/server/helpers/validation.helper.ts @@ -3,7 +3,7 @@ import { Request, NextFunction } from 'express'; import { ServiceValidationError } from '../errors'; -import { Logger } from './logger'; +import { logger } from '../services/logger.service'; /** * Common validation utilities for controllers @@ -32,7 +32,7 @@ export function validateUidParameter(uid: string | undefined, req: Request, next const error = new Error(`Missing ${options.operation.replace('_', ' ')} UID parameter`); if (options.logStartTime) { - Logger.error(req, options.operation, options.logStartTime, error); + logger.error(req, options.operation, options.logStartTime, error); } const validationError = ServiceValidationError.forField('uid', 'UID is required', { @@ -68,7 +68,7 @@ export function validateArrayParameter( const error = new Error(`Missing or empty ${fieldName} array parameter`); if (options.logStartTime) { - Logger.error(req, options.operation, options.logStartTime, error); + logger.error(req, options.operation, options.logStartTime, error); } const validationError = ServiceValidationError.forField(fieldName, `${fieldName} must be a non-empty array`, { @@ -104,7 +104,7 @@ export function validateRequiredParameter( const error = new Error(`Missing required parameter: ${fieldName}`); if (options.logStartTime) { - Logger.error(req, options.operation, options.logStartTime, error); + logger.error(req, options.operation, options.logStartTime, error); } const validationError = ServiceValidationError.forField(fieldName, `${fieldName} is required`, { @@ -133,7 +133,7 @@ export function validateRequestBody(body: T | undefined, req: Request, next: const error = new Error('Missing request body'); if (options.logStartTime) { - Logger.error(req, options.operation, options.logStartTime, error); + logger.error(req, options.operation, options.logStartTime, error); } const validationError = ServiceValidationError.forField('body', 'Request body is required', { diff --git a/apps/lfx-one/src/server/middleware/auth.middleware.ts b/apps/lfx-one/src/server/middleware/auth.middleware.ts index 330d190d..c3ff05f9 100644 --- a/apps/lfx-one/src/server/middleware/auth.middleware.ts +++ b/apps/lfx-one/src/server/middleware/auth.middleware.ts @@ -5,6 +5,7 @@ import { AuthConfig, AuthDecision, AuthMiddlewareResult, RouteAuthConfig, TokenE import { NextFunction, Request, Response } from 'express'; import { AuthenticationError } from '../errors'; +import { logger } from '../services/logger.service'; // OIDC middleware already provides req.oidc with authentication context @@ -64,18 +65,16 @@ function classifyRoute(path: string, config: AuthConfig): RouteAuthConfig { * Checks authentication status from OIDC session */ function checkAuthentication(req: Request): boolean { - req.log.debug( - { - path: req.path, - hasOidc: !!req.oidc, - isAuthenticated: req.oidc?.isAuthenticated(), - cookies: Object.keys(req.cookies || {}), - }, - 'Authentication check debug' - ); + logger.debug(req, 'auth_check', 'Authentication check debug', { + path: req.path, + hasOidc: !!req.oidc, + isAuthenticated: req.oidc?.isAuthenticated(), + cookies: Object.keys(req.cookies || {}), + }); const authenticated = req.oidc?.isAuthenticated() ?? false; - req.log.debug({ path: req.path, authenticated }, authenticated ? 'Authentication check successful' : 'Authentication check failed - not authenticated'); + const message = authenticated ? 'Authentication check successful' : 'Authentication check failed - not authenticated'; + logger.debug(req, 'auth_check', message, { path: req.path, authenticated }); return authenticated; } @@ -86,26 +85,27 @@ function checkAuthentication(req: Request): boolean { * @param attemptRefresh - Whether to attempt token refresh if expired (default: true) */ async function extractBearerToken(req: Request, attemptRefresh: boolean = true): Promise { - try { - req.log.debug( - { - path: req.path, - hasOidc: !!req.oidc, - isAuthenticated: req.oidc?.isAuthenticated(), - hasAccessToken: !!req.oidc?.accessToken, - isTokenExpired: req.oidc?.accessToken?.isExpired(), - tokenValue: req.oidc?.accessToken?.access_token ? 'present' : 'missing', - attemptRefresh, - }, - 'Bearer token extraction debug' - ); + const startTime = logger.startOperation(req, 'token_extraction', { + path: req.path, + hasOidc: !!req.oidc, + isAuthenticated: req.oidc?.isAuthenticated(), + hasAccessToken: !!req.oidc?.accessToken, + isTokenExpired: req.oidc?.accessToken?.isExpired(), + tokenValue: req.oidc?.accessToken?.access_token ? 'present' : 'missing', + attemptRefresh, + }); + try { if (req.oidc?.isAuthenticated()) { // Check if token exists and is expired if (req.oidc.accessToken?.isExpired()) { // For optional routes, don't attempt refresh - just skip token extraction if (!attemptRefresh) { - req.log.debug({ path: req.path }, 'Token expired but refresh not attempted (optional route)'); + logger.success(req, 'token_extraction', startTime, { + path: req.path, + token_extracted: false, + reason: 'skipped_refresh_optional_route', + }); return { success: false, needsLogout: false }; } @@ -114,17 +114,14 @@ async function extractBearerToken(req: Request, attemptRefresh: boolean = true): const refreshedToken = await req.oidc.accessToken.refresh(); if (refreshedToken?.access_token) { req.bearerToken = refreshedToken.access_token; - req.log.debug({ path: req.path }, 'Token refreshed successfully'); + logger.success(req, 'token_refresh', startTime, { path: req.path }); return { success: true, needsLogout: false }; } } catch (refreshError) { - req.log.warn( - { - error: refreshError, - path: req.path, - }, - 'Token refresh failed - user needs to re-authenticate' - ); + logger.error(req, 'token_extraction', startTime, refreshError, { + path: req.path, + failure_reason: 'token_refresh_failed', + }); // Token refresh failed, user needs to re-authenticate return { success: false, needsLogout: true }; } @@ -133,22 +130,24 @@ async function extractBearerToken(req: Request, attemptRefresh: boolean = true): const accessToken = req.oidc.accessToken.access_token; if (typeof accessToken === 'string') { req.bearerToken = accessToken; - req.log.debug({ path: req.path }, 'Bearer token successfully extracted'); + logger.success(req, 'token_extraction', startTime, { path: req.path }); return { success: true, needsLogout: false }; } } } } catch (error) { - req.log.warn( - { - err: error, - path: req.path, - }, - 'Failed to extract bearer token' - ); + logger.error(req, 'token_extraction', startTime, error, { + path: req.path, + failure_reason: 'extraction_error', + }); + return { success: false, needsLogout: false }; } - req.log.debug({ path: req.path }, 'No bearer token extracted'); + logger.success(req, 'token_extraction', startTime, { + path: req.path, + token_extracted: false, + reason: 'not_authenticated', + }); return { success: false, needsLogout: false }; } @@ -160,14 +159,11 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis // Public routes - always allow (check first to short-circuit) if (route.auth === 'public') { - req.log.debug( - { - path: req.path, - routeType: route.type, - authLevel: route.auth, - }, - 'Public route - allowing access' - ); + logger.debug(req, 'auth_decision', 'Public route - allowing access', { + path: req.path, + routeType: route.type, + authLevel: route.auth, + }); return { action: 'allow' }; } @@ -177,52 +173,40 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis if (route.auth === 'optional') { // For optional routes where token is not required, don't fail on token refresh issues if (!route.tokenRequired && needsLogout) { - req.log.debug( - { - path: req.path, - routeType: route.type, - authLevel: route.auth, - tokenRequired: route.tokenRequired, - }, - 'Optional auth route with tokenRequired=false - ignoring token refresh failure' - ); - } - - req.log.debug( - { + logger.debug(req, 'auth_decision', 'Optional auth route with tokenRequired=false - ignoring token refresh failure', { path: req.path, routeType: route.type, authLevel: route.auth, - authenticated, - hasToken, - }, - 'Optional auth route - allowing access' - ); + tokenRequired: route.tokenRequired, + }); + } + + logger.debug(req, 'auth_decision', 'Optional auth route - allowing access', { + path: req.path, + routeType: route.type, + authLevel: route.auth, + authenticated, + hasToken, + }); return { action: 'allow' }; } // If user needs logout due to failed token refresh (only for required auth routes now) if (needsLogout) { - req.log.info( - { - path: req.path, - routeType: route.type, - method: req.method, - }, - 'Token refresh failed - determining response based on request type' - ); + logger.warning(req, 'auth_token_refresh_failure', 'Token refresh failed - user needs logout', { + path: req.path, + routeType: route.type, + method: req.method, + }); // For API routes or non-GET requests, return 401 instead of logout redirect // This prevents breaking XHR/Fetch clients that can't handle HTML redirects if (route.type === 'api' || req.method !== 'GET') { - req.log.info( - { - path: req.path, - routeType: route.type, - method: req.method, - }, - 'API route or non-GET request - returning 401 instead of logout redirect' - ); + logger.debug(req, 'auth_decision_401', 'Returning 401 for API route or non-GET request', { + path: req.path, + routeType: route.type, + method: req.method, + }); return { action: 'error', errorType: 'authentication', @@ -231,14 +215,11 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis } // For SSR GET requests, proceed with logout redirect - req.log.info( - { - path: req.path, - routeType: route.type, - method: req.method, - }, - 'SSR GET request - proceeding with logout redirect' - ); + logger.debug(req, 'auth_decision_logout', 'Proceeding with logout redirect for SSR GET request', { + path: req.path, + routeType: route.type, + method: req.method, + }); return { action: 'logout' }; } @@ -247,14 +228,11 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis if (!authenticated) { // SSR routes - redirect to login if (route.type === 'ssr' && req.method === 'GET') { - req.log.info( - { - path: req.path, - routeType: route.type, - method: req.method, - }, - 'SSR route requires authentication - redirecting to login' - ); + logger.debug(req, 'auth_decision_redirect_login', 'Redirecting to login for unauthenticated SSR GET request', { + path: req.path, + routeType: route.type, + method: req.method, + }); return { action: 'redirect', redirectUrl: `/login?returnTo=${encodeURIComponent(req.originalUrl)}`, @@ -263,14 +241,11 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis // Non-GET SSR routes - return 401 error if (route.type === 'ssr' && req.method !== 'GET') { - req.log.warn( - { - path: req.path, - routeType: route.type, - method: req.method, - }, - 'SSR route requires authentication for non-GET request - returning 401' - ); + logger.warning(req, 'auth_check', 'SSR route requires authentication for non-GET request - returning 401', { + path: req.path, + routeType: route.type, + method: req.method, + }); return { action: 'error', errorType: 'authentication', @@ -280,14 +255,11 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis // API routes - return 401 error if (route.type === 'api') { - req.log.warn( - { - path: req.path, - routeType: route.type, - method: req.method, - }, - 'API route requires authentication - returning 401' - ); + logger.warning(req, 'auth_check', 'API route requires authentication - returning 401', { + path: req.path, + routeType: route.type, + method: req.method, + }); return { action: 'error', errorType: 'authentication', @@ -298,14 +270,11 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis // Token validation for API routes if (route.tokenRequired && !hasToken) { - req.log.warn( - { - path: req.path, - authenticated, - hasToken, - }, - 'API route requires bearer token - returning 401' - ); + logger.warning(req, 'auth_check', 'API route requires bearer token - returning 401', { + path: req.path, + authenticated, + hasToken, + }); return { action: 'error', errorType: 'authentication', @@ -314,16 +283,13 @@ function makeAuthDecision(result: AuthMiddlewareResult, req: Request): AuthDecis } } - req.log.debug( - { - path: req.path, - routeType: route.type, - authLevel: route.auth, - authenticated, - hasToken, - }, - 'Authentication check passed - allowing access' - ); + logger.debug(req, 'auth_decision', 'Authentication check passed - allowing access', { + path: req.path, + routeType: route.type, + authLevel: route.auth, + authenticated, + hasToken, + }); return { action: 'allow' }; } @@ -348,13 +314,10 @@ async function executeAuthDecision(decision: AuthDecision, req: Request, res: Re case 'logout': // Log user out due to token refresh failure - req.log.info( - { - path: req.path, - originalUrl: req.originalUrl, - }, - 'Logging user out due to token refresh failure' - ); + logger.debug(req, 'auth_logout_execution', 'Executing logout due to token refresh failure', { + path: req.path, + originalUrl: req.originalUrl, + }); // Redirect to home page after logout to avoid redirect loops res.oidc.logout({ returnTo: '/' }); break; @@ -380,22 +343,22 @@ async function executeAuthDecision(decision: AuthDecision, req: Request, res: Re */ export function createAuthMiddleware(config: AuthConfig = DEFAULT_CONFIG) { return async (req: Request, res: Response, next: NextFunction): Promise => { - const startTime = Date.now(); + const startTime = logger.startOperation(req, 'auth_middleware', { + path: req.path, + method: req.method, + }); try { // 1. Route classification const routeConfig = classifyRoute(req.path, config); - req.log.debug( - { - path: req.path, - method: req.method, - routeType: routeConfig.type, - authLevel: routeConfig.auth, - tokenRequired: routeConfig.tokenRequired, - }, - 'Starting authentication check' - ); + logger.debug(req, 'auth_middleware', 'Starting authentication check', { + path: req.path, + method: req.method, + routeType: routeConfig.type, + authLevel: routeConfig.auth, + tokenRequired: routeConfig.tokenRequired, + }); // 2. Authentication status check const authenticated = checkAuthentication(req); @@ -428,28 +391,17 @@ export function createAuthMiddleware(config: AuthConfig = DEFAULT_CONFIG) { // 7. Execute decision await executeAuthDecision(decision, req, res, next); - const duration = Date.now() - startTime; - req.log.debug( - { - path: req.path, - decision: decision.action, - authenticated, - hasToken, - duration, - }, - 'Authentication check completed' - ); + logger.success(req, 'auth_middleware', startTime, { + path: req.path, + decision: decision.action, + authenticated, + hasToken, + }); } catch (error) { - const duration = Date.now() - startTime; - req.log.error( - { - err: error, - path: req.path, - method: req.method, - duration, - }, - 'Error in authentication middleware' - ); + logger.error(req, 'auth_middleware', startTime, error, { + path: req.path, + method: req.method, + }); next(error); } }; diff --git a/apps/lfx-one/src/server/middleware/error-handler.middleware.ts b/apps/lfx-one/src/server/middleware/error-handler.middleware.ts index 70aabc33..1df3a6d3 100644 --- a/apps/lfx-one/src/server/middleware/error-handler.middleware.ts +++ b/apps/lfx-one/src/server/middleware/error-handler.middleware.ts @@ -4,6 +4,22 @@ import { NextFunction, Request, Response } from 'express'; import { BaseApiError, isBaseApiError } from '../errors'; +import { logger } from '../services/logger.service'; + +/** + * Derives operation name from request path for logging context + */ +function getOperationFromPath(path: string): string { + // Convert /api/v1/meetings/123 to api_v1_meetings + return ( + path + .replace(/^\//, '') // Remove leading slash + .replace(/\/[0-9a-f-]{36}/gi, '') // Remove UUIDs + .replace(/\/\d+/g, '') // Remove numeric IDs + .replace(/\//g, '_') // Convert slashes to underscores + .replace(/_+$/, '') || 'api_request' + ); // Remove trailing underscores +} export function apiErrorHandler(error: Error | BaseApiError, req: Request, res: Response, next: NextFunction): void { // If response already sent, delegate to default Express error handler @@ -12,11 +28,18 @@ export function apiErrorHandler(error: Error | BaseApiError, req: Request, res: return; } + const operation = getOperationFromPath(req.path); + + // Try to get the operation start time if it was tracked, otherwise use current time + const startTime = logger.getOperationStartTime(req, operation) || Date.now(); + // Handle our structured API errors if (isBaseApiError(error)) { - // Log the error with structured context + // Log the error with structured context for CloudWatch const logLevel = error.getSeverity(); const logContext = { + error_type: error.code, + status_code: error.statusCode, ...error.getLogContext(), request_id: req.id, path: req.path, @@ -25,11 +48,11 @@ export function apiErrorHandler(error: Error | BaseApiError, req: Request, res: }; if (logLevel === 'error') { - req.log.error({ ...logContext, err: error }, `API error: ${error.message}`); + logger.error(req, operation, startTime, error, logContext, { skipIfLogged: true }); } else if (logLevel === 'warn') { - req.log.warn({ ...logContext, err: error }, `API error: ${error.message}`); + logger.warning(req, operation, `API error: ${error.message}`, { ...logContext, err: error }); } else { - req.log.info({ ...logContext, err: error }, `API error: ${error.message}`); + logger.debug(req, operation, `API error: ${error.message}`, { ...logContext, err: error }); } // Send structured response @@ -40,16 +63,19 @@ export function apiErrorHandler(error: Error | BaseApiError, req: Request, res: return; } - // Log unhandled errors - req.log.error( + // Log unhandled errors with CloudWatch-friendly structure + logger.error( + req, + operation, + startTime, + error, { - err: error, + error_type: 'unhandled', path: req.path, method: req.method, user_agent: req.get('User-Agent'), - request_id: req.id, }, - 'Unhandled API error' + { skipIfLogged: true } ); // Default error response for unhandled errors diff --git a/apps/lfx-one/src/server/routes/meetings.route.ts b/apps/lfx-one/src/server/routes/meetings.route.ts index e743f5f8..01584de0 100644 --- a/apps/lfx-one/src/server/routes/meetings.route.ts +++ b/apps/lfx-one/src/server/routes/meetings.route.ts @@ -1,14 +1,12 @@ // Copyright The Linux Foundation and each contributor to LFX. // SPDX-License-Identifier: MIT -import { NextFunction, Request, Response, Router } from 'express'; +import { Router } from 'express'; import { MeetingController } from '../controllers/meeting.controller'; -import { AiService } from '../services/ai.service'; const router = Router(); -const aiService = new AiService(); const meetingController = new MeetingController(); // GET /meetings - get all meetings @@ -64,61 +62,6 @@ router.get('/:uid/attachments/:attachmentId', (req, res, next) => meetingControl router.delete('/:uid/attachments/:attachmentId', (req, res, next) => meetingController.deleteMeetingAttachment(req, res, next)); // AI agenda generation endpoint -router.post('/generate-agenda', async (req: Request, res: Response, next: NextFunction) => { - const startTime = Date.now(); - - req.log.info( - { - operation: 'generate_agenda', - meeting_type: req.body['meetingType'], - has_context: !!req.body['context'], - }, - 'Starting AI agenda generation request' - ); - - try { - const { meetingType, title, projectName, context } = req.body; - - // Validate required fields - if (!meetingType || !title || !projectName) { - return res.status(400).json({ - error: 'Missing required fields: meetingType, title, and projectName are required', - }); - } - - const response = await aiService.generateMeetingAgenda({ - meetingType, - title, - projectName, - context, - }); - - const duration = Date.now() - startTime; - - req.log.info( - { - operation: 'generate_agenda', - duration, - estimated_duration: response.estimatedDuration, - status_code: 200, - }, - 'Successfully generated meeting agenda' - ); - - return res.json(response); - } catch (error) { - const duration = Date.now() - startTime; - req.log.error( - { - err: error, - operation: 'generate_agenda', - duration, - meeting_type: req.body['meetingType'], - }, - 'Failed to generate meeting agenda' - ); - return next(error); - } -}); +router.post('/generate-agenda', (req, res, next) => meetingController.generateAgenda(req, res, next)); export default router; diff --git a/apps/lfx-one/src/server/server-logger.ts b/apps/lfx-one/src/server/server-logger.ts new file mode 100644 index 00000000..f679bb74 --- /dev/null +++ b/apps/lfx-one/src/server/server-logger.ts @@ -0,0 +1,70 @@ +// Copyright The Linux Foundation and each contributor to LFX. +// SPDX-License-Identifier: MIT + +import pino from 'pino'; +import pinoPretty from 'pino-pretty'; + +import { customErrorSerializer } from './helpers/error-serializer'; + +/** + * Base Pino logger instance for server-level operations. + * + * Used for: + * - Server startup/shutdown messages + * - Direct logging from server code outside request context + * - Operations that don't have access to req.log + * - Infrastructure operations (NATS, Snowflake, etc.) + */ + +// Create pretty stream conditionally for development +const prettyStream = + process.env['NODE_ENV'] !== 'production' + ? pinoPretty({ + colorize: true, + translateTime: 'SYS:standard', + ignore: 'pid,hostname', + }) + : process.stdout; + +export const serverLogger = pino( + { + level: process.env['LOG_LEVEL'] || 'info', + base: { + service: 'lfx-one-ssr', + environment: process.env['NODE_ENV'] || 'development', + version: process.env['APP_VERSION'] || '1.0.0', + }, + mixin: () => { + const traceHeader = process.env['_X_AMZN_TRACE_ID']; + if (traceHeader) { + const traceId = traceHeader.split(';')[0]?.replace('Root=', ''); + return { aws_trace_id: traceId }; + } + return {}; + }, + serializers: { + err: customErrorSerializer, + error: customErrorSerializer, + req: pino.stdSerializers.req, + res: pino.stdSerializers.res, + }, + redact: { + paths: + process.env['NODE_ENV'] !== 'production' + ? ['req.headers.*', 'res.headers.*', 'access_token', 'refresh_token', 'authorization', 'cookie'] + : ['access_token', 'refresh_token', 'authorization', 'cookie', 'req.headers.authorization', 'req.headers.cookie', 'res.headers["set-cookie"]'], + remove: true, + }, + formatters: { + level: (label) => { + return { level: label.toUpperCase() }; + }, + bindings: (bindings) => ({ + pid: bindings['pid'], + hostname: bindings['hostname'], + }), + }, + timestamp: pino.stdTimeFunctions.isoTime, + }, + prettyStream +); diff --git a/apps/lfx-one/src/server/server.ts b/apps/lfx-one/src/server/server.ts index 4f18d491..5e7adf73 100644 --- a/apps/lfx-one/src/server/server.ts +++ b/apps/lfx-one/src/server/server.ts @@ -12,12 +12,13 @@ import { dirname, resolve } from 'node:path'; import { fileURLToPath } from 'node:url'; import pino from 'pino'; import pinoHttp from 'pino-http'; -import pinoPretty from 'pino-pretty'; import { customErrorSerializer } from './helpers/error-serializer'; import { validateAndSanitizeUrl } from './helpers/url-validation'; import { authMiddleware } from './middleware/auth.middleware'; import { apiErrorHandler } from './middleware/error-handler.middleware'; +import { serverLogger } from './server-logger'; +import { logger } from './services/logger.service'; import analyticsRouter from './routes/analytics.route'; import committeesRouter from './routes/committees.route'; import meetingsRouter from './routes/meetings.route'; @@ -60,51 +61,6 @@ app.use( }) ); -/** - * Base Pino logger instance for server-level operations. - * - * Used for: - * - Server startup/shutdown messages - * - Direct logging from server code outside request context - * - Operations that don't have access to req.log - * - Can be imported by other modules for consistent logging - */ -// Create pretty stream conditionally for development -const prettyStream = - process.env['NODE_ENV'] !== 'production' - ? pinoPretty({ - colorize: true, - translateTime: 'SYS:standard', - ignore: 'pid,hostname', - }) - : process.stdout; - -const serverLogger = pino( - { - level: process.env['LOG_LEVEL'] || 'info', - serializers: { - err: customErrorSerializer, - error: customErrorSerializer, - req: pino.stdSerializers.req, - res: pino.stdSerializers.res, - }, - redact: { - paths: - process.env['NODE_ENV'] !== 'production' - ? ['req.headers.*', 'res.headers.*', 'access_token', 'refresh_token', 'authorization', 'cookie'] - : ['access_token', 'refresh_token', 'authorization', 'cookie', 'req.headers.authorization', 'req.headers.cookie', 'res.headers["set-cookie"]'], - remove: true, - }, - formatters: { - level: (label) => { - return { level: label.toUpperCase() }; - }, - }, - timestamp: pino.stdTimeFunctions.isoTime, - }, - prettyStream -); - app.use(express.json({ limit: '15mb' })); app.use(express.urlencoded({ extended: true, limit: '15mb' })); @@ -143,11 +99,8 @@ const httpLogger = pinoHttp({ req: pino.stdSerializers.req, res: pino.stdSerializers.res, }, - autoLogging: { - ignore: (req: Request) => { - return req.url === '/health' || req.url === '/api/health' || req.url.startsWith('/.well-known'); - }, - }, + // Disable automatic request/response logging - our LoggerService handles operation logging + autoLogging: false, redact: { paths: process.env['NODE_ENV'] !== 'production' @@ -160,6 +113,10 @@ const httpLogger = pinoHttp({ level: (label) => { return { level: label.toUpperCase() }; }, + bindings: (bindings) => ({ + pid: bindings['pid'], + hostname: bindings['hostname'], + }), }, timestamp: pino.stdTimeFunctions.isoTime, }); @@ -233,6 +190,7 @@ app.use('/api/*', apiErrorHandler); * Require authentication for all non-API routes. */ app.use('/**', async (req: Request, res: Response, next: NextFunction) => { + const ssrStartTime = Date.now(); // Capture start time for duration tracking const auth: AuthContext = { authenticated: false, user: null, @@ -251,13 +209,10 @@ app.use('/**', async (req: Request, res: Response, next: NextFunction) => { } } catch (error) { // If userinfo fetch fails, fall back to basic user info from token - req.log.warn( - { - err: error, - path: req.path, - }, - 'Failed to fetch user info, using basic user data' - ); + logger.warning(req, 'ssr_user_info', 'Failed to fetch user info, using basic user data', { + err: error, + path: req.path, + }); res.oidc.logout(); return; @@ -288,16 +243,13 @@ app.use('/**', async (req: Request, res: Response, next: NextFunction) => { return next(); }) .catch((error) => { - req.log.error( - { - error: error.message, - code: error.code, - url: req.url, - method: req.method, - user_agent: req.get('User-Agent'), - }, - 'Error rendering Angular application' - ); + logger.error(req, 'ssr_render', ssrStartTime, error, { + error_message: error.message, + code: error.code, + url: req.url, + method: req.method, + user_agent: req.get('User-Agent'), + }); if (error.code === 'NOT_FOUND') { res.status(404).send('Not Found'); @@ -328,24 +280,15 @@ app.use((error: Error, req: Request, res: Response, next: NextFunction) => { export function startServer() { const port = process.env['PORT'] || 4000; app.listen(port, () => { - serverLogger.info( - { - port, - url: `http://localhost:${port}`, - node_env: process.env['NODE_ENV'] || 'development', - pm2: process.env['PM2'] === 'true', - }, - 'Node Express server started' - ); + logger.debug(undefined, 'server_startup', 'Node Express server started', { + port, + url: `http://localhost:${port}`, + node_env: process.env['NODE_ENV'] || 'development', + pm2: process.env['PM2'] === 'true', + }); }); } -/** - * Export server logger for use in other modules that need logging - * outside of the HTTP request context (e.g., startup scripts, utilities). - */ -export { serverLogger }; - const metaUrl = import.meta.url; const isMain = isMainModule(metaUrl); const isPM2 = process.env['PM2'] === 'true'; diff --git a/apps/lfx-one/src/server/services/access-check.service.ts b/apps/lfx-one/src/server/services/access-check.service.ts index d9fed543..67268240 100644 --- a/apps/lfx-one/src/server/services/access-check.service.ts +++ b/apps/lfx-one/src/server/services/access-check.service.ts @@ -4,7 +4,7 @@ import { AccessCheckAccessType, AccessCheckApiRequest, AccessCheckApiResponse, AccessCheckRequest, AccessCheckResourceType } from '@lfx-one/shared/interfaces'; import { Request } from 'express'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { MicroserviceProxyService } from './microservice-proxy.service'; /** @@ -28,6 +28,12 @@ export class AccessCheckService { return new Map(); } + const startTime = logger.startOperation(req, 'check_access_permissions', { + request_count: resources.length, + resource_types: [...new Set(resources.map((r) => r.resource))], + access_types: [...new Set(resources.map((r) => r.access))], + }); + try { // Transform requests to the expected API format const apiRequests = resources.map((resource) => `${resource.resource}:${resource.id}#${resource.access}`); @@ -36,13 +42,6 @@ export class AccessCheckService { requests: apiRequests, }; - const sanitizedPayload = Logger.sanitize({ - request_count: resources.length, - resource_types: [...new Set(resources.map((r) => r.resource))], - access_types: [...new Set(resources.map((r) => r.access))], - }); - req.log.info(sanitizedPayload, 'Checking access permissions'); - // Make the API request const response = await this.microserviceProxy.proxyRequest( req, @@ -85,26 +84,17 @@ export class AccessCheckService { userAccessInfo.push({ resourceId: resource.id, username, hasAccess }); } - req.log.debug( - Logger.sanitize({ - operation: 'check_access', - request_count: resources.length, - granted_count: Array.from(resultMap.values()).filter(Boolean).length, - access_details: userAccessInfo, - }), - 'Access check completed successfully' - ); + logger.success(req, 'check_access_permissions', startTime, { + request_count: resources.length, + granted_count: Array.from(resultMap.values()).filter(Boolean).length, + }); return resultMap; } catch (error) { - req.log.error( - { - operation: 'check_access', - request_count: resources.length, - err: error, - }, - 'Access check failed, defaulting to no access' - ); + logger.error(req, 'check_access_permissions', startTime, error, { + request_count: resources.length, + fallback_behavior: 'returning no access', + }); // Return map with all false values as fallback const fallbackMap = new Map(); diff --git a/apps/lfx-one/src/server/services/ai.service.ts b/apps/lfx-one/src/server/services/ai.service.ts index 269911ce..c974dfc9 100644 --- a/apps/lfx-one/src/server/services/ai.service.ts +++ b/apps/lfx-one/src/server/services/ai.service.ts @@ -4,8 +4,9 @@ import { AI_AGENDA_SYSTEM_PROMPT, AI_MODEL, AI_REQUEST_CONFIG, DURATION_ESTIMATION } from '@lfx-one/shared/constants'; import { MeetingType } from '@lfx-one/shared/enums'; import { GenerateAgendaRequest, GenerateAgendaResponse, OpenAIChatRequest, OpenAIChatResponse } from '@lfx-one/shared/interfaces'; +import { Request } from 'express'; -import { serverLogger } from '../server'; +import { logger } from './logger.service'; export class AiService { private readonly aiProxyUrl: string; @@ -23,15 +24,15 @@ export class AiService { } } - public async generateMeetingAgenda(request: GenerateAgendaRequest): Promise { - try { - serverLogger.info('Generating meeting agenda', { - meetingType: request.meetingType, - title: request.title, - hasContext: !!request.context, - projectName: request.projectName, - }); + public async generateMeetingAgenda(req: Request, request: GenerateAgendaRequest): Promise { + const startTime = logger.startOperation(req, 'generate_meeting_agenda', { + meetingType: request.meetingType, + title: request.title, + hasContext: !!request.context, + projectName: request.projectName, + }); + try { const prompt = this.buildPrompt(request); const chatRequest: OpenAIChatRequest = { model: this.model, @@ -76,15 +77,15 @@ export class AiService { }; const response = await this.makeAiRequest(chatRequest); - const result = this.extractAgendaAndDuration(response); + const result = this.extractAgendaAndDuration(req, response); - serverLogger.info('Successfully generated meeting agenda', { + logger.success(req, 'generate_meeting_agenda', startTime, { estimatedDuration: result.estimatedDuration, }); return result; } catch (error) { - serverLogger.error({ err: error }, 'Failed to generate meeting agenda'); + logger.error(req, 'generate_meeting_agenda', startTime, error); throw new Error('Failed to generate meeting agenda'); } } @@ -145,7 +146,7 @@ export class AiService { return response.json(); } - private extractAgendaAndDuration(response: OpenAIChatResponse): GenerateAgendaResponse { + private extractAgendaAndDuration(req: Request, response: OpenAIChatResponse): GenerateAgendaResponse { if (!response.choices || response.choices.length === 0) { throw new Error('No agenda generated'); } @@ -176,9 +177,9 @@ export class AiService { estimatedDuration: cappedDuration, }; } catch (parseError) { - serverLogger.warn('Failed to parse JSON response, falling back to text extraction', { + logger.warning(req, 'generate_meeting_agenda', 'Failed to parse JSON response, falling back to text extraction', { content: content.substring(0, 100), - error: parseError, + err: parseError, }); // Fallback to treating the entire content as agenda with heuristic duration diff --git a/apps/lfx-one/src/server/services/committee.service.ts b/apps/lfx-one/src/server/services/committee.service.ts index 5c4be830..932ffcb1 100644 --- a/apps/lfx-one/src/server/services/committee.service.ts +++ b/apps/lfx-one/src/server/services/committee.service.ts @@ -14,7 +14,7 @@ import { import { Request } from 'express'; import { ResourceNotFoundError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; import { AccessCheckService } from './access-check.service'; import { ETagService } from './etag.service'; import { MicroserviceProxyService } from './microservice-proxy.service'; @@ -110,28 +110,14 @@ export class CommitteeService { // Step 1: Create committee const newCommittee = await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', '/committees', 'POST', {}, committeeData); - req.log.info( - { - operation: 'create_committee', - committee_id: newCommittee.uid, - committee_category: newCommittee.category, - }, - 'Committee created successfully' - ); - // Step 2: Update settings if provided if (business_email_required !== undefined || is_audit_enabled !== undefined) { try { await this.updateCommitteeSettings(req, newCommittee.uid, { business_email_required, is_audit_enabled }); - } catch (error) { - req.log.warn( - { - operation: 'create_committee', - committee_id: newCommittee.uid, - err: error, - }, - 'Failed to update committee settings, but committee was created successfully' - ); + } catch { + logger.warning(req, 'create_committee_settings', 'Failed to update committee settings, but committee was created successfully', { + committee_uid: newCommittee.uid, + }); } } @@ -162,27 +148,14 @@ export class CommitteeService { 'update_committee' ); - req.log.info( - { - operation: 'update_committee', - committee_id: committeeId, - }, - 'Committee updated successfully' - ); - // Step 3: Update settings if provided if (business_email_required !== undefined || is_audit_enabled !== undefined) { try { await this.updateCommitteeSettings(req, committeeId, { business_email_required, is_audit_enabled }); - } catch (error) { - req.log.warn( - { - operation: 'update_committee', - committee_id: committeeId, - err: error, - }, - 'Failed to update committee settings, but committee was updated successfully' - ); + } catch { + logger.warning(req, 'update_committee_settings', 'Failed to update committee settings, but committee was updated successfully', { + committee_uid: committeeId, + }); } } @@ -202,14 +175,6 @@ export class CommitteeService { // Step 2: Delete committee with ETag await this.etagService.deleteWithETag(req, 'LFX_V2_SERVICE', `/committees/${committeeId}`, etag, 'delete_committee'); - - req.log.info( - { - operation: 'delete_committee', - committee_id: committeeId, - }, - 'Committee deleted successfully' - ); } /** @@ -237,14 +202,10 @@ export class CommitteeService { * Fetches count of all members for a specific committee */ public async getCommitteeMembersCount(req: Request, committeeId: string, query: Record = {}): Promise { - req.log.debug( - { - operation: 'get_committee_members_count', - committee_id: committeeId, - query: query, - }, - 'Fetching committee members count' - ); + logger.debug(req, 'get_committee_members_count', 'Fetching committee members count', { + committee_uid: committeeId, + query, + }); const params = { ...query, @@ -292,14 +253,10 @@ export class CommitteeService { public async createCommitteeMember(req: Request, committeeId: string, data: CreateCommitteeMemberRequest): Promise { const newMember = await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/committees/${committeeId}/members`, 'POST', {}, data); - req.log.info( - Logger.sanitize({ - operation: 'create_committee_member', - committee_id: committeeId, - member_id: newMember.uid, - }), - 'Committee member created successfully' - ); + logger.debug(req, 'create_committee_member', 'Committee member created successfully', { + committee_uid: committeeId, + member_uid: newMember.uid, + }); return newMember; } @@ -334,14 +291,10 @@ export class CommitteeService { 'update_committee_member' ); - req.log.info( - { - operation: 'update_committee_member', - committee_id: committeeId, - member_id: memberId, - }, - 'Committee member updated successfully' - ); + logger.debug(req, 'update_committee_member', 'Committee member updated successfully', { + committee_uid: committeeId, + member_uid: memberId, + }); return updatedMember; } @@ -364,14 +317,10 @@ export class CommitteeService { // Step 2: Delete member with ETag await this.etagService.deleteWithETag(req, 'LFX_V2_SERVICE', `/committees/${committeeId}/members/${memberId}`, etag, 'delete_committee_member'); - req.log.info( - { - operation: 'delete_committee_member', - committee_id: committeeId, - member_id: memberId, - }, - 'Committee member deleted successfully' - ); + logger.debug(req, 'delete_committee_member', 'Committee member deleted successfully', { + committee_uid: committeeId, + member_uid: memberId, + }); } /** @@ -399,15 +348,11 @@ export class CommitteeService { const userMemberships = resources.map((resource) => resource.data); - req.log.debug( - { - operation: 'get_committee_members_by_category', - username, - category, - memberships_count: userMemberships.length, - }, - `Fetched user committee memberships for category: ${category}` - ); + logger.debug(req, 'get_committee_members_by_category', 'Committee memberships retrieved', { + username, + category, + memberships_count: userMemberships.length, + }); return userMemberships; } @@ -427,13 +372,9 @@ export class CommitteeService { await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/committees/${committeeId}/settings`, 'PUT', {}, settingsData); - req.log.info( - { - operation: 'update_committee_settings', - committee_id: committeeId, - settings_data: settingsData, - }, - 'Committee settings updated successfully' - ); + logger.debug(req, 'update_committee_settings', 'Committee settings updated successfully', { + committee_uid: committeeId, + settings_data: settingsData, + }); } } diff --git a/apps/lfx-one/src/server/services/etag.service.ts b/apps/lfx-one/src/server/services/etag.service.ts index 504aed6b..6ec98395 100644 --- a/apps/lfx-one/src/server/services/etag.service.ts +++ b/apps/lfx-one/src/server/services/etag.service.ts @@ -5,6 +5,7 @@ import { HTTP_HEADERS } from '@lfx-one/shared/constants'; import { ETagError, ETagResult } from '@lfx-one/shared/interfaces'; import { Request } from 'express'; +import { logger } from './logger.service'; import { MicroserviceProxyService } from './microservice-proxy.service'; /** @@ -17,87 +18,50 @@ export class ETagService { * Fetches a resource with ETag header for safe operations */ public async fetchWithETag(req: Request, service: 'LFX_V2_SERVICE', path: string, operation: string): Promise> { - req.log.debug( - { - operation, - step: 'fetch_with_etag', - path, - }, - 'Fetching resource to obtain ETag header' - ); - - try { - const response = await this.microserviceProxy.proxyRequestWithResponse(req, service, path, 'GET'); - - if (!response.data) { - const error: ETagError = { - code: 'NOT_FOUND', - message: 'Resource not found', - statusCode: 404, - }; - throw error; - } - - const etag = response.headers[HTTP_HEADERS.ETAG.toLowerCase()] || response.headers[HTTP_HEADERS.ETAG]; + logger.debug(req, operation, 'Fetching resource with ETag', { step: 'fetch_with_etag', path }); - if (!etag) { - req.log.warn( - { - operation, - path, - error: 'ETag header not found in response', - available_headers: Object.keys(response.headers), - }, - 'ETag header missing from resource response' - ); + const response = await this.microserviceProxy.proxyRequestWithResponse(req, service, path, 'GET'); - const error: ETagError = { - code: 'ETAG_MISSING', - message: 'Unable to obtain ETag header for safe operation', - statusCode: 500, - headers: response.headers, - }; - throw error; - } + if (!response.data) { + const error = new Error('Resource not found') as Error & ETagError; + error.code = 'NOT_FOUND'; + error.statusCode = 404; + throw error; + } - req.log.debug( - { - operation, - step: 'resource_fetched', - path, - has_etag: true, - }, - 'Resource fetched successfully with ETag' - ); + const etag = response.headers[HTTP_HEADERS.ETAG.toLowerCase()] || response.headers[HTTP_HEADERS.ETAG]; - return { - data: response.data, - etag, - headers: response.headers, - }; - } catch (error) { - if (this.isETagError(error)) { - req.log.error({ error }, 'ETag error'); - } + if (!etag) { + logger.warning(req, operation, 'ETag header not found in response', { + path, + available_headers: Object.keys(response.headers), + }); - // Let original error bubble up - don't transform here + const error = new Error('Unable to obtain ETag header for safe operation') as Error & ETagError; + error.code = 'ETAG_MISSING'; + error.statusCode = 500; + error.headers = response.headers; throw error; } + + logger.debug(req, operation, 'Resource fetched successfully with ETag', { + step: 'resource_fetched', + path, + has_etag: true, + }); + + return { + data: response.data, + etag, + headers: response.headers, + }; } /** * Performs a safe update operation using If-Match header */ public async updateWithETag(req: Request, service: 'LFX_V2_SERVICE', path: string, etag: string, data: any, operation: string): Promise { - req.log.debug( - { - operation, - step: 'update_with_etag', - path, - etag_value: etag, - }, - 'Attempting to update resource with If-Match header' - ); + logger.debug(req, operation, 'Updating resource with ETag', { step: 'update_with_etag', path, has_etag: !!etag }); return await this.microserviceProxy.proxyRequest(req, service, path, 'PUT', {}, data, { [HTTP_HEADERS.IF_MATCH]: etag }); } @@ -106,30 +70,8 @@ export class ETagService { * Performs a safe delete operation using If-Match header */ public async deleteWithETag(req: Request, service: 'LFX_V2_SERVICE', path: string, etag: string, operation: string): Promise { - req.log.debug( - { - operation, - step: 'delete_with_etag', - path, - etag_value: etag, - }, - 'Attempting to delete resource with If-Match header' - ); + logger.debug(req, operation, 'Deleting resource with ETag', { step: 'delete_with_etag', path, has_etag: !!etag }); await this.microserviceProxy.proxyRequest(req, service, path, 'DELETE', {}, undefined, { [HTTP_HEADERS.IF_MATCH]: etag }); } - - /** - * Type guard for ETag errors - */ - private isETagError(error: unknown): error is ETagError { - if (error === null || typeof error !== 'object') return false; - - const errorObj = error as Record; - return ( - typeof errorObj['code'] === 'string' && - typeof errorObj['statusCode'] === 'number' && - ['NOT_FOUND', 'ETAG_MISSING', 'NETWORK_ERROR', 'PRECONDITION_FAILED'].includes(errorObj['code'] as string) - ); - } } diff --git a/apps/lfx-one/src/server/services/logger.service.ts b/apps/lfx-one/src/server/services/logger.service.ts new file mode 100644 index 00000000..fc16f029 --- /dev/null +++ b/apps/lfx-one/src/server/services/logger.service.ts @@ -0,0 +1,449 @@ +// Copyright The Linux Foundation and each contributor to LFX. +// SPDX-License-Identifier: MIT + +import { SENSITIVE_FIELDS } from '@lfx-one/shared/constants'; +import { Request } from 'express'; + +import { serverLogger } from '../server-logger'; + +/** + * Operation state for tracking active operations per request + */ +interface OperationState { + startTime: number; + operation: string; + logged: boolean; +} + +/** + * Options for starting an operation + */ +interface StartOperationOptions { + silent?: boolean; +} + +/** + * Options for error logging + */ +interface ErrorOptions { + skipIfLogged?: boolean; +} + +/** + * LoggerService - Singleton service for consistent, deduplicated logging + * + * Features: + * - Operation tracking to prevent duplicate logs (request-scoped only) + * - CloudWatch-optimized JSON output + * - Request correlation via request_id (when req provided) + * - Duration tracking for performance monitoring + * - Supports both request-scoped (with req) and infrastructure (without req) logging + */ +export class LoggerService { + private static instance: LoggerService; + + /** + * WeakMap to track operations per request without memory leaks + * Key: Request object, Value: Map of operation name to state + */ + private operationStacks: WeakMap> = new WeakMap(); + + private constructor() {} + + /** + * Get the singleton instance + */ + public static getInstance(): LoggerService { + if (!LoggerService.instance) { + LoggerService.instance = new LoggerService(); + } + return LoggerService.instance; + } + + /** + * Starts tracking an operation and logs at INFO level + * Returns startTime for duration calculation + * @param req - Request object (optional - use undefined for infrastructure operations) + */ + public startOperation(req: Request | undefined, operation: string, metadata: Record = {}, options: StartOperationOptions = {}): number { + const startTime = Date.now(); + + // Infrastructure logging (no request context) + if (!req) { + if (!options.silent) { + serverLogger.info( + { + operation, + status: 'started', + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `Starting ${this.formatOperation(operation)}` + ); + } + return startTime; + } + + // Request-scoped logging with deduplication tracking + const stack = this.getOperationStack(req); + + // Check for duplicate start calls + if (stack.has(operation)) { + const existing = stack.get(operation); + if (existing && !existing.logged) { + req.log.warn( + { + operation, + warning: 'duplicate_start_detected', + original_start: existing.startTime, + request_id: req.id, + }, + `Duplicate start detected for ${this.formatOperation(operation)}` + ); + } + } + + // Store operation state + stack.set(operation, { + startTime, + operation, + logged: false, + }); + + // Log start unless silent mode + if (!options.silent) { + req.log.info( + { + operation, + status: 'started', + request_id: req.id, + user_agent: req.get('User-Agent'), + ip_address: req.ip, + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `Starting ${this.formatOperation(operation)}` + ); + } + + return startTime; + } + + /** + * Logs successful completion of an operation + * @param req - Request object (optional - use undefined for infrastructure operations) + */ + public success(req: Request | undefined, operation: string, startTime: number, metadata: Record = {}): void { + const duration = Date.now() - startTime; + + // Infrastructure logging (no request context) + if (!req) { + const { status_code, ...restMetadata } = metadata as { status_code?: number; [key: string]: unknown }; + serverLogger.info( + { + operation, + status: 'success', + duration_ms: duration, + ...(status_code && { status_code }), + ...(Object.keys(restMetadata).length > 0 && { data: restMetadata }), + }, + `Successfully completed ${this.formatOperation(operation)}` + ); + return; + } + + // Request-scoped logging with deduplication tracking + const stack = this.getOperationStack(req); + const opState = stack.get(operation); + + // Mark as logged to prevent duplicate logging + if (opState) { + opState.logged = true; + } + + // Extract status_code from metadata if present, rest goes to data + const { status_code, ...restMetadata } = metadata as { status_code?: number; [key: string]: unknown }; + + req.log.info( + { + operation, + status: 'success', + duration_ms: duration, + status_code: status_code || 200, + request_id: req.id, + ...(Object.keys(restMetadata).length > 0 && { data: restMetadata }), + }, + `Successfully completed ${this.formatOperation(operation)}` + ); + + // Clean up completed operation + stack.delete(operation); + } + + /** + * Logs operation failure with error details + * Can skip logging if already logged (prevents duplicates - request-scoped only) + * @param req - Request object (optional - use undefined for infrastructure operations) + */ + public error( + req: Request | undefined, + operation: string, + startTime: number, + error: unknown, + metadata: Record = {}, + options: ErrorOptions = {} + ): void { + const duration = Date.now() - startTime; + + // Infrastructure logging (no request context) + if (!req) { + serverLogger.error( + { + operation, + status: 'failed', + duration_ms: duration, + err: error, + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `Failed to ${this.formatOperation(operation)}` + ); + return; + } + + // Request-scoped logging with deduplication tracking + const stack = this.getOperationStack(req); + const opState = stack.get(operation); + + // Skip if already logged and skipIfLogged is true + if (options.skipIfLogged && opState?.logged) { + req.log.debug( + { + operation, + skip_reason: 'already_logged', + request_id: req.id, + }, + `Skipping duplicate error log for ${this.formatOperation(operation)}` + ); + return; + } + + // Mark as logged + if (opState) { + opState.logged = true; + } + + req.log.error( + { + operation, + status: 'failed', + duration_ms: duration, + err: error, + request_id: req.id, + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `Failed to ${this.formatOperation(operation)}` + ); + + // Clean up failed operation + stack.delete(operation); + } + + /** + * Logs validation errors + * @param req - Request object (optional - use undefined for infrastructure operations) + */ + public validation(req: Request | undefined, operation: string, validationErrors: unknown[], metadata: Record = {}): void { + // Infrastructure logging (no request context) + if (!req) { + serverLogger.error( + { + operation, + status: 'failed', + error_type: 'validation', + validation_errors: validationErrors, + status_code: 400, + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `Validation failed for ${this.formatOperation(operation)}` + ); + return; + } + + // Request-scoped logging + req.log.error( + { + operation, + status: 'failed', + error_type: 'validation', + validation_errors: validationErrors, + status_code: 400, + request_id: req.id, + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `Validation failed for ${this.formatOperation(operation)}` + ); + } + + /** + * Logs ETag-related operations + * @param req - Request object (optional - use undefined for infrastructure operations) + */ + public etag( + req: Request | undefined, + operation: string, + resourceType: string, + resourceId: string, + etag?: string, + metadata: Record = {} + ): void { + // Infrastructure logging (no request context) + if (!req) { + serverLogger.info( + { + operation, + resource_type: resourceType, + resource_id: resourceId, + etag, + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `ETag operation: ${this.formatOperation(operation)}` + ); + return; + } + + // Request-scoped logging + req.log.info( + { + operation, + resource_type: resourceType, + resource_id: resourceId, + etag, + request_id: req.id, + ...(Object.keys(metadata).length > 0 && { data: metadata }), + }, + `ETag operation: ${this.formatOperation(operation)}` + ); + } + + /** + * Logs warning messages with operation context + * @param req - Request object (optional - use undefined for infrastructure operations) + */ + public warning(req: Request | undefined, operation: string, message: string, metadata: Record = {}): void { + // Extract err from metadata to place at top level for proper error serialization + const { err, ...rest } = metadata; + + // Infrastructure logging (no request context) + if (!req) { + serverLogger.warn( + { + operation, + status: 'warning', + warning_message: message, + ...(err ? { err } : {}), // err at top level for Pino error serializer + ...(Object.keys(rest).length > 0 && { data: rest }), + }, + `Warning during ${this.formatOperation(operation)}: ${message}` + ); + return; + } + + // Request-scoped logging + req.log.warn( + { + operation, + status: 'warning', + warning_message: message, + request_id: req.id, + ...(err ? { err } : {}), // err at top level for Pino error serializer + ...(Object.keys(rest).length > 0 && { data: rest }), + }, + `Warning during ${this.formatOperation(operation)}: ${message}` + ); + } + + /** + * Logs debug messages with operation context + * Use for detailed internal state, preparation steps, or verbose information + * @param req - Request object (optional - use undefined for infrastructure operations) + */ + public debug(req: Request | undefined, operation: string, message: string, metadata: Record = {}): void { + // Extract err from metadata to place at top level for proper error serialization + const { err, ...rest } = metadata; + + // Infrastructure logging (no request context) + if (!req) { + serverLogger.debug( + { + operation, + status: 'debug', + ...(err ? { err } : {}), // err at top level for Pino error serializer + ...(Object.keys(rest).length > 0 && { data: rest }), + }, + `${this.formatOperation(operation)}: ${message}` + ); + return; + } + + // Request-scoped logging + req.log.debug( + { + operation, + status: 'debug', + request_id: req.id, + ...(err ? { err } : {}), // err at top level for Pino error serializer + ...(Object.keys(rest).length > 0 && { data: rest }), + }, + `${this.formatOperation(operation)}: ${message}` + ); + } + + /** + * Sanitizes sensitive data from metadata before logging + */ + public sanitize(metadata: Record): Record { + const sanitized = { ...metadata }; + + Object.keys(sanitized).forEach((key) => { + if (SENSITIVE_FIELDS.some((field) => key.toLowerCase().includes(field))) { + sanitized[key] = '[REDACTED]'; + } + }); + + return sanitized; + } + + /** + * Checks if an operation has been started + */ + public hasOperation(req: Request, operation: string): boolean { + const stack = this.getOperationStack(req); + return stack.has(operation); + } + + /** + * Gets the start time of an operation (useful for nested operations) + */ + public getOperationStartTime(req: Request, operation: string): number | undefined { + const stack = this.getOperationStack(req); + return stack.get(operation)?.startTime; + } + + /** + * Get or create the operation stack for a request + */ + private getOperationStack(req: Request): Map { + if (!this.operationStacks.has(req)) { + this.operationStacks.set(req, new Map()); + } + return this.operationStacks.get(req)!; + } + + /** + * Format operation name for log messages + */ + private formatOperation(operation: string): string { + return operation.replace(/_/g, ' '); + } +} + +// Export singleton instance for convenient usage +export const logger = LoggerService.getInstance(); diff --git a/apps/lfx-one/src/server/services/meeting.service.ts b/apps/lfx-one/src/server/services/meeting.service.ts index cccf722f..c47972b7 100644 --- a/apps/lfx-one/src/server/services/meeting.service.ts +++ b/apps/lfx-one/src/server/services/meeting.service.ts @@ -23,12 +23,12 @@ import { isUuid, transformV1MeetingToV2, transformV1SummaryToV2 } from '@lfx-one import { Request } from 'express'; import { ResourceNotFoundError } from '../errors'; -import { Logger } from '../helpers/logger'; import { getUsernameFromAuth } from '../utils/auth-helper'; import { generateM2MToken } from '../utils/m2m-token.util'; import { AccessCheckService } from './access-check.service'; import { CommitteeService } from './committee.service'; import { ETagService } from './etag.service'; +import { logger } from './logger.service'; import { MicroserviceProxyService } from './microservice-proxy.service'; import { ProjectService } from './project.service'; @@ -176,24 +176,13 @@ export class MeetingService { ...(username && { organizers: [username] }), }; - const sanitizedPayload = Logger.sanitize({ createPayload }); - req.log.debug(sanitizedPayload, 'Creating meeting payload'); + const sanitizedPayload = logger.sanitize({ createPayload }); + logger.debug(req, 'create_meeting', 'Creating meeting payload', sanitizedPayload); const newMeeting = await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', '/meetings', 'POST', undefined, createPayload, { ['X-Sync']: 'true', }); - req.log.info( - { - operation: 'create_meeting', - meeting_id: newMeeting.uid, - project_uid: newMeeting.project_uid, - title: newMeeting.title, - organizer: username || 'none', - }, - 'Meeting created successfully' - ); - return newMeeting; } @@ -222,8 +211,8 @@ export class MeetingService { organizers: Array.from(organizersSet), }; - const sanitizedPayload = Logger.sanitize({ updatePayload, editType }); - req.log.debug(sanitizedPayload, 'Updating meeting payload'); + const sanitizedPayload = logger.sanitize({ updatePayload, editType }); + logger.debug(req, 'update_meeting', 'Updating meeting payload', sanitizedPayload); // Step 2: Update meeting with ETag, including editType query parameter if provided let path = `/meetings/${meetingUid}`; @@ -233,18 +222,6 @@ export class MeetingService { const updatedMeeting = await this.etagService.updateWithETag(req, 'LFX_V2_SERVICE', path, etag, updatePayload, 'update_meeting'); - req.log.info( - { - operation: 'update_meeting', - meeting_uid: meetingUid, - project_uid: updatedMeeting.project_uid, - title: updatedMeeting.title, - edit_type: editType || 'single', - organizer: username || 'none', - }, - 'Meeting updated successfully' - ); - return updatedMeeting; } @@ -257,14 +234,6 @@ export class MeetingService { // Step 2: Delete meeting with ETag await this.etagService.deleteWithETag(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}`, etag, 'delete_meeting'); - - req.log.info( - { - operation: 'delete_meeting', - meeting_uid: meetingUid, - }, - 'Meeting deleted successfully' - ); } /** @@ -276,15 +245,6 @@ export class MeetingService { // Step 2: Cancel occurrence with ETag await this.etagService.deleteWithETag(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/occurrences/${occurrenceId}`, etag, 'cancel_occurrence'); - - req.log.info( - { - operation: 'cancel_occurrence', - meeting_uid: meetingUid, - occurrence_id: occurrenceId, - }, - 'Meeting occurrence canceled successfully' - ); } /** @@ -292,77 +252,35 @@ export class MeetingService { * @param includeRsvp - If true, includes RSVP status for each registrant */ public async getMeetingRegistrants(req: Request, meetingUid: string, includeRsvp: boolean = false): Promise { - try { - const { resources } = await this.microserviceProxy.proxyRequest>( - req, - 'LFX_V2_SERVICE', - `/query/resources`, - 'GET', - { - type: 'meeting_registrant', - tags: `meeting_uid:${meetingUid}`, - } - ); + const { resources } = await this.microserviceProxy.proxyRequest>(req, 'LFX_V2_SERVICE', `/query/resources`, 'GET', { + type: 'meeting_registrant', + tags: `meeting_uid:${meetingUid}`, + }); - let registrants = resources.map((resource) => resource.data); + let registrants = resources.map((resource) => resource.data); - // If include_rsvp is true, fetch RSVP data and attach to registrants - if (includeRsvp) { - try { - const rsvps = await this.getMeetingRsvps(req, meetingUid); - - // Create a map of username to RSVP for quick lookup - const rsvpMap = new Map(rsvps.map((rsvp) => [rsvp.username, rsvp])); - - // Attach RSVP data to each registrant - registrants = registrants.map((registrant) => ({ - ...registrant, - rsvp: registrant.username ? rsvpMap.get(registrant.username) || null : null, - })); - - req.log.info( - { - operation: 'get_meeting_registrants', - meeting_uid: meetingUid, - registrant_count: registrants.length, - rsvp_count: rsvps.length, - include_rsvp: true, - }, - 'Meeting registrants with RSVPs fetched successfully' - ); - } catch (error) { - req.log.warn( - { - operation: 'get_meeting_registrants', - meeting_uid: meetingUid, - err: error, - }, - 'Failed to fetch RSVPs for registrants, returning registrants without RSVP data' - ); - } - } else { - req.log.info( - { - operation: 'get_meeting_registrants', - meeting_uid: meetingUid, - registrant_count: registrants.length, - }, - 'Meeting registrants fetched successfully' - ); - } + // If include_rsvp is true, fetch RSVP data and attach to registrants + if (includeRsvp) { + try { + const rsvps = await this.getMeetingRsvps(req, meetingUid); - return registrants; - } catch (error) { - req.log.error( - { - operation: 'get_meeting_registrants', + // Create a map of username to RSVP for quick lookup + const rsvpMap = new Map(rsvps.map((rsvp) => [rsvp.username, rsvp])); + + // Attach RSVP data to each registrant + registrants = registrants.map((registrant) => ({ + ...registrant, + rsvp: registrant.username ? rsvpMap.get(registrant.username) || null : null, + })); + } catch (error) { + logger.warning(req, 'get_meeting_registrants', 'Failed to fetch RSVPs for registrants, returning registrants without RSVP data', { meeting_uid: meetingUid, err: error, - }, - 'Failed to fetch meeting registrants' - ); - throw error; + }); + } } + + return registrants; } /** @@ -374,15 +292,6 @@ export class MeetingService { email: string, m2mToken?: string ): Promise> { - req.log.info( - { - operation: 'get_meeting_registrants_by_email', - meeting_uid: meetingUid, - email: email, - }, - 'Fetching meeting registrants by email' - ); - // TODO(v1-migration): Remove V1 registrant type detection once all meetings are migrated to V2 const v1 = !isUuid(meetingUid); @@ -398,15 +307,7 @@ export class MeetingService { params.parent = ''; } - req.log.info( - { - operation: 'get_meeting_registrants_by_email', - meeting_uid: meetingUid, - email: email, - v1, - }, - 'Fetching meeting registrants by email params' - ); + logger.debug(req, 'get_meeting_registrants_by_email', 'Fetching meeting registrants by email params', { meeting_uid: meetingUid, email, v1, params }); const headers = m2mToken ? { Authorization: `Bearer ${m2mToken}` } : undefined; @@ -427,41 +328,19 @@ export class MeetingService { * Creates a new meeting registrant */ public async addMeetingRegistrant(req: Request, registrantData: CreateMeetingRegistrantRequest): Promise { - try { - const sanitizedPayload = Logger.sanitize({ registrantData }); - req.log.debug(sanitizedPayload, 'Creating meeting registrant'); + const sanitizedPayload = logger.sanitize({ registrantData }); + logger.debug(req, 'add_meeting_registrant', 'Creating meeting registrant', sanitizedPayload); - const newRegistrant = await this.microserviceProxy.proxyRequest( - req, - 'LFX_V2_SERVICE', - `/meetings/${registrantData.meeting_uid}/registrants`, - 'POST', - undefined, - registrantData - ); - - req.log.info( - { - operation: 'add_meeting_registrant', - meeting_uid: registrantData.meeting_uid, - registrant_uid: newRegistrant.uid, - host: registrantData.host || false, - }, - 'Meeting registrant created successfully' - ); + const newRegistrant = await this.microserviceProxy.proxyRequest( + req, + 'LFX_V2_SERVICE', + `/meetings/${registrantData.meeting_uid}/registrants`, + 'POST', + undefined, + registrantData + ); - return newRegistrant; - } catch (error) { - req.log.error( - { - operation: 'add_meeting_registrant', - meeting_uid: registrantData.meeting_uid, - err: error, - }, - 'Failed to create meeting registrant' - ); - throw error; - } + return newRegistrant; } /** @@ -473,118 +352,59 @@ export class MeetingService { registrantUid: string, updateData: UpdateMeetingRegistrantRequest ): Promise { - try { - // Step 1: Fetch registrant with ETag - const { etag } = await this.etagService.fetchWithETag( - req, - 'LFX_V2_SERVICE', - `/meetings/${meetingUid}/registrants/${registrantUid}`, - 'update_meeting_registrant' - ); - - const sanitizedPayload = Logger.sanitize({ updateData }); - req.log.debug(sanitizedPayload, 'Updating meeting registrant payload'); + // Step 1: Fetch registrant with ETag + const { etag } = await this.etagService.fetchWithETag( + req, + 'LFX_V2_SERVICE', + `/meetings/${meetingUid}/registrants/${registrantUid}`, + 'update_meeting_registrant' + ); - // Step 2: Update registrant with ETag - const updatedRegistrant = await this.etagService.updateWithETag( - req, - 'LFX_V2_SERVICE', - `/meetings/${meetingUid}/registrants/${registrantUid}`, - etag, - updateData, - 'update_meeting_registrant' - ); + const sanitizedPayload = logger.sanitize({ updateData }); + logger.debug(req, 'update_meeting_registrant', 'Updating meeting registrant payload', sanitizedPayload); - req.log.info( - { - operation: 'update_meeting_registrant', - meeting_uid: meetingUid, - registrant_uid: registrantUid, - }, - 'Meeting registrant updated successfully' - ); + // Step 2: Update registrant with ETag + const updatedRegistrant = await this.etagService.updateWithETag( + req, + 'LFX_V2_SERVICE', + `/meetings/${meetingUid}/registrants/${registrantUid}`, + etag, + updateData, + 'update_meeting_registrant' + ); - return updatedRegistrant; - } catch (error) { - req.log.error( - { - operation: 'update_meeting_registrant', - meeting_uid: meetingUid, - registrant_uid: registrantUid, - err: error, - }, - 'Failed to update meeting registrant' - ); - throw error; - } + return updatedRegistrant; } /** * Deletes a meeting registrant using ETag for concurrency control */ public async deleteMeetingRegistrant(req: Request, meetingUid: string, registrantUid: string): Promise { - try { - // Step 1: Fetch registrant with ETag - const { etag } = await this.etagService.fetchWithETag( - req, - 'LFX_V2_SERVICE', - `/meetings/${meetingUid}/registrants/${registrantUid}`, - 'delete_meeting_registrant' - ); - - // Step 2: Delete registrant with ETag - await this.etagService.deleteWithETag(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/registrants/${registrantUid}`, etag, 'delete_meeting_registrant'); + // Step 1: Fetch registrant with ETag + const { etag } = await this.etagService.fetchWithETag( + req, + 'LFX_V2_SERVICE', + `/meetings/${meetingUid}/registrants/${registrantUid}`, + 'delete_meeting_registrant' + ); - req.log.info( - { - operation: 'delete_meeting_registrant', - meeting_uid: meetingUid, - registrant_uid: registrantUid, - }, - 'Meeting registrant deleted successfully' - ); - } catch (error) { - req.log.error( - { - operation: 'delete_meeting_registrant', - meeting_uid: meetingUid, - registrant_uid: registrantUid, - err: error, - }, - 'Failed to delete meeting registrant' - ); - throw error; - } + // Step 2: Delete registrant with ETag + await this.etagService.deleteWithETag(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/registrants/${registrantUid}`, etag, 'delete_meeting_registrant'); } /** * Resend a meeting invitation to a specific registrant */ public async resendMeetingInvitation(req: Request, meetingUid: string, registrantId: string): Promise { - try { - // Call the LFX API endpoint for resending invitation - await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/registrants/${registrantId}/resend`, 'POST'); + const startTime = logger.startOperation(req, 'resend_meeting_invitation', { meeting_uid: meetingUid, registrant_id: registrantId }); - req.log.info( - { - operation: 'resend_meeting_invitation', - meeting_uid: meetingUid, - registrant_id: registrantId, - }, - 'Meeting invitation resent successfully' - ); - } catch (error) { - req.log.error( - { - operation: 'resend_meeting_invitation', - meeting_uid: meetingUid, - registrant_id: registrantId, - err: error, - }, - 'Failed to resend meeting invitation' - ); - throw error; - } + // Call the LFX API endpoint for resending invitation + await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/registrants/${registrantId}/resend`, 'POST'); + + logger.success(req, 'resend_meeting_invitation', startTime, { + meeting_uid: meetingUid, + registrant_id: registrantId, + }); } /** @@ -598,6 +418,8 @@ export class MeetingService { * Fetches past meeting participants by past meeting UID */ public async getPastMeetingParticipants(req: Request, pastMeetingUid: string): Promise { + const startTime = logger.startOperation(req, 'get_past_meeting_participants', { past_meeting_uid: pastMeetingUid }); + const params = { type: 'past_meeting_participant', tags: `past_meeting_uid:${pastMeetingUid}`, @@ -613,14 +435,10 @@ export class MeetingService { const participants = resources.map((resource) => resource.data); - req.log.info( - { - operation: 'get_past_meeting_participants', - past_meeting_uid: pastMeetingUid, - participant_count: participants.length, - }, - 'Past meeting participants retrieved successfully' - ); + logger.success(req, 'get_past_meeting_participants', startTime, { + past_meeting_uid: pastMeetingUid, + participant_count: participants.length, + }); return participants; } @@ -630,6 +448,8 @@ export class MeetingService { * @param v1 - If true, use v1_past_meeting_recording type and id tag format for legacy meetings */ public async getPastMeetingRecording(req: Request, pastMeetingUid: string, v1: boolean = false): Promise { + const startTime = logger.startOperation(req, 'get_past_meeting_recording', { past_meeting_uid: pastMeetingUid, v1 }); + try { // V1 legacy meetings use different type and tag format const params = { @@ -646,43 +466,30 @@ export class MeetingService { ); if (!resources || resources.length === 0) { - req.log.info( - { - operation: 'get_past_meeting_recording', - past_meeting_uid: pastMeetingUid, - v1, - type: params.type, - }, - 'No recording found for past meeting' - ); + logger.warning(req, 'get_past_meeting_recording', 'No recording found for past meeting', { + past_meeting_uid: pastMeetingUid, + v1, + type: params.type, + }); return null; } const recording = resources[0].data; - req.log.info( - { - operation: 'get_past_meeting_recording', - past_meeting_uid: pastMeetingUid, - v1, - recording_uid: recording.uid, - recording_count: recording.recording_count, - session_count: recording.sessions?.length || 0, - }, - 'Past meeting recording retrieved successfully' - ); + logger.success(req, 'get_past_meeting_recording', startTime, { + past_meeting_uid: pastMeetingUid, + v1, + recording_uid: recording.uid, + recording_count: recording.recording_count, + session_count: recording.sessions?.length || 0, + }); return recording; } catch (error) { - req.log.error( - { - operation: 'get_past_meeting_recording', - past_meeting_uid: pastMeetingUid, - v1, - err: error, - }, - 'Failed to retrieve past meeting recording' - ); + logger.error(req, 'get_past_meeting_recording', startTime, error, { + past_meeting_uid: pastMeetingUid, + v1, + }); return null; } } @@ -692,6 +499,8 @@ export class MeetingService { * @param v1 - If true, use v1_past_meeting_summary type for legacy meetings */ public async getPastMeetingSummary(req: Request, pastMeetingUid: string, v1: boolean = false): Promise { + const startTime = logger.startOperation(req, 'get_past_meeting_summary', { past_meeting_uid: pastMeetingUid, v1 }); + try { // V1 legacy meetings use different type and tag format const params = { @@ -708,15 +517,11 @@ export class MeetingService { ); if (!resources || resources.length === 0) { - req.log.info( - { - operation: 'get_past_meeting_summary', - past_meeting_uid: pastMeetingUid, - v1, - type: params.type, - }, - 'No summary found for past meeting' - ); + logger.warning(req, 'get_past_meeting_summary', 'No summary found for past meeting', { + past_meeting_uid: pastMeetingUid, + v1, + type: params.type, + }); return null; } @@ -727,29 +532,20 @@ export class MeetingService { summary = transformV1SummaryToV2(summary); } - req.log.info( - { - operation: 'get_past_meeting_summary', - past_meeting_uid: pastMeetingUid, - v1, - summary_uid: summary.uid, - approved: summary.approved, - requires_approval: summary.requires_approval, - }, - 'Past meeting summary retrieved successfully' - ); + logger.success(req, 'get_past_meeting_summary', startTime, { + past_meeting_uid: pastMeetingUid, + v1, + summary_uid: summary.uid, + approved: summary.approved, + requires_approval: summary.requires_approval, + }); return summary; } catch (error) { - req.log.error( - { - operation: 'get_past_meeting_summary', - past_meeting_uid: pastMeetingUid, - v1, - err: error, - }, - 'Failed to retrieve past meeting summary' - ); + logger.error(req, 'get_past_meeting_summary', startTime, error, { + past_meeting_uid: pastMeetingUid, + v1, + }); return null; } } @@ -763,58 +559,49 @@ export class MeetingService { summaryUid: string, updateData: UpdatePastMeetingSummaryRequest ): Promise { - try { - // Step 1: Fetch summary with ETag - const { etag } = await this.etagService.fetchWithETag( - req, - 'LFX_V2_SERVICE', - `/past_meetings/${pastMeetingUid}/summaries/${summaryUid}`, - 'update_past_meeting_summary' - ); + const startTime = logger.startOperation(req, 'update_past_meeting_summary', { past_meeting_uid: pastMeetingUid, summary_uid: summaryUid }); - const sanitizedPayload = Logger.sanitize({ updateData }); - req.log.debug(sanitizedPayload, 'Updating past meeting summary payload'); + // Step 1: Fetch summary with ETag + const { etag } = await this.etagService.fetchWithETag( + req, + 'LFX_V2_SERVICE', + `/past_meetings/${pastMeetingUid}/summaries/${summaryUid}`, + 'update_past_meeting_summary' + ); - // Step 2: Update summary with ETag - const updatedSummary = await this.etagService.updateWithETag( - req, - 'LFX_V2_SERVICE', - `/past_meetings/${pastMeetingUid}/summaries/${summaryUid}`, - etag, - updateData, - 'update_past_meeting_summary' - ); + const sanitizedPayload = logger.sanitize({ updateData }); + logger.debug(req, 'update_past_meeting_summary', 'Updating past meeting summary payload', sanitizedPayload); - req.log.info( - { - operation: 'update_past_meeting_summary', - past_meeting_uid: pastMeetingUid, - summary_uid: summaryUid, - has_edited_content: !!updateData.edited_content, - has_approved: updateData.approved !== undefined, - }, - 'Past meeting summary updated successfully' - ); + // Step 2: Update summary with ETag + const updatedSummary = await this.etagService.updateWithETag( + req, + 'LFX_V2_SERVICE', + `/past_meetings/${pastMeetingUid}/summaries/${summaryUid}`, + etag, + updateData, + 'update_past_meeting_summary' + ); - return updatedSummary; - } catch (error) { - req.log.error( - { - operation: 'update_past_meeting_summary', - past_meeting_uid: pastMeetingUid, - summary_uid: summaryUid, - err: error, - }, - 'Failed to update past meeting summary' - ); - throw error; - } + logger.success(req, 'update_past_meeting_summary', startTime, { + past_meeting_uid: pastMeetingUid, + summary_uid: summaryUid, + has_edited_content: !!updateData.edited_content, + has_approved: updateData.approved !== undefined, + }); + + return updatedSummary; } /** * Create or update a meeting RSVP */ public async createMeetingRsvp(req: Request, meetingUid: string, rsvpData: CreateMeetingRsvpRequest): Promise { + const startTime = logger.startOperation(req, 'create_meeting_rsvp', { + meeting_uid: meetingUid, + response: rsvpData.response, + scope: rsvpData.scope, + }); + // Backend derives user from bearer token, so we don't need to pass username/email/registrant_id const requestData: CreateMeetingRsvpRequest = { response: rsvpData.response, @@ -826,17 +613,13 @@ export class MeetingService { const rsvp = await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/rsvp`, 'POST', {}, requestData); - req.log.info( - { - operation: 'create_meeting_rsvp', - meeting_uid: meetingUid, - rsvp_id: rsvp.id, - response: rsvpData.response, - scope: rsvpData.scope, - occurrence_id: rsvpData.occurrence_id || undefined, - }, - 'Meeting RSVP created successfully' - ); + logger.success(req, 'create_meeting_rsvp', startTime, { + meeting_uid: meetingUid, + rsvp_id: rsvp.id, + response: rsvpData.response, + scope: rsvpData.scope, + occurrence_id: rsvpData.occurrence_id || undefined, + }); return rsvp; } @@ -849,19 +632,16 @@ export class MeetingService { * @returns Promise resolving to user's RSVP or null */ public async getMeetingRsvpByUsername(req: Request, meetingUid: string, occurrenceId?: string): Promise { + const startTime = logger.startOperation(req, 'get_meeting_rsvp_by_username', { meeting_uid: meetingUid, occurrence_id: occurrenceId }); + try { // Get username from authenticated user const username = await getUsernameFromAuth(req); if (!username) { - req.log.error( - { - operation: 'get_meeting_rsvp_by_username', - meeting_uid: meetingUid, - error: 'No username found in auth context', - }, - 'Failed to get meeting RSVP by username' - ); + logger.error(req, 'get_meeting_rsvp_by_username', startTime, new Error('No username found in auth context'), { + meeting_uid: meetingUid, + }); return null; } @@ -887,29 +667,20 @@ export class MeetingService { // Filter for current user's RSVP (optionally by occurrence) const userRsvp = allRsvps.find((rsvp) => rsvp.username === username && (!occurrenceId || rsvp.occurrence_id === occurrenceId)); - req.log.info( - { - operation: 'get_meeting_rsvp_by_username', - meeting_uid: meetingUid, - occurrence_id: occurrenceId, - found: !!userRsvp, - total_rsvps: allRsvps.length, - rsvp_id: userRsvp?.id, - }, - 'User meeting RSVP retrieved via M2M token' - ); + logger.success(req, 'get_meeting_rsvp_by_username', startTime, { + meeting_uid: meetingUid, + occurrence_id: occurrenceId, + found: !!userRsvp, + total_rsvps: allRsvps.length, + rsvp_id: userRsvp?.id, + }); return userRsvp || null; } catch (error) { - req.log.error( - { - operation: 'get_meeting_rsvp_by_username', - meeting_uid: meetingUid, - occurrence_id: occurrenceId, - err: error, - }, - 'Failed to get meeting RSVP by username' - ); + logger.error(req, 'get_meeting_rsvp_by_username', startTime, error, { + meeting_uid: meetingUid, + occurrence_id: occurrenceId, + }); return null; } } @@ -918,6 +689,8 @@ export class MeetingService { * Get all RSVPs for a meeting */ public async getMeetingRsvps(req: Request, meetingUid: string): Promise { + const startTime = logger.startOperation(req, 'get_meeting_rsvps', { meeting_uid: meetingUid }); + try { const params = { tags: `meeting_uid:${meetingUid}`, @@ -932,25 +705,16 @@ export class MeetingService { params ); - req.log.info( - { - operation: 'get_meeting_rsvps', - meeting_uid: meetingUid, - count: resources.length, - }, - 'Meeting RSVPs retrieved successfully' - ); + logger.success(req, 'get_meeting_rsvps', startTime, { + meeting_uid: meetingUid, + count: resources.length, + }); return resources.map((resource) => resource.data); } catch (error) { - req.log.error( - { - operation: 'get_meeting_rsvps', - meeting_uid: meetingUid, - err: error, - }, - 'Failed to get meeting RSVPs' - ); + logger.error(req, 'get_meeting_rsvps', startTime, error, { + meeting_uid: meetingUid, + }); return []; } } @@ -963,48 +727,21 @@ export class MeetingService { * @returns The created meeting attachment */ public async createMeetingAttachment(req: Request, meetingUid: string, attachmentData: any): Promise { - req.log.debug( - { - operation: 'create_meeting_attachment', - meeting_uid: meetingUid, - }, - 'Creating meeting attachment' - ); + logger.debug(req, 'create_meeting_attachment', 'Creating meeting attachment', { meeting_uid: meetingUid }); - try { - // Call the LFX V2 API endpoint with multipart/form-data - // The attachmentData should be a FormData object from the controller - // The API client will automatically handle FormData and set the correct Content-Type with boundary - const attachment = await this.microserviceProxy.proxyRequest( - req, - 'LFX_V2_SERVICE', - `/meetings/${meetingUid}/attachments`, - 'POST', - undefined, - attachmentData - ); - - req.log.info( - { - operation: 'create_meeting_attachment', - attachment_uid: attachment.uid, - meeting_uid: meetingUid, - }, - 'Meeting attachment created successfully' - ); + // Call the LFX V2 API endpoint with multipart/form-data + // The attachmentData should be a FormData object from the controller + // The API client will automatically handle FormData and set the correct Content-Type with boundary + const attachment = await this.microserviceProxy.proxyRequest( + req, + 'LFX_V2_SERVICE', + `/meetings/${meetingUid}/attachments`, + 'POST', + undefined, + attachmentData + ); - return attachment; - } catch (error) { - req.log.error( - { - operation: 'create_meeting_attachment', - meeting_uid: meetingUid, - err: error, - }, - 'Failed to create meeting attachment' - ); - throw error; - } + return attachment; } /** @@ -1015,42 +752,12 @@ export class MeetingService { * @returns The attachment file data */ public async getMeetingAttachment(req: Request, meetingUid: string, attachmentUid: string): Promise { - req.log.debug( - { - operation: 'get_meeting_attachment', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - }, - 'Fetching meeting attachment' - ); - - try { - // Use the microservice proxy to download the binary file - const buffer = await this.microserviceProxy.proxyBinaryRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/attachments/${attachmentUid}`, 'GET'); + logger.debug(req, 'get_meeting_attachment', 'Fetching meeting attachment', { meeting_uid: meetingUid, attachment_uid: attachmentUid }); - req.log.info( - { - operation: 'get_meeting_attachment', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - file_size: buffer.length, - }, - 'Meeting attachment fetched successfully' - ); + // Use the microservice proxy to download the binary file + const buffer = await this.microserviceProxy.proxyBinaryRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/attachments/${attachmentUid}`, 'GET'); - return buffer; - } catch (error) { - req.log.error( - { - operation: 'get_meeting_attachment', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - err: error, - }, - 'Failed to fetch meeting attachment' - ); - throw error; - } + return buffer; } /** @@ -1060,81 +767,23 @@ export class MeetingService { * @param attachmentUid - Attachment UID to delete */ public async deleteMeetingAttachment(req: Request, meetingUid: string, attachmentUid: string): Promise { - req.log.debug( - { - operation: 'delete_meeting_attachment', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - }, - 'Deleting meeting attachment' - ); - - try { - // Call the LFX V2 API endpoint to delete the attachment - await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/attachments/${attachmentUid}`, 'DELETE'); + logger.debug(req, 'delete_meeting_attachment', 'Deleting meeting attachment', { meeting_uid: meetingUid, attachment_uid: attachmentUid }); - req.log.info( - { - operation: 'delete_meeting_attachment', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - }, - 'Meeting attachment deleted successfully' - ); - } catch (error) { - req.log.error( - { - operation: 'delete_meeting_attachment', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - err: error, - }, - 'Failed to delete meeting attachment' - ); - throw error; - } + // Call the LFX V2 API endpoint to delete the attachment + await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingUid}/attachments/${attachmentUid}`, 'DELETE'); } public async getMeetingAttachmentMetadata(req: Request, meetingUid: string, attachmentUid: string): Promise { - req.log.debug( - { - operation: 'get_meeting_attachment_metadata', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - }, - 'Fetching meeting attachment metadata' - ); + logger.debug(req, 'get_meeting_attachment_metadata', 'Fetching meeting attachment metadata', { meeting_uid: meetingUid, attachment_uid: attachmentUid }); - try { - const metadata = await this.microserviceProxy.proxyRequest( - req, - 'LFX_V2_SERVICE', - `/meetings/${meetingUid}/attachments/${attachmentUid}/metadata`, - 'GET' - ); - - req.log.info( - { - operation: 'get_meeting_attachment_metadata', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - }, - 'Meeting attachment metadata fetched successfully' - ); + const metadata = await this.microserviceProxy.proxyRequest( + req, + 'LFX_V2_SERVICE', + `/meetings/${meetingUid}/attachments/${attachmentUid}/metadata`, + 'GET' + ); - return metadata; - } catch (error) { - req.log.error( - { - operation: 'get_meeting_attachment_metadata', - meeting_uid: meetingUid, - attachment_uid: attachmentUid, - err: error, - }, - 'Failed to fetch meeting attachment metadata' - ); - throw error; - } + return metadata; } /** @@ -1144,53 +793,18 @@ export class MeetingService { * @returns Array of meeting attachments */ public async getMeetingAttachments(req: Request, meetingUid: string): Promise { - req.log.debug( - { - operation: 'get_meeting_attachments', - meeting_uid: meetingUid, - }, - 'Fetching meeting attachments' - ); - - try { - const params = { - type: 'meeting_attachment', - tags: `meeting_uid:${meetingUid}`, - }; - - req.log.debug( - { - meeting_uid: meetingUid, - query_params: params, - }, - 'Fetching attachments with query params' - ); + const params = { + type: 'meeting_attachment', + tags: `meeting_uid:${meetingUid}`, + }; - const { resources } = await this.microserviceProxy.proxyRequest>(req, 'LFX_V2_SERVICE', '/query/resources', 'GET', params); + logger.debug(req, 'get_meeting_attachments', 'Fetching meeting attachments', { meeting_uid: meetingUid, query_params: params }); - const attachments = resources.map((resource) => resource.data); + const { resources } = await this.microserviceProxy.proxyRequest>(req, 'LFX_V2_SERVICE', '/query/resources', 'GET', params); - req.log.info( - { - operation: 'get_meeting_attachments', - meeting_uid: meetingUid, - attachment_count: attachments.length, - }, - 'Meeting attachments retrieved successfully' - ); + const attachments = resources.map((resource) => resource.data); - return attachments; - } catch (error) { - req.log.error( - { - operation: 'get_meeting_attachments', - meeting_uid: meetingUid, - err: error, - }, - 'Failed to get meeting attachments' - ); - throw error; - } + return attachments; } /** @@ -1200,53 +814,18 @@ export class MeetingService { * @returns Array of past meeting attachments */ public async getPastMeetingAttachments(req: Request, pastMeetingUid: string): Promise { - req.log.debug( - { - operation: 'get_past_meeting_attachments', - past_meeting_uid: pastMeetingUid, - }, - 'Fetching past meeting attachments' - ); - - try { - const params = { - type: 'past_meeting_attachment', - tags: `past_meeting_uid:${pastMeetingUid}`, - }; - - req.log.debug( - { - past_meeting_uid: pastMeetingUid, - query_params: params, - }, - 'Fetching past meeting attachments with query params' - ); + const params = { + type: 'past_meeting_attachment', + tags: `past_meeting_uid:${pastMeetingUid}`, + }; - const { resources } = await this.microserviceProxy.proxyRequest>(req, 'LFX_V2_SERVICE', '/query/resources', 'GET', params); + logger.debug(req, 'get_past_meeting_attachments', 'Fetching past meeting attachments', { past_meeting_uid: pastMeetingUid, query_params: params }); - const attachments = resources.map((resource) => resource.data); + const { resources } = await this.microserviceProxy.proxyRequest>(req, 'LFX_V2_SERVICE', '/query/resources', 'GET', params); - req.log.info( - { - operation: 'get_past_meeting_attachments', - past_meeting_uid: pastMeetingUid, - attachment_count: attachments.length, - }, - 'Past meeting attachments retrieved successfully' - ); + const attachments = resources.map((resource) => resource.data); - return attachments; - } catch (error) { - req.log.error( - { - operation: 'get_past_meeting_attachments', - past_meeting_uid: pastMeetingUid, - err: error, - }, - 'Failed to get past meeting attachments' - ); - throw error; - } + return attachments; } /** @@ -1257,42 +836,28 @@ export class MeetingService { * @returns The created meeting registrant */ public async addMeetingRegistrantWithM2M(req: Request, registrantData: CreateMeetingRegistrantRequest, m2mToken: string): Promise { - try { - const sanitizedPayload = Logger.sanitize({ registrantData }); - req.log.debug(sanitizedPayload, 'Creating meeting registrant with M2M token'); + const startTime = logger.startOperation(req, 'add_meeting_registrant_with_m2m', { meeting_uid: registrantData.meeting_uid }); - const newRegistrant = await this.microserviceProxy.proxyRequest( - req, - 'LFX_V2_SERVICE', - `/meetings/${registrantData.meeting_uid}/registrants`, - 'POST', - undefined, - registrantData, - { Authorization: `Bearer ${m2mToken}`, ['X-Sync']: 'true' } - ); + const sanitizedPayload = logger.sanitize({ registrantData }); + logger.debug(req, 'add_meeting_registrant_with_m2m', 'Creating meeting registrant with M2M token', sanitizedPayload); - req.log.info( - { - operation: 'add_meeting_registrant_with_m2m', - meeting_uid: registrantData.meeting_uid, - registrant_uid: newRegistrant.uid, - host: registrantData.host || false, - }, - 'Meeting registrant created successfully with M2M token' - ); + const newRegistrant = await this.microserviceProxy.proxyRequest( + req, + 'LFX_V2_SERVICE', + `/meetings/${registrantData.meeting_uid}/registrants`, + 'POST', + undefined, + registrantData, + { Authorization: `Bearer ${m2mToken}`, ['X-Sync']: 'true' } + ); - return newRegistrant; - } catch (error) { - req.log.error( - { - operation: 'add_meeting_registrant_with_m2m', - meeting_uid: registrantData.meeting_uid, - err: error, - }, - 'Failed to create meeting registrant with M2M token' - ); - throw error; - } + logger.success(req, 'add_meeting_registrant_with_m2m', startTime, { + meeting_uid: registrantData.meeting_uid, + registrant_uid: newRegistrant.uid, + host: registrantData.host || false, + }); + + return newRegistrant; } private async getMeetingCommittees(req: Request, meetings: Meeting[]): Promise { @@ -1314,7 +879,7 @@ export class MeetingService { const committee = await this.committeeService.getCommitteeById(req, uid); return { uid: committee.uid, name: committee.name }; } catch (error) { - req.log.warn({ operation: 'get_meeting_committees', committee_uid: uid, err: error }, 'Committee enrichment failed; continuing without name'); + logger.warning(req, 'get_meeting_committees', 'Committee enrichment failed; continuing without name', { committee_uid: uid, err: error }); return { uid, name: undefined }; } }) diff --git a/apps/lfx-one/src/server/services/microservice-proxy.service.ts b/apps/lfx-one/src/server/services/microservice-proxy.service.ts index 5f5b1eec..8fc0ab93 100644 --- a/apps/lfx-one/src/server/services/microservice-proxy.service.ts +++ b/apps/lfx-one/src/server/services/microservice-proxy.service.ts @@ -35,8 +35,6 @@ export class MicroserviceProxyService { // This ensures that default params cannot be overridden by the caller const mergedQuery = { ...query, ...DEFAULT_QUERY_PARAMS }; - req.log.debug({ path: endpoint, method, mergedQuery, data, customHeaders }, 'Proxy request'); - const response = await this.apiClient.request(method, endpoint, token, mergedQuery, data, customHeaders); return response.data; } catch (error: any) { @@ -120,8 +118,6 @@ export class MicroserviceProxyService { // This ensures that default params cannot be overridden by the caller const mergedQuery = { ...query, ...DEFAULT_QUERY_PARAMS }; - req.log.debug({ path: endpoint, method, mergedQuery, customHeaders }, 'Proxy binary request'); - const response = await this.apiClient.binaryRequest(method, endpoint, token, mergedQuery, customHeaders); return response.data; } catch (error: any) { diff --git a/apps/lfx-one/src/server/services/nats.service.ts b/apps/lfx-one/src/server/services/nats.service.ts index e331bd85..915077f7 100644 --- a/apps/lfx-one/src/server/services/nats.service.ts +++ b/apps/lfx-one/src/server/services/nats.service.ts @@ -2,9 +2,9 @@ // SPDX-License-Identifier: MIT import { NATS_CONFIG } from '@lfx-one/shared/constants'; -import { connect, NatsConnection, Msg, StringCodec, Codec } from 'nats'; +import { Codec, connect, Msg, NatsConnection, StringCodec } from 'nats'; -import { serverLogger } from '../server'; +import { logger } from './logger.service'; /** * Generic NATS service for managing connections and request-reply operations @@ -34,16 +34,12 @@ export class NatsService { timeout: options?.timeout || NATS_CONFIG.REQUEST_TIMEOUT, }; + const startTime = Date.now(); + try { return await connection.request(subject, data, requestOptions); } catch (error) { - serverLogger.error( - { - err: error, - subject, - }, - 'NATS request failed' - ); + logger.error(undefined, 'nats_request', startTime, error, { subject }); throw error; } } @@ -60,13 +56,13 @@ export class NatsService { */ public async shutdown(): Promise { if (this.connection && !this.connection.isClosed()) { - serverLogger.info('Shutting down NATS connection'); + const startTime = logger.startOperation(undefined, 'nats_shutdown', {}); try { await this.connection.drain(); - serverLogger.info('NATS connection closed successfully'); + logger.success(undefined, 'nats_shutdown', startTime, {}); } catch (error) { - serverLogger.error({ err: error }, 'Error during NATS shutdown'); + logger.error(undefined, 'nats_shutdown', startTime, error, {}); } } this.connection = null; @@ -107,26 +103,21 @@ export class NatsService { */ private async createConnection(): Promise { const natsUrl = process.env['NATS_URL'] || NATS_CONFIG.DEFAULT_SERVER_URL; + const startTime = logger.startOperation(undefined, 'nats_connect', { url: natsUrl }); try { - serverLogger.info({ url: natsUrl }, 'Connecting to NATS server on demand'); - const connection = await connect({ servers: [natsUrl], timeout: NATS_CONFIG.CONNECTION_TIMEOUT, }); - serverLogger.info('Successfully connected to NATS server'); + logger.success(undefined, 'nats_connect', startTime, {}); return connection; } catch (error) { - serverLogger.error( - { - err: error, - url: natsUrl, - suggestion: 'If running locally, you may need to port-forward NATS: kubectl port-forward -n lfx svc/lfx-platform-nats 4222:4222', - }, - 'Failed to connect to NATS server' - ); + logger.error(undefined, 'nats_connect', startTime, error, { + url: natsUrl, + suggestion: 'If running locally, you may need to port-forward NATS: kubectl port-forward -n lfx svc/lfx-platform-nats 4222:4222', + }); throw error; } } diff --git a/apps/lfx-one/src/server/services/project.service.ts b/apps/lfx-one/src/server/services/project.service.ts index 21eea064..99ad1bc2 100644 --- a/apps/lfx-one/src/server/services/project.service.ts +++ b/apps/lfx-one/src/server/services/project.service.ts @@ -47,9 +47,9 @@ import { import { Request } from 'express'; import { ResourceNotFoundError } from '../errors'; -import { serverLogger } from '../server'; import { AccessCheckService } from './access-check.service'; import { ETagService } from './etag.service'; +import { logger } from './logger.service'; import { MicroserviceProxyService } from './microservice-proxy.service'; import { NatsService } from './nats.service'; import { SnowflakeService } from './snowflake.service'; @@ -126,13 +126,10 @@ export class ProjectService { } if (resources.length > 1) { - req.log.warn( - { - project_id: uid, - result_count: resources.length, - }, - 'Multiple projects found for single ID lookup' - ); + logger.warning(req, 'get_project_by_id', 'Multiple projects found for single ID lookup', { + project_id: uid, + result_count: resources.length, + }); } const project = resources[0].data; @@ -164,16 +161,7 @@ export class ProjectService { * First resolves slug to ID via NATS, then fetches project data */ public async getProjectBySlug(req: Request, projectSlug: string): Promise { - req.log.debug( - { - slug: projectSlug, - operation: 'get_project_by_slug_via_nats', - step: 'nats_lookup', - }, - 'Resolving project slug to ID via NATS' - ); - - const natsResult = await this.getProjectIdBySlug(projectSlug); + const natsResult = await this.getProjectIdBySlug(req, projectSlug); if (!natsResult.exists || !natsResult.uid) { throw new ResourceNotFoundError('Project', projectSlug, { @@ -183,16 +171,6 @@ export class ProjectService { }); } - req.log.info( - { - slug: projectSlug, - project_id: natsResult.uid, - operation: 'get_project_by_slug_via_nats', - step: 'nats_success', - }, - 'Successfully resolved slug to ID via NATS' - ); - // Now fetch the project using the resolved ID return this.getProjectById(req, natsResult.uid); } @@ -250,13 +228,10 @@ export class ProjectService { // Use manual user info if provided, otherwise fetch from NATS let userInfo: { name: string; email: string; username: string; avatar?: string }; if (manualUserInfo) { - req.log.debug( - { - username: backendIdentifier, - operation: `${operation}_user_project_permissions`, - }, - 'Using manually provided user info' - ); + logger.debug(req, `${operation}_user_project_permissions`, 'Using manual user info', { + username: backendIdentifier, + info_source: 'manual', + }); userInfo = { name: manualUserInfo.name, email: manualUserInfo.email, @@ -311,6 +286,12 @@ export class ProjectService { }); // Step 4: Update settings with ETag + const startTime = logger.startOperation(req, `${operation}_user_project_permissions`, { + project_id: uid, + username: backendIdentifier, + role: role || 'N/A', + }); + const result = await this.etagService.updateWithETag( req, 'LFX_V2_SERVICE', @@ -320,15 +301,11 @@ export class ProjectService { `${operation}_user_project_permissions` ); - req.log.info( - { - operation: `${operation}_user_project_permissions`, - project_id: uid, - username: backendIdentifier, - role: role || 'N/A', - }, - `User ${operation} operation completed successfully` - ); + logger.success(req, `${operation}_user_project_permissions`, startTime, { + project_id: uid, + username: backendIdentifier, + role: role || 'N/A', + }); return result; } @@ -346,9 +323,9 @@ export class ProjectService { // Normalize email input const normalizedEmail = email.trim().toLowerCase(); - try { - req.log.debug({ email: normalizedEmail }, 'Resolving email to sub via NATS'); + const startTime = logger.startOperation(req, 'resolve_email_to_sub', { email: normalizedEmail }); + try { const response = await this.natsService.request(NatsSubjects.EMAIL_TO_SUB, codec.encode(normalizedEmail), { timeout: NATS_CONFIG.REQUEST_TIMEOUT }); const responseText = codec.decode(response.data); @@ -360,7 +337,10 @@ export class ProjectService { // Check if it's an error response if (typeof parsed === 'object' && parsed !== null && parsed.success === false) { - req.log.warn({ email: normalizedEmail, error: parsed.error }, 'User email not found via NATS'); + logger.warning(req, 'resolve_email_to_sub', 'User email not found via NATS', { + email: normalizedEmail, + error: parsed.error, + }); throw new ResourceNotFoundError('User', normalizedEmail, { operation: 'resolve_email_to_sub', @@ -385,7 +365,9 @@ export class ProjectService { username = username.trim(); if (!username || username === '') { - req.log.warn({ email: normalizedEmail }, 'Empty sub returned from NATS'); + logger.warning(req, 'resolve_email_to_sub', 'Empty sub returned from NATS', { + email: normalizedEmail, + }); throw new ResourceNotFoundError('User', normalizedEmail, { operation: 'resolve_email_to_sub', @@ -394,7 +376,10 @@ export class ProjectService { }); } - req.log.info({ email: normalizedEmail, sub: username }, 'Successfully resolved email to sub'); + logger.success(req, 'resolve_email_to_sub', startTime, { + email: normalizedEmail, + sub: username, + }); return username; } catch (error) { @@ -403,8 +388,6 @@ export class ProjectService { throw error; } - req.log.error({ err: error, email: normalizedEmail }, 'Failed to resolve email to sub via NATS'); - // If it's a timeout or no responder error, treat as not found if (error instanceof Error && (error.message.includes('timeout') || error.message.includes('503'))) { throw new ResourceNotFoundError('User', normalizedEmail, { @@ -431,9 +414,9 @@ export class ProjectService { // Normalize email input const normalizedEmail = email.trim().toLowerCase(); - try { - req.log.debug({ email: normalizedEmail }, 'Resolving email to username via NATS'); + const startTime = logger.startOperation(req, 'resolve_email_to_username', { email: normalizedEmail }); + try { const response = await this.natsService.request(NatsSubjects.EMAIL_TO_USERNAME, codec.encode(normalizedEmail), { timeout: NATS_CONFIG.REQUEST_TIMEOUT }); const responseText = codec.decode(response.data); @@ -445,7 +428,10 @@ export class ProjectService { // Check if it's an error response if (typeof parsed === 'object' && parsed !== null && parsed.success === false) { - req.log.warn({ email: normalizedEmail, error: parsed.error }, 'User email not found via NATS'); + logger.warning(req, 'resolve_email_to_username', 'User email not found via NATS', { + email: normalizedEmail, + error: parsed.error, + }); throw new ResourceNotFoundError('User', normalizedEmail, { operation: 'resolve_email_to_username', @@ -470,7 +456,9 @@ export class ProjectService { username = username.trim(); if (!username || username === '') { - req.log.warn({ email: normalizedEmail }, 'Empty username returned from NATS'); + logger.warning(req, 'resolve_email_to_username', 'Empty username returned from NATS', { + email: normalizedEmail, + }); throw new ResourceNotFoundError('User', normalizedEmail, { operation: 'resolve_email_to_username', @@ -479,7 +467,10 @@ export class ProjectService { }); } - req.log.info({ email: normalizedEmail, username }, 'Successfully resolved email to username'); + logger.success(req, 'resolve_email_to_username', startTime, { + email: normalizedEmail, + username, + }); return username; } catch (error) { @@ -488,8 +479,6 @@ export class ProjectService { throw error; } - req.log.error({ err: error, email: normalizedEmail }, 'Failed to resolve email to username via NATS'); - // If it's a timeout or no responder error, treat as not found if (error instanceof Error && (error.message.includes('timeout') || error.message.includes('503'))) { throw new ResourceNotFoundError('User', normalizedEmail, { @@ -525,12 +514,15 @@ export class ProjectService { await this.resolveEmailToSub(req, usernameOrEmail); // Then get the username for user metadata lookup usernameForLookup = await this.resolveEmailToUsername(req, usernameOrEmail); - req.log.debug({ email: originalEmail, resolvedUsername: usernameForLookup }, 'Resolved email to username for user metadata lookup'); + logger.debug(req, 'get_user_info', 'Email resolved to username', { + email: originalEmail, + resolved_username: usernameForLookup, + }); } - try { - req.log.debug({ username: usernameForLookup }, 'Fetching user metadata via NATS'); + const startTime = logger.startOperation(req, 'get_user_info', { username: usernameForLookup }); + try { const response = await this.natsService.request(NatsSubjects.USER_METADATA_READ, codec.encode(usernameForLookup), { timeout: NATS_CONFIG.REQUEST_TIMEOUT, }); @@ -549,7 +541,10 @@ export class ProjectService { // Check if it's an error response if (userMetadata.success === false) { - req.log.warn({ username: usernameForLookup, error: userMetadata.error }, 'User metadata not found via NATS'); + logger.warning(req, 'get_user_info', 'User metadata not found via NATS', { + username: usernameForLookup, + error: userMetadata.error, + }); throw new ResourceNotFoundError('User', usernameForLookup, { operation: 'get_user_info', @@ -558,8 +553,6 @@ export class ProjectService { }); } - req.log.info({ username: usernameForLookup }, 'Successfully fetched user metadata'); - const userData = userMetadata.data || {}; const result: { name: string; email: string; username: string; avatar?: string } = { @@ -575,6 +568,8 @@ export class ProjectService { result.avatar = userData.picture; } + logger.success(req, 'get_user_info', startTime, { username: usernameForLookup }); + return result; } catch (error) { // Re-throw ResourceNotFoundError as-is @@ -582,8 +577,6 @@ export class ProjectService { throw error; } - req.log.error({ err: error, username: usernameForLookup }, 'Failed to fetch user metadata via NATS'); - // If it's a timeout or no responder error, treat as not found if (error instanceof Error && (error.message.includes('timeout') || error.message.includes('503'))) { throw new ResourceNotFoundError('User', usernameForLookup, { @@ -1327,7 +1320,7 @@ export class ProjectService { * Get project UID by slug using NATS request-reply pattern * @private */ - private async getProjectIdBySlug(slug: string): Promise { + private async getProjectIdBySlug(req: Request, slug: string): Promise { const codec = this.natsService.getCodec(); try { @@ -1337,7 +1330,7 @@ export class ProjectService { // Check if we got a valid project ID if (!uid || uid.trim() === '') { - serverLogger.info({ slug }, 'Project slug not found via NATS'); + logger.debug(req, 'get_project_id_by_slug', 'Project slug not found via NATS', { slug }); return { uid: '', slug, @@ -1345,7 +1338,10 @@ export class ProjectService { }; } - serverLogger.info({ slug, project_id: uid }, 'Successfully resolved project slug to ID'); + logger.debug(req, 'get_project_id_by_slug', 'Successfully resolved project slug to ID', { + slug, + project_id: uid, + }); return { uid: uid.trim(), @@ -1353,7 +1349,10 @@ export class ProjectService { exists: true, }; } catch (error) { - serverLogger.error({ err: error, slug }, 'Failed to resolve project slug via NATS'); + logger.warning(req, 'get_project_id_by_slug', 'Failed to resolve project slug via NATS', { + err: error, + slug, + }); // If it's a timeout or no responder error, treat as not found if (error instanceof Error && (error.message.includes('timeout') || error.message.includes('503'))) { diff --git a/apps/lfx-one/src/server/services/snowflake.service.ts b/apps/lfx-one/src/server/services/snowflake.service.ts index 77a77ffa..d7ce3a5a 100644 --- a/apps/lfx-one/src/server/services/snowflake.service.ts +++ b/apps/lfx-one/src/server/services/snowflake.service.ts @@ -7,8 +7,8 @@ import { LockStats, SnowflakePoolStats, SnowflakeQueryOptions, SnowflakeQueryRes import snowflakeSdk from 'snowflake-sdk'; import { MicroserviceError } from '../errors'; -import { serverLogger } from '../server'; import { LockManager } from '../utils/lock-manager'; +import { logger } from './logger.service'; import type { Bind, Connection, ConnectionOptions, LogLevel, Pool, PoolOptions, RowStatement, SnowflakeError } from 'snowflake-sdk'; const { createPool } = snowflakeSdk; @@ -37,8 +37,12 @@ export class SnowflakeService { public static getInstance(): SnowflakeService { if (!SnowflakeService.instance) { SnowflakeService.instance = new SnowflakeService(); - // Safe logging - serverLogger may not be initialized during SSR build - serverLogger?.info('SnowflakeService singleton instance created'); + // Safe logging - logger may not be initialized during SSR build + try { + logger.debug(undefined, 'snowflake_singleton', 'SnowflakeService singleton instance created', {}); + } catch { + // Silently ignore logging errors during SSR build + } } return SnowflakeService.instance; } @@ -49,7 +53,7 @@ export class SnowflakeService { public static resetInstance(): void { if (SnowflakeService.instance) { SnowflakeService.instance.shutdown().catch((err) => { - serverLogger?.error({ err }, 'Error shutting down SnowflakeService during reset'); + logger.error(undefined, 'snowflake_reset', Date.now(), err); }); SnowflakeService.instance = null; } @@ -84,18 +88,15 @@ export class SnowflakeService { // Execute with lock to prevent duplicate queries return this.lockManager.executeLocked(queryHash, async () => { const startTime = Date.now(); + logger.startOperation(undefined, 'snowflake_query', { + query_hash: queryHash, + sql_preview: sqlText.substring(0, 100), + bind_count: binds?.length || 0, + }); + const pool = await this.ensurePool(); try { - serverLogger.info( - { - query_hash: queryHash, - sql_preview: sqlText.substring(0, 100), - bind_count: binds?.length || 0, - }, - 'Executing Snowflake query' - ); - // Execute query with parameterized binds const result: any = await new Promise((resolve, reject) => { pool.use(async (connection: Connection) => { @@ -118,33 +119,21 @@ export class SnowflakeService { }); }); - const duration = Date.now() - startTime; const poolStats = this.getPoolStats(); - serverLogger.info( - { - query_hash: queryHash, - duration_ms: duration, - row_count: result.rows.length, - pool_active: poolStats.activeConnections, - pool_idle: poolStats.idleConnections, - }, - 'Snowflake query executed successfully' - ); + logger.success(undefined, 'snowflake_query', startTime, { + query_hash: queryHash, + row_count: result.rows.length, + pool_active: poolStats.activeConnections, + pool_idle: poolStats.idleConnections, + }); return result as SnowflakeQueryResult; } catch (error) { - const duration = Date.now() - startTime; - - serverLogger.error( - { - query_hash: queryHash, - duration_ms: duration, - err: error, - sql_preview: sqlText.substring(0, 100), - }, - 'Snowflake query execution failed' - ); + logger.error(undefined, 'snowflake_query', startTime, error instanceof Error ? error : new Error(String(error)), { + query_hash: queryHash, + sql_preview: sqlText.substring(0, 100), + }); // Wrap Snowflake SDK errors in MicroserviceError for proper error handling const errorMessage = error instanceof Error ? error.message : String(error); @@ -153,7 +142,7 @@ export class SnowflakeService { service: 'snowflake', errorBody: { query_hash: queryHash, - duration_ms: duration, + duration_ms: Date.now() - startTime, }, originalError: error instanceof Error ? error : undefined, }); @@ -206,7 +195,7 @@ export class SnowflakeService { * Gracefully shutdown the service */ public async shutdown(): Promise { - serverLogger.info('Shutting down SnowflakeService'); + const startTime = logger.startOperation(undefined, 'snowflake_shutdown'); // Shutdown lock manager this.lockManager.shutdown(); @@ -221,9 +210,11 @@ export class SnowflakeService { }); await Promise.race([drainPromise, timeoutPromise]); - serverLogger.info('Snowflake connection pool drained successfully'); + logger.success(undefined, 'snowflake_shutdown', startTime, { + message: 'Snowflake connection pool drained successfully', + }); } catch (error) { - serverLogger.error({ err: error }, 'Error during Snowflake pool shutdown'); + logger.error(undefined, 'snowflake_shutdown', startTime, error instanceof Error ? error : new Error(String(error))); } this.pool = null; @@ -266,7 +257,7 @@ export class SnowflakeService { * @private */ private async createPool(): Promise> { - serverLogger.info('Creating Snowflake connection pool'); + const startTime = logger.startOperation(undefined, 'snowflake_pool_creation'); // Validate all required environment variables const requiredEnvVars = { @@ -284,13 +275,10 @@ export class SnowflakeService { if (missingVars.length > 0) { const errorMessage = `Snowflake configuration error: Missing required environment variables: ${missingVars.join(', ')}`; - serverLogger.error( - { - missing_variables: missingVars, - all_required: Object.keys(requiredEnvVars), - }, - errorMessage - ); + logger.error(undefined, 'snowflake_pool_creation', startTime, new Error(errorMessage), { + missing_variables: missingVars, + all_required: Object.keys(requiredEnvVars), + }); throw new MicroserviceError(errorMessage, 500, 'SNOWFLAKE_CONFIG_ERROR', { operation: 'snowflake_pool_creation', service: 'snowflake', @@ -302,7 +290,7 @@ export class SnowflakeService { } const privateKey = requiredEnvVars.SNOWFLAKE_API_KEY!; - serverLogger.info('Using SNOWFLAKE_API_KEY from environment variable'); + logger.debug(undefined, 'snowflake_pool_creation', 'Using SNOWFLAKE_API_KEY from environment variable', {}); // Pool configuration const minConnections = Number(process.env['SNOWFLAKE_MIN_CONNECTIONS']) || SNOWFLAKE_CONFIG.MIN_CONNECTIONS; @@ -338,29 +326,22 @@ export class SnowflakeService { try { const pool = createPool(connectionOptions, poolOptions); - serverLogger.info( - { - min_connections: minConnections, - max_connections: maxConnections, - idle_timeout_ms: SNOWFLAKE_CONFIG.IDLE_TIMEOUT, - acquire_timeout_ms: SNOWFLAKE_CONFIG.CONNECTION_ACQUIRE_TIMEOUT, - test_on_borrow: true, - account: requiredEnvVars.SNOWFLAKE_ACCOUNT, - warehouse: requiredEnvVars.SNOWFLAKE_WAREHOUSE, - database: requiredEnvVars.SNOWFLAKE_DATABASE, - }, - 'Snowflake connection pool created successfully' - ); + logger.success(undefined, 'snowflake_pool_creation', startTime, { + min_connections: minConnections, + max_connections: maxConnections, + idle_timeout_ms: SNOWFLAKE_CONFIG.IDLE_TIMEOUT, + acquire_timeout_ms: SNOWFLAKE_CONFIG.CONNECTION_ACQUIRE_TIMEOUT, + test_on_borrow: true, + account: requiredEnvVars.SNOWFLAKE_ACCOUNT, + warehouse: requiredEnvVars.SNOWFLAKE_WAREHOUSE, + database: requiredEnvVars.SNOWFLAKE_DATABASE, + }); return pool; } catch (error) { - serverLogger.error( - { - err: error, - account: requiredEnvVars.SNOWFLAKE_ACCOUNT, - }, - 'Failed to create Snowflake connection pool' - ); + logger.error(undefined, 'snowflake_pool_creation', startTime, error instanceof Error ? error : new Error(String(error)), { + account: requiredEnvVars.SNOWFLAKE_ACCOUNT, + }); // Wrap SDK errors in MicroserviceError for proper error handling const errorMessage = error instanceof Error ? error.message : String(error); throw new MicroserviceError(`Snowflake connection pool creation failed: ${errorMessage}`, 500, 'SNOWFLAKE_CONNECTION_ERROR', { @@ -402,25 +383,19 @@ export class SnowflakeService { for (const pattern of writePatterns) { if (pattern.test(normalizedSql)) { - serverLogger.error( - { - sql_preview: normalizedSql.substring(0, 100), - matched_pattern: pattern.toString(), - }, - 'Blocked query with write operation (including CTEs)' - ); + logger.warning(undefined, 'snowflake_validation', 'Blocked query with write operation (including CTEs)', { + sql_preview: normalizedSql.substring(0, 100), + matched_pattern: pattern.toString(), + }); throw new Error('Only SELECT queries are allowed. Write operations detected.'); } } // Ensure query starts with SELECT or WITH (for CTEs) if (!/^\s*SELECT\b/i.test(normalizedSql) && !/^\s*WITH\b/i.test(normalizedSql)) { - serverLogger.error( - { - sql_preview: normalizedSql.substring(0, 100), - }, - 'Blocked non-SELECT query (not starting with SELECT or WITH)' - ); + logger.warning(undefined, 'snowflake_validation', 'Blocked non-SELECT query (not starting with SELECT or WITH)', { + sql_preview: normalizedSql.substring(0, 100), + }); throw new Error('Only SELECT queries are allowed'); } } diff --git a/apps/lfx-one/src/server/services/user.service.ts b/apps/lfx-one/src/server/services/user.service.ts index 62e73bad..9cc2124b 100644 --- a/apps/lfx-one/src/server/services/user.service.ts +++ b/apps/lfx-one/src/server/services/user.service.ts @@ -27,9 +27,9 @@ import { import { Request } from 'express'; import { ResourceNotFoundError } from '../errors'; -import { serverLogger } from '../server'; import { generateM2MToken } from '../utils/m2m-token.util'; import { ApiClientService } from './api-client.service'; +import { logger } from './logger.service'; import { MeetingService } from './meeting.service'; import { NatsService } from './nats.service'; import { ProjectService } from './project.service'; @@ -65,11 +65,10 @@ export class UserService { * @throws ResourceNotFoundError if user not found */ public async getUserInfo(req: Request, userArg: string): Promise { + const startTime = logger.startOperation(req, 'get_user_info', { user_arg_provided: !!userArg }); const codec = this.natsService.getCodec(); try { - req.log.info({ userArgProvided: !!userArg }, 'Fetching user metadata via NATS'); - const response = await this.natsService.request(NatsSubjects.USER_METADATA_READ, codec.encode(userArg), { timeout: NATS_CONFIG.REQUEST_TIMEOUT }); const responseText = codec.decode(response.data); @@ -84,14 +83,14 @@ export class UserService { }); } + logger.success(req, 'get_user_info', startTime, { user_arg_provided: !!userArg }); + return userMetadata; } catch (error) { if (error instanceof ResourceNotFoundError) { throw error; } - req.log.error({ err: error, userArgProvided: !!userArg }, 'Failed to fetch user metadata via NATS'); - if (error instanceof Error && (error.message.includes('timeout') || error.message.includes('503'))) { throw new ResourceNotFoundError('User', undefined, { operation: 'get_user_info', @@ -111,6 +110,12 @@ export class UserService { * @returns Promise with the update response */ public async updateUserMetadata(req: Request, updates: UserMetadataUpdateRequest): Promise { + const startTime = logger.startOperation(req, 'update_user_metadata', { + has_username: !!updates.username, + has_metadata: !!updates.user_metadata, + metadata_fields: updates.user_metadata ? Object.keys(updates.user_metadata) : [], + }); + try { // Validate required fields if (!updates.username) { @@ -121,48 +126,28 @@ export class UserService { throw new Error('Authentication token is required'); } - // Log the update attempt - req.log.info( - { - has_username: !!updates.username, - has_metadata: !!updates.user_metadata, - metadata_fields: updates.user_metadata ? Object.keys(updates.user_metadata) : [], - }, - 'Attempting to update user metadata' - ); - // Send the request via NATS - const response = await this.sendUserMetadataUpdate(updates); + const response = await this.sendUserMetadataUpdate(req, updates); // Log the result if (response.success) { - req.log.info( - { - username: updates.username, - updated_fields: response.updated_fields, - }, - 'User metadata updated successfully' - ); + logger.success(req, 'update_user_metadata', startTime, { + username: updates.username, + updated_fields: response.updated_fields, + }); } else { - req.log.error( - { - username: updates.username, - error: response.error, - message: response.message, - }, - 'Failed to update user metadata' - ); + logger.warning(req, 'update_user_metadata', 'Update failed from NATS service', { + username: updates.username, + error: response.error, + message: response.message, + }); } return response; } catch (error) { - req.log.error( - { - username: updates.username, - err: error, - }, - 'Error in user metadata update service' - ); + logger.error(req, 'update_user_metadata', startTime, error, { + username: updates.username, + }); // Return error response return { @@ -252,7 +237,7 @@ export class UserService { * Shutdown the service and clean up resources */ public async shutdown(): Promise { - serverLogger.info('Shutting down user service'); + logger.debug(undefined, 'user_service_shutdown', 'Shutting down user service', {}); await this.natsService.shutdown(); } @@ -487,66 +472,32 @@ export class UserService { * @returns Array of Meeting objects the user is registered for */ public async getUserMeetings(req: Request, email: string, projectUid: string, query: Record): Promise { - try { - // Step 1: Get all meetings the user has access to, filtered by project - // Note: Writers have API access to all meetings, but we still filter by registration - const meetings = await this.meetingService.getMeetings(req, query, 'meeting', false); - const v1Meetings = await this.meetingService.getMeetings(req, query, 'v1_meeting', false); - - const allMeetings = [...meetings, ...v1Meetings]; - - req.log.info( - { - operation: 'get_user_meetings', - project_uid: projectUid, - total_accessible_meetings: allMeetings.length, - }, - 'Fetched all accessible meetings for user' - ); - - if (allMeetings.length === 0) { - return []; - } + // Step 1: Get all meetings the user has access to, filtered by project + // Note: Writers have API access to all meetings, but we still filter by registration + const meetings = await this.meetingService.getMeetings(req, query, 'meeting', false); + const v1Meetings = await this.meetingService.getMeetings(req, query, 'v1_meeting', false); - req.log.debug( - { - operation: 'get_user_meetings', - total_meetings: allMeetings.length, - regular_meetings: meetings.length, - v1_meetings: v1Meetings.length, - }, - 'Retrieved meetings from API' - ); - - const m2mToken = await generateM2MToken(req); - const baseUrl = process.env['LFX_V2_SERVICE'] || 'http://lfx-api.k8s.orb.local'; - - // Step 2: Filter ALL meetings by registration status - // For "my meetings", we only show meetings the user is actually registered for - // This applies to both public and private meetings, regardless of writer status - const filteredMeetings = await this.filterMeetingsByRegistration(req, allMeetings, email, m2mToken, baseUrl); - - req.log.info( - { - operation: 'get_user_meetings', - total_accessible: allMeetings.length, - registered_meetings: filteredMeetings.length, - }, - 'User meetings filtered by registration' - ); - - return filteredMeetings; - } catch (error) { - req.log.error( - { - operation: 'get_user_meetings', - err: error, - project_uid: projectUid, - }, - 'Failed to get user meetings' - ); - throw error; + const allMeetings = [...meetings, ...v1Meetings]; + + logger.debug(req, 'get_user_meetings', 'Retrieved meetings from API', { + total_meetings: allMeetings.length, + regular_meetings: meetings.length, + v1_meetings: v1Meetings.length, + }); + + if (allMeetings.length === 0) { + return []; } + + const m2mToken = await generateM2MToken(req); + const baseUrl = process.env['LFX_V2_SERVICE'] || 'http://lfx-api.k8s.orb.local'; + + // Step 2: Filter ALL meetings by registration status + // For "my meetings", we only show meetings the user is actually registered for + // This applies to both public and private meetings, regardless of writer status + const filteredMeetings = await this.filterMeetingsByRegistration(req, allMeetings, email, m2mToken, baseUrl); + + return filteredMeetings; } /** @@ -581,25 +532,17 @@ export class UserService { // If resources array has items, user is registered const isRegistered = response.data.resources && response.data.resources.length > 0; - req.log.debug( - { - operation: 'filter_meetings_by_registration', - meeting_uid: meeting.uid, - is_registered: isRegistered, - }, - 'Checked user registration for meeting' - ); + logger.debug(req, 'filter_meetings_by_registration', 'Checked user registration for meeting', { + meeting_uid: meeting.uid, + is_registered: isRegistered, + }); return isRegistered ? meeting : null; } catch (error) { - req.log.warn( - { - operation: 'filter_meetings_by_registration', - meeting_uid: meeting.uid, - err: error, - }, - 'Failed to check registration for meeting, excluding from results' - ); + logger.warning(req, 'filter_meetings_by_registration', 'Failed to check registration for meeting', { + meeting_uid: meeting.uid, + err: error, + }); return null; } }) @@ -616,12 +559,12 @@ export class UserService { // Fetch surveys and user-specific meetings in parallel const [surveys, meetings] = await Promise.all([ this.projectService.getPendingActionSurveys(email, projectSlug).catch((error) => { - req.log.warn({ err: error }, 'Failed to fetch surveys for pending actions'); + logger.warning(req, 'get_board_member_actions', 'Failed to fetch surveys for pending actions', { err: error }); return []; }), this.getUserMeetings(req, email, projectUid, { tags_all: [`project_uid:${projectUid}`, 'meeting_type:Board'] }).catch((error) => { - req.log.warn({ err: error }, 'Failed to fetch user meetings for pending actions'); + logger.warning(req, 'get_board_member_actions', 'Failed to fetch user meetings for pending actions', { err: error }); return []; }), ]); @@ -718,11 +661,14 @@ export class UserService { * Send user metadata update request via NATS * @private */ - private async sendUserMetadataUpdate(request: UserMetadataUpdateRequest): Promise { + private async sendUserMetadataUpdate(req: Request, request: UserMetadataUpdateRequest): Promise { const codec = this.natsService.getCodec(); + const startTime = logger.startOperation(req, 'send_user_metadata_update', { username: request.username }); try { - serverLogger.info({ username: request.username }, 'Sending user metadata update request via NATS'); + logger.debug(req, 'send_user_metadata_update', 'Sending user metadata update request via NATS', { + username: request.username, + }); const requestPayload = JSON.stringify(request); const response = await this.natsService.request(NatsSubjects.USER_METADATA_UPDATE, codec.encode(requestPayload), { @@ -734,34 +680,24 @@ export class UserService { // Check if the response indicates success if (!parsedResponse.success) { - serverLogger.error( - { - username: request.username, - error: parsedResponse.error, - message: parsedResponse.message, - }, - 'User metadata update failed via NATS' - ); + logger.warning(req, 'send_user_metadata_update', 'User metadata update failed via NATS', { + username: request.username, + error: parsedResponse.error, + message: parsedResponse.message, + }); return parsedResponse; } - serverLogger.info( - { - username: request.username, - updated_fields: parsedResponse.updated_fields, - }, - 'Successfully updated user metadata via NATS' - ); + logger.success(req, 'send_user_metadata_update', startTime, { + username: request.username, + updated_fields: parsedResponse.updated_fields, + }); return parsedResponse; } catch (error) { - serverLogger.error( - { - err: error, - username: request.username, - }, - 'Failed to update user metadata via NATS' - ); + logger.error(req, 'send_user_metadata_update', startTime, error, { + username: request.username, + }); // If it's a timeout or no responder error, return appropriate response if (error instanceof Error && (error.message.includes('timeout') || error.message.includes('503'))) { diff --git a/apps/lfx-one/src/server/utils/lock-manager.ts b/apps/lfx-one/src/server/utils/lock-manager.ts index 186dc0bf..c33311c7 100644 --- a/apps/lfx-one/src/server/utils/lock-manager.ts +++ b/apps/lfx-one/src/server/utils/lock-manager.ts @@ -6,7 +6,7 @@ import { SnowflakeLockStrategy } from '@lfx-one/shared/enums'; import { LockEntry, LockStats } from '@lfx-one/shared/interfaces'; import crypto from 'crypto'; -import { serverLogger } from '../server'; +import { logger } from '../services/logger.service'; import type { Bind } from 'snowflake-sdk'; @@ -110,7 +110,7 @@ export class LockManager { // this.redisClient.quit(); // } - serverLogger.info('LockManager shutdown complete'); + logger.success(undefined, 'lock_manager_shutdown', Date.now()); } /** @@ -125,14 +125,11 @@ export class LockManager { existing.waiters++; this.totalHits++; - serverLogger.info( - { - query_hash: key, - waiters: existing.waiters, - is_dedupe_hit: true, - }, - 'Query deduplication hit - reusing existing execution' - ); + logger.debug(undefined, 'query_deduplication_hit', 'Query deduplication hit - reusing existing execution', { + query_hash: key, + waiters: existing.waiters, + is_dedupe_hit: true, + }); return existing.promise; } @@ -149,13 +146,10 @@ export class LockManager { this.memoryLocks.set(key, lockEntry); - serverLogger.info( - { - query_hash: key, - is_dedupe_hit: false, - }, - 'Executing new query' - ); + logger.debug(undefined, 'query_execution_new', 'Executing new query', { + query_hash: key, + is_dedupe_hit: false, + }); try { const result = await promise; @@ -229,13 +223,10 @@ export class LockManager { for (const [key, entry] of this.memoryLocks.entries()) { if (now - entry.timestamp > maxAge) { this.memoryLocks.delete(key); - serverLogger.info( - { - query_hash: key, - age_ms: now - entry.timestamp, - }, - 'Cleaned up stale lock' - ); + logger.debug(undefined, 'lock_cleanup_stale', 'Cleaned up stale lock', { + query_hash: key, + age_ms: now - entry.timestamp, + }); } } }, SNOWFLAKE_CONFIG.LOCK_CLEANUP_INTERVAL); diff --git a/apps/lfx-one/src/server/utils/m2m-token.util.ts b/apps/lfx-one/src/server/utils/m2m-token.util.ts index 3dcbbdf4..1d2ee868 100644 --- a/apps/lfx-one/src/server/utils/m2m-token.util.ts +++ b/apps/lfx-one/src/server/utils/m2m-token.util.ts @@ -5,7 +5,7 @@ import { M2MTokenResponse } from '@lfx-one/shared/interfaces'; import { Request } from 'express'; import { MicroserviceError } from '../errors'; -import { Logger } from '../helpers/logger'; +import { logger } from '../services/logger.service'; /** * Generates a machine-to-machine (M2M) token from Auth0 (production) or Authelia (local dev) @@ -18,15 +18,13 @@ export async function generateM2MToken(req: Request): Promise { const issuerBaseUrl = process.env['M2M_AUTH_ISSUER_BASE_URL']; const isAuthelia = issuerBaseUrl?.includes('auth.k8s.orb.local'); - const startTime = Logger.start(req, 'generate_m2m_token', { + const startTime = logger.startOperation(req, 'generate_m2m_token', { audience: process.env['M2M_AUTH_AUDIENCE'], issuer: issuerBaseUrl, auth_provider: isAuthelia ? 'authelia' : 'auth0', }); try { - req.log.debug(req, 'generate_m2m_token', startTime, { auth_provider: isAuthelia ? 'authelia' : 'auth0' }, 'Generating M2M token...'); - // Select the appropriate request configuration const config = isAuthelia ? AUTHELIA_TOKEN_REQUEST : AUTH0_TOKEN_REQUEST; const tokenEndpoint = new URL(config.endpoint, issuerBaseUrl).toString(); @@ -49,7 +47,7 @@ export async function generateM2MToken(req: Request): Promise { // If JSON parsing fails, use empty object } - Logger.error(req, 'generate_m2m_token', startTime, new Error(`${isAuthelia ? 'Authelia' : 'Auth0'} token request failed: ${response.status}`), { + logger.error(req, 'generate_m2m_token', startTime, new Error(`${isAuthelia ? 'Authelia' : 'Auth0'} token request failed: ${response.status}`), { status: response.status, statusText: response.statusText, error_body: errorBody, @@ -67,7 +65,7 @@ export async function generateM2MToken(req: Request): Promise { const tokenResponse: M2MTokenResponse = await response.json(); if (!tokenResponse.access_token) { - Logger.error(req, 'generate_m2m_token', startTime, new Error('No access token in response'), { + logger.error(req, 'generate_m2m_token', startTime, new Error('No access token in response'), { token_response: tokenResponse, }); @@ -78,7 +76,7 @@ export async function generateM2MToken(req: Request): Promise { }); } - Logger.success(req, 'generate_m2m_token', startTime, { + logger.success(req, 'generate_m2m_token', startTime, { token_type: tokenResponse.token_type, expires_in: tokenResponse.expires_in, scope: tokenResponse.scope, @@ -94,7 +92,7 @@ export async function generateM2MToken(req: Request): Promise { } // Log and wrap unexpected errors - Logger.error(req, 'generate_m2m_token', startTime, error, {}); + logger.error(req, 'generate_m2m_token', startTime, error, {}); const issuerBaseUrl = process.env['M2M_AUTH_ISSUER_BASE_URL']; const isAuthelia = issuerBaseUrl?.includes('auth.k8s.orb.local'); diff --git a/apps/lfx-one/src/server/utils/persona-helper.ts b/apps/lfx-one/src/server/utils/persona-helper.ts index a95db9bb..5a8b2c8c 100644 --- a/apps/lfx-one/src/server/utils/persona-helper.ts +++ b/apps/lfx-one/src/server/utils/persona-helper.ts @@ -5,6 +5,7 @@ import type { PersonaType } from '@lfx-one/shared/interfaces'; import { Request } from 'express'; import { CommitteeService } from '../services/committee.service'; +import { logger } from '../services/logger.service'; import { getUsernameFromAuth } from './auth-helper'; /** @@ -39,12 +40,7 @@ const PERSONA_PRIORITY: PersonaType[] = ['core-developer', 'maintainer', 'board- * along with all unique organization names from the user's committee memberships */ export async function fetchUserPersonaAndOrganizations(req: Request): Promise { - req.log.info( - { - operation: 'fetch_user_persona_and_organizations', - }, - 'Fetching user persona and organizations' - ); + const startTime = logger.startOperation(req, 'fetch_user_persona_and_organizations'); const result: UserPersonaResult = { persona: null, @@ -55,7 +51,9 @@ export async function fetchUserPersonaAndOrganizations(req: Request): Promise 0) { + logger.debug(req, 'matched_persona', 'Persona matched for user', { + username, category, + persona, memberships_count: memberships.length, - }, - 'Found committee memberships' - ); - if (memberships.length > 0) { - req.log.info( - { - username, - category, - persona, - memberships_count: memberships.length, - }, - `User has ${category} committee membership - matched persona ${persona}` - ); + }); matchedPersonas.push(persona); // Collect unique organization names from memberships @@ -102,13 +88,7 @@ export async function fetchUserPersonaAndOrganizations(req: Request): Promise highestPriority ? current : highest; }, matchedPersonas[0]); - req.log.info( - { - username, - matched_personas: matchedPersonas, - selected_persona: result.persona, - organization_count: result.organizationNames.length, - }, - 'Determined user persona and organizations from committee memberships' - ); + logger.success(req, 'fetch_user_persona_and_organizations', startTime, { + username, + matched_personas: matchedPersonas, + selected_persona: result.persona, + organization_count: result.organizationNames.length, + }); return result; } catch (error) { // Log error but don't fail SSR - persona determination is non-critical - req.log.warn( - { - err: error, - }, - 'Failed to determine user persona from committee membership' - ); + logger.error(req, 'fetch_user_persona_and_organizations', startTime, error, { + failure_reason: 'committee_lookup_failed', + }); return result; } } diff --git a/docs/architecture/backend/logging-monitoring.md b/docs/architecture/backend/logging-monitoring.md index 6daa9832..ab3f6560 100644 --- a/docs/architecture/backend/logging-monitoring.md +++ b/docs/architecture/backend/logging-monitoring.md @@ -1,512 +1,686 @@ # Logging & Monitoring -## 📝 Pino Logging System +## 📝 Overview -The application uses Pino for high-performance structured logging with automatic request logging and security redaction. +The application uses a structured logging system built on Pino with operation lifecycle tracking, CloudWatch optimization, and automatic duplicate prevention. All logging is handled through the singleton `LoggerService` class, which supports both request-scoped operations (with `req`) and infrastructure operations (without `req`). -## 🔧 Pino Configuration +## 🏗️ LoggerService Architecture -### Dual Logger Architecture +### Singleton Pattern with Operation Tracking -The application uses a dual logger architecture for optimal performance and flexibility: - -#### Server Logger (Base Logger) +The `LoggerService` is a singleton class that provides consistent, structured logging across the entire application: ```typescript -// apps/lfx-one/src/server/server.ts -import pino from 'pino'; +// Import the singleton instance +import { logger } from '../services/logger.service'; -/** - * Base Pino logger instance for server-level operations. - * Used for server startup/shutdown, direct logging from server code, - * and can be imported by other modules for consistent logging. - */ -const serverLogger = pino({ - level: process.env['LOG_LEVEL'] || 'info', - redact: { - paths: ['access_token', 'refresh_token', 'authorization', 'cookie'], - remove: true, - }, - formatters: { - level: (label) => { - return { level: label.toUpperCase() }; - }, - }, - timestamp: pino.stdTimeFunctions.isoTime, -}); +// Use in controllers and services +const startTime = logger.startOperation(req, 'fetch_projects', { filter: 'active' }); +// ... perform operation +logger.success(req, 'fetch_projects', startTime, { count: projects.length }); ``` -#### HTTP Logger (Request Middleware) +### Key Features -```typescript -/** - * HTTP request/response logging middleware using Pino. - * Provides request-scoped logger accessible via req.log in route handlers. - */ -const httpLogger = pinoHttp({ - logger: serverLogger, // Uses same base logger for consistency - autoLogging: { - ignore: (req: Request) => { - return req.url === '/health' || req.url === '/api/health'; - }, - }, - redact: { - paths: ['req.headers.authorization', 'req.headers.cookie', 'res.headers["set-cookie"]'], - remove: true, - }, - level: 'info', - formatters: { - level: (label) => { - return { level: label.toUpperCase() }; - }, - }, - timestamp: pino.stdTimeFunctions.isoTime, -}); +- **Operation Lifecycle Tracking**: Pairs `startOperation()` → `success()`/`error()` for complete operation visibility +- **Automatic Duration Calculation**: Computes `duration_ms` via `Date.now() - startTime` +- **Duplicate Prevention**: Tracks logged errors to prevent duplicate logs in error middleware (request-scoped only) +- **CloudWatch Optimization**: Structured metadata for efficient AWS CloudWatch queries +- **Memory Safety**: WeakMap-based operation tracking prevents memory leaks +- **Error Serialization**: Custom serializer for clean error output in dev and detailed traces in production +- **Dual Mode Support**: Works with request context (`req`) or without (`undefined`) for infrastructure operations -// Add HTTP logger middleware after health endpoint -app.use(httpLogger); +### Logging Architecture Layers + +```text +server-logger.ts (NEW - breaks circular dependency) + └─ Creates and exports serverLogger (base Pino instance) + └─ Configuration: levels, serializers, formatters, redaction + +server.ts + ├─ Imports serverLogger from server-logger.ts + └─ Creates httpLogger (pinoHttp middleware) + └─ Uses serverLogger as base + └─ Attaches req.log to each request + +logger.service.ts + ├─ Imports serverLogger from server-logger.ts + └─ Singleton LoggerService + ├─ When req provided: uses req.log (request-scoped) + ├─ When req = undefined: uses serverLogger (infrastructure) + └─ Provides unified API for all logging ``` -### Key Features +**Import Pattern:** -- **Dual Logger Architecture**: Separate loggers for server operations and HTTP requests -- **Shared Configuration**: Consistent formatting and settings across both loggers -- **Environment-Based Levels**: Configurable log levels via LOG_LEVEL environment variable -- **High Performance**: Pino is optimized for speed and low overhead -- **Structured Logging**: JSON output with uppercase level formatting -- **Security Redaction**: Automatically removes sensitive headers and tokens -- **Health Check Filtering**: Excludes health endpoints from logs -- **Request Correlation**: Automatic request ID generation -- **Modular Design**: Server logger can be exported and reused in other modules +- ✅ Controllers/Services: `import { logger } from './logger.service'` +- ❌ Never import `serverLogger` directly (except in server.ts and logger.service.ts) -## 📊 Logging Configuration +## 📊 Logging Methods -### Environment Variables +### Operation Lifecycle Methods -```bash -# Set log level for both server and HTTP loggers -LOG_LEVEL=info # Options: trace, debug, info, warn, error, fatal +#### `startOperation(req | undefined, operation, metadata, options)` + +Starts an operation and returns `startTime` for duration tracking. + +```typescript +// Request-scoped operation +const startTime = logger.startOperation(req, 'create_meeting', { + project_uid: projectId, + meeting_type: 'board', +}); -# Other environment variables affecting logging -NODE_ENV=production # Affects stack trace inclusion in logs +// Infrastructure operation (no request context) +const startTime = logger.startOperation(undefined, 'nats_connect', { + url: natsUrl, +}); ``` -### Security Redaction +**Parameters:** -#### Server Logger Redaction +- `req`: Express Request object, or `undefined` for infrastructure operations (NATS, Snowflake, shutdown) +- `operation`: Snake_case operation name (e.g., `create_meeting`, `fetch_user_profile`, `nats_connect`) +- `metadata`: Contextual data (avoid sensitive information) +- `options`: Optional configuration + - `silent`: If true, doesn't log the start (for silent tracking) -```typescript -// Server-level sensitive data redaction -redact: { - paths: [ - 'access_token', // OAuth access tokens - 'refresh_token', // OAuth refresh tokens - 'authorization', // Authorization headers - 'cookie' // Cookie data - ], - remove: true, // Completely removes instead of showing [Redacted] -} -``` +**Returns:** `number` - startTime for use with success/error calls -#### HTTP Logger Redaction +**Log Level:** INFO (unless `silent: true`) + +#### `success(req | undefined, operation, startTime, metadata)` + +Marks an operation as successful and logs with duration. ```typescript -// HTTP request/response sensitive data redaction -redact: { - paths: [ - 'req.headers.authorization', // Bearer tokens - 'req.headers.cookie', // Session cookies - 'res.headers["set-cookie"]' // Set-Cookie headers - ], - remove: true, // Completely removes instead of showing [Redacted] -} +// Request-scoped +logger.success(req, 'create_meeting', startTime, { + meeting_uid: newMeeting.uid, +}); + +// Infrastructure +logger.success(undefined, 'nats_connect', startTime, { + pool_size: connection.pool.size, +}); ``` -### Formatting Configuration +**Parameters:** -```typescript -// Consistent formatting across both loggers -formatters: { - level: (label) => { - return { level: label.toUpperCase() }; // INFO, ERROR, WARN, etc. - }, -}, -timestamp: pino.stdTimeFunctions.isoTime, // ISO 8601 timestamps +- `req`: Express Request object, or `undefined` for infrastructure operations +- `operation`: Same operation name from startOperation +- `startTime`: Value returned from startOperation +- `metadata`: Success-specific data (results, counts, IDs) + +**Log Level:** INFO + +**Output Example:** + +```json +{ + "level": "INFO", + "operation": "create_meeting", + "status": "success", + "duration_ms": 145, + "meeting_uid": "abc123", + "msg": "Operation completed successfully" +} ``` -### Health Check Filtering +#### `error(req | undefined, operation, startTime, error, metadata, options)` + +Marks an operation as failed and logs error details. ```typescript -// Avoid logging noise from health checks -autoLogging: { - ignore: (req: Request) => { - return req.url === '/health' || req.url === '/api/health'; - }, +try { + const meeting = await getMeeting(id); + logger.success(req, 'fetch_meeting', startTime, { meeting_uid: id }); +} catch (error) { + logger.error(req, 'fetch_meeting', startTime, error, { + meeting_uid: id, + attempted_action: 'fetch', + }); + throw error; } ``` -## 🔍 Request Logging +**Parameters:** -### Automatic HTTP Logging +- `req`: Express Request object, or `undefined` for infrastructure operations +- `operation`: Same operation name from startOperation +- `startTime`: Value returned from startOperation +- `error`: Error object or unknown error +- `metadata`: Error-specific context +- `options`: Optional configuration + - `skipIfLogged`: If true, skips logging if already logged (for error middleware, request-scoped only) -Pino-http automatically logs: +**Log Level:** ERROR + +**Output Example:** ```json { - "level": 30, - "time": 1640995200000, - "pid": 12345, - "hostname": "server-name", - "req": { - "id": "req-1", - "method": "GET", - "url": "/project/kubernetes", - "headers": { - "user-agent": "Mozilla/5.0...", - "accept": "text/html,application/xhtml+xml" - }, - "remoteAddress": "127.0.0.1", - "remotePort": 56789 - }, - "res": { - "statusCode": 200, - "headers": { - "content-type": "text/html; charset=utf-8" - } + "level": "ERROR", + "operation": "fetch_meeting", + "status": "failed", + "duration_ms": 52, + "err": { + "type": "ResourceNotFoundError", + "message": "Meeting not found", + "stack": "Error: Meeting not found\n at MeetingService.getMeeting..." }, - "responseTime": 42, - "msg": "request completed" + "meeting_uid": "xyz789", + "msg": "Operation failed" } ``` -## 🚨 Error Logging +### Informational Logging Methods -### Application Error Handling +#### `debug(req | undefined, operation, message, metadata)` -#### Angular SSR Error Logging +Logs debug-level information for development and troubleshooting. ```typescript -// Enhanced error logging in main request handler -.catch((error) => { - req.log.error( - { - error: error.message, - code: error.code, - url: req.url, - method: req.method, - user_agent: req.get('User-Agent'), - }, - 'Error rendering Angular application' - ); - - if (error.code === 'NOT_FOUND') { - res.status(404).send('Not Found'); - } else if (error.code === 'UNAUTHORIZED') { - res.status(401).send('Unauthorized'); - } else { - res.status(500).send('Internal Server Error'); - } +// Request-scoped +logger.debug(req, 'committee_member_lookup', 'Checking committee membership', { + username, + category: 'Board', +}); + +// Infrastructure +logger.debug(undefined, 'snowflake_pool', 'Pool connection acquired', { + active_connections: pool.size, }); ``` -#### API Error Handler Integration +**When to Use:** + +- Internal operation steps that don't need lifecycle tracking +- Informational logging within loops +- Intermediate processing steps +- Infrastructure state logging +- Development troubleshooting + +**Log Level:** DEBUG + +#### `warning(req | undefined, operation, message, metadata)` + +Logs warning-level information for concerning but non-critical issues. ```typescript -// API error handler middleware with enhanced logging -export function apiErrorHandler(error: ApiError, req: Request, res: Response, next: NextFunction): void { - // Log unhandled errors using request logger - req.log.error( - { - error: error.message, - path: req.path, - method: req.method, - user_agent: req.get('User-Agent'), - error_name: error.name, - status_code: error.status || 500, - }, - 'Unhandled API error' - ); - - // Return structured error response - res.status(error.status || 500).json({ - error: error.status ? error.message : 'Internal server error', - code: error.code || 'INTERNAL_ERROR', - path: req.path, - }); -} +// Request-scoped +logger.warning(req, 'token_refresh', 'Token refresh failed - user needs re-authentication', { + err: error, + path: req.path, +}); + +// Infrastructure +logger.warning(undefined, 'nats_connect', 'NATS connection slow', { + connection_time_ms: 5000, +}); ``` -### Enhanced Error Log Format +**When to Use:** -#### Angular SSR Error Log +- Recoverable errors that don't fail the operation +- Data quality issues +- Fallback behavior activation +- User not found scenarios +- Token refresh failures +- Infrastructure performance issues -```json -{ - "level": "ERROR", - "time": "2024-01-01T12:00:00.000Z", - "pid": 12345, - "hostname": "server-name", - "req": { - "id": "req-1", - "method": "GET", - "url": "/problematic-route" - }, - "error": "Something went wrong", - "code": "INTERNAL_ERROR", - "stack": "Error: Something went wrong\n at handler (/app/server.js:123:45)", - "url": "/problematic-route", - "method": "GET", - "user_agent": "Mozilla/5.0 (compatible; browser)", - "msg": "Error rendering Angular application" -} -``` +**Log Level:** WARN -#### API Error Log +#### `validation(req | undefined, operation, errors, metadata)` -```json -{ - "level": "ERROR", - "time": "2024-01-01T12:00:00.000Z", - "pid": 12345, - "hostname": "server-name", - "req": { - "id": "req-2", - "method": "POST", - "url": "/api/projects" - }, - "error": "Validation failed", - "stack": "ValidationError: Required field missing\n at validator (/app/api.js:45:12)", - "path": "/api/projects", - "method": "POST", - "user_agent": "Mozilla/5.0 (compatible; browser)", - "error_name": "ValidationError", - "status_code": 400, - "msg": "Unhandled API error" -} +Logs validation failures with detailed error context. + +```typescript +logger.validation(req, 'create_meeting', ['Missing required field: title'], { + provided_fields: Object.keys(req.body), +}); ``` -## 📈 Health Monitoring & Server Startup +**When to Use:** + +- Request validation failures +- Missing required fields +- Invalid field formats +- Business rule violations + +**Log Level:** WARN + +## 🎯 Log Level Guidelines + +### ERROR + +**When:** System failures requiring immediate attention +**Examples:** + +- Database connection failures +- External service unavailable +- Unhandled exceptions +- Data corruption + +### WARN + +**When:** Concerning issues that don't break functionality +**Examples:** + +- Validation failures +- Token refresh failures +- User not found +- Fallback behaviors +- Data quality issues + +### INFO -### Health Check Endpoint +**When:** Business operation completions +**Examples:** + +- Resource created/updated/deleted +- Successful data retrieval +- Operation start (via startOperation) +- Operation success + +### DEBUG + +**When:** Internal operations and development info +**Examples:** + +- Intermediate processing steps +- Loop iterations +- Intent statements ("fetching", "resolving") +- Authentication checks +- Route classification + +## 🔄 Operation Lifecycle Patterns + +### Standard Controller Pattern ```typescript -// Simple health check endpoint (added before logger middleware) -app.get('/health', (_req: Request, res: Response) => { - res.send('OK'); -}); +export class MeetingController { + public async createMeeting(req: Request, res: Response, next: NextFunction): Promise { + const startTime = logger.startOperation(req, 'create_meeting', { + project_uid: req.body.project_uid, + meeting_type: req.body.type, + }); + + try { + // Validate request + const validationErrors = validateMeetingInput(req.body); + if (validationErrors.length > 0) { + logger.validation(req, 'create_meeting', validationErrors, { + provided_fields: Object.keys(req.body), + }); + return res.status(400).json({ errors: validationErrors }); + } + + // Perform operation + const meeting = await meetingService.createMeeting(req, req.body); + + // Log success + logger.success(req, 'create_meeting', startTime, { + meeting_uid: meeting.uid, + attendee_count: meeting.attendees?.length || 0, + }); + + res.status(201).json(meeting); + } catch (error) { + // Log error (error middleware will see skipIfLogged) + logger.error(req, 'create_meeting', startTime, error, { + project_uid: req.body.project_uid, + }); + next(error); + } + } +} ``` -### Health Check Response +### Service Layer Pattern -```text -GET /health -Response: 200 OK -Body: OK +```typescript +export class MeetingService { + public async getMeetingById(req: Request, meetingId: string): Promise { + // Silent operation tracking for service-level operations + const startTime = logger.startOperation(req, 'get_meeting_by_id', { meeting_id: meetingId }, { silent: true }); + + try { + const meeting = await this.microserviceProxy.proxyRequest(req, 'LFX_V2_SERVICE', `/meetings/${meetingId}`, 'GET'); + + if (!meeting) { + throw new ResourceNotFoundError('Meeting', meetingId, { + operation: 'get_meeting_by_id', + }); + } + + logger.success(req, 'get_meeting_by_id', startTime, { + meeting_uid: meetingId, + }); + + return meeting; + } catch (error) { + logger.error(req, 'get_meeting_by_id', startTime, error, { + meeting_id: meetingId, + }); + throw error; + } + } +} ``` -### Server Startup Logging +### Informational Logging (No Lifecycle) ```typescript -// Enhanced server startup logging -export function startServer() { - const port = process.env['PORT'] || 4000; - app.listen(port, () => { - serverLogger.info( - { - port, - url: `http://localhost:${port}`, - node_env: process.env['NODE_ENV'] || 'development', - pm2: process.env['PM2'] === 'true', - }, - 'Node Express server started' - ); +// Use debug() for informational logging without lifecycle tracking +for (const [category, persona] of Object.entries(COMMITTEE_CATEGORY_TO_PERSONA)) { + logger.debug(req, 'check_committee_category', 'Checking category', { category }); + + const memberships = await committeeService.getCommitteeMembersByCategory(req, username, category); + + logger.debug(req, 'committee_memberships_retrieved', 'Found memberships', { + category, + count: memberships.length, }); } ``` -### Server Startup Log Format +## 🚨 Error Handling & Duplicate Prevention -```json -{ - "level": "INFO", - "time": "2024-01-01T12:00:00.000Z", - "pid": 12345, - "hostname": "server-name", - "port": 4000, - "url": "http://localhost:4000", - "node_env": "production", - "pm2": true, - "msg": "Node Express server started" +### Controller-Level Error Logging + +Controllers log errors before passing them to middleware: + +```typescript +try { + // ... operation +} catch (error) { + logger.error(req, 'operation_name', startTime, error, metadata); + next(error); // Pass to error middleware } ``` -## 🔧 Production Considerations +### Error Middleware with Duplicate Prevention -### Log Level Configuration +The error middleware uses `skipIfLogged` to prevent duplicate logs: ```typescript -// Environment-based log level configuration -const serverLogger = pino({ - level: process.env['LOG_LEVEL'] || 'info', // Configurable via environment - // ... other config -}); +export function apiErrorHandler(error: Error, req: Request, res: Response, next: NextFunction): void { + if (res.headersSent) { + next(error); + return; + } + + const operation = getOperationFromPath(req.path); + + if (isBaseApiError(error)) { + const logLevel = error.getSeverity(); + + if (logLevel === 'error') { + // Skip if already logged by controller + logger.error(req, operation, Date.now(), error, logContext, { skipIfLogged: true }); + } + // ... send response + } +} ``` -### Logger Export and Reusability +### How Duplicate Prevention Works + +1. Controller logs error: `logger.error(req, 'create_meeting', startTime, error, metadata)` +2. LoggerService marks operation as "logged" in WeakMap +3. Error middleware tries to log: `logger.error(req, operation, Date.now(), error, metadata, { skipIfLogged: true })` +4. LoggerService checks if already logged → skips if true +5. Result: Single error log, no duplicates + +## ⏱️ Duration Tracking + +### Correct Usage ```typescript -/** - * Export server logger for use in other modules that need logging - * outside of the HTTP request context (e.g., startup scripts, utilities). - */ -export { serverLogger }; - -// Usage in other modules: -// import { serverLogger } from './server/server'; -// serverLogger.info({ data }, 'Module operation completed'); +// ✅ CORRECT: Capture startTime, use for duration calculation +const startTime = logger.startOperation(req, 'fetch_meetings'); +// ... operation +logger.success(req, 'fetch_meetings', startTime, { count }); ``` -### Log Rotation (Recommended) +### Incorrect Usage -For production deployments, consider log rotation: +```typescript +// ❌ WRONG: startTime=0 causes incorrect duration (time since epoch) +logger.error(req, 'ssr_render', 0, error, metadata); +// Results in duration_ms: 1702915200000 (millions of milliseconds!) -```bash -# Example with PM2 log rotation -pm2 install pm2-logrotate -pm2 set pm2-logrotate:max_size 100M -pm2 set pm2-logrotate:retain 30 -pm2 set pm2-logrotate:compress true +// ✅ CORRECT: Use Date.now() if no operation was started +logger.error(req, 'ssr_render', Date.now(), error, metadata); +// Results in duration_ms: 0 (acceptable for error-only logging) ``` -### Container Logging +### SSR Error Handler Example -When running in containers, logs go to stdout/stderr: +```typescript +app.use('/**', async (req: Request, res: Response, next: NextFunction) => { + const ssrStartTime = Date.now(); // Capture at handler start + + // ... SSR operations -```dockerfile -# Dockerfile - logs to stdout -CMD ["node", "dist/lfx-one/server/server.mjs"] + angularApp.handle(req, { auth }).catch((error) => { + // Use captured startTime for accurate duration + logger.error(req, 'ssr_render', ssrStartTime, error, { + code: error.code, + url: req.url, + }); + }); +}); ``` -## 🎯 Request Correlation +## 🔧 Base Pino Configuration -### Automatic Request IDs +### Server Logger (Base Logger) -Pino-http automatically generates request IDs for correlation: +```typescript +// apps/lfx-one/src/server/server.ts +const serverLogger = pino({ + level: process.env['LOG_LEVEL'] || 'info', + base: { + service: 'lfx-one-ssr', + environment: process.env['NODE_ENV'] || 'development', + }, + serializers: { + err: customErrorSerializer, // Clean dev logs, detailed prod logs + error: customErrorSerializer, + }, + redact: { + paths: ['access_token', 'refresh_token', 'authorization', 'cookie'], + remove: true, + }, + formatters: { + level: (label) => ({ level: label.toUpperCase() }), + }, + timestamp: pino.stdTimeFunctions.isoTime, +}); +``` -```json -{ - "req": { - "id": "req-1", // Automatic request correlation ID - "method": "GET", - "url": "/project/kubernetes" - } -} +### HTTP Logger Middleware + +```typescript +const httpLogger = pinoHttp({ + logger: serverLogger, + autoLogging: false, // LoggerService handles operation logging + serializers: { + err: customErrorSerializer, + error: customErrorSerializer, + }, + level: process.env['LOG_LEVEL'] || 'info', +}); + +app.use(httpLogger); ``` -### Using Request Logger vs Server Logger +### Custom Error Serializer -#### Request-Scoped Logging (req.log) +```typescript +// apps/lfx-one/src/server/helpers/error-serializer.ts +export const customErrorSerializer = (err: Error): Record => { + const isDev = process.env['NODE_ENV'] !== 'production'; + + return { + type: err.constructor.name, + message: err.message, + ...(err.stack && !isDev && { stack: err.stack }), // Stack in prod/debug only + ...(err.cause && { cause: err.cause }), + }; +}; +``` + +## 📈 CloudWatch Optimization + +### Structured Metadata ```typescript -// Use req.log for request-specific operations -app.use('/api/projects', (req: Request, res: Response, next: NextFunction) => { - req.log.info({ uid: req.params.id }, 'Processing project request'); - // ... rest of handler +// ✅ Good: Structured for CloudWatch filtering +logger.success(req, 'fetch_meetings', startTime, { + project_uid: 'abc123', + meeting_type: 'board', + count: 5, + duration_ms: 142, }); + +// Enables CloudWatch queries like: +// fields @timestamp, operation, duration_ms, project_uid +// | filter operation = "fetch_meetings" +// | filter duration_ms > 1000 +// | stats avg(duration_ms) by project_uid ``` -#### Server-Level Logging (serverLogger) +### Operation Naming Convention + +Use snake_case for operation names to ensure CloudWatch compatibility: ```typescript -// Use serverLogger for operations outside request context -import { serverLogger } from './server/server'; +// ✅ Good +logger.startOperation(req, 'create_committee_member'); +logger.startOperation(req, 'fetch_user_profile'); +logger.startOperation(req, 'update_meeting_attendees'); + +// ❌ Bad +logger.startOperation(req, 'createCommitteeMember'); // camelCase +logger.startOperation(req, 'fetch-user-profile'); // kebab-case +``` -// Startup operations -serverLogger.info({ config: 'loaded' }, 'Configuration initialized'); +## 🔒 Security & Redaction -// Background tasks -serverLogger.warn({ task: 'cleanup' }, 'Background cleanup completed'); -``` +### Automatic Redaction -#### When to Use Each Logger +The following fields are automatically redacted: -- **req.log**: HTTP request handling, API operations, user actions -- **serverLogger**: Server startup/shutdown, background tasks, module initialization +- `access_token` +- `refresh_token` +- `authorization` +- `cookie` +- Request headers: `authorization`, `cookie` +- Response headers: `set-cookie` -## 📊 Log Analysis +### Safe Metadata Practices -### JSON Structure Benefits +```typescript +// ✅ Good: No sensitive data +logger.success(req, 'user_login', startTime, { + username: user.username, + login_method: 'oauth', +}); -- **Searchable**: Easy to search by field (method, status, url) -- **Filterable**: Filter by log level, time range, error type -- **Parseable**: Standard JSON format for log aggregation tools -- **Structured**: Consistent field names across all logs +// ❌ Bad: Contains sensitive data +logger.success(req, 'user_login', startTime, { + username: user.username, + password: user.password, // Never log passwords + access_token: token.value, // Will be redacted but shouldn't be included +}); +``` -### Example Log Queries +## 📊 Health Check Filtering -```bash -# Filter by status code -cat logs.json | jq 'select(.res.statusCode >= 400)' +Health check endpoints are excluded from automatic HTTP logging: -# Filter by response time -cat logs.json | jq 'select(.responseTime > 1000)' +```typescript +// Health check endpoint (added before logger middleware) +app.get('/health', (_req: Request, res: Response) => { + res.send('OK'); +}); -# Filter by specific routes -cat logs.json | jq 'select(.req.url | startswith("/api/"))' +// HTTP logger middleware (added after health endpoint) +app.use(httpLogger); ``` -## 🔒 Security Features +URLs excluded from logging: -### Data Protection +- `/health` +- `/api/health` +- `/.well-known/*` -- **Header Redaction**: Authorization and cookie headers removed -- **Sensitive Path Filtering**: Configurable redaction paths -- **Complete Removal**: Sensitive data completely removed, not just masked +## 🎯 Best Practices -### Audit Trail +### DO ✅ -- **Request Tracking**: Every request logged with unique ID -- **Error Tracking**: All errors logged with full context -- **Performance Tracking**: Response times logged for monitoring +1. **Always pair operations**: Every `startOperation()` must have a corresponding `success()` or `error()` call +2. **Capture startTime properly**: Store the return value from `startOperation()` +3. **Use correct methods**: `startOperation` for lifecycle, `debug()` for informational +4. **Include context**: Add relevant metadata for troubleshooting +5. **Follow naming conventions**: Use snake_case for operation names +6. **Use err field**: Always pass errors to the `error` parameter, not in metadata -## 📈 Performance Impact +### DON'T ❌ -### Pino Performance Benefits +1. **Don't use startTime=0**: This causes incorrect duration calculations +2. **Don't use startOperation in loops**: Use `debug()` for repeated informational logs +3. **Don't log sensitive data**: Never log passwords, tokens, or PII +4. **Don't nest ternaries in logs**: Keep log statements simple and readable +5. **Don't skip error handling**: Always log errors before throwing/passing to middleware -- **Fast Serialization**: Optimized JSON serialization -- **Asynchronous**: Non-blocking logging operations -- **Low Memory**: Minimal memory footprint -- **Child Logger Support**: Efficient logger inheritance +### Code Review Checklist -### Minimal Overhead +- [ ] All `startOperation()` calls are paired with `success()` or `error()` +- [ ] startTime is captured and used correctly (not 0) +- [ ] Informational logs use `debug()` instead of `startOperation()` +- [ ] Error middleware uses `{ skipIfLogged: true }` +- [ ] No sensitive data in log metadata +- [ ] Operation names use snake_case +- [ ] Errors use `err` parameter, not metadata fields -```typescript -// Pino is designed for production use with minimal performance impact -// Typical overhead: <1% CPU, <10MB memory for high-traffic applications +## 🔧 Environment Configuration + +```bash +# Log level (trace, debug, info, warn, error, fatal) +LOG_LEVEL=info + +# Node environment (affects error stack traces) +NODE_ENV=production + +# AWS X-Ray trace ID (auto-injected in AWS environments) +_X_AMZN_TRACE_ID=Root=1-67890-abc123 ``` -## 🔧 Current Implementation Status +## 📈 Current Implementation Status -### ✅ Implemented Features +### ✅ Implemented -- **Dual Logger Architecture**: Separate server and HTTP loggers -- **Environment Configuration**: LOG_LEVEL environment variable support -- **Enhanced Error Handling**: API error handler middleware integration -- **Server Startup Logging**: Comprehensive server initialization logging -- **Security Redaction**: Multiple layers of sensitive data protection -- **Exportable Logger**: Server logger available for module imports -- **Consistent Formatting**: Uppercase levels and ISO timestamps -- **Conditional Stack Traces**: Production-safe error logging -- **Request Correlation**: Automatic request ID generation -- **Health Check Filtering**: Excluded from request logs +- LoggerService singleton with operation tracking +- Operation lifecycle (startOperation → success/error) +- Duplicate log prevention +- Duration calculation +- CloudWatch-optimized structured logging +- Custom error serializer +- Security redaction +- Health check filtering +- Validation logging +- WeakMap-based memory safety -### 🔲 Not Yet Implemented +### 🔲 Not Implemented -- Custom log levels for different components - Log aggregation service integration - Metrics collection endpoints - Performance monitoring dashboards - Alert system integration -- Log retention policies +- Automated log retention policies -This logging system provides a solid foundation for monitoring application behavior and troubleshooting issues in both development and production environments. +This logging system provides comprehensive operation visibility, efficient CloudWatch integration, and prevents common logging issues like duplicates and incorrect durations. diff --git a/package.json b/package.json index f5857dc7..d0d385ab 100644 --- a/package.json +++ b/package.json @@ -42,7 +42,7 @@ "lint-staged": "^16.2.7", "prettier": "^3.7.4", "tslib": "^2.8.1", - "turbo": "^2.5.5", + "turbo": "^2.6.3", "typescript": "5.8.3" }, "engines": { diff --git a/yarn.lock b/yarn.lock index f0c4f1db..d610fb03 100644 --- a/yarn.lock +++ b/yarn.lock @@ -11786,7 +11786,7 @@ __metadata: lint-staged: "npm:^16.2.7" prettier: "npm:^3.7.4" tslib: "npm:^2.8.1" - turbo: "npm:^2.5.5" + turbo: "npm:^2.6.3" typescript: "npm:5.8.3" languageName: unknown linkType: soft @@ -16065,58 +16065,58 @@ __metadata: languageName: node linkType: hard -"turbo-darwin-64@npm:2.5.5": - version: 2.5.5 - resolution: "turbo-darwin-64@npm:2.5.5" +"turbo-darwin-64@npm:2.6.3": + version: 2.6.3 + resolution: "turbo-darwin-64@npm:2.6.3" conditions: os=darwin & cpu=x64 languageName: node linkType: hard -"turbo-darwin-arm64@npm:2.5.5": - version: 2.5.5 - resolution: "turbo-darwin-arm64@npm:2.5.5" +"turbo-darwin-arm64@npm:2.6.3": + version: 2.6.3 + resolution: "turbo-darwin-arm64@npm:2.6.3" conditions: os=darwin & cpu=arm64 languageName: node linkType: hard -"turbo-linux-64@npm:2.5.5": - version: 2.5.5 - resolution: "turbo-linux-64@npm:2.5.5" +"turbo-linux-64@npm:2.6.3": + version: 2.6.3 + resolution: "turbo-linux-64@npm:2.6.3" conditions: os=linux & cpu=x64 languageName: node linkType: hard -"turbo-linux-arm64@npm:2.5.5": - version: 2.5.5 - resolution: "turbo-linux-arm64@npm:2.5.5" +"turbo-linux-arm64@npm:2.6.3": + version: 2.6.3 + resolution: "turbo-linux-arm64@npm:2.6.3" conditions: os=linux & cpu=arm64 languageName: node linkType: hard -"turbo-windows-64@npm:2.5.5": - version: 2.5.5 - resolution: "turbo-windows-64@npm:2.5.5" +"turbo-windows-64@npm:2.6.3": + version: 2.6.3 + resolution: "turbo-windows-64@npm:2.6.3" conditions: os=win32 & cpu=x64 languageName: node linkType: hard -"turbo-windows-arm64@npm:2.5.5": - version: 2.5.5 - resolution: "turbo-windows-arm64@npm:2.5.5" +"turbo-windows-arm64@npm:2.6.3": + version: 2.6.3 + resolution: "turbo-windows-arm64@npm:2.6.3" conditions: os=win32 & cpu=arm64 languageName: node linkType: hard -"turbo@npm:^2.5.5": - version: 2.5.5 - resolution: "turbo@npm:2.5.5" - dependencies: - turbo-darwin-64: "npm:2.5.5" - turbo-darwin-arm64: "npm:2.5.5" - turbo-linux-64: "npm:2.5.5" - turbo-linux-arm64: "npm:2.5.5" - turbo-windows-64: "npm:2.5.5" - turbo-windows-arm64: "npm:2.5.5" +"turbo@npm:^2.6.3": + version: 2.6.3 + resolution: "turbo@npm:2.6.3" + dependencies: + turbo-darwin-64: "npm:2.6.3" + turbo-darwin-arm64: "npm:2.6.3" + turbo-linux-64: "npm:2.6.3" + turbo-linux-arm64: "npm:2.6.3" + turbo-windows-64: "npm:2.6.3" + turbo-windows-arm64: "npm:2.6.3" dependenciesMeta: turbo-darwin-64: optional: true @@ -16132,7 +16132,7 @@ __metadata: optional: true bin: turbo: bin/turbo - checksum: 10c0/f51ec295286b4126fee2a5020754126ccff8d062332599aeb2ad26edabd1847bc8c535f81cd4fa3aedcca9fd47e70c4effe3d38cbbac487ceed2db393e89fb0f + checksum: 10c0/3dab627a4e0f855c2ea2cc5e7d3d7abed01a7abace1197983c55e0563c413dfe45c80c121e5fa25d2cca013d895bde457d5cdf3a3d47000dc7d432a4cb68e78f languageName: node linkType: hard