fix: improve diagnostics for failures in outbound HTTP requests (#221)

Author: addaleax

src/log-hook.ts

@@ -380,6 +380,26 @@ export function hookLoggerToMongoLogWriter(
     );
   });
 
+  emitter.on('mongodb-oidc-plugin:outbound-http-request-completed', (ev) => {
+    log.debug?.(
+      'OIDC-PLUGIN',
+      mongoLogId(1_002_000_032),
+      `${contextPrefix}-oidc`,
+      'Outbound HTTP request completed',
+      { ...ev, url: redactUrl(ev.url) }
+    );
+  });
+
+  emitter.on('mongodb-oidc-plugin:outbound-http-request-failed', (ev) => {
+    log.debug?.(
+      'OIDC-PLUGIN',
+      mongoLogId(1_002_000_033),
+      `${contextPrefix}-oidc`,
+      'Outbound HTTP request failed',
+      { ...ev, url: redactUrl(ev.url) }
+    );
+  });
+
   emitter.on('mongodb-oidc-plugin:state-updated', (ev) => {
     log.info(
       'OIDC-PLUGIN',

src/plugin.spec.ts

@@ -1492,5 +1492,45 @@ describe('OIDC plugin (mock OIDC provider)', function () {
       expect(result.accessToken).to.be.a('string');
       expect(customFetch).to.have.been.called;
     });
+
+    it('logs helpful error messages', async function () {
+      const outboundHTTPRequestsCompleted: any[] = [];
+
+      getTokenPayload = () => Promise.reject(new Error('test failure'));
+      const plugin = createMongoDBOIDCPlugin({
+        openBrowserTimeout: 60_000,
+        openBrowser: fetchBrowser,
+        allowedFlows: ['auth-code'],
+        redirectURI: 'http://localhost:0/callback',
+      });
+
+      plugin.logger.on(
+        'mongodb-oidc-plugin:outbound-http-request-completed',
+        (ev) => outboundHTTPRequestsCompleted.push(ev)
+      );
+
+      try {
+        await requestToken(plugin, {
+          issuer: provider.issuer,
+          clientId: 'mockclientid',
+          requestScopes: [],
+        });
+        expect.fail('missed exception');
+      } catch (err: any) {
+        expect(err.message).to.equal(
+          'unexpected HTTP response status code: caused by HTTP response 500 (Internal Server Error): test failure'
+        );
+      }
+      expect(outboundHTTPRequestsCompleted).to.deep.include({
+        url: `${provider.issuer}/.well-known/openid-configuration`,
+        status: 200,
+        statusText: 'OK',
+      });
+      expect(outboundHTTPRequestsCompleted).to.deep.include({
+        url: `${provider.issuer}/token`,
+        status: 500,
+        statusText: 'Internal Server Error',
+      });
+    });
   });
 });

src/plugin.ts

@@ -10,6 +10,7 @@ import { MongoDBOIDCError } from './types';
 import {
   errorString,
   getRefreshTokenId,
+  improveHTTPResponseBasedError,
   messageFromError,
   normalizeObject,
   throwIfAborted,
@@ -400,9 +401,27 @@ export class MongoDBOIDCPluginImpl implements MongoDBOIDCPlugin {
     });
   }
 
-  fetch: CustomFetch = async (url, init) => {
+  private fetch: CustomFetch = async (url, init) => {
     this.logger.emit('mongodb-oidc-plugin:outbound-http-request', { url });
 
+    try {
+      const response = await this.doFetch(url, init);
+      this.logger.emit('mongodb-oidc-plugin:outbound-http-request-completed', {
+        url,
+        status: response.status,
+        statusText: response.statusText,
+      });
+      return response;
+    } catch (err) {
+      this.logger.emit('mongodb-oidc-plugin:outbound-http-request-failed', {
+        url,
+        error: errorString(err),
+      });
+      throw err;
+    }
+  };
+
+  private doFetch: CustomFetch = async (url, init) => {
     if (this.options.customFetch) {
       return await this.options.customFetch(url, init);
     }
@@ -1022,7 +1041,7 @@ export class MongoDBOIDCPluginImpl implements MongoDBOIDCPlugin {
         authStateId: state.id,
         error: errorString(err),
       });
-      throw err;
+      throw await improveHTTPResponseBasedError(err);
     } finally {
       this.options.signal?.removeEventListener('abort', optionsAbortCb);
       driverAbortSignal?.removeEventListener('abort', driverAbortCb);

src/types.ts

@@ -127,6 +127,15 @@ export interface MongoDBOIDCLogEventsMap {
   'mongodb-oidc-plugin:missing-id-token': () => void;
   'mongodb-oidc-plugin:outbound-http-request': (event: { url: string }) => void;
   'mongodb-oidc-plugin:inbound-http-request': (event: { url: string }) => void;
+  'mongodb-oidc-plugin:outbound-http-request-failed': (event: {
+    url: string;
+    error: string;
+  }) => void;
+  'mongodb-oidc-plugin:outbound-http-request-completed': (event: {
+    url: string;
+    status: number;
+    statusText: string;
+  }) => void;
   'mongodb-oidc-plugin:received-server-params': (event: {
     params: OIDCCallbackParams;
   }) => void;

src/util.ts

@@ -4,7 +4,7 @@ import type {
   TokenEndpointResponse,
   TokenEndpointResponseHelpers,
 } from 'openid-client';
-import type { OIDCAbortSignal } from './types';
+import { MongoDBOIDCError, type OIDCAbortSignal } from './types';
 import { createHash, randomBytes } from 'crypto';
 
 class AbortError extends Error {
@@ -235,3 +235,50 @@ export class TokenSet {
       .digest('hex');
   }
 }
+
+// [email protected] has reduced error messages for HTTP errors significantly, reducing e.g.
+// an HTTP error to just a simple 'unexpect HTTP response status code' message, without
+// further diagnostic information. So if the `cause` of an `err` object is a fetch `Response`
+// object, we try to throw a more helpful error.
+export async function improveHTTPResponseBasedError<T>(
+  err: T
+): Promise<T | MongoDBOIDCError> {
+  if (
+    err &&
+    typeof err === 'object' &&
+    'cause' in err &&
+    err.cause &&
+    typeof err.cause === 'object' &&
+    'status' in err.cause &&
+    'statusText' in err.cause &&
+    'text' in err.cause &&
+    typeof err.cause.text === 'function'
+  ) {
+    try {
+      let body = '';
+      try {
+        body = await err.cause.text();
+      } catch {
+        // ignore
+      }
+      let errorMessageFromBody = '';
+      try {
+        const parsed = JSON.parse(body);
+        errorMessageFromBody =
+          ': ' + String(parsed.error_description || parsed.error || '');
+      } catch {
+        // ignore
+      }
+      if (!errorMessageFromBody) errorMessageFromBody = `: ${body}`;
+      return new MongoDBOIDCError(
+        `${errorString(err)}: caused by HTTP response ${String(
+          err.cause.status
+        )} (${String(err.cause.statusText)})${errorMessageFromBody}`,
+        { codeName: 'HTTPResponseError', cause: err }
+      );
+    } catch {
+      return err;
+    }
+  }
+  return err;
+}