Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor(be): request logging #63

Merged
merged 5 commits into from
Dec 7, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
-- CreateTable
CREATE TABLE "RequestLog" (
"id" BIGSERIAL NOT NULL,
"method" TEXT NOT NULL,
"path" TEXT NOT NULL,
"status" INTEGER NOT NULL,
"duration" INTEGER NOT NULL,
"response" TEXT,
"userAgent" TEXT,
"createdAt" TIMESTAMP(3) NOT NULL DEFAULT CURRENT_TIMESTAMP,

CONSTRAINT "RequestLog_pkey" PRIMARY KEY ("id")
);
12 changes: 12 additions & 0 deletions apps/backend/prisma/schema.prisma
Original file line number Diff line number Diff line change
Expand Up @@ -109,6 +109,18 @@ model Log {
createdAt DateTime @default(now())
}

model RequestLog {
id BigInt @id @default(autoincrement())
method String
path String
status Int
duration Int
response String?
userAgent String?

createdAt DateTime @default(now())
}
Comment on lines +112 to +122
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🛠️ Refactor suggestion

Add index and field constraints to RequestLog model

Consider the following improvements to optimize queries and ensure data integrity:

 model RequestLog {
   id        BigInt  @id @default(autoincrement())
-  method    String
+  method    String  @db.VarChar(10)
   path      String
-  status    Int
+  status    Int     @db.SmallInt
   duration  Int
   response  String?
   userAgent String?

   createdAt DateTime @default(now())
+
+  @@index([createdAt(sort: Desc)])
 }

The changes:

  1. Add index on createdAt for faster cleanup queries
  2. Limit method length as HTTP methods are short
  3. Use SmallInt for status codes as they're small numbers
📝 Committable suggestion

‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.

Suggested change
model RequestLog {
id BigInt @id @default(autoincrement())
method String
path String
status Int
duration Int
response String?
userAgent String?
createdAt DateTime @default(now())
}
model RequestLog {
id BigInt @id @default(autoincrement())
method String @db.VarChar(10)
path String
status Int @db.SmallInt
duration Int
response String?
userAgent String?
createdAt DateTime @default(now())
@@index([createdAt(sort: Desc)])
}


enum LogLevel {
log
error
Expand Down
11 changes: 9 additions & 2 deletions apps/backend/src/app.module.ts
Original file line number Diff line number Diff line change
@@ -1,17 +1,19 @@
import { ApolloDriver, type ApolloDriverConfig } from "@nestjs/apollo";
import { CacheModule } from "@nestjs/cache-manager";
import { Module } from "@nestjs/common";
import { MiddlewareConsumer, Module, NestModule } from "@nestjs/common";
import { ConfigModule } from "@nestjs/config";
import { GraphQLModule } from "@nestjs/graphql";
import { ScheduleModule } from "@nestjs/schedule";

import { cacheModuleConfig } from "src/config/cache-module.config";
import { configModuleConfig } from "src/config/config-module.config";
import { GRAPHQL_PATH } from "src/constants/api";
import { RequestLoggerMiddleware } from "src/middleware/request-logger-middleware";
import { DepartureModule } from "src/modules/departure/departure.module";
import { GtfsModule } from "src/modules/gtfs/gtfs.module";
import { ImportModule } from "src/modules/import/import.module";
import { LoggerModule } from "src/modules/logger/logger.module";
import { LogsCleanupModule } from "src/modules/logs-cleanup/logs-cleanup.module";
import { PlatformModule } from "src/modules/platform/platform.module";
import { PrismaModule } from "src/modules/prisma/prisma.module";
import { RouteModule } from "src/modules/route/route.module";
Expand All @@ -26,6 +28,7 @@ import { StopModule } from "src/modules/stop/stop.module";
StopModule,
PrismaModule,
LoggerModule,
LogsCleanupModule,
StatusModule,
GtfsModule,
RouteModule,
Expand All @@ -42,4 +45,8 @@ import { StopModule } from "src/modules/stop/stop.module";
controllers: [],
providers: [],
})
export class AppModule {}
export class AppModule implements NestModule {
configure(consumer: MiddlewareConsumer) {
consumer.apply(RequestLoggerMiddleware).forRoutes("*");
}
}
1 change: 1 addition & 0 deletions apps/backend/src/enums/log.enum.ts
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ export enum LogMessage {
IMPORT_STOPS = "Import stops",
REST = "REST",
GRAPHQL = "GraphQL",
REQUEST_LOGS_CLEANUP = "Request logs cleanup",
}

export enum RestLogStatus {
Expand Down
63 changes: 63 additions & 0 deletions apps/backend/src/middleware/request-logger-middleware.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,63 @@
import { Injectable, NestMiddleware } from "@nestjs/common";
import { NextFunction, Request, Response } from "express";

import { PrismaService } from "src/modules/prisma/prisma.service";

@Injectable()
export class RequestLoggerMiddleware implements NestMiddleware {
constructor(private readonly prisma: PrismaService) {}

async use(req: Request, res: Response, next: NextFunction) {
const start = Date.now();

// Intercept the response to capture the body
const originalSend = res.send;
let responseBody: unknown;

res.send = (body): Response => {
responseBody = body; // Capture the response body
return originalSend.call(res, body); // Call the original `send` method
};

// Attach an event listener to log after the response is sent
res.on("finish", async () => {
const duration = Date.now() - start;
const {
method,
url: path,
headers: { "user-agent": userAgent = null },
} = req;
const { statusCode } = res;
const responseString =
typeof responseBody === "string"
? responseBody
: JSON.stringify(responseBody);

const ignoreResponse = ["/v1/stop/all", "/v1/platform/"].some(
(item) => path.startsWith(item),
);

if (path.startsWith("/status")) {
return;
}

try {
// Log the request details to the database
await this.prisma.requestLog.create({
data: {
method,
path,
status: statusCode,
duration,
userAgent,
response: ignoreResponse ? null : responseString,
},
});
} catch (error) {
console.error("Failed to log request:", error);
}
});
Comment on lines +23 to +59
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue

Potential PII leakage from logging full response bodies

Storing the complete response body in the database may inadvertently capture sensitive or personally identifiable information (PII), leading to security and compliance risks. It's important to ensure that sensitive data is not logged.

Recommendations:

  • Sanitize or redact sensitive information from the response before logging.
  • Limit logging to metadata or summaries rather than full response bodies.
  • Implement conditional logging to only log responses from non-sensitive endpoints.


next();
}
}
3 changes: 1 addition & 2 deletions apps/backend/src/modules/departure/departure.controller.ts
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,6 @@ import {
departureSchema,
type DepartureSchema,
} from "src/modules/departure/schema/departure.schema";
import { LogInterceptor } from "src/modules/logger/log.interceptor";
import {
metroOnlySchema,
vehicleTypeSchema,
Expand All @@ -28,7 +27,7 @@ import { metroOnlyQuery } from "src/swagger/query.swagger";

@ApiTags("departure")
@Controller("departure")
@UseInterceptors(CacheInterceptor, LogInterceptor)
@UseInterceptors(CacheInterceptor)
@CacheTTL(4 * 1000)
Comment on lines +30 to 31
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codebase verification

Logging implementation for departure endpoints needs enhancement

The RequestLoggerMiddleware implementation has some limitations that should be addressed for departure endpoints:

  1. Query parameters are not being logged, which is crucial for debugging complex departure queries
  2. No response size limits or truncation logic is implemented, risking large payloads
  3. No specific handling for cached responses is present

Required changes:

  • Add req.query to the logged data for better debugging
  • Implement response size limits to prevent storage issues
  • Add cache hit/miss indicators in the logs
🔗 Analysis chain

Verify logging coverage for departure endpoints with complex queries

The removal of LogInterceptor is consistent with the logging refactor. However, these departure endpoints handle complex query parameters and potentially large response payloads. We should ensure that the new RequestLoggerMiddleware:

  1. Properly captures all query parameters for debugging
  2. Handles large response payloads efficiently
  3. Respects the cache TTL when logging cached responses
🏁 Scripts executed

The following scripts were executed for the analysis:

Script:

#!/bin/bash
# Description: Verify logging configuration for departure endpoints

# Check if the middleware implements response size limits
rg -A 5 "class RequestLoggerMiddleware" | rg "response.*body|maxSize|truncate"

# Check if query parameter logging is implemented
ast-grep --pattern 'class RequestLoggerMiddleware {
  $$$
  log($$$) {
    $$$
    query: $$$
    $$$
  }
}'

# Check for cache-aware logging configuration
rg "CacheInterceptor.*RequestLoggerMiddleware|RequestLoggerMiddleware.*CacheInterceptor" -A 5

Length of output: 287


Script:

#!/bin/bash
# Let's try a different approach to find the middleware implementation

# Find the middleware file first
fd "request.*logger.*middleware" --type f

# Search for logging-related patterns in the codebase
rg -g "!{test,spec}*" "implements.*NestMiddleware|extends.*NestMiddleware" -A 5

# Look for request/response logging patterns
rg -g "!{test,spec}*" "class.*Logger|class.*Log" -A 10

# Check for query parameter handling in the codebase
rg -g "!{test,spec}*" "req\.query|request\.query" -A 3

Length of output: 5062


Script:

#!/bin/bash
# Let's examine the request logger middleware implementation in detail

# Check the complete implementation of request logger middleware
cat apps/backend/src/middleware/request-logger-middleware.ts

# Look for request log schema to understand what's being logged
fd "prisma.schema" --type f --exec cat {}

# Check for any configuration related to response size limits
fd "config|constants" --type f | rg -i "log|size|limit" --files-with-matches | xargs cat

Length of output: 2297

export class DepartureController {
constructor(
Expand Down
29 changes: 0 additions & 29 deletions apps/backend/src/modules/logger/log.interceptor.ts

This file was deleted.

18 changes: 18 additions & 0 deletions apps/backend/src/modules/logs-cleanup/logs-cleanup.controller.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
import { Controller, OnModuleInit } from "@nestjs/common";
import { Cron, CronExpression } from "@nestjs/schedule";

import { LogsCleanupService } from "src/modules/logs-cleanup/logs-cleanup.service";

@Controller("logs-cleanup")
export class LogsCleanupController implements OnModuleInit {
constructor(private readonly logsCleanupService: LogsCleanupService) {}

async onModuleInit(): Promise<void> {
return this.logsCleanupService.cleanupLogs();
}

@Cron(CronExpression.EVERY_10_MINUTES)
async cronLogsCleanup(): Promise<void> {
return this.logsCleanupService.cleanupLogs();
}
}
11 changes: 11 additions & 0 deletions apps/backend/src/modules/logs-cleanup/logs-cleanup.module.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,11 @@
import { Module } from "@nestjs/common";

import { LogsCleanupController } from "src/modules/logs-cleanup/logs-cleanup.controller";
import { LogsCleanupService } from "src/modules/logs-cleanup/logs-cleanup.service";

@Module({
controllers: [LogsCleanupController],
providers: [LogsCleanupService],
imports: [],
})
export class LogsCleanupModule {}
60 changes: 60 additions & 0 deletions apps/backend/src/modules/logs-cleanup/logs-cleanup.service.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
import { Injectable } from "@nestjs/common";

import { LogLevel, LogMessage } from "src/enums/log.enum";
import { LoggerService } from "src/modules/logger/logger.service";
import { PrismaService } from "src/modules/prisma/prisma.service";

const MAX_COUNT = 500_000;

@Injectable()
export class LogsCleanupService {
constructor(
private readonly prisma: PrismaService,
private readonly logger: LoggerService,
) {}

async cleanupLogs(): Promise<void> {
try {
const recordCount = await this.prisma.requestLog.count();

if (recordCount < MAX_COUNT) {
return;
}

const last = await this.prisma.requestLog.findFirst({
orderBy: { createdAt: "desc" },
skip: MAX_COUNT,
});

if (!last) {
return;
}

const { count } = await this.prisma.requestLog.deleteMany({
where: {
createdAt: {
lte: last.createdAt,
},
},
});

await this.logger.createLog(
LogLevel.log,
LogMessage.REQUEST_LOGS_CLEANUP,
{
message: "Successfully removed old logs",
count,
},
);
} catch (error) {
await this.logger.createLog(
LogLevel.error,
LogMessage.REQUEST_LOGS_CLEANUP,
{
message: "Failed to cleanup logs",
error: JSON.stringify(error),
},
);
}
}
}
3 changes: 1 addition & 2 deletions apps/backend/src/modules/platform/platform.controller.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,6 @@ import { z } from "zod";

import { ApiDescription, ApiQueries } from "src/decorators/swagger.decorator";
import { EndpointVersion } from "src/enums/endpoint-version";
import { LogInterceptor } from "src/modules/logger/log.interceptor";
import { PlatformService } from "src/modules/platform/platform.service";
import {
platformWithDistanceSchema,
Expand All @@ -34,7 +33,7 @@ import {

@ApiTags("platform")
@Controller("platform")
@UseInterceptors(CacheInterceptor, LogInterceptor)
@UseInterceptors(CacheInterceptor)
export class PlatformController {
constructor(private readonly platformService: PlatformService) {}

Expand Down
3 changes: 1 addition & 2 deletions apps/backend/src/modules/stop/stop.controller.ts
Original file line number Diff line number Diff line change
Expand Up @@ -12,13 +12,12 @@ import {
import { ApiParam, ApiQuery, ApiTags } from "@nestjs/swagger";

import { EndpointVersion } from "src/enums/endpoint-version";
import { LogInterceptor } from "src/modules/logger/log.interceptor";
import { StopService } from "src/modules/stop/stop.service";
import { metroOnlyQuery } from "src/swagger/query.swagger";

@ApiTags("stop")
@Controller("stop")
@UseInterceptors(CacheInterceptor, LogInterceptor)
@UseInterceptors(CacheInterceptor)
export class StopController {
constructor(private readonly stopService: StopService) {}

Expand Down
2 changes: 1 addition & 1 deletion apps/web/src/components/Footer/Footer.tsx
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,7 @@ export const Footer = () => {
className="dark:p-2 dark:rounded-xl dark:bg-white transition-all ease-in-out dark:border dark:border-neutral-900 rounded dark:shadow-lg"
bgColor="transparent"
fgColor="black"
level="L"
level="Q"
imageSettings={{
src: "/appstore-icon.svg",
x: undefined,
Expand Down
2 changes: 1 addition & 1 deletion apps/web/src/components/Navbar/NavbarDownloadLink.tsx
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ export const NavbarDownloadLink = () => {
value={APPSTORE_URL}
fgColor="#000000"
bgColor="transparent"
level="L"
level="Q"
imageSettings={{
src: "/appstore-icon.svg",
x: undefined,
Expand Down
Loading