chore: Improved logging booking flow (calcom#11543)

packages/app-store/googlecalendar/lib/CalendarService.ts

@@ -298,6 +298,11 @@ export default class GoogleCalendarService implements Calendar {
         conferenceDataVersion: 1,
       });
 
+      this.log.debug("Updated Google Calendar Event", {
+        startTime: evt?.data.start,
+        endTime: evt?.data.end,
+      });
+
       if (evt && evt.data.id && evt.data.hangoutLink && event.location === MeetLocationType) {
         calendar.events.patch({
           // Update the same event but this time we know the hangout link

packages/core/CalendarManager.ts

@@ -7,6 +7,7 @@ import getApps from "@calcom/app-store/utils";
 import dayjs from "@calcom/dayjs";
 import { getUid } from "@calcom/lib/CalEventParser";
 import logger from "@calcom/lib/logger";
+import { getPiiFreeCalendarEvent } from "@calcom/lib/piiFreeData";
 import { performance } from "@calcom/lib/server/perfObserver";
 import type {
   CalendarEvent,
@@ -225,6 +226,12 @@ export const createEvent = async (
   let success = true;
   let calError: string | undefined = undefined;
 
+  log.debug(
+    "Creating calendar event",
+    JSON.stringify({
+      calEvent: getPiiFreeCalendarEvent(calEvent),
+    })
+  );
   // Check if the disabledNotes flag is set to true
   if (calEvent.hideCalendarNotes) {
     calEvent.additionalNotes = "Notes have been hidden by the organizer"; // TODO: i18n this string?
@@ -280,9 +287,19 @@ export const updateEvent = async (
   let success = false;
   let calError: string | undefined = undefined;
   let calWarnings: string[] | undefined = [];
-
+  log.debug(
+    "Updating calendar event",
+    JSON.stringify({
+      bookingRefUid,
+      calEvent: getPiiFreeCalendarEvent(calEvent),
+    })
+  );
   if (bookingRefUid === "") {
-    log.error("updateEvent failed", "bookingRefUid is empty", calEvent, credential);
+    log.error(
+      "updateEvent failed",
+      "bookingRefUid is empty",
+      JSON.stringify({ calEvent: getPiiFreeCalendarEvent(calEvent) })
+    );
   }
   const updatedResult: NewCalendarEventType | NewCalendarEventType[] | undefined =
     calendar && bookingRefUid
@@ -296,7 +313,10 @@ export const updateEvent = async (
             // @TODO: This code will be off till we can investigate an error with it
             // @see https://github.com/calcom/cal.com/issues/3949
             // await sendBrokenIntegrationEmail(calEvent, "calendar");
-            log.error("updateEvent failed", e, calEvent);
+            log.error(
+              "updateEvent failed",
+              JSON.stringify({ e, calEvent: getPiiFreeCalendarEvent(calEvent) })
+            );
             if (e?.calError) {
               calError = e.calError;
             }

packages/core/getBusyTimes.ts

@@ -4,6 +4,7 @@ import { getBusyCalendarTimes } from "@calcom/core/CalendarManager";
 import dayjs from "@calcom/dayjs";
 import { subtract } from "@calcom/lib/date-ranges";
 import logger from "@calcom/lib/logger";
+import { getPiiFreeBooking } from "@calcom/lib/piiFreeData";
 import { performance } from "@calcom/lib/server/perfObserver";
 import prisma from "@calcom/prisma";
 import type { SelectedCalendar } from "@calcom/prisma/client";
@@ -89,7 +90,6 @@ export async function getBusyTimes(params: {
       in: [BookingStatus.ACCEPTED],
     },
   };
-
   // INFO: Refactored to allow this method to take in a list of current bookings for the user.
   // Will keep support for retrieving a user's bookings if the caller does not already supply them.
   // This function is called from multiple places but we aren't refactoring all of them at this moment
@@ -179,7 +179,13 @@ export async function getBusyTimes(params: {
     []
   );
 
-  logger.silly(`Busy Time from Cal Bookings ${JSON.stringify(busyTimes)}`);
+  logger.debug(
+    `Busy Time from Cal Bookings ${JSON.stringify({
+      busyTimes,
+      bookings: bookings?.map((booking) => getPiiFreeBooking(booking)),
+      numCredentials: credentials?.length,
+    })}`
+  );
   performance.mark("prismaBookingGetEnd");
   performance.measure(`prisma booking get took $1'`, "prismaBookingGetStart", "prismaBookingGetEnd");
   if (credentials?.length > 0) {
@@ -195,7 +201,10 @@ export async function getBusyTimes(params: {
     logger.debug(
       `Connected Calendars get took ${
         endConnectedCalendarsGet - startConnectedCalendarsGet
-      } ms for user ${username}`
+      } ms for user ${username}`,
+      JSON.stringify({
+        calendarBusyTimes,
+      })
     );
 
     const openSeatsDateRanges = Object.keys(bookingSeatCountMap).map((key) => {
@@ -241,6 +250,12 @@ export async function getBusyTimes(params: {
     busyTimes.push(...videoBusyTimes);
     */
   }
+  logger.debug(
+    "getBusyTimes:",
+    JSON.stringify({
+      allBusyTimes: busyTimes,
+    })
+  );
   return busyTimes;
 }
 

packages/core/getUserAvailability.ts

@@ -244,7 +244,6 @@ export const getUserAvailability = async function getUsersWorkingHoursLifeTheUni
   const workingHours = getWorkingHours({ timeZone }, availability);
 
   const endGetWorkingHours = performance.now();
-  logger.debug(`getWorkingHours took ${endGetWorkingHours - startGetWorkingHours}ms for userId ${userId}`);
 
   const dateOverrides = availability
     .filter((availability) => !!availability.date)
@@ -269,10 +268,23 @@ export const getUserAvailability = async function getUsersWorkingHoursLifeTheUni
     end: dayjs(busy.end),
   }));
 
+  const dateRangesInWhichUserIsAvailable = subtract(dateRanges, formattedBusyTimes);
+
+  logger.debug(
+    `getWorkingHours took ${endGetWorkingHours - startGetWorkingHours}ms for userId ${userId}`,
+    JSON.stringify({
+      workingHoursInUtc: workingHours,
+      dateOverrides,
+      dateRangesAsPerAvailability: dateRanges,
+      dateRangesInWhichUserIsAvailable,
+      detailedBusyTimes,
+    })
+  );
+
   return {
     busy: detailedBusyTimes,
     timeZone,
-    dateRanges: subtract(dateRanges, formattedBusyTimes),
+    dateRanges: dateRangesInWhichUserIsAvailable,
     workingHours,
     dateOverrides,
     currentSeats,

packages/core/videoClient.ts

@@ -6,6 +6,7 @@ import { getDailyAppKeys } from "@calcom/app-store/dailyvideo/lib/getDailyAppKey
 import { sendBrokenIntegrationEmail } from "@calcom/emails";
 import { getUid } from "@calcom/lib/CalEventParser";
 import logger from "@calcom/lib/logger";
+import { getPiiFreeCalendarEvent } from "@calcom/lib/piiFreeData";
 import { prisma } from "@calcom/prisma";
 import type { GetRecordingsResponseSchema } from "@calcom/prisma/zod-utils";
 import type { CalendarEvent, EventBusyDate } from "@calcom/types/Calendar";
@@ -95,7 +96,7 @@ const createMeeting = async (credential: CredentialPayload, calEvent: CalendarEv
     returnObject = { ...returnObject, createdEvent: createdMeeting, success: true };
   } catch (err) {
     await sendBrokenIntegrationEmail(calEvent, "video");
-    console.error("createMeeting failed", err, calEvent);
+    log.error("createMeeting failed", JSON.stringify({ err, calEvent: getPiiFreeCalendarEvent(calEvent) }));
 
     // Default to calVideo
     const defaultMeeting = await createMeetingWithCalVideo(calEvent);

packages/features/bookings/lib/handleConfirmation.ts

@@ -52,7 +52,7 @@ export async function handleConfirmation(args: {
       message: "Booking failed",
     };
 
-    log.error(`Booking ${user.username} failed`, error, results);
+    log.error(`Booking ${user.username} failed`, JSON.stringify({ error, results }));
   } else {
     const metadata: AdditionalInformation = {};