Skip to content

Commit

Permalink
Simplify BinaryEngine
Browse files Browse the repository at this point in the history 
This change is about:
1. getting rid of lastErrorLog, lastRustError, lastPanic
state and instead build all the error information when we parse a log line if that's pertinent

2. Let request errors flow up the stack instead to be emitted in the RequestHandler.

3. Only emit events explicitly during lifecycle management of the binary engine
  • Loading branch information
@miguelff
miguelff committed Nov 24, 2022
1 parent 72f7e43 commit ef408ae
Show file tree
Hide file tree
Showing 3 changed files with 80 additions and 158 deletions.
183 changes: 71 additions & 112 deletions packages/engine-core/src/binary/BinaryEngine.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,8 +30,8 @@ import { PrismaClientRustError } from '../common/errors/PrismaClientRustError'
import { PrismaClientRustPanicError } from '../common/errors/PrismaClientRustPanicError'
import { PrismaClientUnknownRequestError } from '../common/errors/PrismaClientUnknownRequestError'
import { getErrorMessageWithLink } from '../common/errors/utils/getErrorMessageWithLink'
import type { RustError, RustLog } from '../common/errors/utils/log'
import { convertLog, getMessage, isRustError, isRustErrorLog } from '../common/errors/utils/log'
import type { RustLog } from '../common/errors/utils/log'
import { convertLog, getMessage, isRustErrorLog } from '../common/errors/utils/log'
import { prismaGraphQLToJSError } from '../common/errors/utils/prismaGraphQLToJSError'
import { EventEmitter } from '../common/types/Events'
import { EngineMetricsOptions, Metrics, MetricsOptionsJson, MetricsOptionsPrometheus } from '../common/types/Metrics'
Expand Down Expand Up @@ -85,22 +85,18 @@ export class BinaryEngine extends Engine {
private logEmitter: EventEmitter
private showColors: boolean
private logQueries: boolean
private logLevel?: 'info' | 'warn'
private env?: Record<string, string>
private flags: string[]
private port?: number
private enableDebugLogs: boolean
private allowTriggerPanic: boolean
private child?: ChildProcessByStdio<null, Readable, Readable>
private clientVersion?: string
private lastPanic?: Error
private globalKillSignalReceived?: string
private startCount = 0
private previewFeatures: string[] = []
private engineEndpoint?: string
private lastErrorLog?: RustLog
private lastRustError?: RustError
private socketPath?: string
private lastError?: PrismaClientRustError
private getConfigPromise?: Promise<GetConfigResult>
private getDmmfPromise?: Promise<DMMF.Document>
private stopPromise?: Promise<void>
Expand Down Expand Up @@ -137,7 +133,6 @@ export class BinaryEngine extends Engine {
generator,
datasources,
showColors,
logLevel,
logQueries,
env,
flags,
Expand Down Expand Up @@ -165,7 +160,6 @@ export class BinaryEngine extends Engine {
this.tracingConfig = tracingConfig
this.logEmitter = logEmitter
this.showColors = showColors ?? false
this.logLevel = logLevel
this.logQueries = logQueries ?? false
this.clientVersion = clientVersion
this.flags = flags ?? []
Expand Down Expand Up @@ -234,40 +228,27 @@ You may have to run ${chalk.greenBright('prisma generate')} for your changes to
this.checkForTooManyEngines()
}

/**
* @deprecated do not rely on this
*/
private setError(err: any) {
if (isRustError(err)) {
this.handleRustError(err)
} else if (isRustErrorLog(err)) {
this.lastErrorLog = err
this.handleRustError(err)
} else {
this.emitError(err)
}
}

private handleRustError(err: RustLog | RustError) {
const wrappedError = new PrismaClientRustError({
clientVersion: this.clientVersion!,
error: err,
})
this.emitError(wrappedError)
if (wrappedError.isPanic()) {
this.handlePanic()
// Set error sets an error for async processing, when this doesn't happen in the span of a request
// lifecycle, and is instead reported through STDOUT/STDERR of the server.
//
// See `throwAsyncErrorIfExists` for more information
private setError(err: RustLog): void {
if (isRustErrorLog(err)) {
this.lastError = new PrismaClientRustError({
clientVersion: this.clientVersion!,
error: err,
})
if (this.lastError.isPanic()) {
if (this.child) {
this.stopPromise = killProcessAndWait(this.child)
}
if (this.currentRequestPromise?.cancel) {
this.currentRequestPromise.cancel()
}
}
}
}

private emitError(err: any) {
const message = err.message ?? err
this.logEmitter.emit('error', {
message: message,
timestamp: new Date(),
target: 'binary engine lifecycle management',
})
}

private checkForTooManyEngines() {
if (engines.length >= 10) {
const runningEngines = engines.filter((e) => e.child)
Expand Down Expand Up @@ -326,15 +307,6 @@ You may have to run ${chalk.greenBright('prisma generate')} for your changes to
return queryEnginePath
}

private handlePanic(): void {
if (this.child) {
this.stopPromise = killProcessAndWait(this.child)
}
if (this.currentRequestPromise?.cancel) {
this.currentRequestPromise.cancel()
}
}

private async resolvePrismaPath(): Promise<{
prismaPath: string
searchedLocations: string[]
Expand Down Expand Up @@ -558,10 +530,8 @@ ${chalk.dim("In case we're mistaken, please report this to us 🙏.")}`)
debug(`There is a child that still runs and we want to start again`)
}

// reset last panic
this.lastRustError = undefined
this.lastErrorLog = undefined
this.lastPanic = undefined
// reset last error
this.lastError = undefined
logger('startin & resettin')
this.globalKillSignalReceived = undefined

Expand Down Expand Up @@ -673,10 +643,9 @@ ${chalk.dim("In case we're mistaken, please report this to us 🙏.")}`)
if (code !== 0 && this.engineStartDeferred && this.startCount === 1) {
let err
let msg = this.stderrLogs
if (this.lastRustError) {
msg = getMessage(this.lastRustError)
} else if (this.lastErrorLog) {
msg = getMessage(this.lastErrorLog)
// get the message from the last error
if (this.lastError) {
msg = getMessage(this.lastError)
}
if (code !== null) {
err = new PrismaClientInitializationError(
Expand All @@ -698,13 +667,13 @@ Make sure that the engine binary at ${prismaPath} is not corrupt.\n` + msg,
if (!this.child) {
return
}
if (this.lastRustError) {
if (this.lastError) {
return
}
if (code === 126) {
this.setError({
timestamp: new Date(),
target: 'exit',
target: 'binary engine process exit',
level: 'error',
fields: {
message: `Couldn't start query engine as it's not executable on this operating system.
Expand All @@ -716,45 +685,41 @@ You very likely have the wrong "binaryTarget" defined in the schema.prisma file.

this.child.on('error', (err): void => {
this.setError({
message: err.message,
backtrace: 'Could not start query engine',
is_panic: false,
timestamp: new Date(),
target: 'binary engine process error',
level: 'error',
fields: {
message: `Couldn't start query engine: ${err}`,
},
})
reject(err)
})

this.child.on('close', (code, signal): void => {
this.connection.close()

let toEmit: { message: string } | undefined

if (code === null && signal === 'SIGABRT' && this.child) {
const error = new PrismaClientRustPanicError(
toEmit = new PrismaClientRustPanicError(
this.getErrorMessageWithLink('Panic in Query Engine with SIGABRT signal'),
this.clientVersion!,
)
this.logEmitter.emit('error', error)
} else if (
code === 255 &&
signal === null &&
// if there is a "this.lastPanic", the panic has already been handled, so we don't need
// to look into it anymore
this.lastErrorLog?.fields.message === 'PANIC' &&
!this.lastPanic
) {
const error = new PrismaClientRustPanicError(
this.getErrorMessageWithLink(
`${this.lastErrorLog.fields.message}: ${this.lastErrorLog.fields.reason} in ${this.lastErrorLog.fields.file}:${this.lastErrorLog.fields.line}:${this.lastErrorLog.fields.column}`,
),
this.clientVersion!,
)
this.setError(error)
} else if (code === 255 && signal === null && this.lastError) {
toEmit = this.lastError
}
})

if (this.lastRustError) {
return reject(new PrismaClientInitializationError(getMessage(this.lastRustError), this.clientVersion!))
}
if (toEmit) {
this.logEmitter.emit('error', {
message: toEmit.message,
timestamp: new Date(),
target: 'binary engine process close',
})
}
})

if (this.lastErrorLog) {
return reject(new PrismaClientInitializationError(getMessage(this.lastErrorLog), this.clientVersion!))
if (this.lastError) {
return reject(new PrismaClientInitializationError(getMessage(this.lastError), this.clientVersion!))
}

try {
Expand Down Expand Up @@ -1084,36 +1049,23 @@ You very likely have the wrong "binaryTarget" defined in the schema.prisma file.
}

/**
* If we have request errors like "ECONNRESET", we need to get the error from a
* different place, not the request itself. This different place can either be
* this.lastRustError or this.lastErrorLog
* This processes errors that didn't ocur synchronously during a request, and were instead inferred
* from the STDOUT/STDERR streams of the Query Engine process.
*
* See `setError` for more information.
*/
private throwAsyncErrorIfExists(forceThrow = false) {
logger('throwAsyncErrorIfExists', this.startCount, this.hasMaxRestarts)
if (this.lastRustError) {
const err = new PrismaClientRustPanicError(
this.getErrorMessageWithLink(getMessage(this.lastRustError)),
this.clientVersion!,
)
if (this.lastRustError.is_panic) {
this.lastPanic = err
}
if (this.hasMaxRestarts || forceThrow) {
throw err
}
}

if (this.lastErrorLog && isRustErrorLog(this.lastErrorLog)) {
const err = new PrismaClientUnknownRequestError(this.getErrorMessageWithLink(getMessage(this.lastErrorLog)), {
clientVersion: this.clientVersion!,
})

if (this.lastErrorLog?.fields?.message === 'PANIC') {
this.lastPanic = err
}

if (this.hasMaxRestarts || forceThrow) {
throw err
if (this.lastError && (this.hasMaxRestarts || forceThrow)) {
const lastError = this.lastError
// reset error, as we are throwing it now
this.lastError = undefined
if (lastError.isPanic()) {
throw new PrismaClientRustPanicError(this.getErrorMessageWithLink(getMessage(lastError)), this.clientVersion!)
} else {
throw new PrismaClientUnknownRequestError(this.getErrorMessageWithLink(getMessage(lastError)), {
clientVersion: this.clientVersion!,
})
}
}
}
Expand All @@ -1129,6 +1081,13 @@ You very likely have the wrong "binaryTarget" defined in the schema.prisma file.
})
}

/**
* handleRequestError will process existing errors coming from the request, or else look
* for the last error happening in the Query Engine process and processed from the STDOUT/STEDERR
* streams.
*
* See `setError` and `throwAsyncErrorIfExists` for more information.
*/
private handleRequestError = async (
error: Error & { code?: string },
): Promise<{ error: Error & { code?: string }; shouldRetry: boolean }> => {
Expand Down
4 changes: 2 additions & 2 deletions packages/engine-core/src/common/errors/types/PrismaClientRustErrorArgs.ts
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
import type { RustError, RustLog } from '../utils/log'
import type { RustLog } from '../utils/log'

export type PrismaClientRustErrorArgs = {
clientVersion: string
error: RustLog | RustError
error: RustLog
}
51 changes: 7 additions & 44 deletions packages/engine-core/src/common/errors/utils/log.ts
View file
Original file line number Diff line number Diff line change
@@ -1,3 +1,5 @@
import { PrismaClientRustError } from '../PrismaClientRustError'

export type LogLevel = 'info' | 'trace' | 'debug' | 'warn' | 'error' | 'query'
export interface RawRustLog {
timestamp: string
Expand All @@ -13,33 +15,15 @@ export interface RustLog {
fields: LogFields
}

// TODO #debt check if this is up to date
export interface RustError {
is_panic: boolean
message: string
backtrace?: string
}

export function getMessage(log: string | RustLog | RustError | any): string {
export function getMessage(log: string | PrismaClientRustError): string {
if (typeof log === 'string') {
return log
} else if (isRustError(log)) {
return getBacktraceFromRustError(log)
} else if (isRustLog(log)) {
return getBacktraceFromLog(log)
}

return JSON.stringify(log)
}

export function getBacktrace(err: RustError | RustLog): string {
if (isRustError(err)) {
return getBacktraceFromRustError(err)
} else {
return log.message
}
return getBacktraceFromLog(err)
}

function getBacktraceFromLog(log: RustLog): string {
export function getBacktrace(log: RustLog): string {
if (log.fields?.message) {
let str = log.fields?.message
if (log.fields?.file) {
Expand All @@ -60,24 +44,7 @@ function getBacktraceFromLog(log: RustLog): string {
return 'Unknown error'
}

function getBacktraceFromRustError(err: RustError): string {
let str = ''
if (err.is_panic) {
str += `PANIC`
}
if (err.backtrace) {
str += ` in ${err.backtrace}`
}
if (err.message) {
str += `\n${err.message}`
}
return str
}

export function isPanic(err: RustError | RustLog): boolean {
if (isRustError(err)) {
return err.is_panic
}
export function isPanic(err: RustLog): boolean {
return err.fields?.message === 'PANIC'
}

Expand All @@ -89,10 +56,6 @@ export function isRustErrorLog(e: any): e is RustLog {
return isRustLog(e) && (e.level === 'error' || e.fields?.message?.includes('fatal error'))
}

export function isRustError(e: any): e is RustError {
return typeof e.is_panic !== 'undefined'
}

export type LogFields = { [key: string]: any }

export interface PanicLogFields {
Expand Down

0 comments on commit ef408ae

Please sign in to comment.