From 561dc45b549fa639295f40722f6c763ce055cd5c Mon Sep 17 00:00:00 2001
From: fflorent <florent.git@zeteo.me>
Date: Thu, 25 Jul 2024 11:29:58 +0200
Subject: [PATCH] Better error logging of responses for OIDC callback

---
 app/server/lib/OIDCConfig.ts  | 28 +++++++++++++++++++++++++---
 test/server/lib/OIDCConfig.ts | 13 +++++++++----
 2 files changed, 34 insertions(+), 7 deletions(-)

diff --git a/app/server/lib/OIDCConfig.ts b/app/server/lib/OIDCConfig.ts
index b852f3b7e64..175c3a9cac4 100644
--- a/app/server/lib/OIDCConfig.ts
+++ b/app/server/lib/OIDCConfig.ts
@@ -65,7 +65,7 @@
 import * as express from 'express';
 import { GristLoginSystem, GristServer } from './GristServer';
 import {
-  Client, ClientMetadata, Issuer, TokenSet, UserinfoResponse
+  Client, ClientMetadata, Issuer, TokenSet, UserinfoResponse, errors as OIDCError
 } from 'openid-client';
 import { Sessions } from './Sessions';
 import log from 'app/server/lib/log';
@@ -234,8 +234,9 @@ export class OIDCConfig {
       res.redirect(targetUrl ?? '/');
     } catch (err) {
       log.error(`OIDC callback failed: ${err.stack}`);
-      if (Object.prototype.hasOwnProperty.call(err, 'response')) {
-        log.error(`Response received: ${err.response?.body ?? err.response}`);
+      const maybeResponse = this._maybeExtractDetailsFromError(err);
+      if (maybeResponse) {
+        log.error('Response received: %o',  maybeResponse);
       }
 
       // Delete entirely the session data when the login failed.
@@ -352,6 +353,27 @@ export class OIDCConfig {
 
     return `${fname} ${lname}`.trim() || userInfo.name;
   }
+
+  /**
+   * Returns some response details from either OIDCClient's RPError or OPError,
+   * which are handy for error logging.
+   */
+  private _maybeExtractDetailsFromError(error: Error) {
+    if (error instanceof OIDCError.OPError || error instanceof OIDCError.RPError) {
+      const { response } = error;
+      if (response) {
+        // Ensure that we don't log a buffer (which might be noisy), at least for now, unless we're sure that
+        // would be relevant.
+        const isBodyPureObject = response.body && Object.getPrototypeOf(response.body) === Object.prototype;
+        return {
+          body: isBodyPureObject ? response.body : undefined,
+          statusCode: response.statusCode,
+          statusMessage: response.statusMessage,
+        };
+      }
+    }
+    return null;
+  }
 }
 
 export async function getOIDCLoginSystem(): Promise<GristLoginSystem | undefined> {
diff --git a/test/server/lib/OIDCConfig.ts b/test/server/lib/OIDCConfig.ts
index 3b41a627952..df1981a4bd7 100644
--- a/test/server/lib/OIDCConfig.ts
+++ b/test/server/lib/OIDCConfig.ts
@@ -5,7 +5,7 @@ import {Sessions} from "app/server/lib/Sessions";
 import log from "app/server/lib/log";
 import {assert} from "chai";
 import Sinon from "sinon";
-import {Client, generators} from "openid-client";
+import {Client, generators, errors as OIDCError} from "openid-client";
 import express from "express";
 import _ from "lodash";
 import {RequestWithLogin} from "app/server/lib/Authorizer";
@@ -672,9 +672,13 @@ describe('OIDCConfig', () => {
         session: DEFAULT_SESSION,
       } as unknown as express.Request;
       clientStub.callbackParams.returns({state: FAKE_STATE});
+      const errorResponse = {
+        body: { property: 'response here' },
+        statusCode: 400,
+        statusMessage: 'statusMessage'
+      } as unknown as any;
 
-      const err: Error & {response?: {body: string }} = new Error('userinfo failed');
-      err.response = { body: 'response here' };
+      const err = new OIDCError.OPError({error: 'userinfo failed'}, errorResponse);
       clientStub.userinfo.rejects(err);
 
       await config.handleCallback(
@@ -685,7 +689,8 @@ describe('OIDCConfig', () => {
 
       assert.equal(logErrorStub.callCount, 2, 'logErrorStub show be called twice');
       assert.include(logErrorStub.firstCall.args[0], err.message);
-      assert.include(logErrorStub.secondCall.args[0], err.response.body);
+      assert.include(logErrorStub.secondCall.args[0], 'Response received');
+      assert.deepEqual(logErrorStub.secondCall.args[1], errorResponse);
       assert.isTrue(sendAppPageStub.calledOnce, "An error should have been sent");
     });
   });