diff --git a/src/bricks/transformers/jq.test.ts b/src/bricks/transformers/jq.test.ts index 6f49950597..67a1af7f60 100644 --- a/src/bricks/transformers/jq.test.ts +++ b/src/bricks/transformers/jq.test.ts @@ -24,6 +24,7 @@ import { BusinessError } from "@/errors/businessErrors"; import { serializeError } from "serialize-error"; import { throwIfInvalidInput } from "@/runtime/runtimeUtils"; import { type RenderedArgs } from "@/types/runtimeTypes"; +import { range } from "lodash"; describe("smoke tests", () => { test("passes input to filter", async () => { @@ -40,6 +41,34 @@ describe("smoke tests", () => { await expect(promise).resolves.toStrictEqual(42); }); + + test("can run concurrently", async () => { + // Smoke test we don't get `generic error, no stack` errors when running concurrently on node. + // Pick a number that's quick-enough to run on CI + const runCount = 20; + + const brick = new JQTransformer(); + const values = Promise.all( + range(runCount).map(async (number) => + brick.transform( + unsafeAssumeValidArg({ + filter: ".foo.data", + data: { foo: { data: number } }, + }), + { + ctxt: {}, + root: null, + logger: new ConsoleLogger(), + runPipeline: neverPromise, + runRendererPipeline: neverPromise, + } + ) + ) + ); + + // There shouldn't be any interference between the concurrent runs + await expect(values).resolves.toStrictEqual(range(runCount).map((n) => n)); + }); }); describe("ctxt", () => { @@ -59,19 +88,32 @@ describe("ctxt", () => { }); }); -describe("parse compile error", () => { - test("compile error has correct metadata", async () => { +describe("json", () => { + test("string data is not interpreted", async () => { + const promise = new JQTransformer().transform( + unsafeAssumeValidArg({ filter: ".", data: "[]" }), + { + ctxt: {}, + root: null, + logger: new ConsoleLogger(), + runPipeline: neverPromise, + runRendererPipeline: neverPromise, + } + ); + + // String is returned as-is, not as a JSON array + await expect(promise).resolves.toStrictEqual("[]"); + }); +}); + +describe("jq compilation errors", () => { + test("error metadata matches", async () => { try { - await new JQTransformer().transform( - unsafeAssumeValidArg({ filter: '"" | fromdate', data: {} }), - { - ctxt: {}, - root: null, - logger: new ConsoleLogger(), - runPipeline: neverPromise, - runRendererPipeline: neverPromise, - } - ); + await throwIfInvalidInput(new JQTransformer(), { + filter: 42, + data: {}, + } as unknown as RenderedArgs); + expect.fail("Invalid test, expected validateInput to throw"); } catch (error) { expect(serializeError(error)).toStrictEqual({ name: "InputValidationError", @@ -80,24 +122,35 @@ describe("parse compile error", () => { message: expect.toBeString(), stack: expect.toBeString(), errors: [ + { + error: expect.toBeString(), + instanceLocation: "#", + keyword: "properties", + keywordLocation: "#/properties", + }, { error: expect.toBeString(), instanceLocation: "#/filter", - keyword: "format", - keywordLocation: "#/properties/filter/format", + keyword: "type", + keywordLocation: "#/properties/filter/type", }, ], }); } }); - test("error metadata matches", async () => { + test("compile error has correct metadata", async () => { try { - await throwIfInvalidInput(new JQTransformer(), { - filter: 42, - data: {}, - } as unknown as RenderedArgs); - expect.fail("Invalid test, expected validateInput to throw"); + await new JQTransformer().transform( + unsafeAssumeValidArg({ filter: '"', data: {} }), + { + ctxt: {}, + root: null, + logger: new ConsoleLogger(), + runPipeline: neverPromise, + runRendererPipeline: neverPromise, + } + ); } catch (error) { expect(serializeError(error)).toStrictEqual({ name: "InputValidationError", @@ -106,27 +159,21 @@ describe("parse compile error", () => { message: expect.toBeString(), stack: expect.toBeString(), errors: [ - { - error: expect.toBeString(), - instanceLocation: "#", - keyword: "properties", - keywordLocation: "#/properties", - }, { error: expect.toBeString(), instanceLocation: "#/filter", - keyword: "type", - keywordLocation: "#/properties/filter/type", + keyword: "format", + keywordLocation: "#/properties/filter/format", }, ], }); } }); - test("invalid fromdate", async () => { + test("missing brace", async () => { // https://github.com/pixiebrix/pixiebrix-extension/issues/3216 const promise = new JQTransformer().transform( - unsafeAssumeValidArg({ filter: '"" | fromdate', data: {} }), + unsafeAssumeValidArg({ filter: "{", data: {} }), { ctxt: {}, root: null, @@ -138,14 +185,14 @@ describe("parse compile error", () => { await expect(promise).rejects.toThrow(InputValidationError); await expect(promise).rejects.toThrow( - 'date "" does not match format "%Y-%m-%dT%H:%M:%SZ"' + "Unexpected end of jq filter, are you missing a parentheses, brace, and/or quote mark?" ); }); - test("missing brace", async () => { + test("multiple compile errors", async () => { // https://github.com/pixiebrix/pixiebrix-extension/issues/3216 const promise = new JQTransformer().transform( - unsafeAssumeValidArg({ filter: "{", data: {} }), + unsafeAssumeValidArg({ filter: "a | b", data: {} }), { ctxt: {}, root: null, @@ -157,10 +204,12 @@ describe("parse compile error", () => { await expect(promise).rejects.toThrow(InputValidationError); await expect(promise).rejects.toThrow( - "Unexpected end of jq filter, are you missing a parentheses, brace, and/or quote mark?" + "Invalid jq filter, see error log for details" ); }); +}); +describe("jq execution errors", () => { test("null iteration", async () => { // https://github.com/pixiebrix/pixiebrix-extension/issues/3216 const promise = new JQTransformer().transform( @@ -177,4 +226,92 @@ describe("parse compile error", () => { await expect(promise).rejects.toThrow(BusinessError); await expect(promise).rejects.toThrow("Cannot iterate over null (null)"); }); + + test("invalid fromdate", async () => { + // https://github.com/pixiebrix/pixiebrix-extension/issues/3216 + const promise = new JQTransformer().transform( + unsafeAssumeValidArg({ filter: '"" | fromdate', data: {} }), + { + ctxt: {}, + root: null, + logger: new ConsoleLogger(), + runPipeline: neverPromise, + runRendererPipeline: neverPromise, + } + ); + + await expect(promise).rejects.toThrow(BusinessError); + await expect(promise).rejects.toThrow( + 'date "" does not match format "%Y-%m-%dT%H:%M:%SZ"' + ); + }); +}); + +describe("known jq-web bugs and quirks", () => { + test("Error if no result set produced", async () => { + // https://github.com/fiatjaf/jq-web/issues/32 + const promise = new JQTransformer().transform( + unsafeAssumeValidArg({ filter: ".[] | .Title", data: [] }), + { + ctxt: {}, + root: null, + logger: new ConsoleLogger(), + runPipeline: neverPromise, + runRendererPipeline: neverPromise, + } + ); + + await expect(promise).rejects.toThrow(BusinessError); + await expect(promise).rejects.toThrow( + "ensure the jq filter produces a result for the data" + ); + }); + + test.skip("running 2048+ times causes FS errors", async () => { + // https://github.com/fiatjaf/jq-web/issues/18 + // Skipping on CI because it's too slow to run this test + + const brick = new JQTransformer(); + const values = Promise.all( + range(3000).map(async (number) => + brick.transform( + unsafeAssumeValidArg({ + filter: ".foo.data", + data: { foo: { data: number } }, + }), + { + ctxt: {}, + root: null, + logger: new ConsoleLogger(), + runPipeline: neverPromise, + runRendererPipeline: neverPromise, + } + ) + ) + ); + + await expect(values).rejects.toThrow( + "Error opening stream, reload the page" + ); + + // Uncomment this when the bug in the dependency has been fixed + // await expect(values).resolves.toStrictEqual(range(3000).map((n) => n)); + }); + + test("error using modulo operator in filter", async () => { + // https://github.com/fiatjaf/jq-web/issues/19 + const promise = new JQTransformer().transform( + unsafeAssumeValidArg({ filter: "1 % 1", data: [] }), + { + ctxt: {}, + root: null, + logger: new ConsoleLogger(), + runPipeline: neverPromise, + runRendererPipeline: neverPromise, + } + ); + + await expect(promise).rejects.toThrow(BusinessError); + await expect(promise).rejects.toThrow("wA is not a function"); + }); }); diff --git a/src/bricks/transformers/jq.ts b/src/bricks/transformers/jq.ts index b6c6284318..03b25cd9c7 100644 --- a/src/bricks/transformers/jq.ts +++ b/src/bricks/transformers/jq.ts @@ -20,13 +20,43 @@ import { type BrickArgs, type BrickOptions } from "@/types/runtimeTypes"; import { type Schema } from "@/types/schemaTypes"; import { propertiesToSchema } from "@/validators/generic"; import { InputValidationError } from "@/bricks/errors"; -import { isErrorObject } from "@/errors/errorHelpers"; +import { getErrorMessage, isErrorObject } from "@/errors/errorHelpers"; import { BusinessError } from "@/errors/businessErrors"; import { applyJq } from "@/sandbox/messenger/executor"; import { isNullOrBlank } from "@/utils/stringUtils"; +import { retryWithJitter } from "@/utils/promiseUtils"; const jqStacktraceRegexp = /jq: error \(at :0\): (?.*)/; +// https://github.com/fiatjaf/jq-web/issues/32 +const JSON_ERROR = "Unexpected end of JSON input"; + +// https://github.com/fiatjaf/jq-web/issues/31 +const GENERIC_ERROR = "generic error, no stack"; + +// https://github.com/fiatjaf/jq-web/issues/18 +const FS_STREAM_ERROR = "FS error"; + +const MAX_TRANSIENT_ERROR_RETRIES = 3; + +/** + * Return true for jq errors that might be transient. + * + * We're excluding FS_STREAM_ERROR because it most likely indicates emscripten has hit the stream limit, so additional + * retries would not succeed: https://github.com/fiatjaf/jq-web/issues/18 + * + * JSON_ERROR can be deterministic for filters/data that produce not result set, but we've also seen some error + * telemetry indicating it might also be transient. + * See https://www.notion.so/native/pixiebrix/e76066f260494677a2416ed50b4cfba8 + */ +function isTransientError(error: unknown): boolean { + return ( + isErrorObject(error) && + (error.message.includes(JSON_ERROR) || + error.message.includes(GENERIC_ERROR)) + ); +} + export class JQTransformer extends TransformerABC { override async isPure(): Promise { return true; @@ -57,47 +87,75 @@ export class JQTransformer extends TransformerABC { async transform( { filter, data }: BrickArgs, - { ctxt, logger }: BrickOptions + { ctxt }: BrickOptions ): Promise { + // This is the legacy behavior, back from runtime v1 when there wasn't explicit data flow. const input = isNullOrBlank(data) ? ctxt : data; - logger.debug("Running jq transform", { filter, data, ctxt, input }); - try { - return await applyJq({ input, filter }); + return await retryWithJitter(async () => applyJq({ input, filter }), { + retries: MAX_TRANSIENT_ERROR_RETRIES, + shouldRetry: isTransientError, + // Provide just enough jitter that two problematic jq calls don't happen again at the same time + maxDelayMillis: 25, + }); } catch (error) { - // The message length check is there because the JQ error message sometimes is cut and if it is we try to parse the stacktrace - // See https://github.com/pixiebrix/pixiebrix-extension/issues/3216 - if ( - !isErrorObject(error) || - (error.message.length > 13 && !error.message.includes("compile error")) - ) { - // Unless there's bug in jq itself, if there's an error at this point, it's business error - if (isErrorObject(error)) { - throw new BusinessError(error.message, { cause: error }); + if (isErrorObject(error)) { + if (error.message.includes(GENERIC_ERROR)) { + // Give a more user-friendly error message for emscripten stream issues out of the user's control + // https://github.com/fiatjaf/jq-web/issues/31 + throw new Error("Unable to run jq, try again", { cause: error }); + } + + if (error.message.includes(JSON_ERROR)) { + // Give a more informative error message for issue cause by the filter/data combination. + // For example, this error can occur for a `.[]` filter when the data is an empty array. + throw new BusinessError( + "Unexpected end of JSON input, ensure the jq filter produces a result for the data", + { cause: error } + ); + } + + if (error.message.includes(FS_STREAM_ERROR)) { + throw new BusinessError("Error opening stream, reload the page"); + } + + // Prefer the full error message from the stack trace, if available, because jq/emscripten may truncate the + // message in the thrown error: https://github.com/pixiebrix/pixiebrix-extension/issues/3216 + const stackMatch = jqStacktraceRegexp.exec(error.stack); + if (stackMatch?.groups?.message) { + throw new BusinessError(stackMatch.groups.message.trim()); + } + + if (error.message.includes("compile error")) { + const message = error.stack.includes("unexpected $end") + ? "Unexpected end of jq filter, are you missing a parentheses, brace, and/or quote mark?" + : "Invalid jq filter, see error log for details"; + + throw new InputValidationError( + // The message does not appear to make its way to ErrorItems on the backend + // FIXME: https://github.com/pixiebrix/pixiebrix-extension/issues/6405 + message, + this.inputSchema, + { filter, data: input }, + [ + { + keyword: "format", + keywordLocation: "#/properties/filter/format", + instanceLocation: "#/filter", + error: error.stack, + }, + ] + ); } - throw error; + // At this point, unless there's a bug in jq itself, it's a business error due to the filter/data combination + throw new BusinessError(error.message, { cause: error }); } - const message = error.stack.includes("unexpected $end") - ? "Unexpected end of jq filter, are you missing a parentheses, brace, and/or quote mark?" - : jqStacktraceRegexp.exec(error.stack)?.groups?.message?.trim() ?? - "Invalid jq filter, see error log for details"; - - throw new InputValidationError( - message, - this.inputSchema, - { filter, data: input }, - [ - { - keyword: "format", - keywordLocation: "#/properties/filter/format", - instanceLocation: "#/filter", - error: error.stack, - }, - ] - ); + // Report non error-objects as application errors, so we see them in our application error telemetry + const message = getErrorMessage(error); + throw new Error(`Error running jq: ${message}`); } } } diff --git a/src/utils/promiseUtils.test.ts b/src/utils/promiseUtils.test.ts index b9b121c117..eb744940fb 100644 --- a/src/utils/promiseUtils.test.ts +++ b/src/utils/promiseUtils.test.ts @@ -15,9 +15,9 @@ * along with this program. If not, see . */ -// From https://github.com/sindresorhus/p-memoize/blob/52fe6052ff2287f528c954c4c67fc5a61ff21360/test.ts#LL198 -import { memoizeUntilSettled } from "@/utils/promiseUtils"; +import { memoizeUntilSettled, retryWithJitter } from "@/utils/promiseUtils"; +// From https://github.com/sindresorhus/p-memoize/blob/52fe6052ff2287f528c954c4c67fc5a61ff21360/test.ts#LL198 test("memoizeUntilSettled", async () => { let index = 0; @@ -28,3 +28,81 @@ test("memoizeUntilSettled", async () => { expect(await memoized()).toBe(2); expect(await Promise.all([memoized(), memoized()])).toStrictEqual([3, 3]); }); + +describe("retryWithJitter", () => { + test("retry count excludes initial attempt", async () => { + const fn = jest.fn(async () => 1); + const result = retryWithJitter(fn, { + retries: 0, + }); + await expect(result).resolves.toEqual(1); + expect(fn).toHaveBeenCalledTimes(1); + }); + + test("no retries", async () => { + const fn = jest.fn(async () => { + throw new Error("error"); + }); + const result = retryWithJitter(fn, { + retries: 0, + }); + await expect(result).rejects.toThrow("error"); + expect(fn).toHaveBeenCalledTimes(1); + }); + + test("it executes a function successfully and returns the result", async () => { + const fn = jest.fn(async () => 1); + const result = await retryWithJitter(fn, { + retries: 3, + }); + expect(result).toBe(1); + expect(fn).toHaveBeenCalledTimes(1); + }); + + test("it retries a function that fails once and returns the result", async () => { + const fn = jest.fn(async () => { + if (fn.mock.calls.length === 1) { + throw new Error("error"); + } + + return 1; + }); + const result = await retryWithJitter(fn, { + retries: 3, + }); + expect(result).toBe(1); + expect(fn).toHaveBeenCalledTimes(2); + }); + + test("it throws an error if the function fails more than the max retries", async () => { + const fn = jest.fn(async () => { + throw new Error("error"); + }); + + await expect( + retryWithJitter(fn, { + retries: 3, + }) + ).rejects.toThrow("error"); + expect(fn).toHaveBeenCalledTimes(3); + }); + + test("it retries on the specified error, and throws on all other errors", async () => { + const fn = jest.fn(async () => { + if (fn.mock.calls.length === 1) { + throw new Error("a specified error"); + } + + throw new Error("different non-specified error"); + }); + + await expect( + retryWithJitter(fn, { + retries: 3, + shouldRetry: (error) => + (error as Error).message.includes("a specified error"), + }) + ).rejects.toThrow("different non-specified error"); + expect(fn).toHaveBeenCalledTimes(2); + }); +}); diff --git a/src/utils/promiseUtils.ts b/src/utils/promiseUtils.ts index 8072d7147c..e266fae802 100644 --- a/src/utils/promiseUtils.ts +++ b/src/utils/promiseUtils.ts @@ -138,6 +138,43 @@ export async function pollUntilTruthy( } while (Date.now() < endBy); } +/** + * Retry with delay jitter. + * @param fn the function to execute + * @param retries the number of times to retry, excluding the initial attempt + * @param shouldRetry whether to retry on a given error; defaults to always retrying + * @param maxDelayMillis the maximum delay between retries, in milliseconds + */ +export async function retryWithJitter( + fn: () => Promise, + { + retries = 1, + shouldRetry = () => true, + maxDelayMillis = 100, + }: { + retries?: number; + shouldRetry?: (error: unknown) => boolean; + maxDelayMillis?: number; + } +): Promise { + for (let attemptCount = 0; attemptCount < retries + 1; attemptCount++) { + try { + // eslint-disable-next-line no-await-in-loop -- retry use-case is an exception to the rule https://eslint.org/docs/latest/rules/no-await-in-loop#when-not-to-use-it + return await fn(); + } catch (error) { + if (!shouldRetry(error) || attemptCount >= retries - 1) { + throw error; + } + + // eslint-disable-next-line no-await-in-loop -- retry use-case is an exception to the rule + await sleep(Math.random() * maxDelayMillis); + } + } + + // Can't reach due to check in catch block, unless retries is 0 + throw new Error("retries must be >= 0"); +} + /** * Returns a new object with all the values from the original resolved */