feat: Improve transaction log parsing (#442)

* feat: Adds transaction log parsing

* delete unused

* add program address in instruction logs

* fix types

* clean up utils

* clean up simulation

* formatted log lines

* Print logs settings

* verbosity tweaks

packages/chai-solana/package.json

@@ -30,6 +30,7 @@
     "chai": "^4.3.4",
     "chai-as-promised": "^7.1.1",
     "chai-bn": "^0.3.0",
+    "colors": "^1.4.0",
     "tslib": "^2.3.1"
   },
   "gitHead": "f9fd3fbd36a7a6dd6f5e9597af5309affe50ac0e",

packages/chai-solana/src/expectTXTable.ts

@@ -1,6 +1,7 @@
 import type { TransactionEnvelope } from "@saberhq/solana-contrib";
-import { printTXTable } from "@saberhq/solana-contrib";
+import { parseTransactionLogs, printTXTable } from "@saberhq/solana-contrib";
 
+import { formatInstructionLogs } from "./printInstructionLogs";
 import { expectTX } from "./utils";
 
 /**
@@ -28,7 +29,23 @@ import { expectTX } from "./utils";
 export const expectTXTable = (
   tx: TransactionEnvelope,
   msg?: string,
-  verbosity?: "printLogs"
+  {
+    verbosity = null,
+    formatLogs = true,
+  }: {
+    /**
+     * Logging verbosity.
+     *
+     * - `always` -- print logs whenever they exist
+     * - `error` -- print logs only if there is an error
+     * - `null` -- never print the full transaction logs
+     */
+    verbosity?: "always" | "error" | null;
+    formatLogs?: boolean;
+  } = {
+    verbosity: null,
+    formatLogs: true,
+  }
 ): Chai.PromisedAssertion => {
   if (tx === null) {
     throw new Error();
@@ -67,8 +84,21 @@ export const expectTXTable = (
         );
       }
 
-      const logs = simulation?.value?.logs;
+      const logs = simulation.value.logs;
       if (logs) {
+        if (
+          verbosity === "always" ||
+          (verbosity === "error" && simulation.value.err)
+        ) {
+          if (formatLogs) {
+            const parsed = parseTransactionLogs(logs, simulation.value.err);
+            const fmt = formatInstructionLogs(parsed);
+            console.log(fmt);
+          } else {
+            console.log(logs.join("\n"));
+          }
+        }
+
         if (simulation.value.err) {
           let lastLine = "";
           for (let i = 0; i < logs.length; i++) {
@@ -91,8 +121,6 @@ export const expectTXTable = (
             }
           }
           console.log("   ", simulation.value.err);
-        } else if (verbosity === "printLogs" && logs) {
-          console.log(logs.join("\n"));
         }
       }
     })

packages/chai-solana/src/printInstructionLogs.ts

@@ -0,0 +1,40 @@
+import type { InstructionLogs } from "@saberhq/solana-contrib";
+import { formatLogEntry } from "@saberhq/solana-contrib";
+import * as colors from "colors/safe";
+
+/**
+ * Formats instruction logs to be printed to the console.
+ * @param logs
+ */
+export const formatInstructionLogs = (logs: readonly InstructionLogs[]) => {
+  logs
+    .map((log, i) => {
+      return [
+        [
+          colors.bold(colors.blue("=> ")),
+          colors.bold(colors.white(`Instruction #${i}: `)),
+          log.programAddress
+            ? colors.yellow(`Program ${log.programAddress}`)
+            : "System",
+        ].join(""),
+        ...log.logs.map((entry) => {
+          const entryStr = formatLogEntry(entry, true);
+          switch (entry.type) {
+            case "text":
+              return colors.gray(entryStr);
+            case "cpi":
+              return colors.cyan(entryStr);
+            case "programError":
+              return colors.red(entryStr);
+            case "runtimeError":
+              return colors.red(entryStr);
+            case "system":
+              return colors.gray(entryStr);
+            case "success":
+              return colors.green(entryStr);
+          }
+        }),
+      ].join("\n");
+    })
+    .join("\n");
+};

packages/solana-contrib/package.json

@@ -33,6 +33,7 @@
   },
   "devDependencies": {
     "@solana/web3.js": "^1.31.0",
+    "@types/jest": "^27.4.0",
     "@types/node": "^16.11.17"
   },
   "peerDependencies": {

packages/solana-contrib/src/interfaces.ts

@@ -186,7 +186,7 @@ export interface Provider extends ReadonlyProvider {
    * Simulates the given transaction, returning emitted logs from execution.
    *
    * @param tx      The transaction to send.
-   * @param signers The set of signers in addition to the provdier wallet that
+   * @param signers The set of signers in addition to the provider wallet that
    *                will sign the transaction.
    * @param opts    Transaction confirmation options.
    */

packages/solana-contrib/src/transaction/TransactionEnvelope.ts

@@ -1,98 +1,31 @@
 import type {
-  AccountMeta,
   Cluster,
   ConfirmOptions,
+  PublicKey,
   RpcResponseAndContext,
   Signer,
   SimulatedTransactionResponse,
   TransactionInstruction,
 } from "@solana/web3.js";
-import { PublicKey, Transaction } from "@solana/web3.js";
+import { Transaction } from "@solana/web3.js";
 
 import { printTXTable } from "..";
 import type { Provider } from "../interfaces";
 import type { PendingTransaction } from "./PendingTransaction";
 import type { TransactionReceipt } from "./TransactionReceipt";
+import type { SerializableInstruction } from "./utils";
+import { generateInspectLinkFromBase64, RECENT_BLOCKHASH_STUB } from "./utils";
 
 /**
- * Instruction that can be serialized to JSON.
+ * Options for simulating a transaction.
  */
-export interface SerializableInstruction {
-  programId: string;
-  keys: (Omit<AccountMeta, "pubkey"> & { publicKey: string })[];
-  data: string;
+export interface TXEnvelopeSimulateOptions extends ConfirmOptions {
+  /**
+   * Verify that the signers of the TX enveloper are valid.
+   */
+  verifySigners?: boolean;
 }
 
-/**
- * Stub of a recent blockhash that can be used to simulate transactions.
- */
-export const RECENT_BLOCKHASH_STUB =
-  "GfVcyD4kkTrj4bKc7WA9sZCin9JDbdT4Zkd3EittNR1W";
-
-/**
- * Builds a transaction with a fake `recentBlockhash` and `feePayer` for the purpose
- * of simulating a sequence of instructions.
- *
- * @param cluster
- * @param ixs
- * @returns
- */
-export const buildStubbedTransaction = (
-  cluster: Cluster,
-  ixs: TransactionInstruction[]
-): Transaction => {
-  const tx = new Transaction();
-  tx.recentBlockhash = RECENT_BLOCKHASH_STUB;
-
-  // random keys that have money in them
-  tx.feePayer =
-    cluster === "devnet"
-      ? new PublicKey("A2jaCHPzD6346348JoEym2KFGX9A7uRBw6AhCdX7gTWP")
-      : new PublicKey("9u9iZBWqGsp5hXBxkVZtBTuLSGNAG9gEQLgpuVw39ASg");
-  tx.instructions = ixs;
-  return tx;
-};
-
-/**
- * Serializes a {@link Transaction} to base64 format without checking signatures.
- * @param tx
- * @returns
- */
-export const serializeToBase64Unchecked = (tx: Transaction): string =>
-  tx
-    .serialize({
-      requireAllSignatures: false,
-      verifySignatures: false,
-    })
-    .toString("base64");
-
-/**
- * Generates a link for inspecting the contents of a transaction.
- *
- * @returns URL
- */
-export const generateInspectLinkFromBase64 = (
-  cluster: Cluster,
-  base64TX: string
-): string => {
-  return `https://explorer.solana.com/tx/inspector?cluster=${cluster}&message=${encodeURIComponent(
-    base64TX
-  )}`;
-};
-
-/**
- * Generates a link for inspecting the contents of a transaction, not checking for
- * or requiring valid signatures.
- *
- * @returns URL
- */
-export const generateUncheckedInspectLink = (
-  cluster: Cluster,
-  tx: Transaction
-): string => {
-  return generateInspectLinkFromBase64(cluster, serializeToBase64Unchecked(tx));
-};
-
 /**
  * Contains a Transaction that is being built.
  */
@@ -164,20 +97,26 @@ export class TransactionEnvelope {
    * @returns
    */
   simulate(
-    opts?: ConfirmOptions
+    opts?: TXEnvelopeSimulateOptions
   ): Promise<RpcResponseAndContext<SimulatedTransactionResponse>> {
-    return this.provider.simulate(this.build(), this.signers, opts);
+    return this.provider.simulate(
+      this.build(),
+      opts?.verifySigners ? this.signers : undefined,
+      opts
+    );
   }
 
   /**
    * Simulates the transaction, without validating signers.
+   *
+   * @deprecated Use {@link TXEnvelope#simulate} instead.
    * @param opts
    * @returns
    */
   simulateUnchecked(
-    opts?: ConfirmOptions
+    opts?: TXEnvelopeSimulateOptions
   ): Promise<RpcResponseAndContext<SimulatedTransactionResponse>> {
-    return this.provider.simulate(this.build(), undefined, opts);
+    return this.simulate({ ...opts, verifySigners: true });
   }
 
   /**
@@ -186,7 +125,7 @@ export class TransactionEnvelope {
    * @returns
    */
   simulateTable(
-    opts?: ConfirmOptions
+    opts?: TXEnvelopeSimulateOptions
   ): Promise<RpcResponseAndContext<SimulatedTransactionResponse>> {
     return this.simulate(opts).then((simulation) => {
       if (simulation?.value?.logs) {

packages/solana-contrib/src/transaction/index.ts

@@ -1,3 +1,6 @@
+export * from "./parseTransactionLogs";
 export * from "./PendingTransaction";
+export * from "./programErr";
 export * from "./TransactionEnvelope";
 export * from "./TransactionReceipt";
+export * from "./utils";

packages/solana-contrib/src/transaction/parseTransactionLogs.test.ts

@@ -0,0 +1,46 @@
+/// <reference types="jest" />
+
+import { parseTransactionLogs } from "./parseTransactionLogs";
+
+describe("parseTransactionLogs", () => {
+  it("should parse the logs", () => {
+    const logs = [
+      `Program GAGEa8FYyJNgwULDNhCBEZzW6a8Zfhs6QRxTZ9XQy151 invoke [1]`,
+      `Program log: Instruction: GaugeCommitVote`,
+      `Program log: Custom program error: 0x66`,
+      `Program GAGEa8FYyJNgwULDNhCBEZzW6a8Zfhs6QRxTZ9XQy151 consumed 2778 of 200000 compute units`,
+      `Program GAGEa8FYyJNgwULDNhCBEZzW6a8Zfhs6QRxTZ9XQy151 failed: custom program error: 0x66`,
+    ];
+
+    const result = parseTransactionLogs(logs, null);
+
+    expect(result).toEqual([
+      {
+        programAddress: "GAGEa8FYyJNgwULDNhCBEZzW6a8Zfhs6QRxTZ9XQy151",
+        logs: [
+          {
+            type: "text",
+            depth: 1,
+            text: "Program log: Instruction: GaugeCommitVote",
+          },
+          {
+            type: "text",
+            depth: 1,
+            text: "Program log: Custom program error: 0x66",
+          },
+          {
+            type: "system",
+            depth: 1,
+            text: "Program GAGEa8FYyJNgwULDNhCBEZzW6a8Zfhs6QRxTZ9XQy151 consumed 2778 of 200000 compute units",
+          },
+          {
+            type: "programError",
+            depth: 1,
+            text: "custom program error: 0x66",
+          },
+        ],
+        failed: true,
+      },
+    ]);
+  });
+});