performance issue with FCP and LkfzZvdl_vfjRXZOPjnov18cGnnK3aDKj0qSQCgkCX8 contract #19

.github/workflows/tests.yml

@@ -11,3 +11,5 @@ jobs:
         run: yarn test:unit
       - name: Run integration tests
         run: yarn test:integration
+      - name: Run regression tests
+        run: yarn test:regression

src/__tests__/regression/readState.test.ts

@@ -37,7 +37,11 @@ describe.each(chunked)('.suite %#', (contracts: string[]) => {
       const result = await readContract(arweave, contractTxId);
       const resultString = JSON.stringify(result).trim();
 
-      const result2 = await smartWeave.contract(contractTxId).readState();
+      const result2 = await smartWeave.contract(contractTxId)
+        .setEvaluationOptions({
+          fcpOptimization: true
+        })
+        .readState();
       const result2String = JSON.stringify(result2.state).trim();
 
       expect(result2String).toEqual(resultString);

src/__tests__/regression/test-cases.json

@@ -108,5 +108,6 @@
   "Qa9SzAuwJR6xZp3UiKzokKEoRnt_utJKjFjTaSR85Xw",
   "38TR3D8BxlPTc89NOW67IkQQUPR8jDLaJNdYv-4wWfM",
   "yWDo0H85PVimIpHM86qEP8BzXHIvyIfQE7NeVgTbhxs",
-  "OrO8n453N6bx921wtsEs-0OCImBLCItNU5oSbFKlFuU"
+  "OrO8n453N6bx921wtsEs-0OCImBLCItNU5oSbFKlFuU",
+  "-q2dbbzO7Gh0mh80Qh5dVTXfH9AC6XNPqawuNGtjzus"
 ]

src/cache/impl/MemBlockHeightCache.ts

@@ -49,7 +49,6 @@ export class MemBlockHeightSwCache<V = any> implements BlockHeightSwCache<V> {
     if (!(await this.contains(cacheKey))) {
       this.storage[cacheKey] = new Map();
     }
-
     this.storage[cacheKey].set(blockHeight, deepCopy(value));
   }
 

src/contract/HandlerBasedContract.ts

@@ -75,7 +75,10 @@ export class HandlerBasedContract<State> implements Contract<State> {
     const { stateEvaluator } = this.smartweave;
     const benchmark = Benchmark.measure();
     const executionContext = await this.createExecutionContext(this.contractTxId, blockHeight);
-    this.logger.debug('Contract src txId', executionContext.contractDefinition.srcTxId);
+    this.logger.info('Execution Context', {
+      blockHeight: executionContext.blockHeight,
+      srcTxId: executionContext.contractDefinition.srcTxId
+    });
     this.logger.debug('context', benchmark.elapsed());
     benchmark.reset();
     const result = await stateEvaluator.eval(executionContext, currentTx || []);

src/core/modules/StateEvaluator.ts

@@ -1,4 +1,4 @@
-import { ExecutionContext, GQLNodeInterface } from '@smartweave';
+import { ExecutionContext, GQLEdgeInterface, GQLNodeInterface } from '@smartweave';
 
 /**
  * Implementors of this class are responsible for evaluating contract's state
@@ -30,6 +30,8 @@ export class DefaultEvaluationOptions implements EvaluationOptions {
   ignoreExceptions = true;
 
   waitForConfirmation = false;
+
+  fcpOptimization = false;
 }
 
 // an interface for the contract EvaluationOptions - can be used to change the behaviour of some of the features.
@@ -40,4 +42,7 @@ export interface EvaluationOptions {
   // allow to wait for confirmation of the interaction transaction - this way
   // you will know, when the new interaction is effectively available on the network
   waitForConfirmation: boolean;
+
+  // experimental optimization for contracts that utilize the Foreign Call Protocol
+  fcpOptimization: boolean;
 }

src/core/modules/impl/DefaultStateEvaluator.ts

@@ -1,6 +1,7 @@
 import {
   Benchmark,
   ContractInteraction,
+  deepCopy,
   EvalStateResult,
   ExecutionContext,
   ExecutionContextModifier,
@@ -10,6 +11,7 @@ import {
   HandlerApi,
   InteractionResult,
   LoggerFactory,
+  MemCache,
   StateEvaluator,
   TagsParser
 } from '@smartweave';
@@ -19,6 +21,8 @@ import Arweave from 'arweave';
 export class DefaultStateEvaluator implements StateEvaluator {
   private readonly logger = LoggerFactory.INST.create('DefaultStateEvaluator');
 
+  private readonly transactionStateCache: MemCache<EvalStateResult<unknown>> = new MemCache();
+
   private readonly tagsParser = new TagsParser();
 
   constructor(
@@ -45,10 +49,10 @@ export class DefaultStateEvaluator implements StateEvaluator {
     currentTx: { interactionTxId: string; contractTxId: string }[]
   ): Promise<EvalStateResult<State>> {
     const stateEvaluationBenchmark = Benchmark.measure();
-    const evaluationOptions = executionContext.evaluationOptions;
+    const { ignoreExceptions } = executionContext.evaluationOptions;
 
     let currentState = baseState.state;
-    const validity = JSON.parse(JSON.stringify(baseState.validity));
+    let validity = deepCopy(baseState.validity);
 
     this.logger.info(
       `Evaluating state for ${executionContext.contractDefinition.txId} [${missingInteractions.length} non-cached of ${executionContext.sortedInteractions.length} all]`
@@ -64,14 +68,22 @@ export class DefaultStateEvaluator implements StateEvaluator {
     this.logger.trace('Init state', JSON.stringify(baseState.state));
 
     for (const missingInteraction of missingInteractions) {
-      this.logger.debug(
-        `${missingInteraction.node.id}: ${missingInteractions.indexOf(missingInteraction) + 1}/${
-          missingInteractions.length
-        } [of all:${executionContext.sortedInteractions.length}]`
-      );
-      const singleInteractionBenchmark = Benchmark.measure();
       const currentInteraction: GQLNodeInterface = missingInteraction.node;
 
+      this.logger.debug(
+        `[${executionContext.contractDefinition.txId}][${missingInteraction.node.id}]: ${
+          missingInteractions.indexOf(missingInteraction) + 1
+        }/${missingInteractions.length} [of all:${executionContext.sortedInteractions.length}]`
+      );
+
+      const state = await this.onNextIteration(currentInteraction, executionContext);
+      if (state !== null) {
+        this.logger.debug('Found in cache');
+        currentState = state.state;
+        validity = state.validity;
+      } else {
+        const singleInteractionBenchmark = Benchmark.measure();
+
         const inputTag = this.tagsParser.getInputTag(missingInteraction, executionContext.contractDefinition.txId);
         if (!inputTag) {
           this.logger.error(`Skipping tx with missing or invalid Input tag - ${currentInteraction.id}`);
@@ -99,32 +111,35 @@ export class DefaultStateEvaluator implements StateEvaluator {
 
         this.logResult<State>(result, currentInteraction, executionContext);
 
-      if (result.type === 'exception' && evaluationOptions.ignoreExceptions !== true) {
+        if (result.type === 'exception' && ignoreExceptions !== true) {
           throw new Error(`Exception while processing ${JSON.stringify(interaction)}:\n${result.result}`);
         }
 
+        if (result.type === 'exception') {
+          this.logger.error('Credit:', (currentState as any).credit);
+        }
+
         validity[currentInteraction.id] = result.type === 'ok';
-
-      currentState = result.state;
-
-      // I'm really NOT a fan of this "modify" feature, but I don't have idea how to better
-      // implement the "evolve" feature
-      for (const { modify } of this.executionContextModifiers) {
         // strangely - state is for some reason modified for some contracts (eg. YLVpmhSq5JmLltfg6R-5fL04rIRPrlSU22f6RQ6VyYE)
         // when calling any async (even simple timeout) function here...
-        // that's a dumb workaround for this issue
+        // that's (ie. deepCopy) a dumb workaround for this issue
         // see https://github.com/ArweaveTeam/SmartWeave/pull/92 for more details
-        const stateCopy = JSON.parse(JSON.stringify(currentState));
-        executionContext = await modify<State>(currentState, executionContext);
-        currentState = stateCopy;
-      }
+        currentState = deepCopy(result.state);
+
         this.logger.debug('Interaction evaluation', singleInteractionBenchmark.elapsed());
+      }
 
       await this.onStateUpdate<State>(
         currentInteraction,
         executionContext,
         new EvalStateResult(currentState, validity)
       );
+
+      // I'm really NOT a fan of this "modify" feature, but I don't have idea how to better
+      // implement the "evolve" feature
+      for (const { modify } of this.executionContextModifiers) {
+        executionContext = await modify<State>(currentState, executionContext);
+      }
     }
     this.logger.debug('State evaluation total:', stateEvaluationBenchmark.elapsed());
     return new EvalStateResult<State>(currentState, validity);
@@ -136,10 +151,16 @@ export class DefaultStateEvaluator implements StateEvaluator {
     executionContext: ExecutionContext<State, HandlerApi<State>>
   ) {
     if (result.type === 'exception') {
-      this.logger.error(`Executing of interaction: [${executionContext.contractDefinition.srcTxId} -> ${currentTx.id}] threw exception:`, `${result.errorMessage}`);
+      this.logger.error(
+        `Executing of interaction: [${executionContext.contractDefinition.srcTxId} -> ${currentTx.id}] threw exception:`,
+        `${result.errorMessage}`
+      );
     }
     if (result.type === 'error') {
-      this.logger.warn(`Executing of interaction: [${executionContext.contractDefinition.srcTxId} -> ${currentTx.id}] returned error:`, result.errorMessage);
+      this.logger.warn(
+        `Executing of interaction: [${executionContext.contractDefinition.srcTxId} -> ${currentTx.id}] returned error:`,
+        result.errorMessage
+      );
     }
   }
 
@@ -157,6 +178,25 @@ export class DefaultStateEvaluator implements StateEvaluator {
     executionContext: ExecutionContext<State, unknown>,
     state: EvalStateResult<State>
   ) {
-    // noop
+    if (executionContext.evaluationOptions.fcpOptimization) {
+      this.transactionStateCache.put(
+        `${executionContext.contractDefinition.txId}|${currentInteraction.id}`,
+        deepCopy(state)
+      );
+    }
+  }
+
+  async onNextIteration<State>(
+    currentInteraction: GQLNodeInterface,
+    executionContext: ExecutionContext<State>
+  ): Promise<EvalStateResult<State>> {
+    const cacheKey = `${executionContext.contractDefinition.txId}|${currentInteraction.id}`;
+    const cachedState = this.transactionStateCache.get(cacheKey);
+
+    if (cachedState == null) {
+      return null;
+    } else {
+      return deepCopy(cachedState as EvalStateResult<State>);
+    }
   }
 }

src/core/modules/impl/HandlerExecutorFactory.ts

@@ -49,6 +49,7 @@ export class HandlerExecutorFactory implements ExecutorFactory<HandlerApi<unknow
 
     // eslint-disable-next-line @typescript-eslint/no-this-alias
     const self = this;
+    const contractLogger = LoggerFactory.INST.create('Contract');
 
     return {
       async handle<Input, Result>(
@@ -59,11 +60,10 @@ export class HandlerExecutorFactory implements ExecutorFactory<HandlerApi<unknow
         currentTx: { interactionTxId: string; contractTxId: string }[]
       ): Promise<InteractionResult<State, Result>> {
         try {
-          const contractLogger = LoggerFactory.INST.create('Contract');
           const handler = contractFunction(swGlobal, BigNumber, clarity, contractLogger) as HandlerFunction<State, Input, Result>;
           const stateCopy = JSON.parse(JSON.stringify(state));
           swGlobal._activeTx = interactionTx;
-          self.logger.debug(`SmartWeave.contract.id:`, swGlobal.contract.id);
+          self.logger.trace(`SmartWeave.contract.id:`, swGlobal.contract.id);
 
           self.assignReadContractState<Input, State>(swGlobal, contractDefinition, executionContext, currentTx);
           self.assignViewContractState<Input, State>(swGlobal, contractDefinition, executionContext);
@@ -117,7 +117,9 @@ export class HandlerExecutorFactory implements ExecutorFactory<HandlerApi<unknow
         to: contractTxId,
         input
       });
-      const childContract = executionContext.smartweave.contract(contractTxId, executionContext.contract);
+      const childContract = executionContext.smartweave
+        .contract(contractTxId, executionContext.contract)
+        .setEvaluationOptions(executionContext.evaluationOptions);
 
       return await childContract.viewStateForTx(input, swGlobal._activeTx);
     };
@@ -130,12 +132,16 @@ export class HandlerExecutorFactory implements ExecutorFactory<HandlerApi<unknow
     currentTx: { interactionTxId: string; contractTxId: string }[]
   ) {
     swGlobal.contracts.readContractState = async (contractTxId: string, height?: number, returnValidity?: boolean) => {
+      const requestedHeight = height || swGlobal.block.height;
       this.logger.debug('swGlobal.readContractState call:', {
         from: contractDefinition.txId,
-        to: contractTxId
+        to: contractTxId,
+        height: requestedHeight,
+        transaction: swGlobal.transaction.id
       });
-      const requestedHeight = height || swGlobal.block.height;
-      const childContract = executionContext.smartweave.contract(contractTxId, executionContext.contract);
+      const childContract = executionContext.smartweave
+        .contract(contractTxId, executionContext.contract)
+        .setEvaluationOptions(executionContext.evaluationOptions);
 
       const stateWithValidity = await childContract.readState(requestedHeight, [
         ...(currentTx || []),

src/plugins/CacheableStateEvaluator.ts

@@ -1,4 +1,4 @@
-import { BlockHeightCacheResult, BlockHeightKey, BlockHeightSwCache } from '@smartweave/cache';
+import { BlockHeightCacheResult, BlockHeightKey, BlockHeightSwCache, MemCache } from '@smartweave/cache';
 import {
   DefaultStateEvaluator,
   EvalStateResult,
@@ -7,8 +7,9 @@ import {
   HandlerApi
 } from '@smartweave/core';
 import Arweave from 'arweave';
-import { GQLNodeInterface } from '@smartweave/legacy';
+import { GQLEdgeInterface, GQLNodeInterface } from '@smartweave/legacy';
 import { Benchmark, LoggerFactory } from '@smartweave/logging';
+import { deepCopy } from '@smartweave/utils';
 
 /**
  * An implementation of DefaultStateEvaluator that adds caching capabilities
@@ -77,6 +78,7 @@ export class CacheableStateEvaluator extends DefaultStateEvaluator {
           const index = missingInteractions.findIndex((tx) => tx.node.id === entry.interactionTxId);
           if (index !== -1) {
             this.cLogger.debug('Inf. Loop fix - removing interaction', {
+              height: missingInteractions[index].node.block.height,
               contractTxId: entry.contractTxId,
               interactionTxId: entry.interactionTxId
             });
@@ -87,7 +89,7 @@ export class CacheableStateEvaluator extends DefaultStateEvaluator {
 
       // if cache is up-to date - return immediately to speed-up the whole process
       if (missingInteractions.length === 0 && cachedState) {
-        this.cLogger.debug(`State up to requested  height [${requestedBlockHeight}]  fully cached!`);
+        this.cLogger.fatal(`State up to requested  height [${requestedBlockHeight}]  fully cached!`);
         return cachedState.cachedValue;
       }
     }
@@ -110,6 +112,8 @@ export class CacheableStateEvaluator extends DefaultStateEvaluator {
     executionContext: ExecutionContext<State>,
     state: EvalStateResult<State>
   ) {
+    await super.onStateUpdate(currentInteraction, executionContext, state);
+
     await this.cache.put(
       new BlockHeightKey(executionContext.contractDefinition.txId, currentInteraction.block.height),
       state