feat: optional userinfo logging

nwtgck · May 21, 2023 · a2cd491 · a2cd491
1 parent a5ea2a0
commit a2cd491
Show file tree

Hide file tree

Showing 5 changed files with 82 additions and 12 deletions.
diff --git a/README.md b/README.md
@@ -118,6 +118,12 @@ openid_connect:
       query_param_name: my_session_forward_url
       allow_url_regexp: ^http://localhost:\d+.*$
     age_seconds: 86400
+  # optional
+  log:
+    # optional
+    userinfo:
+      sub: false
+      email: false
 
 # Close socket when path not allowed
 rejection: socket_close

diff --git a/src/OpenIdConnectUserStore.ts b/src/OpenIdConnectUserStore.ts
@@ -4,41 +4,42 @@ type Userinfo = { sub?: string, email?: string, email_verified?: boolean }
 
 export class OpenIdConnectUserStore {
   private ageSeconds: number = 0;
-  private sessionIdToUserInfo: Map<string, Userinfo & { createdAt: Date }> = new Map();
+  private sessionIdToUserInfoWithDate: Map<string, { userinfo: Userinfo, createdAt: Date }> = new Map();
 
   setAgeSeconds(seconds: number) {
     this.ageSeconds = seconds;
   }
 
-  setUserinfo(userInfo: Userinfo): string {
+  setUserinfo(userinfo: Userinfo): string {
     const sessionId = this.generateSessionId();
-    this.sessionIdToUserInfo.set(sessionId, {
-      ...userInfo,
+    this.sessionIdToUserInfoWithDate.set(sessionId, {
+      userinfo,
       createdAt: new Date(),
     });
     const timer = setTimeout(() => {
-      this.sessionIdToUserInfo.delete(sessionId);
+      this.sessionIdToUserInfoWithDate.delete(sessionId);
     }, this.ageSeconds * 1000);
     timer.unref();
     return sessionId;
   }
 
   findValidUserInfo(sessionId: string): Userinfo | undefined {
-    const userInfo = this.sessionIdToUserInfo.get(sessionId);
-    if (userInfo === undefined) {
+    const userinfoWithDate = this.sessionIdToUserInfoWithDate.get(sessionId);
+    if (userinfoWithDate === undefined) {
       return undefined;
     }
-    if (new Date().getTime() <= userInfo.createdAt.getTime() + (this.ageSeconds * 1000)) {
-      return userInfo;
+    const {userinfo, createdAt} = userinfoWithDate;
+    if (new Date().getTime() <= createdAt.getTime() + (this.ageSeconds * 1000)) {
+      return userinfo;
     }
-    this.sessionIdToUserInfo.delete(sessionId);
+    this.sessionIdToUserInfoWithDate.delete(sessionId);
     return undefined;
   }
 
   private generateSessionId(): string {
     while (true) {
       const sessionId = crypto.randomBytes(64).toString("base64url");
-      if (!this.sessionIdToUserInfo.has(sessionId)) {
+      if (!this.sessionIdToUserInfoWithDate.has(sessionId)) {
         return sessionId;
       }
     }

diff --git a/src/config/v1.ts b/src/config/v1.ts
@@ -65,6 +65,12 @@ export const configV1Schema = z.object({
       }),
       age_seconds: z.number(),
     }),
+    log: z.optional(z.object({
+      userinfo: z.optional(z.object({
+        sub: z.boolean(),
+        email: z.boolean(),
+      })),
+    })),
   })),
 });
 export type ConfigV1 = z.infer<typeof configV1Schema>;

diff --git a/src/openid-connect.tsx b/src/openid-connect.tsx
@@ -31,6 +31,7 @@ export async function handleOpenIdConnect({logger, openIdConnectUserStore, codeV
   req: HttpReq,
   res: HttpRes,
 }): Promise<"authorized" | "responded"> {
+  logger?.info(`OpenID Connect: ${req.method} ${req.url} ${req.httpVersion}`);
   // Always set because config may be hot reloaded
   openIdConnectUserStore.setAgeSeconds(oidcConfig.session.age_seconds);
   const url = new URL(req.url!, `http://${req.headers.host}`);
@@ -50,11 +51,13 @@ export async function handleOpenIdConnect({logger, openIdConnectUserStore, codeV
     return "responded";
   }
   if (!userinfoIsAllowed(oidcConfig.allow_userinfos, userinfo)) {
+    logger?.info(`not allowed userinfo: ${userinfoForLog(oidcConfig.log?.userinfo, userinfo)}`);
     res.writeHead(400, {"Content-Type": "text/plain"});
     res.end(`NOT allowed user: ${JSON.stringify(userinfo)}\n`);
     return "responded";
   }
   if (oidcConfig.session.forward !== undefined) {
+    logger?.info(`session forwarding: userinfo=${userinfoForLog(oidcConfig.log?.userinfo, userinfo)}`);
     const sessionForwardUrl: string | null = url.searchParams.get(oidcConfig.session.forward.query_param_name);
     if (sessionForwardUrl !== null) {
       respondForwardHtml({
@@ -68,10 +71,13 @@ export async function handleOpenIdConnect({logger, openIdConnectUserStore, codeV
       return "responded";
     }
   }
+  logger?.info(`OpenID Connect authorized: userinfo=${userinfoForLog(oidcConfig.log?.userinfo, userinfo)}`);
   return "authorized";
 }
 
-function userinfoIsAllowed(allowUserinfos: OidcConfig["allow_userinfos"], userinfo: { sub?: string, email?: string, email_verified?: boolean }): boolean {
+type Userinfo = { sub?: string, email?: string, email_verified?: boolean };
+
+function userinfoIsAllowed(allowUserinfos: OidcConfig["allow_userinfos"], userinfo: Userinfo): boolean {
   const allowedUserinfo = allowUserinfos.find(u => {
     if ("sub" in u) {
       return u.sub === userinfo.sub;
@@ -130,10 +136,12 @@ async function handleRedirect(logger: Logger | undefined, client: openidClient.B
     }
     const userinfo = await client.userinfo(tokenSet.access_token);
     if (!userinfoIsAllowed(oidcConfig.allow_userinfos, userinfo)) {
+      logger?.info(`not allowed userinfo: ${userinfoForLog(oidcConfig.log?.userinfo, userinfo)}`);
       res.writeHead(400, {"Content-Type": "text/plain"});
       res.end(`NOT allowed user: ${JSON.stringify(userinfo)}\n`);
       return;
     }
+    logger?.info(`allowed userinfo: ${userinfoForLog(oidcConfig.log?.userinfo, userinfo)}`);
     const newSessionId = openIdConnectUserStore.setUserinfo(userinfo);
     const setCookieValue = cookie.serialize(oidcConfig.session.cookie.name, newSessionId, {
       httpOnly: oidcConfig.session.cookie.http_only,
@@ -230,3 +238,21 @@ const retryMax = 10;
     </html>
   ));
 }
+
+function userinfoForLog(config: NonNullable<OidcConfig["log"]>["userinfo"], userinfo: Userinfo): string {
+  const extracted = {
+    sub: config?.sub === true ? userinfo.sub : undefined,
+    ...(config?.email === true ? {
+      email: userinfo.email,
+      email_verified: userinfo.email_verified,
+    } : {}),
+  };
+  const extractedStr = JSON.stringify(extracted);
+  if (extractedStr === "{}") {
+    return "{...}";
+  }
+  if (JSON.stringify(userinfo) !== extractedStr) {
+    return extractedStr.replace(/}$/, ", ...}");
+  }
+  return extractedStr;
+}
diff --git a/test/config-v1.test.ts b/test/config-v1.test.ts
@@ -425,5 +425,36 @@ rejection: socket_close
 
       providerServer.close();
     });
+
+    it("should parse log config", async () => {
+      // language=yaml
+      configRef.set(readConfigV1AndNormalize(`
+        version: "1"
+        config_for: rich_piping_server
+
+        experimental_openid_connect: true
+        openid_connect:
+          issuer_url: https://dummyissue
+          client_id: myclientid
+          client_secret: thisissecret
+          redirect:
+            uri: https://dummyredirecturi/my_callback
+            path: /my_callback
+          allow_userinfos: [ ]
+          session:
+            cookie:
+              name: dummycookiename
+              http_only: true
+            age_seconds: 60
+          log:
+            userinfo:
+              sub: true
+              email: false
+
+        rejection: socket_close
+      `));
+      assert.strictEqual(configRef.get()?.openid_connect?.log?.userinfo?.sub, true);
+      assert.strictEqual(configRef.get()?.openid_connect?.log?.userinfo?.email, false);
+    });
   });
 });