chore: add a bunch of logs to validate api token validation behavior (#…

…6905)

This change is meant to test something in sandbox. It will be reverted
after the investigation.

src/lib/middleware/api-token-middleware.ts

@@ -78,6 +78,9 @@ const apiAccessMiddleware = (
                     // If we're here, we know that api token middleware was enabled, otherwise we'd returned a no-op middleware
                     // We explicitly only protect client and proxy apis, since admin apis are protected by our permission checker
                     // Reject with 401
+                    logger.warn(
+                        `Client api request without valid token (${apiToken}), rejecting`,
+                    );
                     res.status(401).send({
                         message: NO_TOKEN_WHERE_TOKEN_WAS_REQUIRED,
                     });

src/lib/services/api-token-service.ts

@@ -108,6 +108,9 @@ export class ApiTokenService {
     async fetchActiveTokens(): Promise<void> {
         try {
             this.activeTokens = await this.store.getAllActive();
+            this.logger.info(
+                `Fetched active tokens from store, size: ${this.activeTokens.length}`,
+            );
         } catch (e) {
             this.logger.warn('Failed to fetch active tokens', e);
         }
@@ -122,6 +125,9 @@ export class ApiTokenService {
             return undefined;
         }
 
+        this.logger.info(
+            `Checking for token in cache of size: ${this.activeTokens.length}`,
+        );
         let token = this.activeTokens.find(
             (activeToken) =>
                 Boolean(activeToken.secret) &&
@@ -139,13 +145,27 @@ export class ApiTokenService {
         }
 
         const nextAllowedQuery = this.queryAfter.get(secret) ?? 0;
+        this.logger.info(
+            `Token found in cache: ${Boolean(
+                token,
+            )}, next allowed query: ${nextAllowedQuery}`,
+        );
         if (!token && isPast(nextAllowedQuery)) {
+            this.logger.info(
+                `Token not found in cache, querying database for token with secret: ${secret}`,
+            );
             if (this.queryAfter.size > 1000) {
                 // establish a max limit for queryAfter size to prevent memory leak
+                this.logger.info(
+                    'queryAfter size exceeded 1000, clearing cache',
+                );
                 this.queryAfter.clear();
             }
             // prevent querying the same invalid secret multiple times. Expire after 5 minutes
             this.queryAfter.set(secret, addMinutes(new Date(), 5));
+            this.logger.info(
+                `Added ${secret} to queryAfter: ${this.queryAfter.get(secret)}`,
+            );
 
             const stopCacheTimer = this.timer('getTokenWithCache.query');
             token = await this.store.get(secret);
@@ -193,6 +213,7 @@ export class ApiTokenService {
         secret: string,
     ): Promise<IApiUser | undefined> {
         const token = await this.getTokenWithCache(secret);
+        this.logger.info(`getUserForToken ${secret} found: ${token}`);
         if (token) {
             this.lastSeenSecrets.add(token.secret);
             const apiUser: IApiUser = new ApiUser({