Propagation correlationIds in Typescript

The purpose of correlationIds.

• For checking how data transfer in one service, it for easy to check errors by watching the state of data pass through function.
• Check the cycle of one request in the microservice system. Like what is the starting point of it, the ending, and what happened when one request hit service.

AsyncLocalStorage

• Provide by async_hook. This class creates stores that stay coherent through asynchronous operations.Each instance of AsyncLocalStorage maintains an independent storage context. Multiple instances can safely exist simultaneously without the risk of interfering with each other's data.

Propagation correlationIds.

UseLocalStore

The decorator provides the storage of the function. When one function is executed, it can get this storage by calling getLocalStoreInRun

const asyncLocalStorage = new AsyncLocalStorage();

export const UseLocalStore = () => {
  return (
    _target: unknown,
    _propertyKey: string,
    descriptor: PropertyDescriptor
  ) => {
    const original = descriptor.value;
    if (typeof original === "function") {
      descriptor.value = function (...args: unknown[]) {
        return asyncLocalStorage.run(
          {
            correlationIds: {},
          } as AsyncLocalStore,
          () => {
            return original.apply(this, args);
          }
        );
      };
    } else {
      throw new Error("Only work with function");
    }
  };
};

export const getLocalStoreInRun = (): AsyncLocalStore => {
  return asyncLocalStorage.getStore() as AsyncLocalStore;
};

UseCorrelationId

• Simple as named, when the function begins, it will set correlation with the name be passed to this decorator. And when the function ends, it will delete the correlation.

import { randomUUID } from "crypto";
import { getLocalStoreInRun } from "./use-local-store.decorator";

export const UseCorrelationId = (correlationKey: string) => {
  return (
    _target: unknown,
    _propertyKey: string,
    descriptor: PropertyDescriptor
  ) => {
    const original = descriptor.value;
    if (typeof original === "function") {
      descriptor.value = async function (...args: unknown[]) {
        const localStore = getLocalStoreInRun();
        if (!localStore.correlationIds[correlationKey]) {
          localStore.correlationIds[correlationKey] = randomUUID();
          const result = await original.apply(this, args);
          delete localStore.correlationIds[correlationKey];
          return result;
        } else {
          return original.apply(this, args);
        }
      };
    } else {
      throw new Error("Only work with function");
    }
  };
};

Test class.

• I will write a sample class to figure out that the above decorator works as expected.

export class Foo {
  public static consoleLogEnable = true;

  public async loopBar() {
    for (let i = 1; i < 5; i++) {
      await this.bar(i);
      this.log(`${i} loopBar`);
    }
  }

  @UseLocalStore()
  @UseCorrelationId("loopBar")
  public async loopBarWithCorrelationIds() {
    for (let i = 1; i < 5; i++) {
      await this.barWithCorrelationIds(i);
      this.logWithCorrelationId(`${i} loopBar`);
    }
  }

  private async bar(i: number) {
    await Promise.resolve(); // Convert function to async function
    this.log(`${i.toString()} bar`);
  }

  @UseCorrelationId("barWithCorrelationIds")
  private async barWithCorrelationIds(i: number) {
    await Promise.resolve(); // Convert function to async function
    this.logWithCorrelationId(`${i.toString()} bar`);
  }

  private logWithCorrelationId(message: string) {
    const localStore = getLocalStoreInRun();
    Foo.consoleLogEnable &&
      console.log({
        message,
        correlationIds: localStore.correlationIds,
      });
  }

  private log(message: string) {
    Foo.consoleLogEnable &&
      console.log({
        message,
      });
  }
}

• Result

{
  message: '1 bar',
  correlationIds: {
    loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7',
    barWithCorrelationIds: '3a4b48fb-973c-41be-9922-628db127d3f4'
  }
}
{
  message: '1 loopBar',
  correlationIds: { loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7' }
}
{
  message: '2 bar',
  correlationIds: {
    loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7',
    barWithCorrelationIds: '05a2a602-c413-4fd6-ae65-f57d492ea46d'
  }
}
{
  message: '2 loopBar',
  correlationIds: { loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7' }
}
{
  message: '3 bar',
  correlationIds: {
    loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7',
    barWithCorrelationIds: '0ada30b3-7d65-4663-a51c-a28235a9cede'
  }
}
{
  message: '3 loopBar',
  correlationIds: { loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7' }
}
{
  message: '4 bar',
  correlationIds: {
    loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7',
    barWithCorrelationIds: 'b54f4f17-256a-4c4a-b48d-1d5b115814fb'
  }
}
{
  message: '4 loopBar',
  correlationIds: { loopBar: '248b1d9e-42c9-4163-80ac-4a22015447f7' }
}

Benchmarks.

• Code for the benchmark.

import { Suite } from "benchmark";
import { Foo } from "./foo.entity";

const foo = new Foo();
const suite = new Suite();
Foo.consoleLogEnable = false;
suite
  .add("Test log with no correlationId", {
    defer: true,
    fn: async function (deferred) {
      await foo.loopBar();
      deferred.resolve();
    },
  })
  .add("Test log with correlationIds", {
    defer: true,
    fn: async function (deferred) {
      await foo.loopBarWithCorrelationIds();
      deferred.resolve();
    },
  })
  .on("cycle", function (event: { target: any }) {
    console.log(String(event.target));
  })
  .on("complete", function () {
    console.log("Done");
  })
  .run();

Result.

Test log with no correlationId x 1,354,929 ops/sec ±1.56% (83 runs sampled)
Test log with correlationIds x 169,597 ops/sec ±2.91% (79 runs sampled)

So sad. Seem use async_hook to reduce the performance six times with normal function. I had tried with other generate functions but don't have any improvement.

Conclusion

• I think this function can reduce the number of parameters needed to pass to the child function. But need to consider about its performance, like I benchmarked, six times is not a small number. I hope that async_hooks can improve performance in the next version of nodejs.

I'm using node 18, typescript 4.9.4, and enabling emitDecoratorMetadata.