🔊(y-provider) improve and add logs

We have somes entries with "No cookies", we
add more logs to understand why we have this case.
We add the datetime in front of each entries as
well.

Author: AntoLC

src/frontend/servers/y-provider/__tests__/hocusPocusWS.test.ts

@@ -15,10 +15,12 @@ jest.mock('../src/env', () => {
     COLLABORATION_SERVER_ORIGIN: origin,
     COLLABORATION_SERVER_SECRET: 'test-secret-api-key',
     COLLABORATION_BACKEND_BASE_URL: 'http://app-dev:8000',
+    COLLABORATION_LOGGING: 'true',
   };
 });
 
 console.error = jest.fn();
+console.log = jest.fn();
 
 const mockDocFetch = jest.fn();
 jest.mock('@/api/getDoc', () => ({
@@ -109,7 +111,9 @@ describe('Server Tests', () => {
       quiet: true,
       preserveConnection: false,
       onClose: (data) => {
-        expect(console.error).toHaveBeenCalledWith(
+        expect(console.log).toHaveBeenCalledWith(
+          expect.any(String),
+          ' --- ',
           'Invalid room name - Probable hacking attempt:',
           providerName,
           room,
@@ -145,7 +149,9 @@ describe('Server Tests', () => {
       quiet: true,
       preserveConnection: false,
       onClose: (data) => {
-        expect(console.error).toHaveBeenCalledWith(
+        expect(console.log).toHaveBeenLastCalledWith(
+          expect.any(String),
+          ' --- ',
           'Room name is not a valid uuid:',
           room,
         );
@@ -180,7 +186,9 @@ describe('Server Tests', () => {
       quiet: true,
       preserveConnection: false,
       onClose: (data) => {
-        expect(console.error).toHaveBeenCalledWith(
+        expect(console.log).toHaveBeenLastCalledWith(
+          expect.any(String),
+          ' --- ',
           'Room name is not a valid uuid:',
           room,
         );
@@ -218,7 +226,7 @@ describe('Server Tests', () => {
       quiet: true,
       preserveConnection: false,
       onClose: (data) => {
-        expect(console.error).toHaveBeenCalledWith(
+        expect(console.error).toHaveBeenLastCalledWith(
           '[onConnect]',
           'Backend error: Unauthorized',
         );
@@ -261,7 +269,9 @@ describe('Server Tests', () => {
       quiet: true,
       preserveConnection: false,
       onClose: (data) => {
-        expect(console.error).toHaveBeenCalledWith(
+        expect(console.log).toHaveBeenLastCalledWith(
+          expect.any(String),
+          ' --- ',
           'onConnect: Unauthorized to retrieve this document',
           room,
         );

src/frontend/servers/y-provider/src/handlers/collaborationWSHandler.ts

@@ -2,11 +2,8 @@ import { Request } from 'express';
 import * as ws from 'ws';
 
 import { hocusPocusServer } from '@/servers/hocusPocusServer';
-import { logger } from '@/utils';
 
 export const collaborationWSHandler = (ws: ws.WebSocket, req: Request) => {
-  logger('Incoming Origin:', req.headers['origin']);
-
   try {
     hocusPocusServer.handleConnection(ws, req);
   } catch (error) {

src/frontend/servers/y-provider/src/middlewares.ts

@@ -8,6 +8,8 @@ import {
   Y_PROVIDER_API_KEY,
 } from '@/env';
 
+import { logger } from './utils';
+
 const VALID_API_KEYS = [COLLABORATION_SERVER_SECRET, Y_PROVIDER_API_KEY];
 const allowedOrigins = COLLABORATION_SERVER_ORIGIN.split(',');
 
@@ -42,14 +44,16 @@ export const wsSecurity = (
   const origin = req.headers['origin'];
   if (!origin || !allowedOrigins.includes(origin)) {
     ws.close(4001, 'Origin not allowed');
-    console.error('CORS policy violation: Invalid Origin', origin);
+    logger('CORS policy violation: Invalid Origin', origin);
     return;
   }
 
   const cookies = req.headers['cookie'];
   if (!cookies) {
     ws.close(4001, 'No cookies');
-    console.error('CORS policy violation: No cookies');
+    logger('CORS policy violation: No cookies');
+    logger('UA:', req.headers['user-agent']);
+    logger('URL:', req.url);
     return;
   }
 

src/frontend/servers/y-provider/src/servers/hocusPocusServer.ts

@@ -15,21 +15,24 @@ export const hocusPocusServer = Server.configure({
     documentName,
     requestParameters,
     context,
+    request,
   }) {
     const roomParam = requestParameters.get('room');
 
     if (documentName !== roomParam) {
-      console.error(
+      logger(
         'Invalid room name - Probable hacking attempt:',
         documentName,
         requestParameters.get('room'),
       );
+      logger('UA:', request.headers['user-agent']);
+      logger('URL:', request.url);
 
       return Promise.reject(new Error('Wrong room name: Unauthorized'));
     }
 
     if (!uuidValidate(documentName) || uuidVersion(documentName) !== 4) {
-      console.error('Room name is not a valid uuid:', documentName);
+      logger('Room name is not a valid uuid:', documentName);
 
       return Promise.reject(new Error('Wrong room name: Unauthorized'));
     }
@@ -40,7 +43,7 @@ export const hocusPocusServer = Server.configure({
       const document = await fetchDocument(documentName, requestHeaders);
 
       if (!document.abilities.retrieve) {
-        console.error(
+        logger(
           'onConnect: Unauthorized to retrieve this document',
           documentName,
         );
@@ -50,7 +53,7 @@ export const hocusPocusServer = Server.configure({
       can_edit = document.abilities.update;
     } catch (error: unknown) {
       if (error instanceof Error) {
-        console.error('onConnect: backend error', error.message);
+        logger('onConnect: backend error', error.message);
       }
 
       return Promise.reject(new Error('Backend error: Unauthorized'));
@@ -69,12 +72,10 @@ export const hocusPocusServer = Server.configure({
     } catch {}
 
     logger(
-      'Connection established:',
+      'Connection established on room:',
       documentName,
       'canEdit:',
       can_edit,
-      'room:',
-      requestParameters.get('room'),
     );
     return Promise.resolve();
   },

src/frontend/servers/y-provider/src/utils.ts

@@ -4,7 +4,7 @@ import { COLLABORATION_LOGGING } from './env';
 export function logger(...args: any[]) {
   if (COLLABORATION_LOGGING === 'true') {
     // eslint-disable-next-line @typescript-eslint/no-unsafe-argument
-    console.log(...args);
+    console.log(new Date().toISOString(), ' --- ', ...args);
   }
 }