log at the request level instead of through a middleware

Our middleware is FIFO (a queue rather than an actual stack) so the first middleware would call on other middlewares defined by the user before hitting the actual request. As we don't want to observe on users's middleware errors, I moved the logic from a middleware to the point where the request is being made.

Also notice we don't want to block on user handling code upon request resolving, so the error handling code runs asynchronously. This has a side effect. If the execution of the program halts, before the promise is resolved in the next event loop tick, then the error won't be logged. This might not be an acceptable trade-off, and I might change it in a follow-up commit.

packages/client/src/runtime/RequestHandler.ts

@@ -1,6 +1,7 @@
 import { Context } from '@opentelemetry/api'
 import Debug from '@prisma/debug'
 import { getTraceParent, hasBatchIndex, TracingConfig } from '@prisma/engine-core'
+import { EventEmitter } from 'stream'
 import stripAnsi from 'strip-ansi'
 
 import {
@@ -42,6 +43,7 @@ export type RequestParams = {
   unpacker?: Unpacker
   otelParentCtx?: Context
   otelChildCtx?: Context
+  logEmmiter?: EventEmitter
 }
 
 export type HandleErrorParams = {
@@ -154,6 +156,7 @@ export class RequestHandler {
     extensions,
     otelParentCtx,
     otelChildCtx,
+    logEmmiter,
   }: RequestParams) {
     if (this.hooks && this.hooks.beforeRequest) {
       const query = String(document)
@@ -209,7 +212,30 @@ export class RequestHandler {
       }
       return extendedResult
     } catch (error) {
+      this.handleAndLogRequestError({ error, clientMethod, callsite, transaction })
+    }
+  }
+
+  /**
+   * Handles the error and logs it, logging the error is done asynchoronously rather than blocking
+   * waiting for the event handler to finish. This is because event handlers are provided by the user
+   * through client.$on('error', callback) and we don't want to block the request during the callback
+   * execution, as that would affect query runtime metrics.
+   */
+  handleAndLogRequestError({ error, clientMethod, callsite, transaction }: HandleErrorParams, logEmmiter?: EventEmitter): never {
+    // eslint-disable-next-line
+    async function logAsync(l: EventEmitter, err: any) {
+      l.emit('error', err)
+    }
+
+    try {
       this.handleRequestError({ error, clientMethod, callsite, transaction })
+    } catch (err) {
+      if (logEmmiter) {
+        // fire and forget
+        logAsync(logEmmiter, err).catch(() => { })
+      }
+      throw err
     }
   }
 

packages/client/src/runtime/getPrismaClient.ts

@@ -204,8 +204,8 @@ export type LogDefinition = {
 
 export type GetLogType<T extends LogLevel | LogDefinition> = T extends LogDefinition
   ? T['emit'] extends 'event'
-    ? T['level']
-    : never
+  ? T['level']
+  : never
   : never
 export type GetEvents<T extends Array<LogLevel | LogDefinition>> =
   | GetLogType<T[0]>
@@ -474,16 +474,6 @@ export function getPrismaClient(config: GetPrismaClientConfig) {
                 logger.log(`${logger.tags[level] ?? ''}`, event.message || event.query)
               })
             }
-
-            // emit events for unhandled errors
-            if (typeof log === 'string' ? log === 'error' : log.level === 'error') {
-              this.$use((params, next) => {
-                return next(params).catch((e) => {
-                  this._logEmitter.emit('error', e)
-                  throw e
-                })
-              })
-            }
           }
         }
 
@@ -998,7 +988,7 @@ new PrismaClient({
         await this._engine.transaction('commit', headers, info)
       } catch (e: any) {
         // it went bad, then we rollback the transaction
-        await this._engine.transaction('rollback', headers, info).catch(() => {})
+        await this._engine.transaction('rollback', headers, info).catch(() => { })
 
         throw e // silent rollback, throw original error
       }
@@ -1229,6 +1219,7 @@ new PrismaClient({
         unpacker,
         otelParentCtx,
         otelChildCtx: context.active(),
+        logEmmiter: this._logEmitter,
       })
     }
 
@@ -1237,7 +1228,7 @@ new PrismaClient({
         const dmmf = await this._engine.getDmmf()
         return new DMMFHelper(getPrismaClientDMMF(dmmf))
       } catch (error) {
-        this._fetcher.handleRequestError({ ...params, error })
+        this._fetcher.handleAndLogRequestError({ ...params, error }, this._logEmitter)
       }
     })