24848158243

Committed 23 Apr 2026 05:03PM UTC coverage: 71.255% (+1.3%) from 69.952%

Build # 24848158243

Build Type

push

github

Committed by

web-flow

Commit Message

feat: add sb-request-id logging (#1041)

* feat: add sb-request-id logging

Also propagate the existing `reqId` where missed.

Signed-off-by: ferhat elmas <elmas.ferhat@gmail.com>

* chore: system tenant

Signed-off-by: ferhat elmas <elmas.ferhat@gmail.com>

---------

Signed-off-by: ferhat elmas <elmas.ferhat@gmail.com>

Coverage Stats

3480 of 5443 branches covered (63.94%)

Branch coverage included in aggregate %.

81 of 89 new or added lines in 25 files covered. (91.01%)

6 existing lines in 4 files now uncovered.

7333 of 9732 relevant lines covered (75.35%)

377.75 hits per line

Source File
Press 'n' to go to next uncovered line, 'b' for previous

84.11

/src/http/plugins/log-request.ts

import { logSchema, redactQueryParamFromRequest } from '@internal/monitoring'
import type { FastifyReply, FastifyRequest } from 'fastify'
import fastifyPlugin from 'fastify-plugin'

interface RequestLoggerOptions {
  excludeUrls?: string[]
}

type BivariantHandler<Args extends unknown[], Return> = {
  bivarianceHack(...args: Args): Return
}['bivarianceHack']

declare module 'http' {
  interface IncomingMessage {
    executionError?: Error
    resources?: string[]
  }
}

declare module 'fastify' {
  interface FastifyRequest {
    executionError?: Error
    operation?: { type: string }
    resources?: string[]
    startTime: number
    executionTime?: number
  }

  interface FastifyContextConfig {
    operation?: { type: string }
    resources?: BivariantHandler<[req: FastifyRequest], string[]>
    logMetadata?: BivariantHandler<[req: FastifyRequest], Record<string, unknown>>
  }
}

/**
 * Request logger plugin
 * @param options
 */
export const logRequest = (options: RequestLoggerOptions) =>
  fastifyPlugin(
    async (fastify) => {
      fastify.addHook('onRequest', async (req, res) => {
        req.startTime = Date.now()

        res.raw.once('close', () => {
          if (req.raw.aborted) {
            doRequestLog(req, {
              excludeUrls: options.excludeUrls,
              statusCode: 'ABORTED REQ',
              responseTime: (Date.now() - req.startTime) / 1000,
            })
            return
          }

          if (!res.raw.writableFinished) {
            doRequestLog(req, {
              excludeUrls: options.excludeUrls,
              statusCode: 'ABORTED RES',
              responseTime: (Date.now() - req.startTime) / 1000,
            })
          }
        })
      })

      /**
       * Adds req.resources and req.operation to the request object
       */
      fastify.addHook('preHandler', async (req) => {
        let resources = req.resources

        if (resources === undefined) {
          resources = req.routeOptions.config.resources?.(req)
        }

        if (resources === undefined) {
          resources = req.raw.resources
        }

        if (resources === undefined) {
          const params = req.params as Record<string, unknown> | undefined
          let resourceFromParams = ''

          if (params) {
            let first = true
            for (const key in params) {
              if (!Object.prototype.hasOwnProperty.call(params, key)) {
                continue
              }

              if (!first) {
                resourceFromParams += '/'
              }

              const value = params[key]
              resourceFromParams += value == null ? '' : String(value)
              first = false
            }
          }

          resources = resourceFromParams ? [resourceFromParams] : []
        }

        if (resources && resources.length > 0) {
          for (let index = 0; index < resources.length; index++) {
            const resource = resources[index]
            if (!resource.startsWith('/')) {
              resources[index] = `/${resource}`
            }
          }
        }

        req.resources = resources
        req.operation = req.routeOptions.config.operation

        if (req.operation && typeof req.opentelemetry === 'function') {
          req.opentelemetry()?.span?.setAttribute('http.operation', req.operation.type)
        }
      })

      fastify.addHook('onSend', async (req, _, payload) => {
        req.executionTime = Date.now() - req.startTime
        return payload
      })

      fastify.addHook('onResponse', async (req, reply) => {
        doRequestLog(req, {
          reply,
          excludeUrls: options.excludeUrls,
          statusCode: reply.statusCode,
          responseTime: reply.elapsedTime,
          executionTime: req.executionTime,
        })
      })
    },
    { name: 'log-request' }
  )

interface LogRequestOptions {
  reply?: FastifyReply
  excludeUrls?: string[]
  statusCode: number | 'ABORTED REQ' | 'ABORTED RES'
  responseTime: number
  executionTime?: number
}

function doRequestLog(req: FastifyRequest, options: LogRequestOptions) {
  if (options.excludeUrls?.includes(req.url)) {
    return
  }

  const rMeth = req.method
  const rUrl = redactQueryParamFromRequest(req, [
    'token',
    'X-Amz-Credential',
    'X-Amz-Signature',
    'X-Amz-Security-Token',
  ])
  const uAgent = req.headers['user-agent']
  const rId = req.id
  const cIP = req.ip
  const statusCode = options.statusCode
  const error = req.raw.executionError || req.executionError
  const tenantId = req.tenantId

  let reqMetadata: Record<string, unknown> = {}

  if (req.routeOptions.config.logMetadata) {
    try {
      reqMetadata = req.routeOptions.config.logMetadata(req)

      if (reqMetadata) {
        try {
          if (typeof req.opentelemetry === 'function') {
            req.opentelemetry()?.span?.setAttribute('http.metadata', JSON.stringify(reqMetadata))
          }
        } catch (e) {
          // do nothing
          logSchema.warning(req.log, 'Failed to serialize log metadata', {
            type: 'otel',
            error: e,
            sbReqId: req.sbReqId,
          })
        }
      }
    } catch (e) {
      logSchema.error(req.log, 'Failed to get log metadata', {
        type: 'request',
        error: e,
        sbReqId: req.sbReqId,
      })
    }
  }

  const buildLogMessage = `${tenantId} | ${rMeth} | ${statusCode} | ${cIP} | ${rId} | ${rUrl} | ${uAgent}`

  logSchema.request(req.log, buildLogMessage, {
    type: 'request',
    req,
    reqMetadata,
    res: options.reply,
    responseTime: options.responseTime,
    executionTime: options.executionTime,
    error,
    owner: req.owner,
    role: req.jwtPayload?.role,
    resources: req.resources,
    operation: req.operation?.type ?? req.routeOptions.config.operation?.type,
    serverTimes: req.serverTimings,
    sbReqId: req.sbReqId,
  })
}

1	import { logSchema, redactQueryParamFromRequest } from '@internal/monitoring'
2	import type { FastifyReply, FastifyRequest } from 'fastify'
3	import fastifyPlugin from 'fastify-plugin'
4
5	interface RequestLoggerOptions {
6	excludeUrls?: string[]
7	}
8
9	type BivariantHandler<Args extends unknown[], Return> = {
10	bivarianceHack(...args: Args): Return
11	}['bivarianceHack']
12
13	declare module 'http' {
14	interface IncomingMessage {
15	executionError?: Error
16	resources?: string[]
17	}
18	}
19
20	declare module 'fastify' {
21	interface FastifyRequest {
22	executionError?: Error
23	operation?: { type: string }
24	resources?: string[]
25	startTime: number
26	executionTime?: number
27	}
28
29	interface FastifyContextConfig {
30	operation?: { type: string }
31	resources?: BivariantHandler<[req: FastifyRequest], string[]>
32	logMetadata?: BivariantHandler<[req: FastifyRequest], Record<string, unknown>>
33	}
34	}
35
36	/**
37	* Request logger plugin
38	* @param options
39	*/
40	export const logRequest = (options: RequestLoggerOptions) =>	278✔
41	fastifyPlugin(
42	async (fastify) => {
43	fastify.addHook('onRequest', async (req, res) => {	278✔
44	req.startTime = Date.now()	1,555✔
45
46	res.raw.once('close', () => {	1,555✔
47	if (req.raw.aborted) {	1,555!
48	doRequestLog(req, {	×
49	excludeUrls: options.excludeUrls,
50	statusCode: 'ABORTED REQ',
51	responseTime: (Date.now() - req.startTime) / 1000,
52	})
53	return	×
54	}
55
56	if (!res.raw.writableFinished) {	1,555✔
57	doRequestLog(req, {	1,208✔
58	excludeUrls: options.excludeUrls,
59	statusCode: 'ABORTED RES',
60	responseTime: (Date.now() - req.startTime) / 1000,
61	})
62	}
63	})
64	})
65
66	/**
67	* Adds req.resources and req.operation to the request object
68	*/
69	fastify.addHook('preHandler', async (req) => {	278✔
70	let resources = req.resources	1,480✔
71
72	if (resources === undefined) {	1,480!
73	resources = req.routeOptions.config.resources?.(req)	1,480✔
74	}
75
76	if (resources === undefined) {	1,480✔
77	resources = req.raw.resources	1,403✔
78	}
79
80	if (resources === undefined) {	1,480✔
81	const params = req.params as Record<string, unknown> \| undefined	1,403✔
82	let resourceFromParams = ''	1,403✔
83
84	if (params) {	1,403!
85	let first = true	1,403✔
86	for (const key in params) {	1,403✔
87	if (!Object.prototype.hasOwnProperty.call(params, key)) {	1,712!
88	continue	×
89	}
90
91	if (!first) {	1,712✔
92	resourceFromParams += '/'	490✔
93	}
94
95	const value = params[key]	1,712✔
96	resourceFromParams += value == null ? '' : String(value)	1,712!
97	first = false	1,712✔
98	}
99	}
100
101	resources = resourceFromParams ? [resourceFromParams] : []	1,403✔
102	}
103
104	if (resources && resources.length > 0) {	1,480✔
105	for (let index = 0; index < resources.length; index++) {	1,299✔
106	const resource = resources[index]	41,334✔
107	if (!resource.startsWith('/')) {	41,334✔
108	resources[index] = `/${resource}`	41,333✔
109	}
110	}
111	}
112
113	req.resources = resources	1,480✔
114	req.operation = req.routeOptions.config.operation	1,480✔
115
116	if (req.operation && typeof req.opentelemetry === 'function') {	1,480!
117	req.opentelemetry()?.span?.setAttribute('http.operation', req.operation.type)	×
118	}
119	})
120
121	fastify.addHook('onSend', async (req, _, payload) => {	278✔
122	req.executionTime = Date.now() - req.startTime	1,535✔
123	return payload	1,535✔
124	})
125
126	fastify.addHook('onResponse', async (req, reply) => {	278✔
127	doRequestLog(req, {	1,555✔
128	reply,
129	excludeUrls: options.excludeUrls,
130	statusCode: reply.statusCode,
131	responseTime: reply.elapsedTime,
132	executionTime: req.executionTime,
133	})
134	})
135	},
136	{ name: 'log-request' }
137	)
138
139	interface LogRequestOptions {
140	reply?: FastifyReply
141	excludeUrls?: string[]
142	statusCode: number \| 'ABORTED REQ' \| 'ABORTED RES'
143	responseTime: number
144	executionTime?: number
145	}
146
147	function doRequestLog(req: FastifyRequest, options: LogRequestOptions) {
148	if (options.excludeUrls?.includes(req.url)) {	2,763!
149	return	×
150	}
151
152	const rMeth = req.method	2,763✔
153	const rUrl = redactQueryParamFromRequest(req, [	2,763✔
154	'token',
155	'X-Amz-Credential',
156	'X-Amz-Signature',
157	'X-Amz-Security-Token',
158	])
159	const uAgent = req.headers['user-agent']	2,763✔
160	const rId = req.id	2,763✔
161	const cIP = req.ip	2,763✔
162	const statusCode = options.statusCode	2,763✔
163	const error = req.raw.executionError \|\| req.executionError	2,763✔
164	const tenantId = req.tenantId	2,763✔
165
166	let reqMetadata: Record<string, unknown> = {}	2,763✔
167
168	if (req.routeOptions.config.logMetadata) {	2,763✔
169	try {	380✔
170	reqMetadata = req.routeOptions.config.logMetadata(req)	380✔
171
172	if (reqMetadata) {	380!
173	try {	380✔
174	if (typeof req.opentelemetry === 'function') {	380!
175	req.opentelemetry()?.span?.setAttribute('http.metadata', JSON.stringify(reqMetadata))	×
176	}
177	} catch (e) {
178	// do nothing
NEW 179	logSchema.warning(req.log, 'Failed to serialize log metadata', {	×
180	type: 'otel',
181	error: e,
182	sbReqId: req.sbReqId,
183	})
184	}
185	}
186	} catch (e) {
NEW 187	logSchema.error(req.log, 'Failed to get log metadata', {	×
188	type: 'request',
189	error: e,
190	sbReqId: req.sbReqId,
191	})
192	}
193	}
194
195	const buildLogMessage = `${tenantId} \| ${rMeth} \| ${statusCode} \| ${cIP} \| ${rId} \| ${rUrl} \| ${uAgent}`	2,763✔
196
197	logSchema.request(req.log, buildLogMessage, {	2,763✔
198	type: 'request',
199	req,
200	reqMetadata,
201	res: options.reply,
202	responseTime: options.responseTime,
203	executionTime: options.executionTime,
204	error,
205	owner: req.owner,
206	role: req.jwtPayload?.role,
207	resources: req.resources,
208	operation: req.operation?.type ?? req.routeOptions.config.operation?.type,	3,682✔
209	serverTimes: req.serverTimings,
210	sbReqId: req.sbReqId,
211	})
212	}

supabase / storage / 24848158243

Source File Press 'n' to go to next uncovered line, 'b' for previous

Source File
Press 'n' to go to next uncovered line, 'b' for previous