Skip to content

Commit

Permalink
fix: Handle rejected promises
Browse files Browse the repository at this point in the history
Note an event update for a return event for a rejected promise
will contain both `exception` and `return_value` fields to
disambiguate with the case when the returning function throws
an exception directly.
  • Loading branch information
dividedmind committed Dec 20, 2023
1 parent 428ca2d commit 8507ede
Show file tree
Hide file tree
Showing 5 changed files with 198 additions and 16 deletions.
82 changes: 80 additions & 2 deletions src/__tests__/recorder.test.ts
Original file line number Diff line number Diff line change
@@ -1,9 +1,11 @@
/* eslint-disable @typescript-eslint/unbound-method */
import AppMap from "../AppMap";
import { createTestFn } from "./helpers";
import Recording from "../Recording";
import { resetObjectIds } from "../parameter";
import * as recorder from "../recorder";
import { pauseRecorder, resumeRecorder } from "../recorderPause";
import Recording from "../Recording";
import { getTime } from "../util/getTime";
import { createTestFn } from "./helpers";

describe(recorder.record, () => {
it("records the function call", () => {
Expand Down Expand Up @@ -48,8 +50,84 @@ describe(recorder.record, () => {
});
});

describe(recorder.fixReturnEventIfPromiseResult, () => {
it("records a fix up after the promise resolves", async () => {
const promise = Promise.resolve("resolved");
const result = recorder.fixReturnEventIfPromiseResult(
promise,
returnEvent,
callEvent,
getTime(),
);

await expect(result).resolves.toBe("resolved");

expect(Recording.prototype.fixup).toBeCalledTimes(1);
expect(Recording.prototype.fixup).toBeCalledWith({
...returnEvent,
return_value: {
class: "Promise",
value: "Promise { 'resolved' }",
object_id: 1,
},
elapsed: 0,
});
});

it("records a fix up after the promise rejects", async () => {
const promise = Promise.reject(new Error("test"));
const result = recorder.fixReturnEventIfPromiseResult(
promise,
returnEvent,
callEvent,
getTime(),
);
await expect(result).rejects.toThrowError("test");

expect(Recording.prototype.fixup).toBeCalledTimes(1);

// this should have both return_value and exceptions
expect(Recording.prototype.fixup).toBeCalledWith({
...returnEvent,
return_value: {
class: "Promise",
value: "Promise { <rejected> }",
object_id: 2,
},
exceptions: [
{
class: "Error",
message: "test",
object_id: 1,
},
],
elapsed: 0,
});
});

const callEvent: AppMap.FunctionCallEvent = {
event: "call",
defined_class: "Test",
id: 42,
method_id: "test",
static: true,
thread_id: 0,
};
const returnEvent: AppMap.FunctionReturnEvent = {
event: "return",
id: 43,
parent_id: 42,
thread_id: 0,
return_value: {
class: "Promise",
value: "Promise { <pending> }",
},
};
});

afterEach(() => {
jest.clearAllMocks();
resetObjectIds();
});

jest.mock("../Recording");
Expand Down
8 changes: 7 additions & 1 deletion src/parameter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -70,11 +70,17 @@ function propertiesSchema(
}

let nextId = 1;
const objectIds = new WeakMap<object, number>();
let objectIds = new WeakMap<object, number>();

export function objectId(object: object | null): number {
if (object === null) return 0;
const id = objectIds.get(object) ?? nextId++;
if (!objectIds.has(object)) objectIds.set(object, id);
return id;
}

// for testing purposes
export function resetObjectIds() {
nextId = 1;
objectIds = new WeakMap();
}
33 changes: 28 additions & 5 deletions src/recorder.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,8 +3,9 @@ import { isPromise } from "node:util/types";

import AppMap from "./AppMap";
import Recording, { writtenAppMaps } from "./Recording";
import { makeReturnEvent } from "./event";
import { makeExceptionEvent, makeReturnEvent } from "./event";
import { info } from "./message";
import { objectId } from "./parameter";
import { recorderPaused } from "./recorderPause";
import { FunctionInfo } from "./registry";
import commonPathPrefix from "./util/commonPathPrefix";
Expand Down Expand Up @@ -45,10 +46,32 @@ export function fixReturnEventIfPromiseResult(
startTime: number,
) {
if (isPromise(result) && returnEvent.return_value?.value.includes("<pending>"))
return result.then(() => {
recording.fixup(makeReturnEvent(returnEvent.id, callEvent.id, result, getTime() - startTime));
return result;
});
return result.then(
() => {
recording.fixup(
makeReturnEvent(returnEvent.id, callEvent.id, result, getTime() - startTime),
);
return result;
},
(reason) => {
const event = makeExceptionEvent(
returnEvent.id,
callEvent.id,
reason,
getTime() - startTime,
);
// add return_value too, so it's not unambiguous whether the function
// threw or returned a promise which then rejected
event.return_value = {
class: "Promise",
// don't repeat the exception info
value: "Promise { <rejected> }",
object_id: objectId(result),
};
recording.fixup(event);
return result;
},
);

return result;
}
Expand Down
85 changes: 79 additions & 6 deletions test/__snapshots__/simple.test.ts.snap
Original file line number Diff line number Diff line change
Expand Up @@ -205,13 +205,13 @@ exports[`mapping a simple script 1`] = `
{
"children": [
{
"location": "./index.js:13",
"location": "./index.js:14",
"name": "immediatePromise",
"static": true,
"type": "function",
},
{
"location": "./index.js:17",
"location": "./index.js:18",
"name": "throws",
"static": true,
"type": "function",
Expand All @@ -238,6 +238,25 @@ exports[`mapping a simple script 1`] = `
},
],
"eventUpdates": {
"10": {
"elapsed": 31.337,
"event": "return",
"exceptions": [
{
"class": "Error",
"message": "throws intentionally",
"object_id": 5,
},
],
"id": 10,
"parent_id": 9,
"return_value": {
"class": "Promise",
"object_id": 3,
"value": "Promise { <rejected> }",
},
"thread_id": 0,
},
"8": {
"elapsed": 31.337,
"event": "return",
Expand All @@ -256,7 +275,7 @@ exports[`mapping a simple script 1`] = `
"defined_class": "index",
"event": "call",
"id": 1,
"lineno": 17,
"lineno": 18,
"method_id": "throws",
"parameters": [],
"path": "./index.js",
Expand Down Expand Up @@ -360,9 +379,15 @@ exports[`mapping a simple script 1`] = `
"defined_class": "index",
"event": "call",
"id": 9,
"lineno": 13,
"method_id": "immediatePromise",
"parameters": [],
"lineno": 8,
"method_id": "promised",
"parameters": [
{
"class": "Boolean",
"name": "ok",
"value": "false",
},
],
"path": "./index.js",
"static": true,
"thread_id": 0,
Expand All @@ -375,10 +400,58 @@ exports[`mapping a simple script 1`] = `
"return_value": {
"class": "Promise",
"object_id": 3,
"value": "Promise { <pending> }",
},
"thread_id": 0,
},
{
"defined_class": "index",
"event": "call",
"id": 11,
"lineno": 14,
"method_id": "immediatePromise",
"parameters": [],
"path": "./index.js",
"static": true,
"thread_id": 0,
},
{
"elapsed": 31.337,
"event": "return",
"id": 12,
"parent_id": 11,
"return_value": {
"class": "Promise",
"object_id": 4,
"value": "Promise { 'immediate' }",
},
"thread_id": 0,
},
{
"defined_class": "index",
"event": "call",
"id": 13,
"lineno": 18,
"method_id": "throws",
"parameters": [],
"path": "./index.js",
"static": true,
"thread_id": 0,
},
{
"elapsed": 31.337,
"event": "return",
"exceptions": [
{
"class": "Error",
"message": "throws intentionally",
"object_id": 5,
},
],
"id": 14,
"parent_id": 13,
"thread_id": 0,
},
],
"metadata": {
"app": "appmap-node",
Expand Down
6 changes: 4 additions & 2 deletions test/simple/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,9 @@ function foo(x) {
return x * 2;
}

async function promised() {
await setTimeout(100);
async function promised(ok = true) {
await setTimeout(10);
if (!ok) throws();
return "promised return";
}

Expand All @@ -28,4 +29,5 @@ try {

console.log(foo(42));
promised().then(console.log);
promised(false).catch(console.log);
immediatePromise().then(console.log);

0 comments on commit 8507ede

Please sign in to comment.