feat(backend): adding OpenPaymentsServerRouteError #2635

mkurapov · 2024-04-04T14:15:14Z

Changes proposed in this pull request

Adding OpenPaymentsServerRouteError that is caught by a new openPaymentsServerErrorMiddleware (this middleware runs as the last middleware), which will properly handle all of errors thrown in the Open Payments Resource Server routes. This means:
- we wont ever need to use ctx.throw in the routes, we just throw OpenPaymentsServerRouteError which will automatically be handled in the middleware
- all logging is standardized for errors: response code + request body, other details are properly logged
- The new @interledger/openapi package exports OpenAPIValidatorMiddlewareError, which is now also handled explicitly in the middleware

Context

Work toward #1905

Checklist

netlify · 2024-04-04T14:15:36Z

✅ Deploy Preview for brilliant-pasca-3e80ec canceled.

Name	Link
🔨 Latest commit	`57075f4`
🔍 Latest deploy log	https://app.netlify.com/sites/brilliant-pasca-3e80ec/deploys/661e423a0bbd850008ca34d1

# Conflicts: # pnpm-lock.yaml

mkurapov · 2024-04-09T15:01:08Z

packages/backend/src/open_payments/auth/middleware.test.ts

+        .spyOn(tokenIntrospectionClient, 'introspect')
+        .mockResolvedValueOnce({ active: true, access: {} } as TokenInfo) // causes an error other than OpenPaymentsServerRouteError
+
+      expect.assertions(3)


Handy expect.assertions(num) method when testing errors in try/catch to make sure the number assertions actually happened (instead of being ignored)

mkurapov · 2024-04-09T15:01:54Z

packages/backend/src/open_payments/errors.ts

+    }
+
+    if (err instanceof OpenPaymentsServerRouteError) {
+      logger.info(


info because its "expected" behaviour

just digesting this out loud... looks like the paths are:

error is OpenPaymentsServerRouteError:

logs at info level with details

throws with status and message

error is OpenAPIValidatorMiddlewareError:

logs at info level with details

throws with status and message

anything else:

logs at error level with details

throws generic 500

mkurapov · 2024-04-09T15:02:22Z

packages/backend/src/open_payments/payment/outgoing/routes.test.ts

-  describe('get', () => {
-    test('returns 500 for unexpected error', async (): Promise<void> => {


all properly handled in openPaymentsServerErrorMiddleware

mkurapov · 2024-04-09T15:03:06Z

packages/backend/src/open_payments/payment/outgoing/routes.ts

+  const errorMessage =
+    'Outgoing payment does not have wallet address. This should not be possible.'
+  deps.logger.error({ outgoingPaymentId: outgoingPayment.id }, errorMessage)
+  throw new Error(errorMessage)


Just throwing normal error here since it's something quite unexpected, and shouldn't ever actually happen

definitely agree with your reasoning here.

this is not a suggestion, just a stackoverflow post with some interesting food for thought regarding logging errors and throwing them: https://stackoverflow.com/questions/22072343/throw-exception-vs-logging

I did some similar work previously in cleaning up errors/logs and this is triggering flashbacks. One of the things I remember was our GCP error reports would include duplicate (but not obviously duplicate) errors because of this. Could be dependent on structured logger configuration and cloud error reporting/logging services. In these scenarios I changed them to warnings so they didn't show in error reports but could still be filtered in the log viewer. I guess if the error and log message is the same the log could in theory be removed.

I'm just throwing out 1 anecdote and not claiming this is ideal. There are dissenting opinions in that post as well. Just thought it was relevant.

Looks like I should also look at the middleware handling this...

I guess in this case it will:

log at error level

log again at error level in openPaymentsServerErrorMiddleware with some additional generic details

throw generic 500

@BlairCurrey definitely makes sense, and those order of events are correct.

I think I would also prefer just to keep only the "main" log in the middleware, but I think the only reason I included this was because I also wanted to log the outgoingPaymentId, which otherwise wouldn't get logged. I don't have a nice solution of propagating that id out to the log in the middleware (particularly for the create routes)

yeah... that seems fair. I dont think we can expect to log all the context in some central place away from where the actually error happens.

…outes

mkurapov · 2024-04-10T22:19:20Z

packages/backend/src/app.ts

@@ -403,17 +405,26 @@ export class App {
    const { resourceServerSpec, walletAddressServerSpec } =
      await this.container.use('openApi')

+    const validatorMiddlewareOptions = {
+      validateRequest: true,
+      validateResponse: process.env.NODE_ENV !== 'production'


This is what the createValidatorMiddleware function was doing previously, now to keep the same behaviour, it has to be stated explicitly

https://github.com/interledger/open-payments/releases/tag/%40interledger%2Fopenapi%402.0.0

mkurapov · 2024-04-10T22:23:37Z

packages/backend/src/open_payments/wallet_address/model.ts

+export function throwIfMissingWalletAddress(
+  deps: { logger: Logger },
+  resource: WalletAddressSubresource
+): asserts resource is WalletAddressSubresource &
+  Required<Pick<WalletAddressSubresource, 'walletAddress'>> {
+  if (!resource.walletAddress) {
+    const errorMessage = `${resource.$modelClass.name} does not have wallet address. This should be investigated.`
+    deps.logger.error({ id: resource.id }, errorMessage)
+    throw new Error(errorMessage)
+  }
+}


Function checks whether incoming payment, quote or outgoing payment has defined walletAddress property. Maybe the log message could be less about investigation though? The only way this would happen if we don't add walletAddress wasn't added to the withGraphFetched() function when getting the resource.

Ideally this would all be resolved with types (ie. we could specify that if walletAddress is in the withGraphFetched then we can have that directly in the type -> but that would be a pretty big change, although it would be handy I think?

Maybe the log message could be less about investigation though

I guess the pertinent thing is that its just (I assume) completely unexpected.

Is this based off any experience with a missing wallet address? I dont see this used so not exactly sure what the intention is and wondering why we need it.

It's only to make typescript happy:

The WalletAddressSubresource model:

export abstract class WalletAddressSubresource extends BaseModel { ... public readonly walletAddressId!: string public walletAddress?: WalletAddress

In order to have walletAddress defined we need to include it in any withGraphFetched requests. However, Objection of course wouldn't know anything about typescript types, so we're left with walletAddress?: WalletAddress. In our routes, we need the walletAddress to be defined to do e.g.:

ctx.body = incomingPayment.toOpenPaymentsTypeWithMethods( incomingPayment.walletAddress, streamCredentials )

when calling function we just assert that the wallet subresource will for sure have walletAddress defined.

Ah, I see. For some reason I didn't see the usage until now.

Would we save ourselves some trouble by doing it in the service instead? where we are specifying .withGraphFetched('[asset, walletAddress]')? Presumably it's always a problem if we dont find the walletAddress in such cases.

Or is it acting as a typegaurd that wouldn't work if used like that? It kinda looks that way but commenting out it's usage doesn't seem to result in any errors for me.

mkurapov · 2024-04-10T22:24:28Z

packages/backend/src/open_payments/route-errors.ts

+import { OpenAPIValidatorMiddlewareError } from '@interledger/openapi'
+import { WalletAddressSubresource } from './wallet_address/model'
+
+export class OpenPaymentsServerRouteError extends Error {


@njlie what do you think about having something like this in the auth package where we would define a custom GNAPError class and catch it similarily in a middleware?

…outes

# Conflicts: # pnpm-lock.yaml

BlairCurrey · 2024-04-11T18:57:44Z

Is the open api request validation not working for you? I deleted the wallet address from the create incoming payment body in bruno and it makes it all the way to objection before erroring. I think the validator middleware should be picking this up first though?

I think the whole uncaught error path and log in the new middleware looks good though.

{
  "level": 50,
  "time": 1712859649461,
  "pid": 1,
  "hostname": "happy-life-bank-backend",
  "method": "POST",
  "path": "/incoming-payments",
  "err": {
    "type": "Error",
    "message": "undefined passed as a property in argument #0 for 'where' operation. Call skipUndefined() method to ignore the undefined values.",
    "stack": "Error: undefined passed as a property in argument #0 for 'where' operation. Call skipUndefined() method to ignore the undefined values.\n    at /home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/operations/ObjectionToKnexConvertingOperation.js:164:15\n    at Array.reduce (<anonymous>)\n    at convertPlainObject (/home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/operations/ObjectionToKnexConvertingOperation.js:159:27)\n    at /home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/operations/ObjectionToKnexConvertingOperation.js:69:14\n    at Array.map (<anonymous>)\n    at convertArgs (/home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/operations/ObjectionToKnexConvertingOperation.js:57:15)\n    at KnexOperation.getKnexArgs (/home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/operations/ObjectionToKnexConvertingOperation.js:19:12)\n    at KnexOperation.onBuildKnex (/home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/operations/KnexOperation.js:8:59)\n    at PaginationQueryBuilder.callOperationMethod (/home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/QueryBuilderOperationSupport.js:382:33)\n    at /home/rafiki/node_modules/.pnpm/objection@3.1.4_knex@3.1.0/node_modules/objection/lib/queryBuilder/QueryBuilderOperationSupport.js:489:37"
  },
  "msg": "Received unhandled error in Open Payments request"
}

mkurapov · 2024-04-12T14:52:32Z

@BlairCurrey
That is coming from createWalletAddressMiddleware, which is called before the validator middleware.
Unfourtunatetly I still need to update createWalletAddressMiddleware to properly throw the new error type, but I was thinking of doing it in a separate PR since this already is getting a bit too big.

If you try changing, or passing an incorrect value for a different field, you should see the correct validation error:

{"level":30,"time":1712933544211,"pid":1,"hostname":"happy-life-bank-backend","method":"POST","path":"/incoming-payments","message":"Received error validating OpenAPI request: body must NOT have additional properties: sadfdsa","status":400,"msg":"Received OpenAPI validation error when handling Open Payments request"}

BlairCurrey · 2024-04-12T15:34:32Z

packages/backend/src/open_payments/auth/middleware.ts

+      if (!(err instanceof OpenPaymentsServerRouteError)) {
+        throw err
      }

-      if (err instanceof HttpError && err.status === 401) {
-        ctx.status = 401
-        ctx.message = err.message
-        ctx.set('WWW-Authenticate', `GNAP as_uri=${config.authServerGrantUrl}`)
-      } else {
+      ctx.set('WWW-Authenticate', `GNAP as_uri=${config.authServerGrantUrl}`)
+
+      if (!bypassError) {
        throw err
      }
    }
+
+    await next()


no feedback, just a little retrospective: I wish I would have not added bypassError flag here and instead factored that use-case out into a separate function (kinda similar to throwIfSignatureInvalid and authenticatedStatusMiddleware). makes changes like this a lot harder to reason about. I added when implementing the public incoming payment.

Changes look fine though... getting public payment works as expected.

BlairCurrey · 2024-04-12T15:37:12Z

packages/backend/src/open_payments/payment/incoming/routes.test.ts

-
-    test('returns 500 for unexpected error', async (): Promise<void> => {
-      const incomingPaymentService = await deps.use('incomingPaymentService')
-      jest
-        .spyOn(incomingPaymentService, 'getWalletAddressPage')
-        .mockRejectedValueOnce(new Error('unexpected'))
-      const ctx = setup<ListContext>({
-        reqOpts: {
-          headers: { Accept: 'application/json' }
-        },
-        walletAddress
-      })
-      await expect(incomingPaymentRoutes.list(ctx)).rejects.toMatchObject({
-        status: 500,
-        message: `Error trying to list incoming payments`
-      })
-    })


are we removing this because the case is already covered by the general error handling middleware test? or something else? I realize the rejects assertions here are no longer correct but I'm just trying to verify the new behavior is tested.

# Conflicts: # pnpm-lock.yaml

feat(backend): adding OpenPaymentsServerRouteError

64bca59

github-actions bot added type: tests Testing related pkg: backend Changes in the backend package. type: source Changes business logic labels Apr 4, 2024

mkurapov added 5 commits April 9, 2024 15:57

chore(backend): updating auth middleware, adding tests

c63a6a0

chore(backend): adding tests for openPaymentServerErrorMiddleware

e97ca55

Merge branch 'main' into mk/1905/rs-route-errors

05a6385

# Conflicts: # pnpm-lock.yaml

chore(backend): rename middleware

a2f2b33

chore(backend): fix lint

9015c19

mkurapov marked this pull request as ready for review April 9, 2024 14:30

mkurapov commented Apr 9, 2024

View reviewed changes

mkurapov requested review from BlairCurrey, njlie and sabineschaller April 9, 2024 15:03

mkurapov added 3 commits April 10, 2024 12:06

chore(backend): validate OP RS responses in dev environments

b33e431

chore(backend): rename errors file to route-errors

f81f404

feat(backend): use throwIfMissingWalletAddress type assertion fn in r…

3d3d931

…outes

mkurapov commented Apr 10, 2024

View reviewed changes

mkurapov added 4 commits April 11, 2024 00:30

feat(backend): use throwIfMissingWalletAddress type assertion fn in r…

a0654fd

…outes

Merge branch 'main' into mk/1905/rs-route-errors

fc937cc

# Conflicts: # pnpm-lock.yaml

chore(backend): cleanup route error, add request body to log

97844f8

chore(backend): add tests for lists function for model

ed4462d

mkurapov linked an issue Apr 11, 2024 that may be closed by this pull request

Standardize Open Payment errors #1905

Closed

BlairCurrey reviewed Apr 12, 2024

View reviewed changes

BlairCurrey previously approved these changes Apr 12, 2024

View reviewed changes

Merge branch 'main' into mk/1905/rs-route-errors

57075f4

# Conflicts: # pnpm-lock.yaml

mkurapov dismissed BlairCurrey’s stale review via 57075f4 April 16, 2024 09:17

sabineschaller approved these changes Apr 16, 2024

View reviewed changes

mkurapov merged commit 99df005 into main Apr 16, 2024
30 checks passed

mkurapov deleted the mk/1905/rs-route-errors branch April 16, 2024 09:24

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat(backend): adding OpenPaymentsServerRouteError #2635

feat(backend): adding OpenPaymentsServerRouteError #2635

mkurapov commented Apr 4, 2024 •

edited

Loading

netlify bot commented Apr 4, 2024 •

edited

Loading

mkurapov Apr 9, 2024

mkurapov Apr 9, 2024 •

edited

Loading

BlairCurrey Apr 9, 2024

mkurapov Apr 9, 2024

mkurapov Apr 9, 2024

BlairCurrey Apr 9, 2024 •

edited

Loading

BlairCurrey Apr 9, 2024

mkurapov Apr 9, 2024

BlairCurrey Apr 9, 2024

mkurapov Apr 10, 2024

mkurapov Apr 10, 2024

BlairCurrey Apr 11, 2024

mkurapov Apr 12, 2024

BlairCurrey Apr 12, 2024

mkurapov Apr 10, 2024

BlairCurrey commented Apr 11, 2024 •

edited

Loading

mkurapov commented Apr 12, 2024

BlairCurrey Apr 12, 2024

BlairCurrey Apr 12, 2024 •

edited

Loading

		describe('get', () => {
		test('returns 500 for unexpected error', async (): Promise<void> => {

feat(backend): adding OpenPaymentsServerRouteError #2635

feat(backend): adding OpenPaymentsServerRouteError #2635

Conversation

mkurapov commented Apr 4, 2024 • edited Loading

Changes proposed in this pull request

Context

Checklist

netlify bot commented Apr 4, 2024 • edited Loading

✅ Deploy Preview for brilliant-pasca-3e80ec canceled.

Choose a reason for hiding this comment

mkurapov Apr 9, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

BlairCurrey Apr 9, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

BlairCurrey commented Apr 11, 2024 • edited Loading

mkurapov commented Apr 12, 2024

Choose a reason for hiding this comment

BlairCurrey Apr 12, 2024 • edited Loading

Choose a reason for hiding this comment

mkurapov commented Apr 4, 2024 •

edited

Loading

netlify bot commented Apr 4, 2024 •

edited

Loading

mkurapov Apr 9, 2024 •

edited

Loading

BlairCurrey Apr 9, 2024 •

edited

Loading

BlairCurrey commented Apr 11, 2024 •

edited

Loading

BlairCurrey Apr 12, 2024 •

edited

Loading