Merge pull request #14 from rocicorp/cleanup

Logging cleanups

backend/rds.ts

@@ -154,7 +154,7 @@ async function executeStatementInDatabase(
       name,
       value,
     }));
-  console.log("Executing", database, sql, params);
+  console.log("Executing", database, sql, JSON.stringify(params, null, ''));
   const command = new ExecuteStatementCommand({
     database: database ?? "",
     resourceArn,

pages/api/replicache-pull.ts

@@ -6,12 +6,12 @@ import { getCookieVersion, getLastMutationID } from "../../backend/data";
 import { must } from "../../backend/decode";
 
 export default async (req: NextApiRequest, res: NextApiResponse) => {
-  console.log(`Processing pull`, req.body);
+  console.log(`Processing pull`, JSON.stringify(req.body, null, ''));
 
   const pull = must(pullRequest.decode(req.body));
   let cookie = pull.baseStateID === "" ? 0 : parseInt(pull.baseStateID);
 
-  console.time(`Reading all objects...`);
+  const t0 = Date.now();
   let entries;
   let lastMutationID = 0;
 
@@ -24,8 +24,8 @@ export default async (req: NextApiRequest, res: NextApiResponse) => {
       getCookieVersion(executor),
     ]);
   });
-  console.log({ lastMutationID });
-  console.timeEnd(`Reading all objects...`);
+  console.log('lastMutationID: ', lastMutationID);
+  console.log('Read all objects in', Date.now() - t0);
 
   // Grump. Typescript seems to not understand that the argument to transact()
   // is guaranteed to have been called before transact() exits.
@@ -68,7 +68,7 @@ export default async (req: NextApiRequest, res: NextApiResponse) => {
     }
   }
 
-  console.log(`Returning`, resp);
+  console.log(`Returning`, JSON.stringify(resp, null, ''));
   res.json(resp);
   res.end();
 };

pages/api/replicache-push.ts

@@ -72,17 +72,18 @@ type Mutation = t.TypeOf<typeof mutation>;
 
 export default async (req: NextApiRequest, res: NextApiResponse) => {
   const push = must(pushRequest.decode(req.body));
-  console.log("Processing push", push);
+  console.log("Processing push", JSON.stringify(push, null, ''));
 
+  const t0 = Date.now();
   for (let i = 0; i < push.mutations.length; i++) {
     await transact(async (executor) => {
       let lastMutationID = await getLastMutationID(executor, push.clientID);
-      console.log({ lastMutationID });
+      console.log('lastMutationID:', lastMutationID);
 
       // Scan forward from here collapsing any collapsable mutations.
       for (; i < push.mutations.length; i++) {
         let mutation = push.mutations[i];
-        console.log({ mutation });
+        console.log('mutation:', JSON.stringify(mutation, null, ''));
 
         const expectedMutationID = lastMutationID + 1;
         if (mutation.id < expectedMutationID) {
@@ -99,16 +100,17 @@ export default async (req: NextApiRequest, res: NextApiResponse) => {
         }
 
         const next = push.mutations[i + 1];
-        console.log("Considering for collapse", mutation, next);
+        console.log("Considering for collapse", JSON.stringify(mutation, null, ''), JSON.stringify(next, null, ''));
         if (next) {
           if (collapse(mutation, next)) {
             lastMutationID = mutation.id;
-            console.log("Collapsed into", next);
+            console.log("Collapsed into", JSON.stringify(next, null, ''));
             continue;
           }
         }
 
         const s = storage(executor);
+        const t1 = Date.now();
 
         switch (mutation.name) {
           case "moveShape":
@@ -129,22 +131,25 @@ export default async (req: NextApiRequest, res: NextApiResponse) => {
         }
 
         await setLastMutationID(executor, push.clientID, expectedMutationID);
-
+        console.log('Processed mutation in', Date.now() - t1);
         break;
       }
     });
   }
 
+  console.log('Processed all mutations in', Date.now() - t0);
+
   const pusher = new Pusher({
     appId: "1157097",
     key: "d9088b47d2371d532c4c",
     secret: "64204dab73c42e17afc3",
     cluster: "us3",
     useTLS: true,
   });
-  console.time(`sending poke...`);
+
+  const t2 = Date.now();
   await pusher.trigger("default", "poke", {});
-  console.timeEnd(`sending poke...`);
+  console.log('Sent poke in', Date.now() - t2);
 
   res.status(200).json({});
 };

pages/index.tsx

@@ -34,7 +34,6 @@ export default function Home() {
       id: d.clientID,
       defaultUserInfo,
     });
-    rep.sync();
 
     Pusher.logToConsole = true;
     var pusher = new Pusher("d9088b47d2371d532c4c", {