From 1a770775f20aafdf80b3da1ee7e3bed59a228021 Mon Sep 17 00:00:00 2001 From: rouzwelt Date: Thu, 6 Nov 2025 03:35:48 +0000 Subject: [PATCH] init --- src/core/process/order.test.ts | 64 ++++++++++++++++++++++++++++++++ src/core/process/order.ts | 36 +++++++++++++++--- src/core/process/receipt.test.ts | 12 ++++-- src/core/process/receipt.ts | 6 ++- src/core/process/round.test.ts | 18 ++++++--- src/core/process/round.ts | 10 +++-- 6 files changed, 125 insertions(+), 21 deletions(-) diff --git a/src/core/process/order.test.ts b/src/core/process/order.test.ts index d9bd0b21..a29bcc61 100644 --- a/src/core/process/order.test.ts +++ b/src/core/process/order.test.ts @@ -107,6 +107,8 @@ describe("Test processOrder", () => { expect(result.value.spanAttributes["details.order"]).toEqual("0xid"); expect(result.value.spanAttributes["details.pair"]).toBe("BUY/SELL"); expect(result.value.spanAttributes["details.orderbook"]).toEqual("0xorderbook"); + expect(result.value.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.quoteOrder"]).toHaveLength(2); expect(result.value.endTime).toBeTypeOf("number"); // ensure pair maps are updated on quote 0 @@ -134,6 +136,8 @@ describe("Test processOrder", () => { expect(result.error.spanAttributes["details.pair"]).toBe("BUY/SELL"); expect(result.error.spanAttributes["details.orderbook"]).toEqual("0xorderbook"); expect(result.error.endTime).toBeTypeOf("number"); + expect(result.error.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.error.spanAttributes["event.quoteOrder"]).toHaveLength(2); // ensure pair maps are updated on quote failure expect(mockOrderManager.removeFromPairMaps).toHaveBeenCalledWith(mockArgs.orderDetails); @@ -223,6 +227,16 @@ describe("Test processOrder", () => { expect(result.value.spanAttributes["details.inputToEthPrice"]).toBe("100"); expect(result.value.spanAttributes["details.outputToEthPrice"]).toBe("no-way"); expect(result.value.endTime).toBeTypeOf("number"); + expect(result.value.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.quoteOrder"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getPairMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getPairMarketPrice"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getEthMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getEthMarketPrice"]).toHaveLength(2); }); it('should set outputToEthPrice to "0" if getMarketPrice returns undefined for output and gasCoveragePercentage is "0"', async () => { @@ -254,6 +268,16 @@ describe("Test processOrder", () => { expect(result.value.spanAttributes["details.inputToEthPrice"]).toBe("100"); expect(result.value.spanAttributes["details.outputToEthPrice"]).toBe("0"); expect(result.value.endTime).toBeTypeOf("number"); + expect(result.value.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.quoteOrder"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getPairMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getPairMarketPrice"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getEthMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getEthMarketPrice"]).toHaveLength(2); }); it('should return FailedToGetEthPrice if getMarketPrice returns undefined and gasCoveragePercentage is not "0"', async () => { @@ -279,6 +303,12 @@ describe("Test processOrder", () => { expect(result.error.spanAttributes["details.pair"]).toBe("BUY/SELL"); expect(result.error.spanAttributes["details.orderbook"]).toEqual("0xorderbook"); expect(result.error.endTime).toBeTypeOf("number"); + expect(result.error.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.error.spanAttributes["event.quoteOrder"]).toHaveLength(2); + expect(result.error.spanAttributes["details.duration.getPairMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.error.spanAttributes["event.getPairMarketPrice"]).toHaveLength(2); }); it('should set input/outputToEthPrice to "0" if getMarketPrice returns undefined and gasCoveragePercentage is "0"', async () => { @@ -306,6 +336,16 @@ describe("Test processOrder", () => { expect(result.value.spanAttributes["details.pair"]).toBe("BUY/SELL"); expect(result.value.spanAttributes["details.orderbook"]).toEqual("0xorderbook"); expect(result.value.endTime).toBeTypeOf("number"); + expect(result.value.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.quoteOrder"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getPairMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getPairMarketPrice"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getEthMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getEthMarketPrice"]).toHaveLength(2); }); it("should return ok result if findBestTrade throws with noneNodeError", async () => { @@ -338,6 +378,18 @@ describe("Test processOrder", () => { expect(result.value.spanAttributes["details.noneNodeError"]).toBe(true); expect(result.value.spanAttributes["details.test"]).toBe("something"); expect(result.value.endTime).toBeTypeOf("number"); + expect(result.value.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.quoteOrder"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getPairMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getPairMarketPrice"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getEthMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getEthMarketPrice"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.findBestTrade"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.findBestTrade"]).toHaveLength(2); }); it("should return ok result if findBestTrade throws without noneNodeError", async () => { @@ -370,6 +422,18 @@ describe("Test processOrder", () => { expect(result.value.spanAttributes["details.noneNodeError"]).toBe(false); expect(result.value.spanAttributes["details.test"]).toBe("something"); expect(result.value.endTime).toBeTypeOf("number"); + expect(result.value.spanAttributes["details.duration.quoteOrder"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.quoteOrder"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getPairMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getPairMarketPrice"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.getEthMarketPrice"]).toBeGreaterThan( + 0, + ); + expect(result.value.spanAttributes["event.getEthMarketPrice"]).toHaveLength(2); + expect(result.value.spanAttributes["details.duration.findBestTrade"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.findBestTrade"]).toHaveLength(2); }); it("should proceed to processTransaction if all steps succeed (happy path)", async () => { diff --git a/src/core/process/order.ts b/src/core/process/order.ts index c97f3fb8..1a4eeb2d 100644 --- a/src/core/process/order.ts +++ b/src/core/process/order.ts @@ -59,7 +59,7 @@ export async function processOrder( spanAttributes["details.pair"] = tokenPair; spanAttributes["details.orderbook"] = orderDetails.orderbook; - spanAttributes["event.quoteOrder"] = performance.now(); + const quoteOrderTime = performance.now(); try { await this.orderManager.quoteOrder(orderDetails); if (orderDetails.takeOrder.quote?.maxOutput === 0n) { @@ -67,6 +67,9 @@ export async function processOrder( // of orders with 0 maxoutput this will make counterparty lookups faster this.orderManager.removeFromPairMaps(orderDetails); const endTime = performance.now(); + const quoteOrderDuration = endTime - quoteOrderTime; + spanAttributes["details.duration.quoteOrder"] = quoteOrderDuration; + spanAttributes["event.quoteOrder"] = [quoteOrderTime, quoteOrderDuration]; return async () => { return Result.ok({ ...baseResult, @@ -80,6 +83,9 @@ export async function processOrder( } catch (e) { this.orderManager.removeFromPairMaps(orderDetails); const endTime = performance.now(); + const quoteOrderDuration = endTime - quoteOrderTime; + spanAttributes["details.duration.quoteOrder"] = quoteOrderDuration; + spanAttributes["event.quoteOrder"] = [quoteOrderTime, quoteOrderDuration]; return async () => Result.err({ ...baseResult, @@ -90,6 +96,9 @@ export async function processOrder( } // record order quote details in span attributes + const quoteOrderDuration = performance.now() - quoteOrderTime; + spanAttributes["details.duration.quoteOrder"] = quoteOrderDuration; + spanAttributes["event.quoteOrder"] = [quoteOrderTime, quoteOrderDuration]; spanAttributes["details.quote"] = JSON.stringify({ maxOutput: formatUnits(orderDetails.takeOrder.quote!.maxOutput, 18), ratio: formatUnits(orderDetails.takeOrder.quote!.ratio, 18), @@ -143,7 +152,7 @@ export async function processOrder( } // record market price in span attributes - spanAttributes["event.getPairMarketPrice"] = performance.now(); + const getPairMarketPriceTime = performance.now(); const marketPriceResult = await this.state.getMarketPrice( fromToken, toToken, @@ -155,9 +164,15 @@ export async function processOrder( parseUnits(marketPriceResult.value.price, 18), ); } + const getPairMarketPriceDuration = performance.now() - getPairMarketPriceTime; + spanAttributes["details.duration.getPairMarketPrice"] = getPairMarketPriceDuration; + spanAttributes["event.getPairMarketPrice"] = [ + getPairMarketPriceTime, + getPairMarketPriceDuration, + ]; // get in/out tokens to eth price - spanAttributes["event.getEthMarketPrice"] = performance.now(); + const getEthMarketPriceTime = performance.now(); let inputToEthPrice = ""; let outputToEthPrice = ""; const inputToEthPriceResult = await this.state.getMarketPrice( @@ -204,8 +219,11 @@ export async function processOrder( spanAttributes["details.gasPriceL1"] = this.state.l1GasPrice.toString(); } spanAttributes["gasPriceMultiplier"] = this.state.gasPriceMultiplier; + const getEthMarketPriceDuration = performance.now() - getEthMarketPriceTime; + spanAttributes["details.duration.getEthMarketPrice"] = getEthMarketPriceDuration; + spanAttributes["event.getEthMarketPrice"] = [getEthMarketPriceTime, getEthMarketPriceDuration]; - spanAttributes["event.findBestTrade"] = performance.now(); + const findBestTradeTime = performance.now(); const trade = await this.findBestTrade({ orderDetails, signer, @@ -214,10 +232,11 @@ export async function processOrder( inputToEthPrice, outputToEthPrice, }); + const endTime = performance.now(); if (trade.isErr()) { const result: ProcessOrderSuccess = { ...baseResult, - endTime: performance.now(), + endTime, }; // record all span attributes for (const attrKey in trade.error.spanAttributes) { @@ -229,6 +248,9 @@ export async function processOrder( } else { spanAttributes["details.noneNodeError"] = false; } + const findBestTradeDuration = endTime - findBestTradeTime; + spanAttributes["details.duration.findBestTrade"] = findBestTradeDuration; + spanAttributes["event.findBestTrade"] = [findBestTradeTime, findBestTradeDuration]; return async () => Result.ok(result); } @@ -246,6 +268,9 @@ export async function processOrder( spanAttributes[attrKey] = trade.value.spanAttributes[attrKey]; } } + const findBestTradeDuration = endTime - findBestTradeTime; + spanAttributes["details.duration.findBestTrade"] = findBestTradeDuration; + spanAttributes["event.findBestTrade"] = [findBestTradeTime, findBestTradeDuration]; // get block number let blockNumber: number; @@ -263,7 +288,6 @@ export async function processOrder( } // process the found transaction opportunity - spanAttributes["event.processTransaction"] = performance.now(); return processTransaction({ rawtx, signer, diff --git a/src/core/process/receipt.test.ts b/src/core/process/receipt.test.ts index 714aa40a..6d32de8b 100644 --- a/src/core/process/receipt.test.ts +++ b/src/core/process/receipt.test.ts @@ -117,7 +117,8 @@ describe("Test processReceipt", () => { expect(result.value.spanAttributes["details.netProfit"]).toBeDefined(); expect(result.value.spanAttributes["details.netProfit"]).toBeTypeOf("number"); expect(result.value.spanAttributes["details.gasCostL1"]).toBeUndefined(); - expect(result.value.spanAttributes["details.mineTime"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["details.duration.transaction"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.transaction"]).toHaveLength(2); }); it("should calculate gas cost correctly including L1 fee", async () => { @@ -149,7 +150,8 @@ describe("Test processReceipt", () => { expect(result.value.inputTokenIncome).toBeUndefined(); expect(result.value.outputTokenIncome).toBeUndefined(); expect(result.value.endTime).toBeTypeOf("number"); - expect(result.value.spanAttributes["details.mineTime"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["details.duration.transaction"]).toBeGreaterThan(0); + expect(result.value.spanAttributes["event.transaction"]).toHaveLength(2); }); }); @@ -174,7 +176,8 @@ describe("Test processReceipt", () => { expect(result.error.error).toBe(mockSimulation); expect(result.error.txUrl).toBe(mockArgs.txUrl); expect(result.error.spanAttributes["txNoneNodeError"]).toBe(true); - expect(result.error.spanAttributes["details.mineTime"]).toBeGreaterThan(0); + expect(result.error.spanAttributes["details.duration.transaction"]).toBeGreaterThan(0); + expect(result.error.spanAttributes["event.transaction"]).toHaveLength(2); expect(result.error.endTime).toBeTypeOf("number"); }); @@ -210,7 +213,8 @@ describe("Test processReceipt", () => { assert(result.isErr()); expect(result.error.spanAttributes["txNoneNodeError"]).toBe(false); - expect(result.error.spanAttributes["details.mineTime"]).toBeGreaterThan(0); + expect(result.error.spanAttributes["details.duration.transaction"]).toBeGreaterThan(0); + expect(result.error.spanAttributes["event.transaction"]).toHaveLength(2); expect(result.error.endTime).toBeTypeOf("number"); }); diff --git a/src/core/process/receipt.ts b/src/core/process/receipt.ts index 0963cd01..78b080a1 100644 --- a/src/core/process/receipt.ts +++ b/src/core/process/receipt.ts @@ -48,7 +48,11 @@ export async function processReceipt({ }: ProcessReceiptArgs): Promise> { const l1Fee = getL1Fee(receipt); const gasCost = receipt.effectiveGasPrice * receipt.gasUsed + l1Fee; - baseResult.spanAttributes["details.mineTime"] = performance.now() - txSendTime; + + // record transaction time + const txMineDuration = performance.now() - txSendTime; + baseResult.spanAttributes["details.duration.transaction"] = txMineDuration; + baseResult.spanAttributes["event.transaction"] = [txSendTime, txMineDuration]; // keep track of gas consumption of the account and bounty token baseResult.gasCost = gasCost; diff --git a/src/core/process/round.test.ts b/src/core/process/round.test.ts index 11225ba4..7aa75cea 100644 --- a/src/core/process/round.test.ts +++ b/src/core/process/round.test.ts @@ -806,7 +806,10 @@ describe("Test finalizeRound", () => { const mockSettle = vi.fn().mockResolvedValue( Result.ok({ status: ProcessOrderStatus.FoundOpportunity, - spanAttributes: { "event.something": 1234, "event.another": 5678 }, + spanAttributes: { + "event.something": [1234, 456], + "event.another": [5678, 123], + }, endTime: 789, }), ); @@ -822,8 +825,8 @@ describe("Test finalizeRound", () => { const addEventSpy = vi.spyOn(PreAssembledSpan.prototype, "addEvent"); await finalizeRound.call(mockSolver, settlements); - expect(addEventSpy).toHaveBeenCalledWith("something", undefined, 1234); - expect(addEventSpy).toHaveBeenCalledWith("another", undefined, 5678); + expect(addEventSpy).toHaveBeenCalledWith("something", { duration: 456 }, 1234); + expect(addEventSpy).toHaveBeenCalledWith("another", { duration: 123 }, 5678); addEventSpy.mockRestore(); }); @@ -1337,7 +1340,10 @@ describe("Test finalizeRound", () => { const mockSettle = vi.fn().mockResolvedValue( Result.err({ reason: "unknown_reason", - spanAttributes: { "event.something": 1234, "event.another": 5678 }, + spanAttributes: { + "event.something": [1234, 456], + "event.another": [5678, 123], + }, status: "failed", error: new Error("unexpected"), endTime: 789, @@ -1355,8 +1361,8 @@ describe("Test finalizeRound", () => { const addEventSpy = vi.spyOn(PreAssembledSpan.prototype, "addEvent"); await finalizeRound.call(mockSolver, settlements); - expect(addEventSpy).toHaveBeenCalledWith("something", undefined, 1234); - expect(addEventSpy).toHaveBeenCalledWith("another", undefined, 5678); + expect(addEventSpy).toHaveBeenCalledWith("something", { duration: 456 }, 1234); + expect(addEventSpy).toHaveBeenCalledWith("another", { duration: 123 }, 5678); addEventSpy.mockRestore(); }); diff --git a/src/core/process/round.ts b/src/core/process/round.ts index 5b243b70..787da8c6 100644 --- a/src/core/process/round.ts +++ b/src/core/process/round.ts @@ -200,10 +200,11 @@ export async function finalizeRound( for (const attrKey in value.spanAttributes) { // record event attrs if (attrKey.startsWith("event.")) { + const _event = value.spanAttributes[attrKey] as number[]; report.addEvent( attrKey.replace("event.", ""), - undefined, - value.spanAttributes[attrKey] as number, + { duration: _event[1] }, + _event[0] as number, ); delete value.spanAttributes[attrKey]; } @@ -245,10 +246,11 @@ export async function finalizeRound( for (const attrKey in err.spanAttributes) { // record event attrs if (attrKey.startsWith("event.")) { + const _event = err.spanAttributes[attrKey] as number[]; report.addEvent( attrKey.replace("event.", ""), - undefined, - err.spanAttributes[attrKey] as number, + { duration: _event[1] }, + _event[0] as number, ); delete err.spanAttributes[attrKey]; }