feat: track cached response times

packages/gateway/src/durable-objects/gateway-metrics.js

@@ -1,3 +1,8 @@
+import {
+  responseTimeHistogram,
+  createResponseTimeHistogramObject,
+} from '../utils/histogram.js'
+
 /**
  * @typedef {Object} GatewayMetrics
  * @property {number} totalResponseTime total response time of the requests
@@ -86,7 +91,9 @@ export class GatewayMetrics0 {
     }
 
     // Get all the histogram buckets where the response time is smaller
-    const histogramCandidates = histogram.filter((h) => stats.responseTime < h)
+    const histogramCandidates = responseTimeHistogram.filter(
+      (h) => stats.responseTime < h
+    )
     histogramCandidates.forEach((candidate) => {
       gwHistogram[candidate] += 1
     })
@@ -95,21 +102,14 @@ export class GatewayMetrics0 {
   }
 }
 
-// We will count occurences per bucket where response time is less or equal than bucket value
-export const histogram = [
-  300, 500, 750, 1000, 1500, 2000, 3000, 5000, 10000, 20000,
-]
-
 function createMetricsTracker() {
-  const h = histogram.map((h) => [h, 0])
-
   /** @type {GatewayMetrics} */
   const m = {
     totalResponseTime: 0,
     totalWinnerRequests: 0,
     totalResponsesByStatus: {},
     totalRequestsPreventedByReason: {},
-    responseTimeHistogram: Object.fromEntries(h),
+    responseTimeHistogram: createResponseTimeHistogramObject(),
   }
 
   return m

packages/gateway/src/durable-objects/summary-metrics.js

@@ -1,24 +1,30 @@
+import {
+  responseTimeHistogram,
+  createResponseTimeHistogramObject,
+} from '../utils/histogram.js'
+
 /**
  * @typedef {Object} SummaryMetrics
  * @property {number} totalWinnerResponseTime total response time of the requests
  * @property {number} totalWinnerSuccessfulRequests total number of successful requests
+ * @property {number} totalCachedResponseTime total response time to forward cached responses
  * @property {number} totalCachedResponses total number of cached responses
  * @property {BigInt} totalContentLengthBytes total content length of responses
  * @property {BigInt} totalCachedContentLengthBytes total content length of cached responses
  * @property {Record<string, number>} contentLengthHistogram
+ * @property {Record<string, number>} responseTimeHistogram
  *
- * @typedef {Object} ResponseWinnerStats
+ * @typedef {Object} FetchStats
  * @property {number} responseTime number of milliseconds to get response
  * @property {number} contentLength content length header content
- *
- * @typedef {Object} ContentLengthStats
- * @property {number} contentLength content length header content
  */
 
 // Key to track total time for winner gateway to respond
 const TOTAL_WINNER_RESPONSE_TIME_ID = 'totalWinnerResponseTime'
 // Key to track total successful requests
 const TOTAL_WINNER_SUCCESSFUL_REQUESTS_ID = 'totalWinnerSuccessfulRequests'
+// Key to track total time for forwarding cached response
+const TOTAL_CACHED_RESPONSE_TIME_ID = 'totalCachedResponseTime'
 // Key to track total cached requests
 const TOTAL_CACHED_RESPONSES_ID = 'totalCachedResponses'
 // Key to track total content length of responses
@@ -27,11 +33,13 @@ const TOTAL_CONTENT_LENGTH_BYTES_ID = 'totalContentLengthBytes'
 const TOTAL_CACHED_CONTENT_LENGTH_BYTES_ID = 'totalCachedContentLengthBytes'
 // Key to track content size histogram
 const CONTENT_LENGTH_HISTOGRAM_ID = 'contentLengthHistogram'
+// Key to track response time histogram
+const RESPONSE_TIME_HISTOGRAM_ID = 'responseTimeHistogram'
 
 /**
- * Durable Object for keeping generic Metrics of gateway.nft.storage
+ * Durable Object for keeping summary metrics of gateway.nft.storage
  */
-export class SummaryMetrics0 {
+export class SummaryMetrics1 {
   constructor(state) {
     this.state = state
 
@@ -43,6 +51,9 @@ export class SummaryMetrics0 {
       // Total successful requests
       this.totalWinnerSuccessfulRequests =
         (await this.state.storage.get(TOTAL_WINNER_SUCCESSFUL_REQUESTS_ID)) || 0
+      // Total cached response time
+      this.totalCachedResponseTime =
+        (await this.state.storage.get(TOTAL_CACHED_RESPONSE_TIME_ID)) || 0
       // Total cached requests
       this.totalCachedResponses =
         (await this.state.storage.get(TOTAL_CACHED_RESPONSES_ID)) || 0
@@ -57,7 +68,11 @@ export class SummaryMetrics0 {
       // Content length histogram
       this.contentLengthHistogram =
         (await this.state.storage.get(CONTENT_LENGTH_HISTOGRAM_ID)) ||
-        createHistogramObject()
+        createContentLengthHistogramObject()
+      // Response time histogram
+      this.responseTimeHistogram =
+        (await this.state.storage.get(RESPONSE_TIME_HISTOGRAM_ID)) ||
+        createResponseTimeHistogramObject()
     })
   }
 
@@ -74,11 +89,13 @@ export class SummaryMetrics0 {
             JSON.stringify({
               totalWinnerResponseTime: this.totalWinnerResponseTime,
               totalWinnerSuccessfulRequests: this.totalWinnerSuccessfulRequests,
+              totalCachedResponseTime: this.totalCachedResponseTime,
               totalCachedResponses: this.totalCachedResponses,
               totalContentLengthBytes: this.totalContentLengthBytes.toString(),
               totalCachedContentLengthBytes:
                 this.totalCachedContentLengthBytes.toString(),
               contentLengthHistogram: this.contentLengthHistogram,
+              responseTimeHistogram: this.responseTimeHistogram,
             })
           )
         default:
@@ -87,33 +104,36 @@ export class SummaryMetrics0 {
     }
 
     // POST
-    let data
+    /** @type {FetchStats} */
+    const data = await request.json()
     switch (url.pathname) {
       case '/metrics/winner':
-        /** @type {ResponseWinnerStats} */
-        data = await request.json()
         await this._updateWinnerMetrics(data)
         return new Response()
       case '/metrics/cache':
-        /** @type {ContentLengthStats} */
-        data = await request.json()
-        await this._updateWinnerMetrics(data)
+        await this._updatedCacheMetrics(data)
         return new Response()
       default:
         return new Response('Not found', { status: 404 })
     }
   }
 
   /**
-   * @param {ContentLengthStats} stats
+   * @param {FetchStats} stats
    */
   async _updatedCacheMetrics(stats) {
     // Update metrics
+    this.totalCachedResponseTime += stats.responseTime
     this.totalCachedResponses += 1
     this.totalCachedContentLengthBytes += BigInt(stats.contentLength)
     this._updateContentLengthMetrics(stats)
-    // Sabe updated metrics
+    this._updateResponseTimeHistogram(stats)
+    // Save updated metrics
     await Promise.all([
+      this.state.storage.put(
+        TOTAL_CACHED_RESPONSE_TIME_ID,
+        this.totalCachedResponseTime
+      ),
       this.state.storage.put(
         TOTAL_CACHED_RESPONSES_ID,
         this.totalCachedResponses
@@ -130,17 +150,22 @@ export class SummaryMetrics0 {
         CONTENT_LENGTH_HISTOGRAM_ID,
         this.contentLengthHistogram
       ),
+      this.state.storage.put(
+        RESPONSE_TIME_HISTOGRAM_ID,
+        this.responseTimeHistogram
+      ),
     ])
   }
 
   /**
-   * @param {ResponseWinnerStats} stats
+   * @param {FetchStats} stats
    */
   async _updateWinnerMetrics(stats) {
     // Updated Metrics
     this.totalWinnerResponseTime += stats.responseTime
     this.totalWinnerSuccessfulRequests += 1
     this._updateContentLengthMetrics(stats)
+    this._updateResponseTimeHistogram(stats)
     // Save updated Metrics
     await Promise.all([
       this.state.storage.put(
@@ -159,11 +184,15 @@ export class SummaryMetrics0 {
         CONTENT_LENGTH_HISTOGRAM_ID,
         this.contentLengthHistogram
       ),
+      this.state.storage.put(
+        RESPONSE_TIME_HISTOGRAM_ID,
+        this.responseTimeHistogram
+      ),
     ])
   }
 
   /**
-   * @param {ContentLengthStats} stats
+   * @param {FetchStats} stats
    */
   _updateContentLengthMetrics(stats) {
     this.totalContentLengthBytes += BigInt(stats.contentLength)
@@ -183,9 +212,29 @@ export class SummaryMetrics0 {
 
     this.contentLengthHistogram = tmpHistogram
   }
+
+  /**
+   * @param {FetchStats} stats
+   */
+  _updateResponseTimeHistogram(stats) {
+    const tmpHistogram = {
+      ...this.responseTimeHistogram,
+    }
+
+    // Get all the histogram buckets where the response time is smaller
+    const histogramCandidates = responseTimeHistogram.filter(
+      (h) => stats.responseTime < h
+    )
+
+    histogramCandidates.forEach((candidate) => {
+      tmpHistogram[candidate] += 1
+    })
+
+    this.responseTimeHistogram = tmpHistogram
+  }
 }
 
-function createHistogramObject() {
+function createContentLengthHistogramObject() {
   const h = contentLengthHistogram.map((h) => [h, 0])
   return Object.fromEntries(h)
 }

packages/gateway/src/gateway.js

@@ -34,12 +34,15 @@ import {
  * @param {import('./index').Ctx} ctx
  */
 export async function gatewayGet(request, env, ctx) {
+  const startTs = Date.now()
   const cache = caches.default
   let res = await cache.match(request.url)
 
   if (res) {
     // Update cache metrics in background
-    ctx.waitUntil(updateSummaryCacheMetrics(request, env, res))
+    const responseTime = Date.now() - startTs
+
+    ctx.waitUntil(updateSummaryCacheMetrics(request, env, res, responseTime))
     return res
   }
 
@@ -222,15 +225,17 @@ function getHeaders(request) {
  * @param {Request} request
  * @param {import('./env').Env} env
  * @param {Response} response
+ * @param {number} responseTime
  */
-async function updateSummaryCacheMetrics(request, env, response) {
+async function updateSummaryCacheMetrics(request, env, response, responseTime) {
   // Get durable object for gateway
   const id = env.summaryMetricsDurable.idFromName(SUMMARY_METRICS_ID)
   const stub = env.summaryMetricsDurable.get(id)
 
-  /** @type {import('./durable-objects/summary-metrics').ContentLengthStats} */
+  /** @type {import('./durable-objects/summary-metrics').FetchStats} */
   const contentLengthStats = {
     contentLength: Number(response.headers.get('content-length')),
+    responseTime,
   }
 
   await stub.fetch(
@@ -267,7 +272,7 @@ async function updateSummaryWinnerMetrics(request, env, gwResponse) {
   const id = env.summaryMetricsDurable.idFromName(SUMMARY_METRICS_ID)
   const stub = env.summaryMetricsDurable.get(id)
 
-  /** @type {import('./durable-objects/summary-metrics').ResponseWinnerStats} */
+  /** @type {import('./durable-objects/summary-metrics').FetchStats} */
   const fetchStats = {
     responseTime: gwResponse.responseTime,
     contentLength: Number(gwResponse.response.headers.get('content-length')),

packages/gateway/src/index.js

@@ -7,7 +7,7 @@ import { metricsGet } from './metrics.js'
 
 // Export Durable Object namespace from the root module.
 export { GatewayMetrics0 } from './durable-objects/gateway-metrics.js'
-export { SummaryMetrics0 } from './durable-objects/summary-metrics.js'
+export { SummaryMetrics1 } from './durable-objects/summary-metrics.js'
 export { CidsTracker0 } from './durable-objects/cids.js'
 export { GatewayRateLimits0 } from './durable-objects/gateway-rate-limits.js'
 

packages/gateway/src/metrics.js

@@ -7,7 +7,7 @@ import {
   SUMMARY_METRICS_ID,
   HTTP_STATUS_SUCCESS,
 } from './constants.js'
-import { histogram } from './durable-objects/gateway-metrics.js'
+import { responseTimeHistogram } from './utils/histogram.js'
 import { contentLengthHistogram } from './durable-objects/summary-metrics.js'
 
 /**
@@ -80,9 +80,26 @@ export async function metricsGet(request, env, ctx) {
   })
 
   const metrics = [
+    `# HELP nftgateway_summary_responses_total Total winner and cached responses returned.`,
+    `# TYPE nftgateway_summary_responses_total counter`,
+    `nftgateway_summary_responses_total{env="${env.ENV}"} ${
+      metricsCollected.summaryMetrics.totalWinnerSuccessfulRequests +
+      metricsCollected.summaryMetrics.totalCachedResponses
+    }`,
+    `# HELP nftgateway_summary_response_time_seconds_total Accumulated summary response time of winner responses and cached responses.`,
+    `# TYPE nftgateway_summary_response_time_seconds_total summary`,
+    `nftgateway_summary_response_time_seconds_total{env="${env.ENV}"} ${msToS(
+      metricsCollected.summaryMetrics.totalWinnerResponseTime +
+        metricsCollected.summaryMetrics.totalCachedResponseTime
+    )}`,
     `# HELP nftgateway_cache_hit_responses_total Total cached responses returned.`,
     `# TYPE nftgateway_cache_hit_responses_total counter`,
     `nftgateway_cache_hit_responses_total{env="${env.ENV}"} ${metricsCollected.summaryMetrics.totalCachedResponses}`,
+    `# HELP nftgateway_cache_hit_response_time_seconds_total Accumulated cached response time.`,
+    `# TYPE nftgateway_cache_hit_response_time_seconds_total summary`,
+    `nftgateway_cache_hit_response_time_seconds_total{env="${env.ENV}"} ${msToS(
+      metricsCollected.summaryMetrics.totalCachedResponseTime
+    )}`,
     `# HELP nftgateway_winner_requests_total Total winner requests.`,
     `# TYPE nftgateway_winner_requests_total counter`,
     `nftgateway_winner_requests_total{env="${env.ENV}"} ${metricsCollected.summaryMetrics.totalWinnerSuccessfulRequests}`,
@@ -91,6 +108,18 @@ export async function metricsGet(request, env, ctx) {
     `nftgateway_winner_response_time_seconds_total{env="${env.ENV}"} ${msToS(
       metricsCollected.summaryMetrics.totalWinnerResponseTime
     )}`,
+    `# HELP nftgateway_summary_responses_per_time_total total of responses per response time bucket`,
+    `# TYPE nftgateway_summary_responses_per_time_total histogram`,
+    ...responseTimeHistogram.map(
+      (t) =>
+        `nftgateway_summary_responses_per_time_total{le="${msToS(t)}",env="${
+          env.ENV
+        }"} ${metricsCollected.summaryMetrics.responseTimeHistogram[t]}`
+    ),
+    `nftgateway_summary_responses_per_time_total{le="+Inf",env="${env.ENV}"} ${
+      metricsCollected.summaryMetrics.totalWinnerSuccessfulRequests +
+      metricsCollected.summaryMetrics.totalCachedResponses
+    }`,
     `# HELP nftgateway_response_time_seconds_total Accumulated response time of each gateway.`,
     `# TYPE nftgateway_response_time_seconds_total summary`,
     ...env.ipfsGateways.map(
@@ -184,11 +213,15 @@ export async function metricsGet(request, env, ctx) {
     ),
     `# HELP nftgateway_requests_per_time_total total of requests per response time bucket`,
     `# TYPE nftgateway_requests_per_time_total histogram`,
-    ...histogram.map((t) => {
+    ...responseTimeHistogram.map((t) => {
       return env.ipfsGateways
         .map(
           (gw) =>
-            `nftgateway_requests_per_time_total{gateway="${gw}",le="${t}",env="${env.ENV}"} ${metricsCollected.ipfsGateways[gw].responseTimeHistogram[t]}`
+            `nftgateway_requests_per_time_total{gateway="${gw}",le="${msToS(
+              t
+            )}",env="${env.ENV}"} ${
+              metricsCollected.ipfsGateways[gw].responseTimeHistogram[t]
+            }`
         )
         .join('\n')
     }),
@@ -208,7 +241,10 @@ export async function metricsGet(request, env, ctx) {
       (t) =>
         `nftgateway_responses_content_length_total{le="${t}",env="${env.ENV}"} ${metricsCollected.summaryMetrics.contentLengthHistogram[t]}`
     ),
-    `nftgateway_responses_content_length_total{le="+Inf",env="${env.ENV}"} ${metricsCollected.summaryMetrics.totalWinnerSuccessfulRequests}`,
+    `nftgateway_responses_content_length_total{le="+Inf",env="${env.ENV}"} ${
+      metricsCollected.summaryMetrics.totalWinnerSuccessfulRequests +
+      metricsCollected.summaryMetrics.totalCachedResponses
+    }`,
     `# HELP nftgateway_responses_content_length_bytes_total Accumulated content length of delivered cached responses`,
     `# TYPE nftgateway_responses_content_length_bytes_total summary`,
     `nftgateway_responses_content_length_bytes_total{env="${env.ENV}"} ${metricsCollected.summaryMetrics.totalContentLengthBytes}`,

packages/gateway/src/utils/histogram.js

@@ -0,0 +1,8 @@
+export const responseTimeHistogram = [
+  50, 100, 200, 300, 500, 750, 1000, 1500, 2000, 3000, 5000, 10000, 20000,
+]
+
+export function createResponseTimeHistogramObject() {
+  const h = responseTimeHistogram.map((h) => [h, 0])
+  return Object.fromEntries(h)
+}