feat: implement structured logging for server and client

Server:
- Add pino and pino-http for structured logging
- Create @Logged class decorator using Proxy pattern for automatic method logging
- Add pino redact config for sensitive data (password, token, etc.)
- Move AuthMiddleware to controllers folder (per architecture diagram)
- Add LoggingMiddleware for HTTP request logging
- Replace console.log/error with structured logger in controllers and app.ts
- Decorate all repositories and GPTAdapter with @Logged

Client:
- Add react-native-logs with namespaced loggers (apiLogger, storeLogger)
- Add request/response logging to ApiClient with duration tracking
This commit is contained in:
2026-01-10 16:59:40 +01:00
parent 675785ec93
commit 71f84d1cc7
24 changed files with 576 additions and 37 deletions

View File

@@ -34,6 +34,7 @@
"react-dom": "19.1.0",
"react-native": "0.81.5",
"react-native-gesture-handler": "~2.28.0",
"react-native-logs": "^5.5.0",
"react-native-reanimated": "~4.1.1",
"react-native-safe-area-context": "5.6.0",
"react-native-screens": "~4.16.0",

View File

@@ -0,0 +1 @@
export { log, apiLogger, storeLogger } from "./logger";

View File

@@ -0,0 +1,30 @@
import { logger, consoleTransport } from "react-native-logs";
const log = logger.createLogger({
levels: {
debug: 0,
info: 1,
warn: 2,
error: 3,
},
severity: __DEV__ ? "debug" : "warn",
transport: consoleTransport,
transportOptions: {
colors: {
debug: "white",
info: "blueBright",
warn: "yellowBright",
error: "redBright",
},
},
async: true,
dateFormat: "time",
printLevel: true,
printDate: true,
enabled: true,
});
export const apiLogger = log.extend("API");
export const storeLogger = log.extend("Store");
export { log };

View File

@@ -1,4 +1,5 @@
import { Platform } from "react-native";
import { apiLogger } from "../logging";
const API_BASE_URL =
process.env.EXPO_PUBLIC_API_URL ||
@@ -19,20 +20,33 @@ async function request<T>(
endpoint: string,
options?: RequestOptions,
): Promise<T> {
const response = await fetch(`${API_BASE_URL}${endpoint}`, {
method,
headers: {
"Content-Type": "application/json",
...options?.headers,
},
body: options?.body ? JSON.stringify(options.body) : undefined,
});
const start = performance.now();
apiLogger.debug(`${method} ${endpoint}`);
if (!response.ok) {
throw new Error(`HTTP ${response.status}`);
try {
const response = await fetch(`${API_BASE_URL}${endpoint}`, {
method,
headers: {
"Content-Type": "application/json",
...options?.headers,
},
body: options?.body ? JSON.stringify(options.body) : undefined,
});
const duration = Math.round(performance.now() - start);
if (!response.ok) {
apiLogger.error(`${method} ${endpoint} - ${response.status} (${duration}ms)`);
throw new Error(`HTTP ${response.status}`);
}
apiLogger.debug(`${method} ${endpoint} - ${response.status} (${duration}ms)`);
return response.json();
} catch (error) {
const duration = Math.round(performance.now() - start);
apiLogger.error(`${method} ${endpoint} failed (${duration}ms): ${error}`);
throw error;
}
return response.json();
}
export const ApiClient = {

View File

@@ -15,6 +15,8 @@
"jsonwebtoken": "^9.0.3",
"mongoose": "^9.1.1",
"openai": "^6.15.0",
"pino": "^10.1.1",
"pino-http": "^11.0.0",
"rrule": "^2.8.1"
},
"devDependencies": {
@@ -22,6 +24,7 @@
"@types/express": "^5.0.6",
"@types/jsonwebtoken": "^9.0.10",
"@types/node": "^24.10.1",
"pino-pretty": "^13.1.3",
"tsx": "^4.21.0",
"typescript": "^5.9.3"
}

View File

@@ -7,6 +7,7 @@ import {
executeToolCall,
ToolDefinition,
} from "./utils";
import { Logged } from "../logging";
/**
* Convert tool definitions to OpenAI format.
@@ -24,6 +25,7 @@ function toOpenAITools(
}));
}
@Logged("GPTAdapter")
export class GPTAdapter implements AIProvider {
private client: OpenAI;
private model: string;

View File

@@ -3,7 +3,12 @@ import mongoose from "mongoose";
import "dotenv/config";
import { createRoutes } from "./routes";
import { AuthController, ChatController, EventController } from "./controllers";
import {
AuthController,
ChatController,
EventController,
httpLogger,
} from "./controllers";
import { AuthService, ChatService, EventService } from "./services";
import {
MongoUserRepository,
@@ -11,6 +16,7 @@ import {
MongoChatRepository,
} from "./repositories";
import { GPTAdapter } from "./ai";
import { logger } from "./logging";
const app = express();
const port = process.env.PORT || 3000;
@@ -18,6 +24,7 @@ const mongoUri = process.env.MONGODB_URI || "mongodb://localhost:27017/caldav";
// Middleware
app.use(express.json());
app.use(httpLogger);
// CORS - only needed for web browser development
// Native mobile apps don't send Origin headers and aren't affected by CORS
@@ -86,7 +93,7 @@ app.post("/api/ai/test", async (req, res) => {
});
res.json(result);
} catch (error) {
console.error("AI test error:", error);
logger.error({ error }, "AI test error");
res.status(500).json({ error: String(error) });
}
});
@@ -95,13 +102,13 @@ app.post("/api/ai/test", async (req, res) => {
async function start() {
try {
await mongoose.connect(mongoUri);
console.log("Connected to MongoDB");
logger.info("Connected to MongoDB");
app.listen(port, () => {
console.log(`Server running on port ${port}`);
logger.info({ port }, "Server started");
});
} catch (error) {
console.error("Failed to start server:", error);
logger.fatal({ error }, "Failed to start server");
process.exit(1);
}
}

View File

@@ -7,7 +7,10 @@ import {
GetMessagesOptions,
} from "@caldav/shared";
import { ChatService } from "../services";
import { AuthenticatedRequest } from "../middleware";
import { createLogger } from "../logging";
import { AuthenticatedRequest } from "./AuthMiddleware";
const log = createLogger("ChatController");
export class ChatController {
constructor(private chatService: ChatService) {}
@@ -19,6 +22,7 @@ export class ChatController {
const response = await this.chatService.processMessage(userId, data);
res.json(response);
} catch (error) {
log.error({ error, userId: req.user?.userId }, "Error processing message");
res.status(500).json({ error: "Failed to process message" });
}
}
@@ -44,6 +48,7 @@ export class ChatController {
);
res.json(response);
} catch (error) {
log.error({ error, conversationId: req.params.conversationId }, "Error confirming event");
res.status(500).json({ error: "Failed to confirm event" });
}
}
@@ -59,6 +64,7 @@ export class ChatController {
);
res.json(response);
} catch (error) {
log.error({ error, conversationId: req.params.conversationId }, "Error rejecting event");
res.status(500).json({ error: "Failed to reject event" });
}
}
@@ -72,6 +78,7 @@ export class ChatController {
const conversations = await this.chatService.getConversations(userId);
res.json(conversations);
} catch (error) {
log.error({ error, userId: req.user?.userId }, "Error getting conversations");
res.status(500).json({ error: "Failed to get conversations" });
}
}
@@ -102,6 +109,7 @@ export class ChatController {
if ((error as Error).message === "Conversation not found") {
res.status(404).json({ error: "Conversation not found" });
} else {
log.error({ error, conversationId: req.params.id }, "Error getting conversation");
res.status(500).json({ error: "Failed to get conversation" });
}
}

View File

@@ -1,6 +1,9 @@
import { Response } from "express";
import { EventService } from "../services";
import { AuthenticatedRequest } from "../middleware";
import { createLogger } from "../logging";
import { AuthenticatedRequest } from "./AuthMiddleware";
const log = createLogger("EventController");
export class EventController {
constructor(private eventService: EventService) {}
@@ -10,7 +13,7 @@ export class EventController {
const event = await this.eventService.create(req.user!.userId, req.body);
res.status(201).json(event);
} catch (error) {
console.error("Error creating event:", error);
log.error({ error, userId: req.user?.userId }, "Error creating event");
res.status(500).json({ error: "Failed to create event" });
}
}
@@ -27,7 +30,7 @@ export class EventController {
}
res.json(event);
} catch (error) {
console.error("Error getting event:", error);
log.error({ error, eventId: req.params.id }, "Error getting event");
res.status(500).json({ error: "Failed to get event" });
}
}
@@ -37,7 +40,7 @@ export class EventController {
const events = await this.eventService.getAll(req.user!.userId);
res.json(events);
} catch (error) {
console.error("Error getting events:", error);
log.error({ error, userId: req.user?.userId }, "Error getting events");
res.status(500).json({ error: "Failed to get events" });
}
}
@@ -69,7 +72,7 @@ export class EventController {
);
res.json(events);
} catch (error) {
console.error("Error getting events by range:", error);
log.error({ error, start: req.query.start, end: req.query.end }, "Error getting events by range");
res.status(500).json({ error: "Failed to get events" });
}
}
@@ -87,7 +90,7 @@ export class EventController {
}
res.json(event);
} catch (error) {
console.error("Error updating event:", error);
log.error({ error, eventId: req.params.id }, "Error updating event");
res.status(500).json({ error: "Failed to update event" });
}
}
@@ -104,7 +107,7 @@ export class EventController {
}
res.status(204).send();
} catch (error) {
console.error("Error deleting event:", error);
log.error({ error, eventId: req.params.id }, "Error deleting event");
res.status(500).json({ error: "Failed to delete event" });
}
}

View File

@@ -0,0 +1,27 @@
import pinoHttp from "pino-http";
import { logger } from "../logging";
export const httpLogger = pinoHttp({
logger,
customLogLevel: (_req, res, err) => {
if (res.statusCode >= 500 || err) return "error";
if (res.statusCode >= 400) return "warn";
return "info";
},
customSuccessMessage: (req, res) => {
return `${req.method} ${req.url} ${res.statusCode}`;
},
customErrorMessage: (req, _res, err) => {
return `${req.method} ${req.url} failed: ${err.message}`;
},
redact: ["req.headers.authorization"],
serializers: {
req: (req) => ({
method: req.method,
url: req.url,
}),
res: (res) => ({
statusCode: res.statusCode,
}),
},
});

View File

@@ -1,3 +1,5 @@
export * from "./AuthController";
export * from "./ChatController";
export * from "./EventController";
export * from "./AuthMiddleware";
export * from "./LoggingMiddleware";

View File

@@ -0,0 +1,76 @@
import { createLogger } from "./logger";
export function Logged(name: string) {
const log = createLogger(name);
// eslint-disable-next-line @typescript-eslint/no-explicit-any
return function <T extends { new (...args: any[]): any }>(Constructor: T) {
return class extends Constructor {
// eslint-disable-next-line @typescript-eslint/no-explicit-any
constructor(...args: any[]) {
super(...args);
// Return a Proxy that intercepts method calls lazily
return new Proxy(this, {
get(target, propKey, receiver) {
const original = Reflect.get(target, propKey, receiver);
if (typeof original !== "function" || propKey === "constructor") {
return original;
}
// eslint-disable-next-line @typescript-eslint/no-explicit-any
const originalFn = original as (...args: any[]) => any;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
return function (this: any, ...methodArgs: any[]) {
const start = performance.now();
const method = String(propKey);
// Pino's redact handles sanitization - just pass args directly
log.debug({ method, args: methodArgs }, `${method} started`);
const logCompletion = (err?: unknown) => {
const duration = Math.round(performance.now() - start);
if (err) {
const message =
err instanceof Error ? err.message : String(err);
log.error(
{ method, duration, error: message },
`${method} failed`,
);
} else {
log.info({ method, duration }, `${method} completed`);
}
};
try {
const result = originalFn.apply(this, methodArgs);
// Check if async - preserves sync/async nature of method
if (result instanceof Promise) {
return result
.then((val) => {
logCompletion();
return val;
})
.catch((err) => {
logCompletion(err);
throw err;
});
}
// Synchronous completion
logCompletion();
return result;
} catch (err) {
logCompletion(err);
throw err;
}
};
},
});
}
};
};
}

View File

@@ -0,0 +1,2 @@
export { logger, createLogger, type Logger } from "./logger";
export { Logged } from "./Logged";

View File

@@ -0,0 +1,43 @@
import pino from "pino";
const isDevelopment = process.env.NODE_ENV !== "production";
export const logger = pino({
level: process.env.LOG_LEVEL || (isDevelopment ? "debug" : "info"),
redact: {
paths: [
// Root level
"password",
"passwordHash",
"token",
// One level deep (e.g. user.password)
"*.password",
"*.passwordHash",
"*.token",
// In arrays (for 'args' in decorator)
"args[*].password",
"args[*].passwordHash",
"args[*].token",
],
censor: "[REDACTED]",
},
transport: isDevelopment
? {
target: "pino-pretty",
options: {
colorize: true,
translateTime: "SYS:HH:MM:ss",
ignore: "pid,hostname",
},
}
: undefined,
base: {
service: "caldav-server",
},
});
export function createLogger(module: string) {
return logger.child({ module });
}
export type Logger = pino.Logger;

View File

@@ -1 +0,0 @@
export * from "./AuthMiddleware";

View File

@@ -6,8 +6,10 @@ import {
UpdateMessageDTO,
} from "@caldav/shared";
import { ChatRepository } from "../../services/interfaces";
import { Logged } from "../../logging";
import { ChatMessageModel, ConversationModel } from "./models";
@Logged("MongoChatRepository")
export class MongoChatRepository implements ChatRepository {
// Conversations
async getConversationsByUser(userId: string): Promise<Conversation[]> {

View File

@@ -1,7 +1,9 @@
import { CalendarEvent, CreateEventDTO, UpdateEventDTO } from "@caldav/shared";
import { EventRepository } from "../../services/interfaces";
import { Logged } from "../../logging";
import { EventModel } from "./models";
@Logged("MongoEventRepository")
export class MongoEventRepository implements EventRepository {
async findById(id: string): Promise<CalendarEvent | null> {
const event = await EventModel.findById(id);

View File

@@ -1,7 +1,9 @@
import { User } from "@caldav/shared";
import { UserRepository, CreateUserData } from "../../services/interfaces";
import { Logged } from "../../logging";
import { UserModel } from "./models";
@Logged("MongoUserRepository")
export class MongoUserRepository implements UserRepository {
async findById(id: string): Promise<User | null> {
throw new Error("Not implemented");

View File

@@ -1,6 +1,5 @@
import { Router } from "express";
import { ChatController } from "../controllers";
import { authenticate } from "../middleware";
import { ChatController, authenticate } from "../controllers";
export function createChatRoutes(chatController: ChatController): Router {
const router = Router();

View File

@@ -1,6 +1,5 @@
import { Router } from "express";
import { EventController } from "../controllers";
import { authenticate } from "../middleware";
import { EventController, authenticate } from "../controllers";
export function createEventRoutes(eventController: EventController): Router {
const router = Router();

View File

@@ -7,7 +7,8 @@
"strict": true,
"esModuleInterop": true,
"forceConsistentCasingInFileNames": true,
"skipLibCheck": true
"experimentalDecorators": true,
"emitDecoratorMetadata": true
},
"include": ["src"]
}