feat: Async context tracking

[zermelo-wisen]

Implement Async Tracking in AppMap-Node Agent Using AsyncLocalStorage

Problem

The current implementation of the AppMap-Node agent struggles with proper asynchronous tracking, leading to misleading call hierarchies. Specifically, the agent does not maintain the correct context of asynchronous computations, resulting in inaccuracies when representing operations that involve Promise or other asynchronous constructs.

For example:

function bar(x) { return x * 2; }

async function foo() {
  await setTimeout(() => 1, 100);
  console.log(bar(1));
}

foo();
console.log(bar(2));

In this case, the call to bar(1) is incorrectly represented as coming after bar(2) because the foo()'s context is lost early.

Analysis

The main issues with the current implementation are:

1. Fixup After Promise Settlements: Return events are only fixed up when Promise settlements are observed.
2. Early Context Closure: The context of an async function closes as soon as it returns, leading to incorrect parent-child relationships in the reported events.
3. Immediate Event Streaming: Events are streamed as they come, which can disrupt the correct chronological context, especially with async functions.

We need to update the tracking mechanism to keep the context alive throughout the async function's execution and ensure that events are accurately reported.

Proposed Changes

1. Context Preservation:

   • Use AsyncLocalStorage to preserve the execution context across asynchronous operations.
   • Ensure any asynchronous operations, such as await or callback procedures, maintain the correct parent context in the generated AppMaps.

2. Event Streaming:

   • Amend the event streaming logic to respect asynchronous boundaries instead of streaming events immediately.
   • Queue events until the corresponding async context finalizes, ensuring the correct call hierarchy is maintained.

Detailed Changes

1. Update Recording.ts:

   • Modify the function that handles function calls to use AsyncLocalStorage to store context information.
   • Adjust the logic that generates function return and exception events to account for async contexts.

2. Adjust Event Generation Logic:

   • Ensure that the fixupPromise function correctly associates the context of async operations.
   • Keep async contexts open until the async function fully completes.

3. Modify Event Emission:

   • Adjust how and when events are emitted to ensure they respect the actual call hierarchy within asynchronous flows.

4. Tests and Validation:

   • Update the relevant tests in test/jest/asyncLib.test.js and other relevant test files to validate the accuracy of the reported call hierarchies.
   • Ensure extensive tests cover various async scenarios to validate the new tracking mechanism's effectiveness.

Making these adjustments will significantly improve the accuracy of asynchronous tracking in the AppMap-Node agent, providing clearer and more accurate call hierarchies and execution flows in AppMaps.

Resolves #103

[zermelo-wisen]

Fixes #103.

The main objective of this PR is to enhance the AppMap-Node agent's ability to track asynchronous operations accurately. The previous implementation faced challenges in correctly maintaining the context of asynchronous computations, leading to inaccurate call hierarchies.

Here are some changes made to achieve this:

Changes in AppMapStream.ts

• Rename emit to push:
  • The emit function is renamed to push to better reflect its role in managing the event buffer and syncing.
  • This method ensures consistency across the codebase when queuing events.

Changes in Recording.ts

• Integration of AsyncLocalStorage:

  • Added AsyncLocalStorage from node:async_hooks to help preserve the context across asynchronous operations.
  • Introduced rootBuffer, asyncStorage, fork, run, and getContext methods to manage the asynchronous execution context.

• Context-Sensitive Event Emission:

  • The emit function checks whether the recording is running before emitting events.
  • Uses the async context (AsyncLocalStorage) to manage buffered events, preserving the call hierarchy and ensuring accurate representation.

• Enhanced Finish and Abandon Methods:

  • Adjusted to handle asynchronous contexts properly and ensure the event buffer is passed and disposed of correctly.

Changes in AppMapStream.test.ts and Recording.test.ts

• Updated the test files to reflect the renaming of emit to push.

Changes in prisma.ts

• Managed query method contexts to create sql events in the same async context with the function call events created to represent Prisma query methods.

An example AppMap produced from the added test.

Before the async tracking feature

After the async tracking feature:

[zermelo-wisen]

Added the ability to control async tracking via the async_tracking_timout filed in configuration file and the APPMAP_ASYNC_TRACKING_TIMEOUT environment variable. The environment variable takes precedence over the config file value. If neither is set, a default timeout of 3000 milliseconds is applied. Setting the value to 0 disables async tracking entirely.

Effects of the timeout value can easily be seen with this test:

https://github.com/getappmap/appmap-node/blob/16a861fb0c4c288c1b321f2cba7d55faaf46c95c/test/simple.test.ts#L124-L149

https://github.com/getappmap/appmap-node/blob/11e8a081ae36478de2288d28401a992ad61517df/test/simple/asyncTimeout.mjs#L1-L16

[appland-release]

:tada: This PR is included in version 2.24.0 :tada:

The release is available on:

• npm package (@latest dist-tag)
• GitHub release

Your semantic-release bot :package::rocket: