add slow query logging

Author: dglowinski

src/swapService/config/constants.ts

@@ -1,2 +1,3 @@
 export const SWAP_DEFAULT_DEADLINE = 1800n
 export const BINARY_SEARCH_TIMEOUT_SECONDS = 30
+export const LOG_SLOW_QUERY_TIMEOUT_SECONDS = 1

src/swapService/runner.ts

@@ -67,11 +67,11 @@ export async function runPipeline(
     amountOutMin: finalResult.quotes[0].amountOutMin,
     route: finalResult.quotes[0].route,
   })
-  console.log(
-    finalResult.quotes
-      .map((q) => q.route.map((r) => r.providerName).join(" "))
-      .join(", "),
-  )
+  // console.log(
+  //   finalResult.quotes
+  //     .map((q) => q.route.map((r) => r.providerName).join(" "))
+  //     .join(", "),
+  // )
 
   // console.log('finalResult.quotes: ', JSON.stringify(finalResult.quotes, null, 2));
   return finalResult.quotes

src/swapService/strategies/balmySDK/customSourceList.ts

@@ -1,4 +1,11 @@
-import type { IFetchService, IProviderService } from "@balmy/sdk"
+import { LOG_SLOW_QUERY_TIMEOUT_SECONDS } from "@/swapService/config/constants"
+import type {
+  IFetchService,
+  IProviderService,
+  SourceId,
+  SourceListQuoteRequest,
+  SourceListQuoteResponse,
+} from "@balmy/sdk"
 import { LocalSourceList } from "@balmy/sdk/dist/services/quotes/source-lists/local-source-list"
 import { CustomKyberswapQuoteSource } from "./sources/kyberswapQuoteSource"
 import { CustomLiFiQuoteSource } from "./sources/lifiQuoteSource"
@@ -45,5 +52,40 @@ export class CustomSourceList extends LocalSourceList {
       ...customSources,
     }
     delete mutableThis.sources.balmy
+
+    // wrap getQuote in timer
+    const getQuoteSuper = mutableThis.getQuote.bind(this)
+
+    mutableThis.getQuote = async (
+      request: SourceListQuoteRequest,
+      sourceId: SourceId,
+    ): Promise<SourceListQuoteResponse> => {
+      const startTime = process.hrtime()
+      const result = await getQuoteSuper(request, sourceId)
+      const elapsedSeconds = parseHrtimeToSeconds(process.hrtime(startTime))
+      if (elapsedSeconds > LOG_SLOW_QUERY_TIMEOUT_SECONDS) {
+        const { chainId, sellToken, buyToken, order } = request
+        const requestGist = {
+          chainId,
+          sellToken,
+          buyToken,
+          order,
+        }
+        console.log(
+          `SLOW QUERY: ${sourceId} ${elapsedSeconds}s ${stringify(requestGist)}`,
+        )
+      }
+      return result
+    }
   }
 }
+
+function parseHrtimeToSeconds(hrtime: [number, number]) {
+  return Number((hrtime[0] + hrtime[1] / 1e9).toFixed(3))
+}
+
+function stringify(obj: object) {
+  return JSON.stringify(obj, (_, v) =>
+    typeof v === "bigint" ? v.toString() : v,
+  )
+}