fix: Improve error handling around calls to this.next in middleware

.circleci/workflows.yml

@@ -28,7 +28,7 @@ mainBuildFilters: &mainBuildFilters
       only:
         - develop
         - /^release\/\d+\.\d+\.\d+$/
-        - 'emily/next-version'
+        - 'mikep/22825-next-middleware'
 
 # usually we don't build Mac app - it takes a long time
 # but sometimes we want to really confirm we are doing the right thing
@@ -37,7 +37,7 @@ macWorkflowFilters: &darwin-workflow-filters
   when:
     or:
     - equal: [ develop, << pipeline.git.branch >> ]
-    - equal: [ 'mschile/chrome_memory_fix', << pipeline.git.branch >> ]
+    - equal: [ 'mikep/22825-next-middleware', << pipeline.git.branch >> ]
     - matches:
         pattern: /^release\/\d+\.\d+\.\d+$/
         value: << pipeline.git.branch >>
@@ -46,7 +46,7 @@ linuxArm64WorkflowFilters: &linux-arm64-workflow-filters
   when:
     or:
     - equal: [ develop, << pipeline.git.branch >> ]
-    - equal: [ 'mschile/chrome_memory_fix', << pipeline.git.branch >> ]
+    - equal: [ 'mikep/22825-next-middleware', << pipeline.git.branch >> ]
     - matches:
         pattern: /^release\/\d+\.\d+\.\d+$/
         value: << pipeline.git.branch >>
@@ -130,7 +130,7 @@ commands:
       - run:
           name: Check current branch to persist artifacts
           command: |
-            if [[ "$CIRCLE_BRANCH" != "develop" && "$CIRCLE_BRANCH" != "release/"* && "$CIRCLE_BRANCH" != "emily/next-version" ]]; then
+            if [[ "$CIRCLE_BRANCH" != "develop" && "$CIRCLE_BRANCH" != "release/"* && "$CIRCLE_BRANCH" != "mikep/22825-next-middleware" ]]; then
               echo "Not uploading artifacts or posting install comment for this branch."
               circleci-agent step halt
             fi

cli/CHANGELOG.md

@@ -5,7 +5,8 @@ _Released 02/14/2023 (PENDING)_
 
 **Bugfixes:**
 
- - Fixed an issue with the Cloud project selection modal not showing the correct prompts. Fixes [#25520](https://github.com/cypress-io/cypress/issues/25520).
+- Fixed an issue with the Cloud project selection modal not showing the correct prompts. Fixes [#25520](https://github.com/cypress-io/cypress/issues/25520).
+- Fixed an issue in middleware where error-handling code could itself generate an error and fail to report the original issue. Fixes [#22825](https://github.com/cypress-io/cypress/issues/22825).
 
 **Features:**
 

packages/errors/src/errorUtils.ts

@@ -50,9 +50,10 @@ type AllowedChalkColors = 'red' | 'blue' | 'green' | 'magenta' | 'yellow'
  *
  * @param err
  * @param color
+ * @param causeDepth If error has a `cause` limits the maximum depth of causes to log. Set to `0` to not log any `cause`
  * @returns
  */
-export const logError = function (err: CypressError | ErrorLike, color: AllowedChalkColors = 'red') {
+export const logError = function (err: CypressError | ErrorLike, color: AllowedChalkColors = 'red', causeDepth: number = 3) {
   console.log(chalk[color](err.message))
 
   if (err.details) {
@@ -67,5 +68,11 @@ export const logError = function (err: CypressError | ErrorLike, color: AllowedC
 
   console.log(chalk[color](err.stack ?? ''))
 
+  if (causeDepth > 0 && err['cause']) {
+    // Limit the recursions on `cause` in case there is a loop
+    console.log(chalk[color]('Caused by:'))
+    logError(err['cause'], color, causeDepth - 1)
+  }
+
   return err
 }

packages/errors/test/unit/errors_spec.ts

@@ -3,7 +3,7 @@ import style from 'ansi-styles'
 import chai, { expect } from 'chai'
 /* eslint-disable no-console */
 import chalk from 'chalk'
-import sinon from 'sinon'
+import sinon, { SinonSpy } from 'sinon'
 import * as errors from '../../src'
 import { parseResolvedPattern } from '../../src/errorUtils'
 
@@ -72,16 +72,65 @@ describe('lib/errors', () => {
       expect(console.log).to.be.calledWithMatch(chalk.magenta(userError.stack ?? ''))
     })
 
-    it('logs err.stack in development', () => {
-      process.env.CYPRESS_INTERNAL_ENV = 'development'
+    describe('err.stack', () => {
+      it('is logged if not a known Cypress error', () => {
+        const err = new Error('foo')
 
-      const err = new Error('foo')
+        const ret = errors.log(err)
 
-      const ret = errors.log(err)
+        expect(ret).to.eq(err)
+
+        expect(console.log).to.be.calledWith(chalk.red(err.stack ?? ''))
+      })
+
+      it('is not logged if a known Cypress error', () => {
+        const err = new Error('foo')
+
+        err['isCypressErr'] = true
+
+        const ret = errors.log(err)
+
+        expect(ret).to.be.undefined
+
+        expect(console.log).not.to.be.calledWith(chalk.red(err.stack ?? ''))
+      })
+    })
+
+    context('err.cause', () => {
+      let err
+
+      beforeEach(() => {
+        err = new Error('foo')
+        err['cause'] = err
+      })
+
+      it('is not logged if a known Cypress error', () => {
+        err['isCypressErr'] = true
+
+        const ret = errors.log(err)
+
+        expect(ret).to.be.undefined
+
+        expect(console.log).not.to.be.calledWith(chalk.red('Caused by:'))
+      })
+
+      it('is not logged if max cause depth === 0', () => {
+        const ret = errors.log(err, 'red', 0)
+
+        expect(ret).to.eq(ret)
+
+        expect(console.log).not.to.be.calledWith(chalk.red('Caused by:'))
+      })
+
+      it('is logged to a specified max depth', () => {
+        const ret = errors.log(err, 'red', 5)
+
+        expect(ret).to.eq(err)
 
-      expect(ret).to.eq(err)
+        const causeLogs = (console.log as SinonSpy).getCalls().filter((call) => call.args[0] === chalk.red('Caused by:'))
 
-      expect(console.log).to.be.calledWith(chalk.red(err.stack ?? ''))
+        expect(causeLogs).to.have.length(5)
+      })
     })
   })
 

packages/proxy/lib/http/index.ts

@@ -23,6 +23,7 @@ import type { RemoteStates } from '@packages/server/lib/remote_states'
 import type { CookieJar } from '@packages/server/lib/util/cookies'
 import type { RequestedWithAndCredentialManager } from '@packages/server/lib/util/requestedWithAndCredentialManager'
 import type { AutomationCookie } from '@packages/server/lib/automation/cookies'
+import { errorUtils } from '@packages/errors'
 
 function getRandomColorFn () {
   return chalk.hex(`#${Number(
@@ -70,7 +71,7 @@ export const defaultMiddleware = {
 export type ServerCtx = Readonly<{
   config: CyServer.Config & Cypress.Config
   shouldCorrelatePreRequests?: () => boolean
-  getFileServerToken: () => string
+  getFileServerToken: () => string | undefined
   getCookieJar: () => CookieJar
   remoteStates: RemoteStates
   requestedWithAndCredentialManager: RequestedWithAndCredentialManager
@@ -182,7 +183,14 @@ export function _runStage (type: HttpStages, ctx: any, onError: Function) {
       const fullCtx = {
         next: () => {
           fullCtx.next = () => {
-            throw new Error('Error running proxy middleware: Cannot call this.next() more than once in the same middleware function. Doing so can cause unintended issues.')
+            const error = new Error('Error running proxy middleware: Detected `this.next()` was called more than once in the same middleware function, but a middleware can only be completed once.')
+
+            if (ctx.error) {
+              error.message = error.message += '\nThis middleware invocation previously encountered an error which may be related, see `error.cause`'
+              error['cause'] = ctx.error
+            }
+
+            throw error
           }
 
           copyChangedCtx()
@@ -207,6 +215,8 @@ export function _runStage (type: HttpStages, ctx: any, onError: Function) {
       try {
         middleware.call(fullCtx)
       } catch (err) {
+        err.message = `Internal error while proxying "${ctx.req.method} ${ctx.req.proxiedUrl}" in ${middlewareName}:\n${err.message}`
+        errorUtils.logError(err)
         fullCtx.onError(err)
       }
     })
@@ -230,7 +240,7 @@ export class Http {
   config: CyServer.Config
   shouldCorrelatePreRequests: () => boolean
   deferredSourceMapCache: DeferredSourceMapCache
-  getFileServerToken: () => string
+  getFileServerToken: () => string | undefined
   remoteStates: RemoteStates
   middleware: HttpMiddlewareStacks
   netStubbingState: NetStubbingState

packages/proxy/test/unit/http/index.spec.ts

@@ -63,13 +63,13 @@ describe('http', function () {
       incomingRequest.throws(new Error('oops'))
 
       error.callsFake(function () {
-        expect(this.error.message).to.eq('oops')
+        expect(this.error.message).to.eq('Internal error while proxying "GET url" in 0:\noops')
         this.end()
       })
 
       return new Http(httpOpts)
       // @ts-ignore
-      .handle({}, { on, off })
+      .handle({ method: 'GET', proxiedUrl: 'url' }, { on, off })
       .then(function () {
         expect(incomingRequest).to.be.calledOnce
         expect(incomingResponse).to.not.be.called
@@ -88,13 +88,13 @@ describe('http', function () {
       incomingResponse.throws(new Error('oops'))
 
       error.callsFake(function () {
-        expect(this.error.message).to.eq('oops')
+        expect(this.error.message).to.eq('Internal error while proxying "GET url" in 0:\noops')
         this.end()
       })
 
       return new Http(httpOpts)
       // @ts-ignore
-      .handle({}, { on, off })
+      .handle({ method: 'GET', proxiedUrl: 'url' }, { on, off })
       .then(function () {
         expect(incomingRequest).to.be.calledOnce
         expect(incomingResponse).to.be.calledOnce
@@ -141,7 +141,7 @@ describe('http', function () {
       })
 
       error.callsFake(function () {
-        expect(this.error.message).to.eq('goto error stack')
+        expect(this.error.message).to.eq('Internal error while proxying "GET url" in 1:\ngoto error stack')
         expect(this).to.include.keys(expectedKeys)
         this.errorAdded = errorAdded
         this.next()
@@ -159,7 +159,7 @@ describe('http', function () {
 
       return new Http(httpOpts)
       // @ts-ignore
-      .handle({}, { on, off })
+      .handle({ method: 'GET', proxiedUrl: 'url' }, { on, off })
       .then(function () {
         [
           incomingRequest, incomingRequest2,

packages/proxy/test/unit/http/request-middleware.spec.ts

@@ -770,4 +770,70 @@ describe('http/request-middleware', () => {
       })
     })
   })
+
+  describe('SendRequestOutgoing', () => {
+    const { SendRequestOutgoing } = RequestMiddleware
+
+    let ctx
+
+    beforeEach(() => {
+      const headers = {}
+      const remoteStates = new RemoteStates(() => {})
+
+      ctx = {
+        onError: sinon.stub(),
+        request: {
+          create: (opts) => {
+            return {
+              inputArgs: opts,
+              on: (event, callback) => {
+                if (event === 'response') {
+                  callback()
+                }
+              },
+            }
+          },
+        },
+        req: {
+          body: '{}',
+          headers,
+          socket: {
+            on: () => {},
+          },
+        },
+        res: {
+          on: (event, listener) => {},
+          off: (event, listener) => {},
+        } as Partial<CypressOutgoingResponse>,
+        remoteStates,
+      }
+    })
+
+    context('same-origin file request', () => {
+      beforeEach(() => {
+        ctx.getFileServerToken = () => 'abcd1234'
+        ctx.req.proxiedUrl = 'https://www.cypress.io/file'
+        ctx.remoteStates.set({
+          origin: 'https://www.cypress.io',
+          strategy: 'file',
+        } as any)
+      })
+
+      it('adds `x-cypress-authorization` header', async () => {
+        await testMiddleware([SendRequestOutgoing], ctx)
+        .then(() => {
+          expect(ctx.req.headers['x-cypress-authorization']).to.equal('abcd1234')
+        })
+      })
+
+      it('handles nil fileServer token', async () => {
+        ctx.getFileServerToken = () => undefined
+
+        await testMiddleware([SendRequestOutgoing], ctx)
+        .then(() => {
+          expect(ctx.req.headers['x-cypress-authorization']).to.be.undefined
+        })
+      })
+    })
+  })
 })