From 1fcf0c0d8b9a3d200bfb81092c38c4d375af8791 Mon Sep 17 00:00:00 2001 From: Anna Larch Date: Mon, 29 Jan 2024 23:38:00 +0100 Subject: [PATCH] enh(appointments): add moar debug logging and overwrite app id Signed-off-by: Anna Larch --- .../Appointments/AvailabilityGenerator.php | 10 +++++++++- lib/Service/Appointments/BookingService.php | 10 +++++++--- lib/Service/Appointments/DailyLimitFilter.php | 12 ++++++++++-- .../Appointments/EventConflictFilter.php | 11 +++++++++-- lib/Service/Appointments/MailService.php | 18 +++++++++--------- lib/Service/Appointments/SlotExtrapolator.php | 14 +++++++++++++- 6 files changed, 57 insertions(+), 18 deletions(-) diff --git a/lib/Service/Appointments/AvailabilityGenerator.php b/lib/Service/Appointments/AvailabilityGenerator.php index e25d38f30f..20d1e56b26 100644 --- a/lib/Service/Appointments/AvailabilityGenerator.php +++ b/lib/Service/Appointments/AvailabilityGenerator.php @@ -31,6 +31,7 @@ use DateTimeZone; use OCA\Calendar\Db\AppointmentConfig; use OCP\AppFramework\Utility\ITimeFactory; +use Psr\Log\LoggerInterface; use function ceil; use function max; use function min; @@ -39,7 +40,7 @@ class AvailabilityGenerator { /** @var ITimeFactory */ private $timeFactory; - public function __construct(ITimeFactory $timeFactory) { + public function __construct(ITimeFactory $timeFactory, private LoggerInterface $logger) { $this->timeFactory = $timeFactory; } @@ -79,11 +80,17 @@ public function generate(AppointmentConfig $config, // If we reach this state then there are no available dates anymore if ($latestEnd <= $earliestStart) { + $this->logger->debug('Appointment config ' . $config->getToken() . ' has {latestEnd} as latest end but {earliestStart} as earliest start. No slots available.', [ + 'latestEnd' => $latestEnd, + 'earliestStart' => $earliestStart, + 'app' => 'appointments' + ]); return []; } if (empty($config->getAvailability())) { // No availability -> full time range is available + $this->logger->debug('Full time range available', ['app' => 'appointments']); return [ new Interval($earliestStart, $latestEnd), ]; @@ -95,6 +102,7 @@ public function generate(AppointmentConfig $config, $slots = $availabilityRule['slots']; $applicableSlots = $this->filterDates($start, $slots, $timeZone); + $this->logger->debug('Found ' . count($applicableSlots) . ' applicable slot(s) after date filtering', ['app' => 'appointments']); $intervals = []; foreach ($applicableSlots as $slot) { diff --git a/lib/Service/Appointments/BookingService.php b/lib/Service/Appointments/BookingService.php index e57120766d..8d358de54c 100644 --- a/lib/Service/Appointments/BookingService.php +++ b/lib/Service/Appointments/BookingService.php @@ -142,13 +142,13 @@ public function confirmBooking(Booking $booking, AppointmentConfig $config): Boo $this->mailService->sendBookingInformationEmail($booking, $config, $calendar); $this->mailService->sendOrganizerBookingInformationEmail($booking, $config, $calendar); } catch (ServiceException $e) { - $this->logger->info('Could not send booking emails after confirmation from user ' . $booking->getEmail(), ['exception' => $e]); + $this->logger->info('Could not send booking emails after confirmation from user ' . $booking->getEmail(), ['exception' => $e, 'app' => 'appointments']); } try { $this->mailService->sendOrganizerBookingInformationNotification($booking, $config); } catch (\InvalidArgumentException $e) { - $this->logger->warning('Could not send booking information notification after confirmation by user ' . $booking->getEmail(), ['exception' => $e]); + $this->logger->warning('Could not send booking information notification after confirmation by user ' . $booking->getEmail(), ['exception' => $e, 'app' => 'appointments']); } return $booking; @@ -203,10 +203,13 @@ public function getAvailableSlots(AppointmentConfig $config, int $startTime, int if ($config->getFutureLimit() !== null) { /** @var int $maxEndTime */ $maxEndTime = time() + $config->getFutureLimit(); + $this->logger->debug('Maximum end time: ' . $maxEndTime, ['app' => 'appointments']); if ($startTime > $maxEndTime) { + $this->logger->debug( 'Start time is higher than maximum end time. Start time: ' . $startTime, ['app' => 'appointments']); return []; } if ($endTime > $maxEndTime) { + $this->logger->debug( 'End time is higher than maximum end time. Setting end time to maximum end time. End time: ' . $endTime, ['app' => 'appointments']); $endTime = $maxEndTime; } } @@ -224,7 +227,8 @@ public function getAvailableSlots(AppointmentConfig $config, int $startTime, int 'availabilityIntervals' => count($availabilityIntervals), 'allPossibleSlots' => count($allPossibleSlots), 'filteredByDailyLimit' => count($filteredByDailyLimit), - 'available' => count($available) + 'available' => count($available), + 'app' => 'appointments', ]); return $available; diff --git a/lib/Service/Appointments/DailyLimitFilter.php b/lib/Service/Appointments/DailyLimitFilter.php index 188f69c08b..fe76e822e4 100644 --- a/lib/Service/Appointments/DailyLimitFilter.php +++ b/lib/Service/Appointments/DailyLimitFilter.php @@ -28,6 +28,7 @@ use OCA\Calendar\Db\AppointmentConfig; use OCP\Calendar\ICalendarQuery; use OCP\Calendar\IManager; +use Psr\Log\LoggerInterface; use function array_filter; use function array_values; use function count; @@ -36,7 +37,7 @@ class DailyLimitFilter { /** @var IManager */ private $calendarManger; - public function __construct(IManager $calendarManger) { + public function __construct(IManager $calendarManger, private LoggerInterface $logger) { $this->calendarManger = $calendarManger; } @@ -47,6 +48,10 @@ public function __construct(IManager $calendarManger) { * @return Interval[] */ public function filter(AppointmentConfig $config, array $slots): array { + $this->logger->debug('Slots before daily limit filtering:' . count($slots), ['app' => 'appointments']); + if(empty($slots)) { + return []; + } // 0. If there is no limit then we don't have to filter anything if ($config->getDailyMax() === null) { return $slots; @@ -90,10 +95,13 @@ public function filter(AppointmentConfig $config, array $slots): array { } // 3. Filter out the slots that are on an unavailable day - return array_values(array_filter($slots, function (Interval $slot) use ($available): bool { + $available = array_values(array_filter($slots, function (Interval $slot) use ($available): bool { $startOfDay = $slot->getStartAsObject()->setTime(0, 0, 0, 0); $ts = $startOfDay->getTimestamp(); return $available[$ts]; })); + + $this->logger->debug('Slots after daily limit filtering:' . count($available), ['app' => 'appointments']); + return $available; } } diff --git a/lib/Service/Appointments/EventConflictFilter.php b/lib/Service/Appointments/EventConflictFilter.php index 1af6fa0d34..879ee7df92 100644 --- a/lib/Service/Appointments/EventConflictFilter.php +++ b/lib/Service/Appointments/EventConflictFilter.php @@ -54,6 +54,10 @@ public function __construct(IManager $calendarManager, * @return Interval[] */ public function filter(AppointmentConfig $config, array $slots): array { + $this->logger->debug('Slots before event conflict filtering:' . count($slots), ['app' => 'appointments']); + if(empty($slots)) { + return []; + } $query = $this->calendarManager->newQuery($config->getPrincipalUri()); foreach ($config->getCalendarFreebusyUrisAsArray() as $uri) { $query->addSearchCalendar($uri); @@ -63,7 +67,7 @@ public function filter(AppointmentConfig $config, array $slots): array { $query->addType('VEVENT'); $preparationDuration = DateInterval::createFromDateString($config->getPreparationDuration() . ' seconds'); $followUpDuration = DateInterval::createFromDateString($config->getFollowupDuration() . ' seconds'); - return array_filter($slots, function (Interval $slot) use ($followUpDuration, $preparationDuration, $query, $config): bool { + $available = array_filter($slots, function (Interval $slot) use ($followUpDuration, $preparationDuration, $query, $config): bool { $query->setTimerangeStart($slot->getStartAsObject()->sub($preparationDuration)); $query->setTimerangeEnd($slot->getEndAsObject()->add($followUpDuration)); @@ -81,7 +85,7 @@ public function filter(AppointmentConfig $config, array $slots): array { $this->logger->debug('Appointment config ' . $config->getToken() . ' is looking within {start} and {followup} in calendar {calendarUri}. Conflicting UIDs are {uids}', [ 'start' => $slot->getStartAsObject()->sub($preparationDuration)->format(DateTimeInterface::ATOM), - 'end' => $slot->getEndAsObject()->add($followUpDuration)->format(DateTimeInterface::ATOM), + 'followup' => $slot->getEndAsObject()->add($followUpDuration)->format(DateTimeInterface::ATOM), 'calendarUri' => $config->getTargetCalendarUri(), 'uids' => implode(' : ', $uids) ]); @@ -89,5 +93,8 @@ public function filter(AppointmentConfig $config, array $slots): array { // If there is at least one event at this time then the slot is taken return empty($objects); }); + + $this->logger->debug('Slots after event conflict filtering:' . count($available), ['app' => 'appointments']); + return $available; } } diff --git a/lib/Service/Appointments/MailService.php b/lib/Service/Appointments/MailService.php index c52fb0f369..07dea98af5 100644 --- a/lib/Service/Appointments/MailService.php +++ b/lib/Service/Appointments/MailService.php @@ -146,14 +146,14 @@ public function sendConfirmationEmail(Booking $booking, AppointmentConfig $confi try { $failed = $this->mailer->send($message); if (count($failed) > 0) { - $this->logger->warning('Mail delivery failed for some recipients.'); + $this->logger->warning('Mail delivery failed for some recipients.', ['app' => 'appointments']); foreach ($failed as $fail) { - $this->logger->debug('Failed to deliver email to ' . $fail); + $this->logger->debug('Failed to deliver email to ' . $fail, ['app' => 'appointments']); } throw new ServiceException('Could not send mail for recipient(s) ' . implode(', ', $failed)); } } catch (Exception $ex) { - $this->logger->error($ex->getMessage(), ['exception' => $ex]); + $this->logger->error($ex->getMessage(), ['exception' => $ex, 'app' => 'appointments']); throw new ServiceException('Could not send mail: ' . $ex->getMessage(), $ex->getCode(), $ex); } } @@ -215,14 +215,14 @@ public function sendBookingInformationEmail(Booking $booking, AppointmentConfig try { $failed = $this->mailer->send($message); if (count($failed) > 0) { - $this->logger->warning('Mail delivery failed for some recipients.'); + $this->logger->warning('Mail delivery failed for some recipients.', ['app' => 'appointments']); foreach ($failed as $fail) { - $this->logger->debug('Failed to deliver email to ' . $fail); + $this->logger->debug('Failed to deliver email to ' . $fail, ['app' => 'appointments']); } throw new ServiceException('Could not send mail for recipient(s) ' . implode(', ', $failed)); } } catch (Exception $ex) { - $this->logger->error($ex->getMessage(), ['exception' => $ex]); + $this->logger->error($ex->getMessage(), ['exception' => $ex, 'app' => 'appointments']); throw new ServiceException('Could not send mail: ' . $ex->getMessage(), $ex->getCode(), $ex); } } @@ -320,14 +320,14 @@ public function sendOrganizerBookingInformationEmail(Booking $booking, Appointme try { $failed = $this->mailer->send($message); if (count($failed) > 0) { - $this->logger->warning('Mail delivery failed for some recipients.'); + $this->logger->warning('Mail delivery failed for some recipients.', ['app' => 'appointments']); foreach ($failed as $fail) { - $this->logger->debug('Failed to deliver email to ' . $fail); + $this->logger->debug('Failed to deliver email to ' . $fail, ['app' => 'appointments']); } throw new ServiceException('Could not send mail for recipient(s) ' . implode(', ', $failed)); } } catch (Exception $ex) { - $this->logger->error('Could not send appointment organizer email: ' . $ex->getMessage(), ['exception' => $ex]); + $this->logger->error('Could not send appointment organizer email: ' . $ex->getMessage(), ['exception' => $ex, 'app' => 'appointments']); throw new ServiceException('Could not send mail: ' . $ex->getMessage(), $ex->getCode(), $ex); } } diff --git a/lib/Service/Appointments/SlotExtrapolator.php b/lib/Service/Appointments/SlotExtrapolator.php index 36119c1a00..d85de21bfc 100644 --- a/lib/Service/Appointments/SlotExtrapolator.php +++ b/lib/Service/Appointments/SlotExtrapolator.php @@ -26,17 +26,28 @@ namespace OCA\Calendar\Service\Appointments; use OCA\Calendar\Db\AppointmentConfig; +use Psr\Log\LoggerInterface; class SlotExtrapolator { + + public function __construct(private LoggerInterface $logger) { + + } /** * @param AppointmentConfig $config * @param Interval[] $availabilityIntervals - * @param int $to * * @return Interval[] */ public function extrapolate(AppointmentConfig $config, array $availabilityIntervals): array { + $this->logger->debug('Intervals before extrapolating:' . count($availabilityIntervals), ['app' => 'appointments']); + if(empty($availabilityIntervals)) { + return []; + } + foreach ($availabilityIntervals as $availabilityInterval) { + $this->logger->debug('Interval start: ' . $availabilityInterval->getStart() . ', interval end: ' . $availabilityInterval->getEnd(), ['app' => 'appointments']); + } $increment = $config->getIncrement(); $length = $config->getLength(); $slots = []; @@ -50,6 +61,7 @@ public function extrapolate(AppointmentConfig $config, } } + $this->logger->debug('Slots after extrapolating:' . count($slots), ['app' => 'appointments']); return $slots; } }