Skip to content

Commit 534bbe9

Browse files
batalabsbatalabs
committed
fix: standardize logging with structured data and add cache monitoring support
**Logging Improvements:** - Replace JSON.stringify with structured logging for Sentry aggregation - Change logger format from string output to object-based for field filtering - Enable grouping/filtering by method, path, statusCode, duration, userId, eventType **WebSocket Logging Standardization:** - Enhance websocketEvent() method with HTTP-like fields (duration, resourceId, resourceType, status) - Migrate all WebSocket operations to use logger.websocketEvent() - Add structured logging for connection, disconnection, message processing, and broadcasts - Include performance tracking (fast/medium/slow) for WebSocket messages - Track session duration on disconnection
1 parent 7806a76 commit 534bbe9

File tree

8 files changed

+283
-113
lines changed

8 files changed

+283
-113
lines changed

‎CHANGELOG.md‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,8 @@
11
## [1.11.1](https://github.com/typelets/typelets-api/compare/v1.11.0...v1.11.1) (2025-10-18)
22

3-
43
### Bug Fixes
54

6-
* reduce log noise and prevent sensitive data logging ([df00e25](https://github.com/typelets/typelets-api/commit/df00e2523f1f04016bc18536858cbd600632f003))
5+
- reduce log noise and prevent sensitive data logging ([df00e25](https://github.com/typelets/typelets-api/commit/df00e2523f1f04016bc18536858cbd600632f003))
76

87
# [1.11.0](https://github.com/typelets/typelets-api/compare/v1.10.0...v1.11.0) (2025-10-18)
98

‎src/lib/cache.ts‎

Lines changed: 99 additions & 48 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ import { Cluster, ClusterOptions } from "ioredis";
22
import { logger } from "./logger";
33
import { db, folders } from "../db";
44
import { eq } from "drizzle-orm";
5+
import * as Sentry from "@sentry/node";
56

67
let client: Cluster | null = null;
78

@@ -73,71 +74,121 @@ export async function getCache<T>(key: string): Promise<T | null> {
7374
const cache = getCacheClient();
7475
if (!cache) return null;
7576

76-
const startTime = Date.now();
77-
try {
78-
const data = await cache.get(key);
79-
const duration = Date.now() - startTime;
80-
const hit = data !== null;
77+
return await Sentry.startSpan(
78+
{
79+
op: "cache.get",
80+
name: "cache.get",
81+
attributes: {
82+
"cache.key": key,
83+
},
84+
},
85+
async (span) => {
86+
const startTime = Date.now();
87+
try {
88+
const data = await cache.get(key);
89+
const duration = Date.now() - startTime;
90+
const hit = data !== null;
91+
92+
// Set Sentry span attributes
93+
span.setAttribute("cache.hit", hit);
94+
if (data) {
95+
span.setAttribute("cache.item_size", data.length);
96+
}
8197

82-
// Log cache operation with metrics
83-
logger.cacheOperation("get", key, hit, duration);
98+
// Log cache operation with metrics
99+
logger.cacheOperation("get", key, hit, duration);
84100

85-
return data ? JSON.parse(data) : null;
86-
} catch (error) {
87-
logger.cacheError("get", key, error instanceof Error ? error : new Error(String(error)));
88-
return null;
89-
}
101+
return data ? JSON.parse(data) : null;
102+
} catch (error) {
103+
span.setStatus({ code: 2, message: "error" }); // SPAN_STATUS_ERROR
104+
logger.cacheError("get", key, error instanceof Error ? error : new Error(String(error)));
105+
return null;
106+
}
107+
}
108+
);
90109
}
91110

92111
export async function setCache(key: string, value: unknown, ttlSeconds?: number): Promise<void> {
93112
const cache = getCacheClient();
94113
if (!cache) return;
95114

96-
const startTime = Date.now();
97-
try {
98-
const serialized = JSON.stringify(value);
99-
if (ttlSeconds) {
100-
await cache.setex(key, ttlSeconds, serialized);
101-
} else {
102-
await cache.set(key, serialized);
103-
}
104-
const duration = Date.now() - startTime;
115+
await Sentry.startSpan(
116+
{
117+
op: "cache.put",
118+
name: "cache.put",
119+
attributes: {
120+
"cache.key": key,
121+
},
122+
},
123+
async (span) => {
124+
const startTime = Date.now();
125+
try {
126+
const serialized = JSON.stringify(value);
127+
128+
// Set Sentry span attributes
129+
span.setAttribute("cache.item_size", serialized.length);
130+
if (ttlSeconds) {
131+
span.setAttribute("cache.ttl", ttlSeconds);
132+
}
105133

106-
// Log cache operation with metrics
107-
logger.cacheOperation("set", key, undefined, duration, ttlSeconds);
108-
} catch (error) {
109-
logger.cacheError("set", key, error instanceof Error ? error : new Error(String(error)));
110-
}
134+
if (ttlSeconds) {
135+
await cache.setex(key, ttlSeconds, serialized);
136+
} else {
137+
await cache.set(key, serialized);
138+
}
139+
const duration = Date.now() - startTime;
140+
141+
// Log cache operation with metrics
142+
logger.cacheOperation("set", key, undefined, duration, ttlSeconds);
143+
} catch (error) {
144+
span.setStatus({ code: 2, message: "error" }); // SPAN_STATUS_ERROR
145+
logger.cacheError("set", key, error instanceof Error ? error : new Error(String(error)));
146+
}
147+
}
148+
);
111149
}
112150

113151
export async function deleteCache(...keys: string[]): Promise<void> {
114152
const cache = getCacheClient();
115153
if (!cache || keys.length === 0) return;
116154

117-
const startTime = Date.now();
118-
try {
119-
// In cluster mode, keys may hash to different slots
120-
// Use pipeline to delete individually (more efficient than separate awaits)
121-
if (keys.length === 1) {
122-
await cache.del(keys[0]);
123-
} else {
124-
const pipeline = cache.pipeline();
125-
for (const key of keys) {
126-
pipeline.del(key);
155+
await Sentry.startSpan(
156+
{
157+
op: "cache.remove",
158+
name: "cache.remove",
159+
attributes: {
160+
"cache.key": keys[0], // Use first key as representative
161+
"cache.key_count": keys.length,
162+
},
163+
},
164+
async (span) => {
165+
const startTime = Date.now();
166+
try {
167+
// In cluster mode, keys may hash to different slots
168+
// Use pipeline to delete individually (more efficient than separate awaits)
169+
if (keys.length === 1) {
170+
await cache.del(keys[0]);
171+
} else {
172+
const pipeline = cache.pipeline();
173+
for (const key of keys) {
174+
pipeline.del(key);
175+
}
176+
await pipeline.exec();
177+
}
178+
const duration = Date.now() - startTime;
179+
180+
// Log cache operation with metrics (use first key as representative)
181+
logger.cacheOperation("delete", keys[0], undefined, duration, undefined, keys.length);
182+
} catch (error) {
183+
span.setStatus({ code: 2, message: "error" }); // SPAN_STATUS_ERROR
184+
logger.cacheError(
185+
"delete",
186+
keys.join(", "),
187+
error instanceof Error ? error : new Error(String(error))
188+
);
127189
}
128-
await pipeline.exec();
129190
}
130-
const duration = Date.now() - startTime;
131-
132-
// Log cache operation with metrics (use first key as representative)
133-
logger.cacheOperation("delete", keys[0], undefined, duration, undefined, keys.length);
134-
} catch (error) {
135-
logger.cacheError(
136-
"delete",
137-
keys.join(", "),
138-
error instanceof Error ? error : new Error(String(error))
139-
);
140-
}
191+
);
141192
}
142193

143194
export async function deleteCachePattern(pattern: string): Promise<void> {

‎src/lib/logger.ts‎

Lines changed: 27 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -33,8 +33,12 @@ class Logger {
3333
return level.priority <= this.currentLogLevel.priority;
3434
}
3535

36-
private formatLog(level: string, message: string, meta: LogMetadata = {}): string {
37-
const logEntry = {
36+
private formatLog(
37+
level: string,
38+
message: string,
39+
meta: LogMetadata = {}
40+
): Record<string, unknown> {
41+
return {
3842
timestamp: new Date().toISOString(),
3943
level,
4044
service: this.service,
@@ -43,31 +47,34 @@ class Logger {
4347
message,
4448
...meta,
4549
};
46-
47-
return JSON.stringify(logEntry);
4850
}
4951

5052
error(message: string, meta: LogMetadata = {}, error?: Error): void {
5153
if (this.shouldLog(LOG_LEVELS.error)) {
52-
console.error(this.formatLog("error", message, meta));
54+
const logData = this.formatLog("error", message, meta);
55+
if (error) {
56+
logData.errorMessage = error.message;
57+
logData.errorStack = error.stack;
58+
}
59+
console.error(message, logData);
5360
}
5461
}
5562

5663
warn(message: string, meta: LogMetadata = {}): void {
5764
if (this.shouldLog(LOG_LEVELS.warn)) {
58-
console.warn(this.formatLog("warn", message, meta));
65+
console.warn(message, this.formatLog("warn", message, meta));
5966
}
6067
}
6168

6269
info(message: string, meta: LogMetadata = {}): void {
6370
if (this.shouldLog(LOG_LEVELS.info)) {
64-
console.log(this.formatLog("info", message, meta));
71+
console.log(message, this.formatLog("info", message, meta));
6572
}
6673
}
6774

6875
debug(message: string, meta: LogMetadata = {}): void {
6976
if (this.shouldLog(LOG_LEVELS.debug)) {
70-
console.log(this.formatLog("debug", message, meta));
77+
console.log(message, this.formatLog("debug", message, meta));
7178
}
7279
}
7380

@@ -89,16 +96,24 @@ class Logger {
8996
});
9097
}
9198

92-
websocketEvent(eventType: string, userId?: string, connectionCount?: number): void {
99+
websocketEvent(
100+
eventType: string,
101+
userId?: string,
102+
duration?: number,
103+
resourceId?: string,
104+
resourceType?: string,
105+
status?: string
106+
): void {
93107
const meta: LogMetadata = {
94108
type: "websocket_event",
95109
eventType,
96110
userId: userId || "anonymous",
97111
};
98112

99-
if (connectionCount !== undefined) {
100-
meta.connectionCount = connectionCount;
101-
}
113+
if (duration !== undefined) meta.duration = duration;
114+
if (resourceId) meta.resourceId = resourceId;
115+
if (resourceType) meta.resourceType = resourceType;
116+
if (status) meta.status = status;
102117

103118
this.info("WebSocket event", meta);
104119
}

‎src/version.ts‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,2 +1,2 @@
11
// This file is automatically updated by semantic-release
2-
export const VERSION = "1.11.1"
2+
export const VERSION = "1.11.1";

‎src/websocket/auth/handler.ts‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -124,7 +124,8 @@ export class AuthHandler {
124124
console.log(`User ${ws.userId} authenticated via WebSocket`);
125125
}
126126
} catch (error: unknown) {
127-
console.error("WebSocket authentication failed:", error);
127+
const errorMessage = error instanceof Error ? error.message : String(error);
128+
console.error("WebSocket authentication failed", { error: errorMessage });
128129

129130
const isTokenExpired = (error as Record<string, unknown>)?.reason === "token-expired";
130131

@@ -218,7 +219,8 @@ export class AuthHandler {
218219

219220
return isValid;
220221
} catch (error) {
221-
console.error("Error verifying message signature:", error);
222+
const errorMessage = error instanceof Error ? error.message : String(error);
223+
console.error("Error verifying message signature", { error: errorMessage });
222224
return false;
223225
}
224226
}

‎src/websocket/handlers/base.ts‎

Lines changed: 20 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,9 @@ import { db, notes, folders } from "../../db";
22
import { eq, and } from "drizzle-orm";
33
import { AuthenticatedWebSocket, WebSocketMessage, ResourceOperationConfig } from "../types";
44
import { ConnectionManager } from "../middleware/connection-manager";
5+
import { logger } from "../../lib/logger";
6+
7+
const isDevelopment = process.env.NODE_ENV === "development";
58

69
export class BaseResourceHandler {
710
constructor(protected readonly _connectionManager: ConnectionManager) {}
@@ -64,7 +67,12 @@ export class BaseResourceHandler {
6467
return;
6568
}
6669
} catch (error) {
67-
console.error(`Error authorizing ${config.resourceType} ${config.operation}:`, error);
70+
const errorMessage = error instanceof Error ? error.message : String(error);
71+
console.error(`Error authorizing ${config.resourceType} ${config.operation}`, {
72+
resourceType: config.resourceType,
73+
operation: config.operation,
74+
error: errorMessage,
75+
});
6876
ws.send(
6977
JSON.stringify({
7078
type: "error",
@@ -89,8 +97,6 @@ export class BaseResourceHandler {
8997
}
9098
}
9199

92-
console.log(`User ${ws.userId} ${config.logAction}`);
93-
94100
// Build sync message
95101
const syncMessage: Record<string, unknown> = {
96102
type: config.syncMessageType,
@@ -117,6 +123,16 @@ export class BaseResourceHandler {
117123

118124
// Broadcast to user devices
119125
const sentCount = this._connectionManager.broadcastToUserDevices(ws.userId, syncMessage, ws);
120-
console.log(`Broadcasted message to ${sentCount} devices for user ${ws.userId}`);
126+
127+
if (isDevelopment) {
128+
logger.websocketEvent(
129+
`${config.resourceType}_${config.operation}`,
130+
ws.userId,
131+
undefined,
132+
resourceId,
133+
config.resourceType,
134+
`${sentCount}_devices`
135+
);
136+
}
121137
}
122138
}

0 commit comments

Comments
 (0)