Even more traces

packages/core/getUserAvailability.ts

@@ -7,10 +7,8 @@ import { parseBookingLimit, parseDurationLimit } from "@calcom/lib";
 import { getWorkingHours } from "@calcom/lib/availability";
 import { buildDateRanges, subtract } from "@calcom/lib/date-ranges";
 import { HttpError } from "@calcom/lib/http-error";
-import logger from "@calcom/lib/logger";
 import { checkBookingLimit } from "@calcom/lib/server";
 import { tracer, context } from "@calcom/lib/server/otel-initializer";
-import { performance } from "@calcom/lib/server/perfObserver";
 import { getTotalBookingDuration } from "@calcom/lib/server/queries";
 import prisma, { availabilityUserSelect } from "@calcom/prisma";
 import { BookingStatus } from "@calcom/prisma/enums";
@@ -202,6 +200,11 @@ export async function getUserAvailability(
 
   const bookingLimits = parseBookingLimit(eventType?.bookingLimits);
   if (bookingLimits) {
+    const getBusyTimesFromBookingLimitsSpan = tracer.startSpan(
+      "getBusyTimesFromBookingLimits-" + user.id,
+      undefined,
+      context.active()
+    );
     const bookingBusyTimes = await getBusyTimesFromBookingLimits(
       bookings,
       bookingLimits,
@@ -210,10 +213,16 @@ export async function getUserAvailability(
       eventType
     );
     bufferedBusyTimes = bufferedBusyTimes.concat(bookingBusyTimes);
+    getBusyTimesFromBookingLimitsSpan.end();
   }
 
   const durationLimits = parseDurationLimit(eventType?.durationLimits);
   if (durationLimits) {
+    const getBusyTimesFromDurationLimitsSpan = tracer.startSpan(
+      "getBusyTimesFromDurationLimits-" + user.id,
+      undefined,
+      context.active()
+    );
     const durationBusyTimes = await getBusyTimesFromDurationLimits(
       bookings,
       durationLimits,
@@ -223,6 +232,7 @@ export async function getUserAvailability(
       eventType
     );
     bufferedBusyTimes = bufferedBusyTimes.concat(durationBusyTimes);
+    getBusyTimesFromDurationLimitsSpan.end();
   }
 
   const userSchedule = user.schedules.filter(
@@ -234,9 +244,8 @@ export async function getUserAvailability(
       ? eventType.schedule
       : userSchedule;
 
-  const startGetWorkingHours = performance.now();
-
   const timeZone = schedule?.timeZone || eventType?.timeZone || user.timeZone;
+  const getWorkingHoursSpan = tracer.startSpan("getWorkingHours-" + user.id, undefined, context.active());
 
   const availability = (
     schedule.availability || (eventType?.availability.length ? eventType.availability : user.availability)
@@ -245,13 +254,10 @@ export async function getUserAvailability(
     userId: user.id,
   }));
 
-  const getWorkingHoursSpan = tracer.startSpan("getWorkingHours-" + user.id, undefined, context.active());
   const workingHours = getWorkingHours({ timeZone }, availability);
   getWorkingHoursSpan.end();
 
-  const endGetWorkingHours = performance.now();
-  logger.debug(`getWorkingHours took ${endGetWorkingHours - startGetWorkingHours}ms for userId ${userId}`);
-
+  const dateOverridesSpan = tracer.startSpan("dateOverrides-" + user.id, undefined, context.active());
   const dateOverrides = availability
     .filter((availability) => !!availability.date)
     .map((override) => {
@@ -263,6 +269,10 @@ export async function getUserAvailability(
       };
     });
 
+  dateOverridesSpan.end();
+
+  const buildDateRangesSpan = tracer.startSpan("buildDateRanges-" + user.id, undefined, context.active());
+
   const dateRanges = buildDateRanges({
     dateFrom,
     dateTo,
@@ -270,6 +280,8 @@ export async function getUserAvailability(
     timeZone,
   });
 
+  buildDateRangesSpan.end();
+
   const formattedBusyTimes = bufferedBusyTimes.map((busy) => ({
     start: dayjs(busy.start),
     end: dayjs(busy.end),

packages/trpc/server/routers/viewer/slots/util.ts

@@ -277,7 +277,14 @@ export async function getSchedule(input: TGetScheduleInputSchema) {
   const dateOverrides = userAvailability.flatMap((availability) =>
     availability.dateOverrides.map((override) => ({ userId: availability.user.id, ...override }))
   );
+  const getAggregateWorkingHoursSpan = tracer.startSpan(
+    "getAggregateWorkingHours",
+    undefined,
+    context.active()
+  );
   const workingHours = getAggregateWorkingHours(userAvailability, eventType.schedulingType);
+  getAggregateWorkingHoursSpan.end();
+
   const availabilityCheckProps = {
     eventLength: input.duration || eventType.length,
     currentSeats,
@@ -313,6 +320,7 @@ export async function getSchedule(input: TGetScheduleInputSchema) {
 
   let availableTimeSlots: typeof timeSlots = [];
   // Load cached busy slots
+  const selectedSlotsSpan = tracer.startSpan("selectedSlots", undefined, context.active());
   const selectedSlots =
     /* FIXME: For some reason this returns undefined while testing in Jest */
     (await prisma.selectedSlots.findMany({
@@ -333,9 +341,16 @@ export async function getSchedule(input: TGetScheduleInputSchema) {
     where: { eventTypeId: { equals: eventType.id }, id: { notIn: selectedSlots.map((item) => item.id) } },
   });
 
+  selectedSlotsSpan.end();
+
   availableTimeSlots = timeSlots;
 
   if (selectedSlots?.length > 0) {
+    const selectedSlotsProcessingSpan = tracer.startSpan(
+      "selectedSlotsProcessing",
+      undefined,
+      context.active()
+    );
     let occupiedSeats: typeof selectedSlots = selectedSlots.filter(
       (item) => item.isSeat && item.eventTypeId === eventType.id
     );
@@ -409,8 +424,10 @@ export async function getSchedule(input: TGetScheduleInputSchema) {
           return !!item;
         }
       );
+    selectedSlotsProcessing.end();
   }
 
+  const computedAvailableSlotsSpan = tracer.startSpan("computedAvailableSlots", undefined, context.active());
   availableTimeSlots = availableTimeSlots.filter((slot) => isTimeWithinBounds(slot.time));
 
   const computedAvailableSlots = availableTimeSlots.reduce(
@@ -450,6 +467,7 @@ export async function getSchedule(input: TGetScheduleInputSchema) {
     Object.create(null)
   );
 
+  computedAvailableSlotsSpan.end();
   logger.debug(`getSlots took ${getSlotsTime}ms and executed ${getSlotsCount} times`);
 
   logger.debug(