Merge pull request #828 from MatrixAI/feature-clearer-error-logging

Adding better error messaging when stringifying errors in logging
MatrixAI · Oct 15, 2024 · f40659a · f40659a
2 parents d474676 + 3bbf42e
commit f40659a
Show file tree

Hide file tree

Showing 27 changed files with 231 additions and 136 deletions.
diff --git a/src/ErrorPolykey.ts b/src/ErrorPolykey.ts
@@ -39,6 +39,13 @@ class ErrorPolykey<T> extends AbstractError<T> {
     json.data.exitCode = this.exitCode;
     return json;
   }
+
+  public toString(): string {
+    const messageString =
+      this.message.length > 0 ? `("${this.message}")` : '()';
+    const chainString = this.cause != null ? `>${String(this.cause)}` : '';
+    return `${this.name}${messageString}${chainString}`;
+  }
 }
 
 export default ErrorPolykey;
diff --git a/src/PolykeyAgent.ts b/src/PolykeyAgent.ts
@@ -803,7 +803,9 @@ class PolykeyAgent {
       const setNodeProms = new Array<Promise<void>>();
       for (const nodeIdEncoded in optionsDefaulted.seedNodes) {
         const nodeId = nodesUtils.decodeNodeId(nodeIdEncoded);
-        if (nodeId == null) utils.never();
+        if (nodeId == null) {
+          utils.never(`failed to decode NodeId "${nodeIdEncoded}"`);
+        }
         const setNodeProm = this.nodeManager.setNode(
           nodeId,
           optionsDefaulted.seedNodes[nodeIdEncoded],
@@ -825,7 +827,9 @@ class PolykeyAgent {
         const initialNodes = seedNodeEntries.map(
           ([nodeIdEncoded, nodeAddress]) => {
             const nodeId = nodesUtils.decodeNodeId(nodeIdEncoded);
-            if (nodeId == null) utils.never('nodeId should be defined');
+            if (nodeId == null) {
+              utils.never(`failed to decode NodeId "${nodeIdEncoded}"`);
+            }
             return [nodeId, nodeAddress] as [NodeId, NodeAddress];
           },
         );

diff --git a/src/client/authenticationMiddleware.ts b/src/client/authenticationMiddleware.ts
@@ -105,7 +105,9 @@ function authenticationMiddlewareClient(
       >({
         transform: async (chunk, controller) => {
           if (forwardFirst) {
-            if (chunk.params == null) utils.never();
+            if (chunk.params == null) {
+              utils.never('chunk.params must be defined');
+            }
             if (chunk.params.metadata?.authorization == null) {
               const token = await session.readToken();
               if (token != null) {

diff --git a/src/client/handlers/IdentitiesAuthenticate.ts b/src/client/handlers/IdentitiesAuthenticate.ts
@@ -50,7 +50,7 @@ class IdentitiesAuthenticate extends ServerHandler<
     const authFlow = provider.authenticate(ctx.timer.getTimeout());
     let authFlowResult = await authFlow.next();
     if (authFlowResult.done) {
-      never();
+      never('authFlow signalled done too soon');
     }
     if (ctx.signal.aborted) throw ctx.signal.reason;
     yield {
@@ -61,7 +61,7 @@ class IdentitiesAuthenticate extends ServerHandler<
     };
     authFlowResult = await authFlow.next();
     if (!authFlowResult.done) {
-      never();
+      never('authFlow did not signal done when expected');
     }
     if (ctx.signal.aborted) throw ctx.signal.reason;
     yield {

diff --git a/src/client/handlers/KeysDecrypt.ts b/src/client/handlers/KeysDecrypt.ts
@@ -19,7 +19,7 @@ class KeysDecrypt extends UnaryHandler<
   ): Promise<ClientRPCResponseResult<DataMessage>> => {
     const { keyRing }: { keyRing: KeyRing } = this.container;
     const data = keyRing.decrypt(Buffer.from(input.data, 'binary'));
-    if (data == null) never();
+    if (data == null) never('failed to decrypt DataMessage');
     return {
       data: data.toString('binary'),
     };

diff --git a/src/client/handlers/KeysEncrypt.ts b/src/client/handlers/KeysEncrypt.ts
@@ -27,7 +27,7 @@ class KeysEncrypt extends UnaryHandler<
     try {
       const jwk = input.publicKeyJwk;
       publicKey = keysUtils.publicKeyFromJWK(jwk);
-      if (publicKey == null) never();
+      if (publicKey == null) never('failed to get public key from JWK');
     } catch (e) {
       throw new keysErrors.ErrorPublicKeyParse(undefined, { cause: e });
     }

diff --git a/src/client/handlers/KeysVerify.ts b/src/client/handlers/KeysVerify.ts
@@ -26,7 +26,7 @@ class KeysVerify extends UnaryHandler<
     try {
       const jwk = input.publicKeyJwk;
       publicKey = keysUtils.publicKeyFromJWK(jwk);
-      if (publicKey == null) never();
+      if (publicKey == null) never('failed to get public key from JWK');
     } catch (e) {
       throw new keysErrors.ErrorPublicKeyParse(undefined, { cause: e });
     }

diff --git a/src/discovery/Discovery.ts b/src/discovery/Discovery.ts
@@ -171,7 +171,9 @@ class Discovery {
       if (e === discoveryStoppingTaskReason) {
         // We need to recreate the task for the vertex
         const vertexId = gestaltsUtils.decodeGestaltId(vertex);
-        if (vertexId == null) never();
+        if (vertexId == null) {
+          never(`failed to decode vertex GestaltId "${vertex}"`);
+        }
         await this.scheduleDiscoveryForVertex(
           vertexId,
           undefined,
@@ -399,15 +401,17 @@ class Discovery {
   ): Promise<void> {
     this.logger.debug(`Processing vertex: ${vertex}`);
     const vertexId = gestaltsUtils.decodeGestaltId(vertex);
-    if (vertexId == null) never();
+    if (vertexId == null) {
+      never(`failed to decode vertex GestaltId "${vertex}"`);
+    }
     const [type, id] = vertexId;
     switch (type) {
       case 'node':
         return await this.processNode(id, ctx, lastProcessedCutoffTime);
       case 'identity':
         return await this.processIdentity(id, ctx, lastProcessedCutoffTime);
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 
@@ -446,7 +450,7 @@ class Discovery {
       this.logger.info(
         `Failed to discover ${nodesUtils.encodeNodeId(
           nodeId,
-        )} - ${e.toString()}`,
+        )} - Reason: ${String(e)}`,
       );
       return;
     }
@@ -470,7 +474,9 @@ class Discovery {
           );
           break;
         default:
-          never();
+          never(
+            `signedClaim.payload.typ must be "ClaimLinkNode" or "ClaimLinkIdentity" got "${signedClaim.payload.typ}"`,
+          );
       }
     }
     await this.gestaltGraph.setVertexProcessedTime(
@@ -488,9 +494,13 @@ class Discovery {
     // Could be node1 or node2 in the claim so get the one that's
     // not equal to nodeId from above
     const node1Id = nodesUtils.decodeNodeId(signedClaim.payload.iss);
-    if (node1Id == null) never();
+    if (node1Id == null) {
+      never(`failed to decode issuer NodeId "${signedClaim.payload.iss}"`);
+    }
     const node2Id = nodesUtils.decodeNodeId(signedClaim.payload.sub);
-    if (node2Id == null) never();
+    if (node2Id == null) {
+      never(`failed to decode subject NodeId "${signedClaim.payload.sub}"`);
+    }
     // Verify the claim
     const node1PublicKey = keysUtils.publicKeyFromNodeId(node1Id);
     const node2PublicKey = keysUtils.publicKeyFromNodeId(node2Id);
@@ -519,7 +529,9 @@ class Discovery {
       },
     );
     const claimId = decodeClaimId(signedClaim.payload.jti);
-    if (claimId == null) never();
+    if (claimId == null) {
+      never(`failed to decode claimId "${signedClaim.payload.jti}"`);
+    }
     await this.gestaltGraph.setClaimIdNewest(nodeId, claimId);
     // Add this vertex to the queue if it hasn't already been visited
     const linkedGestaltId: GestaltId = ['node', linkedNodeId];
@@ -556,7 +568,9 @@ class Discovery {
       return;
     }
     // Attempt to get the identity info on the identity provider
-    if (signedClaim.payload.sub == null) never();
+    if (signedClaim.payload.sub == null) {
+      never('signedClaim.payload.sub must be defined');
+    }
     const [providerId, identityId] = JSON.parse(signedClaim.payload.sub);
     const identityInfo = await this.getIdentityInfo(
       providerId,
@@ -617,7 +631,9 @@ class Discovery {
       },
     );
     const claimId = decodeClaimId(signedClaim.payload.jti);
-    if (claimId == null) never();
+    if (claimId == null) {
+      never(`failed to decode ClaimId "${signedClaim.payload.jti}"`);
+    }
     await this.gestaltGraph.setClaimIdNewest(nodeId, claimId);
     // Add this identity vertex to the queue if it is not present
     const providerIdentityId = JSON.parse(signedClaim.payload.sub!);
@@ -675,7 +691,9 @@ class Discovery {
       // Claims on an identity provider will always be node -> identity
       // So just cast payload data as such
       const linkedNodeId = nodesUtils.decodeNodeId(claim.payload.iss);
-      if (linkedNodeId == null) never();
+      if (linkedNodeId == null) {
+        never(`failed to decode issuer NodeId "${claim.payload.iss}"`);
+      }
       // With this verified chain, we can link
       const linkedVertexNodeInfo = {
         nodeId: linkedNodeId,
@@ -927,7 +945,7 @@ class Discovery {
       const data = claim.payload;
       // Verify the claim with the public key of the node
       const nodeId = nodesUtils.decodeNodeId(data.iss);
-      if (nodeId == null) never();
+      if (nodeId == null) never(`failed to decode issuer NodeId "${data.iss}"`);
       const publicKey = keysUtils.publicKeyFromNodeId(nodeId);
       const token = Token.fromSigned(claim);
       // If verified, add to the record

diff --git a/src/gestalts/GestaltGraph.ts b/src/gestalts/GestaltGraph.ts
@@ -298,7 +298,7 @@ class GestaltGraph {
           break;
         case 'identity':
         default:
-          never();
+          never(`type must be either "node" or "identity" got "${type}"`);
       }
     }
     // 2. remove the node information.
@@ -318,7 +318,7 @@ class GestaltGraph {
       case 'identity':
         return this.setIdentity(info, tran);
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 
@@ -335,7 +335,7 @@ class GestaltGraph {
       case 'identity':
         return this.unsetIdentity(id, tran);
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 
@@ -468,7 +468,9 @@ class GestaltGraph {
         never('lastProcessedTime should be valid here');
       }
       const gestaltId = gestaltsUtils.decodeGestaltId(gestaltIdEncoded);
-      if (gestaltId == null) never('GestaltId should be valid here');
+      if (gestaltId == null) {
+        never(`failed to decode GestaltId "${gestaltIdEncoded}"`);
+      }
       yield [gestaltId, lastProcessedTime];
     }
   }
@@ -872,7 +874,9 @@ class GestaltGraph {
         tran,
       );
     } else {
-      never();
+      never(
+        `invalid claim between "${gestaltInfo1[0]}" and "${gestaltInfo2[0]}", must be a node to node or identity to node claim`,
+      );
     }
   }
 
@@ -1065,7 +1069,9 @@ class GestaltGraph {
         tran,
       );
     } else {
-      never();
+      never(
+        `invalid link between "${type1}" and "${type2}", must be node to node or node to identity`,
+      );
     }
   }
 
@@ -1104,7 +1110,7 @@ class GestaltGraph {
         return perm.gestalt;
       }
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 
@@ -1143,7 +1149,7 @@ class GestaltGraph {
         return;
       }
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 
@@ -1183,7 +1189,7 @@ class GestaltGraph {
         return;
       }
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 
@@ -1231,7 +1237,7 @@ class GestaltGraph {
       case 'identity':
         return await this.getGestaltByIdentity(id, tran);
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 
@@ -1335,7 +1341,7 @@ class GestaltGraph {
         return ['identity', gestaltIdentityInfo];
       }
       default:
-        never();
+        never(`type must be either "node" or "identity" got "${type}"`);
     }
   }
 

diff --git a/src/git/http.ts b/src/git/http.ts
@@ -324,9 +324,7 @@ async function parsePackRequest(
         case 'done':
           return [wants, haves, capabilities];
         default:
-          utils.never(
-            `Type should be either 'want' or 'have', found '${type}'`,
-          );
+          utils.never(`Type should be either "want" or "have", got "${type}"`);
       }
     }
   }

diff --git a/src/git/utils.ts b/src/git/utils.ts
@@ -248,7 +248,9 @@ async function listObjectsAll({
   const objectSet: Set<string> = new Set();
   const objectDirs = await fs.promises.readdir(objectsDirPath);
   for (const objectDir of objectDirs) {
-    if (typeof objectDir !== 'string') utils.never();
+    if (typeof objectDir !== 'string') {
+      utils.never('objectDir should be a string');
+    }
     if (excludedDirs.includes(objectDir)) continue;
     const objectIds = await fs.promises.readdir(
       path.join(objectsDirPath, objectDir),

diff --git a/src/nodes/NodeConnection.ts b/src/nodes/NodeConnection.ts
@@ -279,7 +279,7 @@ class NodeConnection {
     }
     const quicConnection = quicClient.connection;
     const throwFunction = () =>
-      never('We should never get connections before setting up handling');
+      never('we should never get connections before setting up handling');
     quicConnection.addEventListener(
       quicEvents.EventQUICConnectionStream.name,
       throwFunction,
@@ -293,7 +293,9 @@ class NodeConnection {
       toError: networkUtils.toError,
       logger: logger.getChild(RPCClient.name),
     });
-    if (validatedNodeId == null) never();
+    if (validatedNodeId == null) {
+      never(`connection validated but no valid NodeId was returned`);
+    }
     // Obtaining remote node ID from certificate chain. It should always exist in the chain if validated.
     //  This may de different from the NodeId we validated it as if it renewed at some point.
     const connection = quicClient.connection;