feat: adds client/server side logging (#716)

* chore: adds basic logger

Signed-off-by: Anthony D. Mays <[email protected]>

* chore: configures batching for client logger

* wip: attempts to add a prisma transport for logger

* chore: updates logs table to use jsonb

* chore: adds event beaconing for features

* chore: adds environment to logger config

* chore: removes file logger from default config

---------

Signed-off-by: Anthony D. Mays <[email protected]>

Author: anthonydmays

lib/javascript/fullstack_demo/package-lock.json

@@ -19,7 +19,9 @@
     "@upstash/redis": "^1.34.3",
     "lowdb": "^7.0.1",
     "lucide-react": "^0.468.0",
-    "next": "^14.2.22"
+    "next": "^14.2.22",
+    "uuid": "^11.0.5",
+    "winston": "^3.17.0"
   },
   "devDependencies": {
     "@testing-library/dom": "^10.4.0",
@@ -46,4 +48,4 @@
     "vitest": "^2.1.8",
     "vitest-fetch-mock": "^0.4.3"
   }
-}
+}

lib/javascript/fullstack_demo/package.json

@@ -18,3 +18,12 @@ model Todos {
   created_at DateTime @default(now()) @db.Timestamptz(6)
   updated_at DateTime @default(now()) @db.Timestamp(6)
 }
+
+/// This model contains row level security and requires additional setup for migrations. Visit https://pris.ly/d/row-level-security for more info.
+model Logs {
+  id        String   @id @default(dbgenerated("gen_random_uuid()")) @db.Uuid
+  level     String   @db.VarChar
+  message   String   @default("") @db.VarChar
+  timestamp DateTime @db.Timestamp(6)
+  meta      Json?
+}

lib/javascript/fullstack_demo/prisma/schema.prisma

@@ -0,0 +1,10 @@
+import { logger } from '@/util/server-logger';
+
+export async function POST(request: Request) {
+  const batch = await request.json();
+  for (const log of batch) {
+    const { level, message, vars } = log;
+    logger.log(level, message, { ...(vars || {}) });
+  }
+  return new Response(null, { status: 204 });
+}

lib/javascript/fullstack_demo/src/app/api/log/route.ts

@@ -1,4 +1,5 @@
-import { Todo } from '@/models';
+import { LogEvent, Todo } from '@/models';
+import { logger } from '@/util/client-logger';
 import { PlusIcon } from 'lucide-react';
 import { useState } from 'react';
 
@@ -14,6 +15,7 @@ export const AddTodo: React.FC<AddTodoProps> = ({ onAdd }) => {
     if (newTodo.trim() !== '') {
       const todo: Todo = { id: Date.now(), text: newTodo, completed: false };
       await fetch('/api/todos', { method: 'POST', body: JSON.stringify(todo) });
+      logger.event(LogEvent.TODO_ADD, { id: todo.id });
       setNewTodo('');
       if (onAdd) {
         onAdd(todo);

lib/javascript/fullstack_demo/src/components/add-todo/add-todo.tsx

@@ -1,4 +1,5 @@
-import { Todo } from '@/models';
+import { LogEvent, Todo } from '@/models';
+import { logger } from '@/util/client-logger';
 import { TodoComponent } from './todo';
 
 export type TodoProps = {
@@ -8,22 +9,26 @@ export type TodoProps = {
 
 export const TodoList: React.FC<TodoProps> = ({ todos, onChange }) => {
   const toggleTodo = async (id: number) => {
+    logger.event(LogEvent.TODO_TOGGLE, { id });
     const todo = todos.find((todo) => todo.id === id);
     if (!todo) return;
     todo.completed = !todo.completed;
     await fetch(`/api/todos/${id}`, {
       method: 'PATCH',
       body: JSON.stringify(todo),
     });
+    logger.event(LogEvent.TODO_TOGGLE, { id });
     if (onChange) {
       onChange(todo.id);
     }
   };
 
   const deleteTodo = async (id: number) => {
+    logger.event(LogEvent.TODO_DELETE, { id });
     await fetch(`/api/todos/${id}`, {
       method: 'DELETE',
     });
+    logger.event(LogEvent.TODO_DELETE, { id });
     if (onChange) {
       onChange(id);
     }

lib/javascript/fullstack_demo/src/components/todo-list/todo-list.tsx

@@ -1,9 +1,19 @@
 import { clerkMiddleware, createRouteMatcher } from '@clerk/nextjs/server';
+import { NextResponse } from 'next/server';
+import { v4 as uuidv4 } from 'uuid';
 
+const CORRELATION_ID_HEADER = 'x-correlation-id';
 const isProtectedRoute = createRouteMatcher(['/(.*)']);
 
 export default clerkMiddleware(async (auth, req) => {
+  const correlationId = uuidv4();
+  req.headers.set(CORRELATION_ID_HEADER, correlationId);
+
   if (isProtectedRoute(req)) await auth.protect();
+
+  const response = NextResponse.next();
+  response.headers.set(CORRELATION_ID_HEADER, correlationId);
+  return response;
 });
 
 export const config = {

lib/javascript/fullstack_demo/src/middleware.ts

@@ -1,5 +1,21 @@
+import { LogLevel } from './util/logger';
+
 export interface Todo {
   id: number;
   text: string;
   completed: boolean;
 }
+
+export interface Log {
+  level: LogLevel;
+  message: string;
+  vars: {};
+}
+
+export enum LogEvent {
+  LOG_IN = 'log_in',
+  LOG_OUT = 'log_out',
+  TODO_TOGGLE = 'todo_toggle',
+  TODO_DELETE = 'todo_delete',
+  TODO_ADD = 'todo_add',
+}

lib/javascript/fullstack_demo/src/models.ts

@@ -0,0 +1,92 @@
+import { Log, LogEvent } from '@/models';
+import { Logger, LogLevel } from './logger';
+
+const FLUSH_AFTER_SIZE = 15;
+const MAX_BATCH_SIZE = 100;
+const FLUSH_INTERVAL_MS = 1000 * 5; // 5 seconds
+
+class ClientLogger implements Logger {
+  private readonly buffer: Log[] = [];
+  private flushing = false;
+
+  constructor() {
+    setInterval(() => this.flush(), FLUSH_INTERVAL_MS);
+  }
+
+  log(level: LogLevel, message: string, vars = {}): void {
+    vars = { ...this.getDefaultVars(), ...(vars || {}) };
+    this.buffer.push({ level, message, vars });
+    if (this.buffer.length >= FLUSH_AFTER_SIZE && !this.flushing) {
+      this.flush();
+    }
+  }
+
+  private getDefaultVars() {
+    if (typeof window === 'undefined') {
+      return [];
+    }
+
+    return {
+      client: {
+        type: 'web',
+        userAgent: navigator.userAgent,
+        location: window.location.href,
+      },
+    };
+  }
+
+  async flush(): Promise<void> {
+    if (this.buffer.length === 0 || this.flushing) {
+      return;
+    }
+
+    this.flushing = true;
+
+    const batch = this.buffer.splice(0, MAX_BATCH_SIZE);
+    let backoffInMs = FLUSH_INTERVAL_MS;
+
+    do {
+      try {
+        await this.sendLogs(batch);
+        this.flushing = false;
+      } catch (e) {
+        console.error('Failed to send logs', e);
+        backoffInMs *= 2;
+        await this.delay(backoffInMs);
+      }
+    } while (this.flushing);
+  }
+
+  async sendLogs(batch: Log[]): Promise<void> {
+    let endpoint = '/api/log';
+    if (typeof window === 'undefined') {
+      endpoint = `${process.env?.NEXT_PUBLIC_API_URL || ''}/api/host`;
+    }
+    await fetch(endpoint, {
+      method: 'POST',
+      headers: {
+        'Content-Type': 'application/json',
+      },
+      body: JSON.stringify(batch),
+    });
+  }
+
+  async delay(ms: number): Promise<void> {
+    return new Promise((resolve) => setTimeout(resolve, ms));
+  }
+
+  debug(format: string, vars = {}): void {
+    this.log('debug', format, vars);
+  }
+  info(format: string, vars = {}): void {
+    this.log('info', format, vars);
+  }
+  error(format: string, vars = {}): void {
+    this.log('error', format, vars);
+  }
+  event(eventId: LogEvent, vars = {}): void {
+    this.log('info', '', { ...vars, eventId });
+  }
+}
+
+export const logger = new ClientLogger();

lib/javascript/fullstack_demo/src/util/client-logger.ts

@@ -0,0 +1,11 @@
+import { LogEvent } from '@/models';
+
+export interface Logger {
+  log(level: LogLevel, message: string, vars?: {}): void;
+  debug(format: string, vars?: {}): void;
+  info(format: string, vars?: {}): void;
+  error(format: string, vars?: {}): void;
+  event(id: LogEvent, vars?: {}): void;
+}
+
+export type LogLevel = 'debug' | 'info' | 'error' | 'warn';