fix structured exception logging and do not let GA ping prevent profi…

…le activation failures (#5123) * fix structured exception logging for profile activation failures
mozilla · Oct 2, 2024 · 797d83d · 797d83d
1 parent 80c318e
commit 797d83d
Show file tree

Hide file tree

Showing 5 changed files with 61 additions and 48 deletions.
diff --git a/src/app/(proper_react)/layout.tsx b/src/app/(proper_react)/layout.tsx
@@ -45,16 +45,10 @@ export default async function Layout({ children }: { children: ReactNode }) {
           gaCookieClientId,
           parsedCookieTimestamp,
         );
-      } catch (ex) {
-        if (ex instanceof Error) {
-          logger.error("Could not parse _ga cookie from header", {
-            message: ex.message,
-          });
-        } else {
-          logger.error("Could not parse _ga cookie from header", {
-            message: JSON.stringify(ex),
-          });
-        }
+      } catch (e) {
+        logger.error("could_not_parse_ga_cookie_from_header", {
+          message: (e as Error).message,
+        });
       }
     }
   }

diff --git a/src/app/api/v1/fxa-rp-events/route.ts b/src/app/api/v1/fxa-rp-events/route.ts
@@ -433,7 +433,8 @@ export async function POST(request: NextRequest) {
           );
           logger.error("failed_activating_subscription", {
             subscriber_id: subscriber.id,
-            exception: e,
+            message: (e as Error).message,
+            stack: (e as Error).stack,
           });
           return NextResponse.json(
             { success: false, message: "failed_activating_subscription" },

diff --git a/src/app/functions/server/googleAnalytics.test.ts b/src/app/functions/server/googleAnalytics.test.ts
@@ -21,6 +21,9 @@ jest.mock("./logging", () => {
     error(message: string, details: object) {
       console.error(message, details);
     }
+    warn(message: string, details: object) {
+      console.warn(message, details);
+    }
   }
 
   const logger = new Logging();
@@ -31,6 +34,7 @@ jest.mock("./logging", () => {
 
 beforeEach(() => {
   jest.spyOn(console, "error").mockImplementation(() => {});
+  jest.spyOn(console, "warn").mockImplementation(() => {});
 });
 
 it("sends event name and parameters to GA", async () => {
@@ -102,57 +106,67 @@ it("sends event name and parameters to GA and receives error response", async ()
   });
 });
 
-it("throws exception when no client_id is stored", async () => {
+it("logs a warning when client_id is not stored in DB", async () => {
   jest.mock("../../../db/tables/google_analytics_clients", () => {
     return {
-      getClientIdForSubscriber: jest.fn(() => ""),
+      getClientIdForSubscriber: jest.fn(() =>
+        Promise.resolve({
+          cookie_timestamp: new Date(1234),
+        }),
+      ),
     };
   });
+  const loggingSpy = jest.spyOn(console, "warn");
 
   const { sendPingToGA } = await import("./googleAnalytics");
-  await expect(
-    sendPingToGA(0, "testEvent", { testParam1: "testValue1" }),
-  ).rejects.toEqual(Error("No stored GA cookie for subscriber [0]"));
+  await sendPingToGA(0, "testEvent", { testParam1: "testValue1" });
+
+  expect(loggingSpy).toHaveBeenCalledWith("missing_ga4_client_id", {
+    subscriberId: 0,
+  });
 });
 
-it("throws exception client_id is not present", async () => {
+it("logs a warning if cookie_timestamp is not present", async () => {
   jest.mock("../../../db/tables/google_analytics_clients", () => {
     return {
       getClientIdForSubscriber: jest.fn(() =>
         Promise.resolve({
-          cookie_timestamp: new Date(1234),
+          client_id: "testClientId1",
         }),
       ),
     };
   });
+  const loggingSpy = jest.spyOn(console, "warn");
+
   const { sendPingToGA } = await import("./googleAnalytics");
-  await expect(
-    sendPingToGA(0, "testEvent", { testParam1: "testValue1" }),
-  ).rejects.toEqual(
-    Error(
-      "No GA client_id found for subscriber [0], cannot send backend events to Google Analytics",
-    ),
-  );
+  await sendPingToGA(0, "testEvent", { testParam1: "testValue1" });
+
+  expect(loggingSpy).toHaveBeenCalledWith("missing_ga4_client_id", {
+    subscriberId: 0,
+  });
 });
 
-it("throws exception cookie_timestamp is not present", async () => {
+it("logs a warning if cookie_timestamp cannot be parsed", async () => {
   jest.mock("../../../db/tables/google_analytics_clients", () => {
     return {
       getClientIdForSubscriber: jest.fn(() =>
         Promise.resolve({
           client_id: "testClientId1",
+          cookie_timestamp: "invalid",
         }),
       ),
     };
   });
+  const loggingSpy = jest.spyOn(console, "warn");
+
   const { sendPingToGA } = await import("./googleAnalytics");
-  await expect(
-    sendPingToGA(0, "testEvent", { testParam1: "testValue1" }),
-  ).rejects.toEqual(
-    Error(
-      "No GA client_id found for subscriber [0], cannot send backend events to Google Analytics",
-    ),
-  );
+  await sendPingToGA(0, "testEvent", { testParam1: "testValue1" });
+
+  expect(loggingSpy).toHaveBeenCalledWith("could_not_parse_ga4_cookie", {
+    message: "cookie_timestamp.getTime is not a function",
+    stack: expect.anything(),
+    subscriberId: 0,
+  });
 });
 
 it("throws exception when required env vars are not set", async () => {

diff --git a/src/app/functions/server/googleAnalytics.ts b/src/app/functions/server/googleAnalytics.ts
@@ -26,20 +26,25 @@ export async function sendPingToGA(
     );
   }
 
-  const gaClientInfo = await getClientIdForSubscriber(subscriberId);
-  if (!gaClientInfo) {
-    throw new Error(`No stored GA cookie for subscriber [${subscriberId}]`);
-  }
-
-  const { client_id, cookie_timestamp } = gaClientInfo;
+  const { client_id, cookie_timestamp } =
+    await getClientIdForSubscriber(subscriberId);
 
   if (!client_id || !cookie_timestamp) {
-    throw new Error(
-      `No GA client_id found for subscriber [${subscriberId}], cannot send backend events to Google Analytics`,
-    );
+    logger.warn("missing_ga4_client_id", { subscriberId });
+    return;
   }
 
-  const clientId = `${client_id}.${Math.floor(cookie_timestamp.getTime() / 1000)}`;
+  let clientId;
+  try {
+    clientId = `${client_id}.${Math.floor(cookie_timestamp.getTime() / 1000)}`;
+  } catch (e) {
+    logger.warn("could_not_parse_ga4_cookie", {
+      subscriberId,
+      message: (e as Error).message,
+      stack: (e as Error).stack,
+    });
+    return;
+  }
 
   // Do not show these pings in the production environment by default. These will show up in the DebugView dashboard.
   // @see https://developers.google.com/analytics/devguides/collection/protocol/ga4/verify-implementation?client_type=gtag

diff --git a/src/db/tables/google_analytics_clients.ts b/src/db/tables/google_analytics_clients.ts
@@ -31,12 +31,11 @@ async function addClientIdForSubscriber(
 async function getClientIdForSubscriber(
   subscriberId: number,
 ): Promise<GoogleAnalyticsClientsRow> {
-  return (await knex("google_analytics_clients")
+  const res = await knex("google_analytics_clients")
     .select("client_id", "cookie_timestamp")
-    .where(
-      "subscriber_id",
-      subscriberId,
-    )) as unknown as GoogleAnalyticsClientsRow;
+    .where("subscriber_id", subscriberId);
+
+  return res[0] as GoogleAnalyticsClientsRow;
 }
 
 export { addClientIdForSubscriber, getClientIdForSubscriber };