feat: booking errors logging (#12325)

Fixes: https://github.com/calcom/cal.com/issues/12297
Fixes https://github.com/calcom/cal.com/issues/11234

- Displaying error message and X-Vercel-Id( Unique Request Id ) to user on book event form
- Improve error logging 
- Add Error codes

Few things to discuss

1) How to handle calendar integration failures ?
   Currently if for example google integration is broken and someone is trying to book that person then we log the error but don't inform the user that the google calendar is broken and the meeting goes through.
   
 Should I throw error when integration is broken ?
   
<img width="758" alt="Screenshot 2023-11-12 at 12 52 36 AM" src="https://github.com/calcom/cal.com/assets/53316345/c4d921c4-9c8a-4b9b-82a2-bbe0fdbcb3d4">

   
2)  How to handle conferencing app failures? 
 We just default to Cal Video  as location if we are unable to generated conferencing url and log the error and not inform the user(organizer).

apps/api/test/lib/bookings/_post.test.ts

@@ -8,6 +8,7 @@ import { describe, expect, test, vi } from "vitest";
 
 import dayjs from "@calcom/dayjs";
 import sendPayload from "@calcom/features/webhooks/lib/sendPayload";
+import { ErrorCode } from "@calcom/lib/errorCodes";
 import { buildBooking, buildEventType, buildWebhook } from "@calcom/lib/test/builder";
 import prisma from "@calcom/prisma";
 
@@ -148,7 +149,7 @@ describe.skipIf(true)("POST /api/bookings", () => {
       expect(res._getStatusCode()).toBe(500);
       expect(JSON.parse(res._getData())).toEqual(
         expect.objectContaining({
-          message: "No available users found.",
+          message: ErrorCode.NoAvailableUsersFound,
         })
       );
     });

apps/web/public/static/locales/en/common.json

@@ -56,6 +56,15 @@
   "a_refund_failed": "A refund failed",
   "awaiting_payment_subject": "Awaiting Payment: {{title}} on {{date}}",
   "meeting_awaiting_payment": "Your meeting is awaiting payment",
+  "payment_not_created_error": "Payment could not be created",
+  "couldnt_charge_card_error": "Could not charge card for Payment",
+  "no_available_users_found_error": "No available users found. Could you try another time slot?",
+  "request_body_end_time_internal_error": "Internal Error. Request body does not contain end time",
+  "create_calendar_event_error": "Unable to create Calendar event in Organizer's calendar",
+  "update_calendar_event_error": "Unable to update Calendar event.",
+  "delete_calendar_event_error": "Unable to delete Calendar event.",
+  "already_signed_up_for_this_booking_error": "You are already signed up for this booking.",
+  "hosts_unavailable_for_booking": "Some of the hosts are unavailable for booking.",
   "help": "Help",
   "price": "Price",
   "paid": "Paid",
@@ -1363,6 +1372,7 @@
   "event_name_info": "The event type name",
   "event_date_info": "The event date",
   "event_time_info": "The event start time",
+  "event_type_not_found": "EventType not Found",
   "location_info": "The location of the event",
   "additional_notes_info": "The additional notes of booking",
   "attendee_name_info": "The person booking's name",

packages/app-store/alby/lib/PaymentService.ts

@@ -3,12 +3,16 @@ import type { Booking, Payment, PaymentOption, Prisma } from "@prisma/client";
 import { v4 as uuidv4 } from "uuid";
 import type z from "zod";
 
+import { ErrorCode } from "@calcom/lib/errorCodes";
+import logger from "@calcom/lib/logger";
 import prisma from "@calcom/prisma";
 import type { CalendarEvent } from "@calcom/types/Calendar";
 import type { IAbstractPaymentService } from "@calcom/types/PaymentService";
 
 import { albyCredentialKeysSchema } from "./albyCredentialKeysSchema";
 
+const log = logger.getSubLogger({ prefix: ["payment-service:alby"] });
+
 export class PaymentService implements IAbstractPaymentService {
   private credentials: z.infer<typeof albyCredentialKeysSchema> | null;
 
@@ -36,7 +40,7 @@ export class PaymentService implements IAbstractPaymentService {
         },
       });
       if (!booking || !this.credentials?.account_lightning_address) {
-        throw new Error();
+        throw new Error("Alby: Booking or Lightning address not found");
       }
 
       const uid = uuidv4();
@@ -80,8 +84,8 @@ export class PaymentService implements IAbstractPaymentService {
       }
       return paymentData;
     } catch (error) {
-      console.error(error);
-      throw new Error("Payment could not be created");
+      log.error("Alby: Payment could not be created", bookingId);
+      throw new Error(ErrorCode.PaymentCreationFailure);
     }
   }
   async update(): Promise<Payment> {

packages/app-store/paypal/lib/PaymentService.ts

@@ -4,12 +4,16 @@ import z from "zod";
 
 import Paypal from "@calcom/app-store/paypal/lib/Paypal";
 import { WEBAPP_URL } from "@calcom/lib/constants";
+import { ErrorCode } from "@calcom/lib/errorCodes";
+import logger from "@calcom/lib/logger";
 import prisma from "@calcom/prisma";
 import type { CalendarEvent } from "@calcom/types/Calendar";
 import type { IAbstractPaymentService } from "@calcom/types/PaymentService";
 
 import { paymentOptionEnum } from "../zod";
 
+const log = logger.getSubLogger({ prefix: ["payment-service:paypal"] });
+
 export const paypalCredentialKeysSchema = z.object({
   client_id: z.string(),
   secret_key: z.string(),
@@ -87,8 +91,8 @@ export class PaymentService implements IAbstractPaymentService {
       }
       return paymentData;
     } catch (error) {
-      console.error(error);
-      throw new Error("Payment could not be created");
+      log.error("Paypal: Payment could not be created for bookingId", bookingId);
+      throw new Error(ErrorCode.PaymentCreationFailure);
     }
   }
   async update(): Promise<Payment> {
@@ -166,8 +170,8 @@ export class PaymentService implements IAbstractPaymentService {
       }
       return paymentData;
     } catch (error) {
-      console.error(error);
-      throw new Error("Payment could not be created");
+      log.error("Paypal: Payment method could not be collected for bookingId", bookingId);
+      throw new Error("Paypal: Payment method could not be collected");
     }
   }
   chargeCard(

packages/app-store/stripepayment/lib/PaymentService.ts

@@ -4,7 +4,9 @@ import { v4 as uuidv4 } from "uuid";
 import z from "zod";
 
 import { sendAwaitingPaymentEmail } from "@calcom/emails";
+import { ErrorCode } from "@calcom/lib/errorCodes";
 import { getErrorFromUnknown } from "@calcom/lib/errors";
+import logger from "@calcom/lib/logger";
 import prisma from "@calcom/prisma";
 import type { CalendarEvent } from "@calcom/types/Calendar";
 import type { IAbstractPaymentService } from "@calcom/types/PaymentService";
@@ -14,6 +16,8 @@ import { createPaymentLink } from "./client";
 import { retrieveOrCreateStripeCustomerByEmail } from "./customer";
 import type { StripePaymentData, StripeSetupIntentData } from "./server";
 
+const log = logger.getSubLogger({ prefix: ["payment-service:stripe"] });
+
 export const stripeCredentialKeysSchema = z.object({
   stripe_user_id: z.string(),
   default_currency: z.string(),
@@ -129,7 +133,8 @@ export class PaymentService implements IAbstractPaymentService {
       return paymentData;
     } catch (error) {
       console.error(`Payment could not be created for bookingId ${bookingId}`, error);
-      throw new Error("Payment could not be created");
+      log.error("Stripe: Payment could not be created", bookingId, JSON.stringify(error));
+      throw new Error("payment_not_created_error");
     }
   }
 
@@ -199,8 +204,12 @@ export class PaymentService implements IAbstractPaymentService {
 
       return paymentData;
     } catch (error) {
-      console.error(`Payment method could not be collected for bookingId ${bookingId}`, error);
-      throw new Error("Payment could not be created");
+      log.error(
+        "Stripe: Payment method could not be collected for bookingId",
+        bookingId,
+        JSON.stringify(error)
+      );
+      throw new Error("Stripe: Payment method could not be collected");
     }
   }
 
@@ -277,8 +286,8 @@ export class PaymentService implements IAbstractPaymentService {
 
       return paymentData;
     } catch (error) {
-      console.error(`Could not charge card for payment ${payment.id}`, error);
-      throw new Error("Payment could not be created");
+      log.error("Stripe: Could not charge card for payment", _bookingId, JSON.stringify(error));
+      throw new Error(ErrorCode.ChargeCardFailure);
     }
   }
 
@@ -369,7 +378,7 @@ export class PaymentService implements IAbstractPaymentService {
       await this.stripe.paymentIntents.cancel(payment.externalId, { stripeAccount });
       return true;
     } catch (e) {
-      console.error(e);
+      log.error("Stripe: Unable to delete Payment in stripe of paymentId", paymentId, JSON.stringify(e));
       return false;
     }
   }

packages/core/CalendarManager.ts

@@ -206,7 +206,7 @@ export const getBusyCalendarTimes = async (
   selectedCalendars: SelectedCalendar[]
 ) => {
   let results: EventBusyDate[][] = [];
-  const months = getMonths(dateFrom, dateTo);
+  // const months = getMonths(dateFrom, dateTo);
   try {
     // Subtract 11 hours from the start date to avoid problems in UTC- time zones.
     const startDate = dayjs(dateFrom).subtract(11, "hours").format();
@@ -348,6 +348,19 @@ export const updateEvent = async (
           })
       : undefined;
 
+  if (!updatedResult) {
+    logger.error(
+      "updateEvent failed",
+      safeStringify({
+        success,
+        bookingRefUid,
+        credential: getPiiFreeCredential(credential),
+        originalEvent: getPiiFreeCalendarEvent(calEvent),
+        calError,
+      })
+    );
+  }
+
   if (Array.isArray(updatedResult)) {
     calWarnings = updatedResult.flatMap((res) => res.additionalInfo?.calWarnings ?? []);
   } else {
@@ -388,10 +401,11 @@ export const deleteEvent = async ({
   if (calendar) {
     return calendar.deleteEvent(bookingRefUid, event, externalCalendarId);
   } else {
-    log.warn(
+    log.error(
       "Could not do deleteEvent - No calendar adapter found",
       safeStringify({
         credential: getPiiFreeCredential(credential),
+        event,
       })
     );
   }

packages/core/getUserAvailability.ts

@@ -164,7 +164,7 @@ export const getUserAvailability = async function getUsersWorkingHoursLifeTheUni
 
   const user = initialData?.user || (await getUser(where));
 
-  if (!user) throw new HttpError({ statusCode: 404, message: "No user found" });
+  if (!user) throw new HttpError({ statusCode: 404, message: "No user found in getUserAvailability" });
   log.debug(
     "getUserAvailability for user",
     safeStringify({ user: { id: user.id }, slot: { dateFrom, dateTo } })

packages/features/bookings/Booker/components/BookEventForm/BookEventForm.tsx

@@ -28,7 +28,6 @@ import { useBookingSuccessRedirect } from "@calcom/lib/bookingSuccessRedirect";
 import { MINUTES_TO_BOOK } from "@calcom/lib/constants";
 import { useLocale } from "@calcom/lib/hooks/useLocale";
 import { useRouterQuery } from "@calcom/lib/hooks/useRouterQuery";
-import { HttpError } from "@calcom/lib/http-error";
 import { trpc } from "@calcom/trpc";
 import { Alert, Button, EmptyScreen, Form, showToast } from "@calcom/ui";
 import { Calendar } from "@calcom/ui/components/icon";
@@ -153,6 +152,7 @@ export const BookEventFormChild = ({
   const verifiedEmail = useBookerStore((state) => state.verifiedEmail);
   const setVerifiedEmail = useBookerStore((state) => state.setVerifiedEmail);
   const bookingSuccessRedirect = useBookingSuccessRedirect();
+  const [responseVercelIdHeader, setResponseVercelIdHeader] = useState<string | null>(null);
 
   const router = useRouter();
   const { t, i18n } = useLocale();
@@ -220,7 +220,12 @@ export const BookEventFormChild = ({
         booking: responseData,
       });
     },
-    onError: () => {
+    onError: (err, _, ctx) => {
+      // TODO:
+      // const vercelId = ctx?.meta?.headers?.get("x-vercel-id");
+      // if (vercelId) {
+      //   setResponseVercelIdHeader(vercelId);
+      // }
       errorRef && errorRef.current?.scrollIntoView({ behavior: "smooth" });
     },
   });
@@ -390,7 +395,8 @@ export const BookEventFormChild = ({
                 bookingForm.formState.errors["globalError"],
                 createBookingMutation,
                 createRecurringBookingMutation,
-                t
+                t,
+                responseVercelIdHeader
               )}
             />
           </div>
@@ -438,16 +444,19 @@ const getError = (
   bookingMutation: UseMutationResult<any, any, any, any>,
   // eslint-disable-next-line @typescript-eslint/no-explicit-any
   recurringBookingMutation: UseMutationResult<any, any, any, any>,
-  t: TFunction
+  t: TFunction,
+  responseVercelIdHeader: string | null
 ) => {
   if (globalError) return globalError.message;
 
   const error = bookingMutation.error || recurringBookingMutation.error;
 
-  return error instanceof HttpError || error instanceof Error ? (
-    <>{t("can_you_try_again")}</>
+  return error.message ? (
+    <>
+      {responseVercelIdHeader ?? ""} {t(error.message)}
+    </>
   ) : (
-    "Unknown error"
+    <>{t("can_you_try_again")}</>
   );
 };
 

packages/features/bookings/lib/handleNewBooking.ts

@@ -6,6 +6,7 @@ import { isValidPhoneNumber } from "libphonenumber-js";
 import { cloneDeep } from "lodash";
 import type { NextApiRequest } from "next";
 import short, { uuid } from "short-uuid";
+import type { Logger } from "tslog";
 import { v5 as uuidv5 } from "uuid";
 import z from "zod";
 
@@ -52,6 +53,7 @@ import { cancelScheduledJobs, scheduleTrigger } from "@calcom/features/webhooks/
 import { isPrismaObjOrUndefined, parseRecurringEvent } from "@calcom/lib";
 import { getVideoCallUrlFromCalEvent } from "@calcom/lib/CalEventParser";
 import { getDefaultEvent, getUsernameList } from "@calcom/lib/defaultEvents";
+import { ErrorCode } from "@calcom/lib/errorCodes";
 import { getErrorFromUnknown } from "@calcom/lib/errors";
 import getPaymentAppData from "@calcom/lib/getPaymentAppData";
 import { getTeamIdFromEventType } from "@calcom/lib/getTeamIdFromEventType";
@@ -362,7 +364,8 @@ async function ensureAvailableUsers(
   eventType: Awaited<ReturnType<typeof getEventTypesFromDB>> & {
     users: IsFixedAwareUser[];
   },
-  input: { dateFrom: string; dateTo: string; timeZone: string; originalRescheduledBooking?: BookingType }
+  input: { dateFrom: string; dateTo: string; timeZone: string; originalRescheduledBooking?: BookingType },
+  loggerWithEventDetails: Logger<unknown>
 ) {
   const availableUsers: IsFixedAwareUser[] = [];
   const duration = dayjs(input.dateTo).diff(input.dateFrom, "minute");
@@ -433,7 +436,8 @@ async function ensureAvailableUsers(
     }
   }
   if (!availableUsers.length) {
-    throw new Error("No available users found.");
+    loggerWithEventDetails.error(`No available users found.`);
+    throw new Error(ErrorCode.NoAvailableUsersFound);
   }
   return availableUsers;
 }
@@ -556,7 +560,7 @@ async function getBookingData({
     return true;
   };
   if (!reqBodyWithEnd(reqBody)) {
-    throw new Error("Internal Error.");
+    throw new Error(ErrorCode.RequestBodyWithouEnd);
   }
   // reqBody.end is no longer an optional property.
   if ("customInputs" in reqBody) {
@@ -691,10 +695,11 @@ async function handler(
 
   const fullName = getFullName(bookerName);
 
+  // Why are we only using "en" locale
   const tGuests = await getTranslation("en", "common");
 
   const dynamicUserList = Array.isArray(reqBody.user) ? reqBody.user : getUsernameList(reqBody.user);
-  if (!eventType) throw new HttpError({ statusCode: 404, message: "eventType.notFound" });
+  if (!eventType) throw new HttpError({ statusCode: 404, message: "event_type_not_found" });
 
   const isTeamEventType =
     !!eventType.schedulingType && ["COLLECTIVE", "ROUND_ROBIN"].includes(eventType.schedulingType);
@@ -935,7 +940,8 @@ async function handler(
         dateTo: dayjs(reqBody.end).tz(reqBody.timeZone).format(),
         timeZone: reqBody.timeZone,
         originalRescheduledBooking,
-      }
+      },
+      loggerWithEventDetails
     );
 
     const luckyUsers: typeof users = [];
@@ -965,7 +971,7 @@ async function handler(
     if (
       availableUsers.filter((user) => user.isFixed).length !== users.filter((user) => user.isFixed).length
     ) {
-      throw new Error("Some of the hosts are unavailable for booking.");
+      throw new Error(ErrorCode.HostsUnavailableForBooking);
     }
     // Pushing fixed user before the luckyUser guarantees the (first) fixed user as the organizer.
     users = [...availableUsers.filter((user) => user.isFixed), ...luckyUsers];
@@ -1283,7 +1289,7 @@ async function handler(
       booking.attendees.find((attendee) => attendee.email === invitee[0].email) &&
       dayjs.utc(booking.startTime).format() === evt.startTime
     ) {
-      throw new HttpError({ statusCode: 409, message: "Already signed up for this booking." });
+      throw new HttpError({ statusCode: 409, message: ErrorCode.AlreadySignedUpForBooking });
     }
 
     // There are two paths here, reschedule a booking with seats and booking seats without reschedule
@@ -2694,7 +2700,7 @@ const findBookingQuery = async (bookingId: number) => {
 
   // This should never happen but it's just typescript safe
   if (!foundBooking) {
-    throw new Error("Internal Error.");
+    throw new Error("Internal Error. Couldn't find booking");
   }
 
   // Don't leak any sensitive data

packages/features/bookings/lib/handleNewBooking/test/fresh-booking.test.ts

@@ -13,6 +13,7 @@ import { describe, expect } from "vitest";
 
 import { appStoreMetadata } from "@calcom/app-store/appStoreMetaData";
 import { WEBAPP_URL } from "@calcom/lib/constants";
+import { ErrorCode } from "@calcom/lib/errorCodes";
 import { resetTestEmails } from "@calcom/lib/testEmails";
 import { BookingStatus } from "@calcom/prisma/enums";
 import { test } from "@calcom/web/test/fixtures/fixtures";
@@ -1024,7 +1025,7 @@ describe("handleNewBooking", () => {
             });
 
             await expect(async () => await handleNewBooking(req)).rejects.toThrowError(
-              "No available users found"
+              ErrorCode.NoAvailableUsersFound
             );
           },
           timeout
@@ -1111,7 +1112,7 @@ describe("handleNewBooking", () => {
             });
 
             await expect(async () => await handleNewBooking(req)).rejects.toThrowError(
-              "No available users found"
+              ErrorCode.NoAvailableUsersFound
             );
           },
           timeout
@@ -1239,7 +1240,7 @@ describe("handleNewBooking", () => {
        * NOTE: We might want to think about making the bookings get ACCEPTED automatically if the booker is the organizer of the event-type. This is a design decision it seems for now.
        */
       test(
-        `should make a fresh booking in PENDING state even when the booker is the organizer of the event-type 
+        `should make a fresh booking in PENDING state even when the booker is the organizer of the event-type
         1. Should create a booking in the database with status PENDING
         2. Should send emails to the booker as well as organizer for booking request and awaiting approval
         3. Should trigger BOOKING_REQUESTED webhook

packages/features/bookings/lib/handleNewBooking/test/recurring-event.test.ts

@@ -2,6 +2,7 @@ import { v4 as uuidv4 } from "uuid";
 import { describe, expect } from "vitest";
 
 import { WEBAPP_URL } from "@calcom/lib/constants";
+import { ErrorCode } from "@calcom/lib/errorCodes";
 import logger from "@calcom/lib/logger";
 import { BookingStatus } from "@calcom/prisma/enums";
 import { test } from "@calcom/web/test/fixtures/fixtures";
@@ -368,7 +369,7 @@ describe("handleNewBooking", () => {
             }),
         });
 
-        expect(() => handleRecurringEventBooking(req, res)).rejects.toThrow("No available users found");
+        expect(() => handleRecurringEventBooking(req, res)).rejects.toThrow(ErrorCode.NoAvailableUsersFound);
         // Actually the first booking goes through in this case but the status is still a failure. We should do a dry run to check if booking is possible  for the 2 slots and if yes, then only go for the actual booking otherwise fail the recurring bookign
       },
       timeout

packages/features/bookings/lib/handleNewBooking/test/team-bookings/collective-scheduling.test.ts

@@ -4,6 +4,7 @@ import { describe, expect } from "vitest";
 
 import { appStoreMetadata } from "@calcom/app-store/appStoreMetaData";
 import { WEBAPP_URL } from "@calcom/lib/constants";
+import { ErrorCode } from "@calcom/lib/errorCodes";
 import { SchedulingType } from "@calcom/prisma/enums";
 import { BookingStatus } from "@calcom/prisma/enums";
 import { test } from "@calcom/web/test/fixtures/fixtures";
@@ -353,7 +354,7 @@ describe("handleNewBooking", () => {
 
             await expect(async () => {
               await handleNewBooking(req);
-            }).rejects.toThrowError("Some of the hosts are unavailable for booking");
+            }).rejects.toThrowError(ErrorCode.HostsUnavailableForBooking);
           },
           timeout
         );
@@ -666,7 +667,7 @@ describe("handleNewBooking", () => {
 
             await expect(async () => {
               await handleNewBooking(req);
-            }).rejects.toThrowError("No available users found.");
+            }).rejects.toThrowError(ErrorCode.NoAvailableUsersFound);
           },
           timeout
         );

packages/lib/errorCodes.ts

@@ -0,0 +1,9 @@
+export enum ErrorCode {
+  PaymentCreationFailure = "payment_not_created_error",
+  NoAvailableUsersFound = "no_available_users_found_error",
+  ChargeCardFailure = "couldnt_charge_card_error",
+  RequestBodyWithouEnd = "request_body_end_time_internal_error",
+  AlreadySignedUpForBooking = "already_signed_up_for_this_booking_error",
+  HostsUnavailableForBooking = "hosts_unavailable_for_booking",
+  EventTypeNotFound = "event_type_not_found_error",
+}