add configurable logging

nikgraf · Aug 18, 2023 · 165cb79 · 165cb79
1 parent 77ab099
commit 165cb79
Show file tree

Hide file tree

Showing 10 changed files with 112 additions and 48 deletions.
diff --git a/docs/specification.md b/docs/specification.md
@@ -53,10 +53,11 @@ parentSnapshotProof = hash(parentSnapshotProof of the prev snapshot, snapshotCip
 #### Verifying if the snapshot is based on a previous snapshot
 
 In order to verify that a snapshot is based on a previous snapshot the following information is required:
+
 - ciphertext hash and parentSnapshotProof of all past snapshots to and including the known one (snapshotProofChain)
 - the new snapshot
 
-It's the responsibility of the server to store the necessary information and allow a client to query the snapshotProofChain. 
+It's the responsibility of the server to store the necessary information and allow a client to query the snapshotProofChain.
 
 ##### Example
 

diff --git a/examples/backend/src/index.ts b/examples/backend/src/index.ts
@@ -46,6 +46,7 @@ async function main() {
       createSnapshot: createSnapshotDb,
       createUpdate: createUpdateDb,
       hasAccess: async () => true,
+      logging: "error",
     })
   );
 

diff --git a/examples/frontend/pages/doc/[docId].tsx b/examples/frontend/pages/doc/[docId].tsx
@@ -82,6 +82,7 @@ const Document: React.FC<{ docId: string }> = ({ docId }) => {
       return true;
     },
     sodium,
+    logging: "debug",
   });
 
   const initiateEditor = () => {

diff --git a/examples/frontend/pages/tiptap/[docId].tsx b/examples/frontend/pages/tiptap/[docId].tsx
@@ -72,6 +72,7 @@ const Document: React.FC<{ docId: string }> = ({ docId }) => {
       return true;
     },
     sodium,
+    logging: "debug",
   });
 
   const editor = useEditor({

diff --git a/examples/frontend/pages/todos/[docId].tsx b/examples/frontend/pages/todos/[docId].tsx
@@ -67,6 +67,7 @@ const Document: React.FC<{ docId: string }> = ({ docId }) => {
       return true;
     },
     sodium,
+    logging: "debug",
   });
 
   return (

diff --git a/packages/secsync-react-yjs/src/useYjsSync.ts b/packages/secsync-react-yjs/src/useYjsSync.ts
@@ -77,7 +77,6 @@ export const useYjsSync = (config: YjsSyncMachineConfig) => {
         send({ type: "ADD_CHANGES", data: [update] });
       }
     };
-    // TODO switch to v2 updates
     yDoc.on("updateV2", onUpdate);
 
     // only connect the awareness after the document loaded

diff --git a/packages/secsync/src/createSyncMachine.ts b/packages/secsync/src/createSyncMachine.ts
@@ -155,6 +155,7 @@ export type Context = SyncMachineConfig &
     _shouldReconnect: boolean;
     _errorTrace: Error[];
     _ephemeralUpdateErrors: Error[];
+    logging: SyncMachineConfig["logging"];
   };
 
 const disconnectionContextReset: InternalContextReset = {
@@ -227,6 +228,7 @@ export const createSyncMachine = () =>
         deserializeChanges: () => [],
         onSnapshotSaved: () => undefined,
         isValidCollaborator: async () => false,
+        logging: "off",
         additionalAuthenticationDataValidations: undefined,
         _activeSnapshotInfo: null,
         _latestServerVersion: null,
@@ -436,7 +438,9 @@ export const createSyncMachine = () =>
           };
         }),
         addToPendingUpdatesQueue: assign((context, event) => {
-          console.debug("addToPendingUpdatesQueue", event.data);
+          if (context.logging === "debug") {
+            console.debug("addToPendingUpdatesQueue", event.data);
+          }
           return {
             _pendingChangesQueue: [
               ...context._pendingChangesQueue,
@@ -508,24 +512,28 @@ export const createSyncMachine = () =>
       services: {
         scheduleRetry: (context) => (callback) => {
           const delay = 100 * 1.8 ** context._websocketRetries;
-          console.debug("schedule websocket connection in ", delay);
+          if (context.logging === "debug") {
+            console.debug("schedule websocket connection in ", delay);
+          }
           setTimeout(() => {
             callback("WEBSOCKET_RETRY");
             // calculating slow exponential back-off
           }, delay);
         },
         processQueues: (context, event) => async (send) => {
-          console.debug("clocks", JSON.stringify(context._updateClocks));
-          console.debug("processQueues event", event);
-          console.debug("_incomingQueue", context._incomingQueue.length);
-          console.debug(
-            "_customMessageQueue",
-            context._customMessageQueue.length
-          );
-          console.debug(
-            "_pendingChangesQueue",
-            context._pendingChangesQueue.length
-          );
+          if (context.logging === "debug") {
+            console.debug("clocks", JSON.stringify(context._updateClocks));
+            console.debug("processQueues event", event);
+            console.debug("_incomingQueue", context._incomingQueue.length);
+            console.debug(
+              "_customMessageQueue",
+              context._customMessageQueue.length
+            );
+            console.debug(
+              "_pendingChangesQueue",
+              context._pendingChangesQueue.length
+            );
+          }
 
           let activeSnapshotInfo: ActiveSnapshotInfo | null =
             context._activeSnapshotInfo;
@@ -545,7 +553,9 @@ export const createSyncMachine = () =>
           try {
             const createAndSendSnapshot = async () => {
               const snapshotData = await context.getNewSnapshotData();
-              console.log("createAndSendSnapshot", snapshotData);
+              if (context.logging === "debug") {
+                console.log("createAndSendSnapshot", snapshotData);
+              }
 
               if (activeSnapshotInfo === null) {
                 const publicData: SnapshotPublicData = {
@@ -667,7 +677,9 @@ export const createSyncMachine = () =>
               rawSnapshot: SnapshotWithServerData,
               parentSnapshotProofInfo?: ParentSnapshotProofInfo
             ) => {
-              console.debug("processSnapshot", rawSnapshot);
+              if (context.logging === "debug") {
+                console.debug("processSnapshot", rawSnapshot);
+              }
               const snapshot = parseSnapshotWithServerData(
                 rawSnapshot,
                 context.additionalAuthenticationDataValidations?.snapshot
@@ -786,7 +798,9 @@ export const createSyncMachine = () =>
                 }
                 context.applyChanges(changes);
               } catch (error) {
-                console.debug("APPLYING CHANGES in catch", error);
+                if (context.logging === "debug") {
+                  console.debug("APPLYING CHANGES in catch", error);
+                }
                 // still try to apply all existing changes
                 context.applyChanges(changes);
                 throw error;
@@ -849,7 +863,9 @@ export const createSyncMachine = () =>
                   break;
 
                 case "snapshot":
-                  console.log("snapshot", event);
+                  if (context.logging === "debug") {
+                    console.log("snapshot", event);
+                  }
                   await processSnapshot(
                     event.snapshot,
                     activeSnapshotInfo ? activeSnapshotInfo : undefined
@@ -858,7 +874,9 @@ export const createSyncMachine = () =>
                   break;
 
                 case "snapshot-saved":
-                  console.log("snapshot saved", event);
+                  if (context.logging === "debug") {
+                    console.log("snapshot saved", event);
+                  }
                   // in case the event is received for a snapshot that was not active in sending
                   // we remove the activeSendingSnapshotInfo since any activeSendingSnapshotInfo
                   // that is in flight will fail
@@ -876,8 +894,10 @@ export const createSyncMachine = () =>
                     context.onSnapshotSaved();
                   }
                   break;
-                case "snapshot-save-failed": // TODO rename to snapshotSaveFailed or similar
-                  console.log("snapshot saving failed", event);
+                case "snapshot-save-failed":
+                  if (context.logging === "debug") {
+                    console.log("snapshot saving failed", event);
+                  }
                   if (event.snapshot) {
                     const snapshot = parseSnapshotWithServerData(
                       event.snapshot,
@@ -914,15 +934,19 @@ export const createSyncMachine = () =>
                     await processUpdates(event.updates);
                   }
 
-                  console.log("retry send snapshot");
+                  if (context.logging === "debug") {
+                    console.log("retry send snapshot");
+                  }
                   await createAndSendSnapshot();
                   break;
 
                 case "update":
                   await processUpdates([event]);
                   break;
                 case "update-saved":
-                  console.debug("update saved", event);
+                  if (context.logging === "debug") {
+                    console.debug("update saved", event);
+                  }
                   latestServerVersion = event.serverVersion;
                   confirmedUpdatesClock = event.clock;
                   updatesInFlight = updatesInFlight.filter(
@@ -931,12 +955,14 @@ export const createSyncMachine = () =>
 
                   break;
                 case "update-save-failed":
-                  console.log(
-                    "update saving failed",
-                    event.snapshotId,
-                    event.clock,
-                    event.requiresNewSnapshot
-                  );
+                  if (context.logging === "debug") {
+                    console.log(
+                      "update saving failed",
+                      event.snapshotId,
+                      event.clock,
+                      event.requiresNewSnapshot
+                    );
+                  }
 
                   if (event.requiresNewSnapshot) {
                     await createAndSendSnapshot();
@@ -1032,10 +1058,14 @@ export const createSyncMachine = () =>
                   latestServerVersion,
                 })
               ) {
-                console.debug("send snapshot");
+                if (context.logging === "debug") {
+                  console.debug("send snapshot");
+                }
                 await createAndSendSnapshot();
               } else {
-                console.debug("send update");
+                if (context.logging === "debug") {
+                  console.debug("send update");
+                }
                 const key = await context.getUpdateKey(event);
                 const rawChanges = context._pendingChangesQueue;
                 pendingChangesQueue = [];
@@ -1066,7 +1096,9 @@ export const createSyncMachine = () =>
               documentDecryptionState,
             };
           } catch (error) {
-            console.error("Processing queue error:", error);
+            if (context.logging === "debug" || context.logging === "error") {
+              console.error("Processing queue error:", error);
+            }
             if (error instanceof SecsyncProcessingEphemeralUpdateError) {
               const newEphemeralUpdateErrors = [
                 ...context._ephemeralUpdateErrors,

diff --git a/packages/secsync/src/server/createWebSocketConnection.ts b/packages/secsync/src/server/createWebSocketConnection.ts
@@ -43,6 +43,8 @@ type WebsocketConnectionParams = {
   ): Promise<UpdateWithServerData>;
   hasAccess(hasAccessParams: HasAccessParams): Promise<boolean>;
   additionalAuthenticationDataValidations?: AdditionalAuthenticationDataValidations;
+  /** default: "off" */
+  logging?: "off" | "error";
 };
 
 export const createWebSocketConnection =
@@ -52,8 +54,10 @@ export const createWebSocketConnection =
     createUpdate,
     hasAccess,
     additionalAuthenticationDataValidations,
+    logging: loggingParam,
   }: WebsocketConnectionParams) =>
   async (connection: WebSocket, request: IncomingMessage) => {
+    const logging = loggingParam || "off";
     let documentId = "";
 
     const handleDocumentError = () => {
@@ -158,7 +162,9 @@ export const createWebSocketConnection =
               connection
             );
           } catch (error) {
-            console.error("SNAPSHOT FAILED ERROR:", error);
+            if (logging === "error") {
+              console.error("SNAPSHOT FAILED ERROR:", error);
+            }
             if (error instanceof SecsyncSnapshotBasedOnOutdatedSnapshotError) {
               let document = await getDocument({
                 documentId,
@@ -174,9 +180,11 @@ export const createWebSocketConnection =
                   })
                 );
               } else {
-                console.error(
-                  'document not found for "snapshotBasedOnOutdatedSnapshot" error'
-                );
+                if (logging === "error") {
+                  console.error(
+                    'document not found for "snapshotBasedOnOutdatedSnapshot" error'
+                  );
+                }
                 handleDocumentError();
               }
             } else if (error instanceof SecsyncSnapshotMissesUpdatesError) {
@@ -194,9 +202,11 @@ export const createWebSocketConnection =
                 );
               } else {
                 // log since it's an unexpected error
-                console.error(
-                  'document not found for "snapshotMissesUpdates" error'
-                );
+                if (logging === "error") {
+                  console.error(
+                    'document not found for "snapshotMissesUpdates" error'
+                  );
+                }
                 handleDocumentError();
               }
             } else if (error instanceof SecsyncNewSnapshotRequiredError) {
@@ -207,7 +217,9 @@ export const createWebSocketConnection =
               );
             } else {
               // log since it's an unexpected error
-              console.error(error);
+              if (logging === "error") {
+                console.error(error);
+              }
               handleDocumentError();
             }
           }
@@ -259,7 +271,9 @@ export const createWebSocketConnection =
               connection
             );
           } catch (err) {
-            console.error("update failed", err);
+            if (logging === "error") {
+              console.error("update failed", err);
+            }
             if (savedUpdate === null || savedUpdate === undefined) {
               connection.send(
                 JSON.stringify({
@@ -300,7 +314,9 @@ export const createWebSocketConnection =
         removeConnection(documentId, connection);
       });
     } catch (error) {
-      console.error(error);
+      if (logging === "error") {
+        console.error(error);
+      }
       handleDocumentError();
     }
   };
diff --git a/packages/secsync/src/types.ts b/packages/secsync/src/types.ts
@@ -174,6 +174,8 @@ export type SyncMachineConfig = {
   onCustomMessage?: (message: any) => Promise<void> | void;
   knownSnapshotInfo?: KnownSnapshotInfo;
   additionalAuthenticationDataValidations?: AdditionalAuthenticationDataValidations;
+  /** default: "off" */
+  logging?: "off" | "error" | "debug";
 };
 
 export type CreateSnapshotParams = {