feat: adds debug logs (#6237)

Co-authored-by: Matthias Nannt <mail@matthiasnannt.com>

apps/web/lib/utils/logger-helpers.test.ts

@@ -1,5 +1,5 @@
 import { afterEach, beforeEach, describe, expect, test, vi } from "vitest";
-import { deepDiff, redactPII } from "./utils";
+import { deepDiff, redactPII, sanitizeUrlForLogging } from "./logger-helpers";
 
 // Patch redis multi before any imports
 beforeEach(async () => {
@@ -104,7 +104,7 @@ describe("withAuditLogging", () => {
   });
   test("logs audit event for successful handler", async () => {
     const handler = vi.fn().mockResolvedValue("ok");
-    const { withAuditLogging } = await import("./handler");
+    const { withAuditLogging } = await import("../../modules/ee/audit-logs/lib/handler");
     const wrapped = withAuditLogging("created", "survey", handler);
     const ctx = {
       user: {
@@ -143,7 +143,7 @@ describe("withAuditLogging", () => {
   });
   test("logs audit event for failed handler and throws", async () => {
     const handler = vi.fn().mockRejectedValue(new Error("fail"));
-    const { withAuditLogging } = await import("./handler");
+    const { withAuditLogging } = await import("../../modules/ee/audit-logs/lib/handler");
     const wrapped = withAuditLogging("created", "survey", handler);
     const ctx = {
       user: {
@@ -181,3 +181,37 @@ describe("withAuditLogging", () => {
     expect(handler).toHaveBeenCalled();
   });
 });
+
+describe("sanitizeUrlForLogging", () => {
+  test("returns sanitized URL with token", () => {
+    expect(sanitizeUrlForLogging("https://example.com?token=1234567890")).toBe(
+      "https://example.com/?token=********"
+    );
+  });
+
+  test("returns sanitized URL with code", () => {
+    expect(sanitizeUrlForLogging("https://example.com?code=1234567890")).toBe(
+      "https://example.com/?code=********"
+    );
+  });
+
+  test("returns sanitized URL with state", () => {
+    expect(sanitizeUrlForLogging("https://example.com?state=1234567890")).toBe(
+      "https://example.com/?state=********"
+    );
+  });
+
+  test("returns sanitized URL with multiple keys", () => {
+    expect(
+      sanitizeUrlForLogging("https://example.com?token=1234567890&code=1234567890&state=1234567890")
+    ).toBe("https://example.com/?token=********&code=********&state=********");
+  });
+
+  test("returns sanitized URL without query params", () => {
+    expect(sanitizeUrlForLogging("https://example.com")).toBe("https://example.com/");
+  });
+
+  test("returns sanitized URL with invalid URL", () => {
+    expect(sanitizeUrlForLogging("not-a-valid-url")).toBe("[invalid-url]");
+  });
+});

apps/web/lib/utils/logger-helpers.ts

@@ -1,3 +1,5 @@
+import { isStringUrl } from "@/lib/utils/url";
+
 const SENSITIVE_KEYS = [
   "email",
   "name",
@@ -33,8 +35,11 @@ const SENSITIVE_KEYS = [
   "image",
   "stripeCustomerId",
   "fileName",
+  "state",
 ];
 
+const URL_SENSITIVE_KEYS = ["token", "code", "state"];
+
 /**
  * Redacts sensitive data from the object by replacing the sensitive keys with "********".
  * @param obj - The object to redact.
@@ -45,6 +50,10 @@ export const redactPII = (obj: any, seen: WeakSet<any> = new WeakSet()): any =>
     return obj.toISOString();
   }
 
+  if (typeof obj === "string" && isStringUrl(obj)) {
+    return sanitizeUrlForLogging(obj);
+  }
+
   if (obj && typeof obj === "object") {
     if (seen.has(obj)) return "[Circular]";
     seen.add(obj);
@@ -89,3 +98,24 @@ export const deepDiff = (oldObj: any, newObj: any): any => {
   }
   return Object.keys(diff).length > 0 ? diff : undefined;
 };
+
+/**
+ * Sanitizes a URL for logging by redacting sensitive parameters.
+ * @param url - The URL to sanitize.
+ * @returns The sanitized URL.
+ */
+export const sanitizeUrlForLogging = (url: string): string => {
+  try {
+    const urlObj = new URL(url);
+
+    URL_SENSITIVE_KEYS.forEach((key) => {
+      if (urlObj.searchParams.has(key)) {
+        urlObj.searchParams.set(key, "********");
+      }
+    });
+
+    return urlObj.origin + urlObj.pathname + (urlObj.search ? `${urlObj.search}` : "");
+  } catch {
+    return "[invalid-url]";
+  }
+};

apps/web/lib/utils/url.test.ts

@@ -1,7 +1,7 @@
 import { cleanup } from "@testing-library/react";
 import { afterEach, describe, expect, test } from "vitest";
 import { TActionClassPageUrlRule } from "@formbricks/types/action-classes";
-import { isValidCallbackUrl, testURLmatch } from "./url";
+import { isStringUrl, isValidCallbackUrl, testURLmatch } from "./url";
 
 afterEach(() => {
   cleanup();
@@ -91,3 +91,13 @@ describe("isValidCallbackUrl", () => {
     expect(isValidCallbackUrl("not-a-valid-url", WEBAPP_URL)).toBe(false);
   });
 });
+
+describe("isStringUrl", () => {
+  test("returns true for valid URL", () => {
+    expect(isStringUrl("https://example.com")).toBe(true);
+  });
+
+  test("returns false for invalid URL", () => {
+    expect(isStringUrl("not-a-valid-url")).toBe(false);
+  });
+});

apps/web/lib/utils/url.ts

@@ -49,3 +49,12 @@ export const isValidCallbackUrl = (url: string, WEBAPP_URL: string): boolean =>
     return false;
   }
 };
+
+export const isStringUrl = (url: string): boolean => {
+  try {
+    new URL(url);
+    return true;
+  } catch {
+    return false;
+  }
+};

apps/web/modules/auth/lib/authOptions.ts

@@ -324,6 +324,7 @@ export const authOptions: NextAuthOptions = {
       if (account?.provider === "credentials" || account?.provider === "token") {
         // check if user's email is verified or not
         if (!user.emailVerified && !EMAIL_VERIFICATION_DISABLED) {
+          logger.error("Email Verification is Pending");
           throw new Error("Email Verification is Pending");
         }
         await updateUserLastLoginAt(user.email);

apps/web/modules/ee/audit-logs/lib/handler.ts

@@ -2,6 +2,7 @@ import { AUDIT_LOG_ENABLED, AUDIT_LOG_GET_USER_IP } from "@/lib/constants";
 import { ActionClientCtx, AuthenticatedActionClientCtx } from "@/lib/utils/action-client/types/context";
 import { getClientIpFromHeaders } from "@/lib/utils/client-ip";
 import { getOrganizationIdFromEnvironmentId } from "@/lib/utils/helper";
+import { deepDiff, redactPII } from "@/lib/utils/logger-helpers";
 import { logAuditEvent } from "@/modules/ee/audit-logs/lib/service";
 import {
   TActor,
@@ -13,7 +14,6 @@ import {
 } from "@/modules/ee/audit-logs/types/audit-log";
 import { getIsAuditLogsEnabled } from "@/modules/ee/license-check/lib/utils";
 import { logger } from "@formbricks/logger";
-import { deepDiff, redactPII } from "./utils";
 
 /**
  * Builds an audit event and logs it.

apps/web/modules/ee/sso/lib/sso-handlers.ts

@@ -4,6 +4,7 @@ import { getIsFreshInstance } from "@/lib/instance/service";
 import { verifyInviteToken } from "@/lib/jwt";
 import { createMembership } from "@/lib/membership/service";
 import { findMatchingLocale } from "@/lib/utils/locale";
+import { redactPII } from "@/lib/utils/logger-helpers";
 import { createBrevoCustomer } from "@/modules/auth/lib/brevo";
 import { createUser, getUserByEmail, updateUser } from "@/modules/auth/lib/user";
 import { getIsValidInviteToken } from "@/modules/auth/signup/lib/invite";
@@ -31,12 +32,36 @@ export const handleSsoCallback = async ({
   account: Account;
   callbackUrl: string;
 }) => {
+  const contextLogger = logger.withContext({
+    correlationId: crypto.randomUUID(),
+    name: "formbricks",
+  });
+
+  contextLogger.debug(
+    {
+      ...redactPII({ user, account, callbackUrl }),
+      hasEmail: !!user.email,
+      hasName: !!user.name,
+    },
+    "SSO callback initiated"
+  );
+
   const isSsoEnabled = await getIsSsoEnabled();
   if (!isSsoEnabled) {
+    contextLogger.debug({ isSsoEnabled }, "SSO not enabled");
     return false;
   }
 
   if (!user.email || account.type !== "oauth") {
+    contextLogger.debug(
+      {
+        hasEmail: !!user.email,
+        accountType: account.type,
+        reason: !user.email ? "missing_email" : "invalid_account_type",
+      },
+      "SSO callback rejected: missing email or invalid account type"
+    );
+
     return false;
   }
 
@@ -45,12 +70,18 @@ export const handleSsoCallback = async ({
   if (provider === "saml") {
     const isSamlSsoEnabled = await getIsSamlSsoEnabled();
     if (!isSamlSsoEnabled) {
+      contextLogger.debug({ provider: "saml" }, "SSO callback rejected: SAML not enabled in license");
       return false;
     }
   }
 
   if (account.provider) {
     // check if accounts for this provider / account Id already exists
+    contextLogger.debug(
+      { lookupType: "sso_provider_account" },
+      "Checking for existing user with SSO provider"
+    );
+
     const existingUserWithAccount = await prisma.user.findFirst({
       include: {
         accounts: {
@@ -66,12 +97,29 @@ export const handleSsoCallback = async ({
     });
 
     if (existingUserWithAccount) {
+      contextLogger.debug(
+        {
+          existingUserId: existingUserWithAccount.id,
+          emailMatches: existingUserWithAccount.email === user.email,
+        },
+        "Found existing user with SSO provider"
+      );
+
       // User with this provider found
       // check if email still the same
       if (existingUserWithAccount.email === user.email) {
+        contextLogger.debug(
+          { existingUserId: existingUserWithAccount.id },
+          "SSO callback successful: existing user, email matches"
+        );
         return true;
       }
 
+      contextLogger.debug(
+        { existingUserId: existingUserWithAccount.id },
+        "Email changed in SSO provider, checking for conflicts"
+      );
+
       // user seemed to change his email within the provider
       // check if user with this email already exist
       // if not found just update user with new email address
@@ -79,9 +127,20 @@ export const handleSsoCallback = async ({
       const otherUserWithEmail = await getUserByEmail(user.email);
 
       if (!otherUserWithEmail) {
+        contextLogger.debug(
+          { existingUserId: existingUserWithAccount.id, action: "email_update" },
+          "No other user with this email found, updating user email after SSO provider change"
+        );
+
         await updateUser(existingUserWithAccount.id, { email: user.email });
         return true;
       }
+
+      contextLogger.debug(
+        { existingUserId: existingUserWithAccount.id, conflictingUserId: otherUserWithEmail.id },
+        "SSO callback failed: email conflict after provider change"
+      );
+
       throw new Error(
         "Looks like you updated your email somewhere else. A user with this new email exists already."
       );
@@ -90,13 +149,24 @@ export const handleSsoCallback = async ({
     // There is no existing account for this identity provider / account id
     // check if user account with this email already exists
     // if user already exists throw error and request password login
+    contextLogger.debug({ lookupType: "email" }, "No existing SSO account found, checking for user by email");
+
     const existingUserWithEmail = await getUserByEmail(user.email);
 
     if (existingUserWithEmail) {
+      contextLogger.debug(
+        { existingUserId: existingUserWithEmail.id, action: "existing_user_login" },
+        "SSO callback successful: existing user found by email"
+      );
       // Sign in the user with the existing account
       return true;
     }
 
+    contextLogger.debug(
+      { action: "new_user_creation" },
+      "No existing user found, proceeding with new user creation"
+    );
+
     let userName = user.name;
 
     if (provider === "openid") {
@@ -108,6 +178,16 @@ export const handleSsoCallback = async ({
       } else if (oidcUser.preferred_username) {
         userName = oidcUser.preferred_username;
       }
+
+      contextLogger.debug(
+        {
+          hasName: !!oidcUser.name,
+          hasGivenName: !!oidcUser.given_name,
+          hasFamilyName: !!oidcUser.family_name,
+          hasPreferredUsername: !!oidcUser.preferred_username,
+        },
+        "Extracted OIDC user name"
+      );
     }
 
     if (provider === "saml") {
@@ -117,6 +197,14 @@ export const handleSsoCallback = async ({
       } else if (samlUser.firstName || samlUser.lastName) {
         userName = `${samlUser.firstName} ${samlUser.lastName}`;
       }
+      contextLogger.debug(
+        {
+          hasName: !!samlUser.name,
+          hasFirstName: !!samlUser.firstName,
+          hasLastName: !!samlUser.lastName,
+        },
+        "Extracted SAML user name"
+      );
     }
 
     // Get multi-org license status
@@ -124,9 +212,23 @@ export const handleSsoCallback = async ({
 
     const isFirstUser = await getIsFreshInstance();
 
+    contextLogger.debug(
+      {
+        isMultiOrgEnabled,
+        isFirstUser,
+        skipInviteForSso: SKIP_INVITE_FOR_SSO,
+        hasDefaultTeamId: !!DEFAULT_TEAM_ID,
+      },
+      "License and instance configuration checked"
+    );
+
     // Additional security checks for self-hosted instances without auto-provisioning and no multi-org enabled
     if (!isFirstUser && !SKIP_INVITE_FOR_SSO && !isMultiOrgEnabled) {
       if (!callbackUrl) {
+        contextLogger.debug(
+          { reason: "missing_callback_url" },
+          "SSO callback rejected: missing callback URL for invite validation"
+        );
         return false;
       }
 
@@ -139,6 +241,10 @@ export const handleSsoCallback = async ({
 
         // Allow sign-in if multi-org is enabled, otherwise check for invite token
         if (source === "signin" && !inviteToken) {
+          contextLogger.debug(
+            { reason: "signin_without_invite_token" },
+            "SSO callback rejected: signin without invite token"
+          );
           return false;
         }
 
@@ -146,16 +252,32 @@ export const handleSsoCallback = async ({
         // Verify invite token and check email match
         const { email, inviteId } = verifyInviteToken(inviteToken);
         if (email !== user.email) {
+          contextLogger.debug(
+            { reason: "invite_email_mismatch", inviteId },
+            "SSO callback rejected: invite token email mismatch"
+          );
           return false;
         }
         // Check if invite token is still valid
         const isValidInviteToken = await getIsValidInviteToken(inviteId);
         if (!isValidInviteToken) {
+          contextLogger.debug(
+            { reason: "invalid_invite_token", inviteId },
+            "SSO callback rejected: invalid or expired invite token"
+          );
           return false;
         }
+        contextLogger.debug({ inviteId }, "Invite token validation successful");
       } catch (err) {
+        contextLogger.debug(
+          {
+            reason: "invite_token_validation_error",
+            error: err instanceof Error ? err.message : "unknown_error",
+          },
+          "SSO callback rejected: invite token validation failed"
+        );
         // Log and reject on any validation errors
-        logger.error(err, "Invalid callbackUrl");
+        contextLogger.error(err, "Invalid callbackUrl");
         return false;
       }
     }
@@ -163,6 +285,12 @@ export const handleSsoCallback = async ({
     let organization: Organization | null = null;
 
     if (!isFirstUser && !isMultiOrgEnabled) {
+      contextLogger.debug(
+        {
+          assignmentStrategy: SKIP_INVITE_FOR_SSO && DEFAULT_TEAM_ID ? "default_team" : "first_organization",
+        },
+        "Determining organization assignment"
+      );
       if (SKIP_INVITE_FOR_SSO && DEFAULT_TEAM_ID) {
         organization = await getOrganizationByTeamId(DEFAULT_TEAM_ID);
       } else {
@@ -170,13 +298,29 @@ export const handleSsoCallback = async ({
       }
 
       if (!organization) {
+        contextLogger.debug(
+          { reason: "no_organization_found" },
+          "SSO callback rejected: no organization found for assignment"
+        );
         return false;
       }
 
       const canDoRoleManagement = await getRoleManagementPermission(organization.billing.plan);
-      if (!canDoRoleManagement && !callbackUrl) return false;
+      if (!canDoRoleManagement && !callbackUrl) {
+        contextLogger.debug(
+          {
+            reason: "insufficient_role_permissions",
+            organizationId: organization.id,
+            canDoRoleManagement,
+          },
+          "SSO callback rejected: insufficient role management permissions"
+        );
+        return false;
+      }
     }
 
+    contextLogger.debug({ hasUserName: !!userName, identityProvider: provider }, "Creating new SSO user");
+
     const userProfile = await createUser({
       name:
         userName ||
@@ -191,13 +335,28 @@ export const handleSsoCallback = async ({
       locale: await findMatchingLocale(),
     });
 
+    contextLogger.debug(
+      { newUserId: userProfile.id, identityProvider: provider },
+      "New SSO user created successfully"
+    );
+
     // send new user to brevo
     createBrevoCustomer({ id: userProfile.id, email: userProfile.email });
 
-    if (isMultiOrgEnabled) return true;
+    if (isMultiOrgEnabled) {
+      contextLogger.debug(
+        { isMultiOrgEnabled, newUserId: userProfile.id },
+        "Multi-org enabled, skipping organization assignment"
+      );
+      return true;
+    }
 
     // Default organization assignment if env variable is set
     if (organization) {
+      contextLogger.debug(
+        { newUserId: userProfile.id, organizationId: organization.id, role: "member" },
+        "Assigning user to organization"
+      );
       await createMembership(organization.id, userProfile.id, { role: "member", accepted: true });
       await createAccount({
         ...account,
@@ -205,6 +364,10 @@ export const handleSsoCallback = async ({
       });
 
       if (SKIP_INVITE_FOR_SSO && DEFAULT_TEAM_ID) {
+        contextLogger.debug(
+          { newUserId: userProfile.id, defaultTeamId: DEFAULT_TEAM_ID },
+          "Creating default team membership"
+        );
         await createDefaultTeamMembership(userProfile.id);
       }
 
@@ -226,6 +389,7 @@ export const handleSsoCallback = async ({
     // Without default organization assignment
     return true;
   }
+  contextLogger.debug("SSO callback successful: default return");
 
   return true;
 };

apps/web/modules/ee/sso/lib/tests/sso-handlers.test.ts

@@ -85,6 +85,13 @@ vi.mock("@formbricks/lib/jwt", () => ({
 vi.mock("@formbricks/logger", () => ({
   logger: {
     error: vi.fn(),
+    debug: vi.fn(),
+    withContext: (context: Record<string, any>) => {
+      return {
+        ...context,
+        debug: vi.fn(),
+      };
+    },
   },
 }));
 

apps/web/modules/email/components/preview-email-template.tsx

@@ -313,32 +313,32 @@ export async function PreviewEmailTemplate({
           <EmailFooter />
         </EmailTemplateWrapper>
       );
-      case TSurveyQuestionTypeEnum.PictureSelection:
-        return (
-          <EmailTemplateWrapper styling={styling} surveyUrl={url}>
-            <QuestionHeader headline={headline} subheader={subheader} className="mr-8" />
-            <Section className="mx-0 mt-4">
-              {firstQuestion.choices.map((choice) =>
-                firstQuestion.allowMulti ? (
-                  <Img
-                    className="rounded-custom mb-3 mr-3 inline-block h-[150px] w-[250px]"
-                    key={choice.id}
-                    src={choice.imageUrl}
-                  />
-                ) : (
-                  <Link
-                    className="rounded-custom mb-3 mr-3 inline-block h-[150px] w-[250px]"
-                    href={`${urlWithPrefilling}${firstQuestion.id}=${choice.id}`}
-                    key={choice.id}
-                    target="_blank">
-                    <Img className="rounded-custom h-full w-full" src={choice.imageUrl} />
-                  </Link>
-                )
-              )}
-            </Section>
-            <EmailFooter />
-          </EmailTemplateWrapper>
-        );
+    case TSurveyQuestionTypeEnum.PictureSelection:
+      return (
+        <EmailTemplateWrapper styling={styling} surveyUrl={url}>
+          <QuestionHeader headline={headline} subheader={subheader} className="mr-8" />
+          <Section className="mx-0 mt-4">
+            {firstQuestion.choices.map((choice) =>
+              firstQuestion.allowMulti ? (
+                <Img
+                  className="rounded-custom mb-3 mr-3 inline-block h-[150px] w-[250px]"
+                  key={choice.id}
+                  src={choice.imageUrl}
+                />
+              ) : (
+                <Link
+                  className="rounded-custom mb-3 mr-3 inline-block h-[150px] w-[250px]"
+                  href={`${urlWithPrefilling}${firstQuestion.id}=${choice.id}`}
+                  key={choice.id}
+                  target="_blank">
+                  <Img className="rounded-custom h-full w-full" src={choice.imageUrl} />
+                </Link>
+              )
+            )}
+          </Section>
+          <EmailFooter />
+        </EmailTemplateWrapper>
+      );
     case TSurveyQuestionTypeEnum.Cal:
       return (
         <EmailTemplateWrapper styling={styling} surveyUrl={url}>