Skip to content

Commit 8e49503

Browse files
miaulalalamiaulalala
authored
Merge pull request #5723 from nextcloud/enh/moar-logging
enh(appointments): add moar debug logging and overwrite app id
2 parents 1c6eb45 + 9d54b96 commit 8e49503

9 files changed

+74
-31
lines changed

‎lib/Service/Appointments/AvailabilityGenerator.php

+9-1
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@
3131
use DateTimeZone;
3232
use OCA\Calendar\Db\AppointmentConfig;
3333
use OCP\AppFramework\Utility\ITimeFactory;
34+
use Psr\Log\LoggerInterface;
3435
use function ceil;
3536
use function max;
3637
use function min;
@@ -39,7 +40,7 @@ class AvailabilityGenerator {
3940
/** @var ITimeFactory */
4041
private $timeFactory;
4142

42-
public function __construct(ITimeFactory $timeFactory) {
43+
public function __construct(ITimeFactory $timeFactory, private LoggerInterface $logger) {
4344
$this->timeFactory = $timeFactory;
4445
}
4546

@@ -79,11 +80,17 @@ public function generate(AppointmentConfig $config,
7980

8081
// If we reach this state then there are no available dates anymore
8182
if ($latestEnd <= $earliestStart) {
83+
$this->logger->debug('Appointment config ' . $config->getToken() . ' has {latestEnd} as latest end but {earliestStart} as earliest start. No slots available.', [
84+
'latestEnd' => $latestEnd,
85+
'earliestStart' => $earliestStart,
86+
'app' => 'calendar-appointments'
87+
]);
8288
return [];
8389
}
8490

8591
if (empty($config->getAvailability())) {
8692
// No availability -> full time range is available
93+
$this->logger->debug('Full time range available', ['app' => 'calendar-appointments']);
8794
return [
8895
new Interval($earliestStart, $latestEnd),
8996
];
@@ -95,6 +102,7 @@ public function generate(AppointmentConfig $config,
95102
$slots = $availabilityRule['slots'];
96103

97104
$applicableSlots = $this->filterDates($start, $slots, $timeZone);
105+
$this->logger->debug('Found ' . count($applicableSlots) . ' applicable slot(s) after date filtering', ['app' => 'calendar-appointments']);
98106

99107
$intervals = [];
100108
foreach ($applicableSlots as $slot) {

‎lib/Service/Appointments/BookingService.php

+7-3
Original file line numberDiff line numberDiff line change
@@ -142,13 +142,13 @@ public function confirmBooking(Booking $booking, AppointmentConfig $config): Boo
142142
$this->mailService->sendBookingInformationEmail($booking, $config, $calendar);
143143
$this->mailService->sendOrganizerBookingInformationEmail($booking, $config, $calendar);
144144
} catch (ServiceException $e) {
145-
$this->logger->info('Could not send booking emails after confirmation from user ' . $booking->getEmail(), ['exception' => $e]);
145+
$this->logger->info('Could not send booking emails after confirmation from user ' . $booking->getEmail(), ['exception' => $e, 'app' => 'calendar-appointments']);
146146
}
147147

148148
try {
149149
$this->mailService->sendOrganizerBookingInformationNotification($booking, $config);
150150
} catch (\InvalidArgumentException $e) {
151-
$this->logger->warning('Could not send booking information notification after confirmation by user ' . $booking->getEmail(), ['exception' => $e]);
151+
$this->logger->warning('Could not send booking information notification after confirmation by user ' . $booking->getEmail(), ['exception' => $e, 'app' => 'calendar-appointments']);
152152
}
153153

154154
return $booking;
@@ -203,10 +203,13 @@ public function getAvailableSlots(AppointmentConfig $config, int $startTime, int
203203
if ($config->getFutureLimit() !== null) {
204204
/** @var int $maxEndTime */
205205
$maxEndTime = time() + $config->getFutureLimit();
206+
$this->logger->debug('Maximum end time: ' . $maxEndTime, ['app' => 'calendar-appointments']);
206207
if ($startTime > $maxEndTime) {
208+
$this->logger->debug('Start time is higher than maximum end time. Start time: ' . $startTime, ['app' => 'calendar-appointments']);
207209
return [];
208210
}
209211
if ($endTime > $maxEndTime) {
212+
$this->logger->debug('End time is higher than maximum end time. Setting end time to maximum end time. End time: ' . $endTime, ['app' => 'calendar-appointments']);
210213
$endTime = $maxEndTime;
211214
}
212215
}
@@ -224,7 +227,8 @@ public function getAvailableSlots(AppointmentConfig $config, int $startTime, int
224227
'availabilityIntervals' => count($availabilityIntervals),
225228
'allPossibleSlots' => count($allPossibleSlots),
226229
'filteredByDailyLimit' => count($filteredByDailyLimit),
227-
'available' => count($available)
230+
'available' => count($available),
231+
'app' => 'calendar-appointments',
228232
]);
229233

230234
return $available;

‎lib/Service/Appointments/DailyLimitFilter.php

+10-2
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@
2828
use OCA\Calendar\Db\AppointmentConfig;
2929
use OCP\Calendar\ICalendarQuery;
3030
use OCP\Calendar\IManager;
31+
use Psr\Log\LoggerInterface;
3132
use function array_filter;
3233
use function array_values;
3334
use function count;
@@ -36,7 +37,7 @@ class DailyLimitFilter {
3637
/** @var IManager */
3738
private $calendarManger;
3839

39-
public function __construct(IManager $calendarManger) {
40+
public function __construct(IManager $calendarManger, private LoggerInterface $logger) {
4041
$this->calendarManger = $calendarManger;
4142
}
4243

@@ -47,6 +48,10 @@ public function __construct(IManager $calendarManger) {
4748
* @return Interval[]
4849
*/
4950
public function filter(AppointmentConfig $config, array $slots): array {
51+
$this->logger->debug('Slots before daily limit filtering:' . count($slots), ['app' => 'calendar-appointments']);
52+
if(empty($slots)) {
53+
return [];
54+
}
5055
// 0. If there is no limit then we don't have to filter anything
5156
if ($config->getDailyMax() === null) {
5257
return $slots;
@@ -90,10 +95,13 @@ public function filter(AppointmentConfig $config, array $slots): array {
9095
}
9196

9297
// 3. Filter out the slots that are on an unavailable day
93-
return array_values(array_filter($slots, function (Interval $slot) use ($available): bool {
98+
$available = array_values(array_filter($slots, function (Interval $slot) use ($available): bool {
9499
$startOfDay = $slot->getStartAsObject()->setTime(0, 0, 0, 0);
95100
$ts = $startOfDay->getTimestamp();
96101
return $available[$ts];
97102
}));
103+
104+
$this->logger->debug('Slots after daily limit filtering:' . count($available), ['app' => 'calendar-appointments']);
105+
return $available;
98106
}
99107
}

‎lib/Service/Appointments/EventConflictFilter.php

+9-2
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,10 @@ public function __construct(IManager $calendarManager,
5454
* @return Interval[]
5555
*/
5656
public function filter(AppointmentConfig $config, array $slots): array {
57+
$this->logger->debug('Slots before event conflict filtering:' . count($slots), ['app' => 'calendar-appointments']);
58+
if(empty($slots)) {
59+
return [];
60+
}
5761
$query = $this->calendarManager->newQuery($config->getPrincipalUri());
5862
foreach ($config->getCalendarFreebusyUrisAsArray() as $uri) {
5963
$query->addSearchCalendar($uri);
@@ -63,7 +67,7 @@ public function filter(AppointmentConfig $config, array $slots): array {
6367
$query->addType('VEVENT');
6468
$preparationDuration = DateInterval::createFromDateString($config->getPreparationDuration() . ' seconds');
6569
$followUpDuration = DateInterval::createFromDateString($config->getFollowupDuration() . ' seconds');
66-
return array_filter($slots, function (Interval $slot) use ($followUpDuration, $preparationDuration, $query, $config): bool {
70+
$available = array_filter($slots, function (Interval $slot) use ($followUpDuration, $preparationDuration, $query, $config): bool {
6771
$query->setTimerangeStart($slot->getStartAsObject()->sub($preparationDuration));
6872
$query->setTimerangeEnd($slot->getEndAsObject()->add($followUpDuration));
6973

@@ -81,13 +85,16 @@ public function filter(AppointmentConfig $config, array $slots): array {
8185

8286
$this->logger->debug('Appointment config ' . $config->getToken() . ' is looking within {start} and {followup} in calendar {calendarUri}. Conflicting UIDs are {uids}', [
8387
'start' => $slot->getStartAsObject()->sub($preparationDuration)->format(DateTimeInterface::ATOM),
84-
'end' => $slot->getEndAsObject()->add($followUpDuration)->format(DateTimeInterface::ATOM),
88+
'followup' => $slot->getEndAsObject()->add($followUpDuration)->format(DateTimeInterface::ATOM),
8589
'calendarUri' => $config->getTargetCalendarUri(),
8690
'uids' => implode(' : ', $uids)
8791
]);
8892

8993
// If there is at least one event at this time then the slot is taken
9094
return empty($objects);
9195
});
96+
97+
$this->logger->debug('Slots after event conflict filtering:' . count($available), ['app' => 'calendar-appointments']);
98+
return $available;
9299
}
93100
}

‎lib/Service/Appointments/MailService.php

+9-9
Original file line numberDiff line numberDiff line change
@@ -146,14 +146,14 @@ public function sendConfirmationEmail(Booking $booking, AppointmentConfig $confi
146146
try {
147147
$failed = $this->mailer->send($message);
148148
if (count($failed) > 0) {
149-
$this->logger->warning('Mail delivery failed for some recipients.');
149+
$this->logger->warning('Mail delivery failed for some recipients.', ['app' => 'calendar-appointments']);
150150
foreach ($failed as $fail) {
151-
$this->logger->debug('Failed to deliver email to ' . $fail);
151+
$this->logger->debug('Failed to deliver email to ' . $fail, ['app' => 'calendar-appointments']);
152152
}
153153
throw new ServiceException('Could not send mail for recipient(s) ' . implode(', ', $failed));
154154
}
155155
} catch (Exception $ex) {
156-
$this->logger->error($ex->getMessage(), ['exception' => $ex]);
156+
$this->logger->error($ex->getMessage(), ['exception' => $ex, 'app' => 'calendar-appointments']);
157157
throw new ServiceException('Could not send mail: ' . $ex->getMessage(), $ex->getCode(), $ex);
158158
}
159159
}
@@ -215,14 +215,14 @@ public function sendBookingInformationEmail(Booking $booking, AppointmentConfig
215215
try {
216216
$failed = $this->mailer->send($message);
217217
if (count($failed) > 0) {
218-
$this->logger->warning('Mail delivery failed for some recipients.');
218+
$this->logger->warning('Mail delivery failed for some recipients.', ['app' => 'calendar-appointments']);
219219
foreach ($failed as $fail) {
220-
$this->logger->debug('Failed to deliver email to ' . $fail);
220+
$this->logger->debug('Failed to deliver email to ' . $fail, ['app' => 'calendar-appointments']);
221221
}
222222
throw new ServiceException('Could not send mail for recipient(s) ' . implode(', ', $failed));
223223
}
224224
} catch (Exception $ex) {
225-
$this->logger->error($ex->getMessage(), ['exception' => $ex]);
225+
$this->logger->error($ex->getMessage(), ['exception' => $ex, 'app' => 'calendar-appointments']);
226226
throw new ServiceException('Could not send mail: ' . $ex->getMessage(), $ex->getCode(), $ex);
227227
}
228228
}
@@ -320,14 +320,14 @@ public function sendOrganizerBookingInformationEmail(Booking $booking, Appointme
320320
try {
321321
$failed = $this->mailer->send($message);
322322
if (count($failed) > 0) {
323-
$this->logger->warning('Mail delivery failed for some recipients.');
323+
$this->logger->warning('Mail delivery failed for some recipients.', ['app' => 'calendar-appointments']);
324324
foreach ($failed as $fail) {
325-
$this->logger->debug('Failed to deliver email to ' . $fail);
325+
$this->logger->debug('Failed to deliver email to ' . $fail, ['app' => 'calendar-appointments']);
326326
}
327327
throw new ServiceException('Could not send mail for recipient(s) ' . implode(', ', $failed));
328328
}
329329
} catch (Exception $ex) {
330-
$this->logger->error('Could not send appointment organizer email: ' . $ex->getMessage(), ['exception' => $ex]);
330+
$this->logger->error('Could not send appointment organizer email: ' . $ex->getMessage(), ['exception' => $ex, 'app' => 'calendar-appointments']);
331331
throw new ServiceException('Could not send mail: ' . $ex->getMessage(), $ex->getCode(), $ex);
332332
}
333333
}

‎lib/Service/Appointments/SlotExtrapolator.php

+13-1
Original file line numberDiff line numberDiff line change
@@ -26,17 +26,28 @@
2626
namespace OCA\Calendar\Service\Appointments;
2727

2828
use OCA\Calendar\Db\AppointmentConfig;
29+
use Psr\Log\LoggerInterface;
2930

3031
class SlotExtrapolator {
32+
33+
public function __construct(private LoggerInterface $logger) {
34+
35+
}
3136
/**
3237
* @param AppointmentConfig $config
3338
* @param Interval[] $availabilityIntervals
34-
* @param int $to
3539
*
3640
* @return Interval[]
3741
*/
3842
public function extrapolate(AppointmentConfig $config,
3943
array $availabilityIntervals): array {
44+
$this->logger->debug('Intervals before extrapolating:' . count($availabilityIntervals), ['app' => 'calendar-appointments']);
45+
if(empty($availabilityIntervals)) {
46+
return [];
47+
}
48+
foreach ($availabilityIntervals as $availabilityInterval) {
49+
$this->logger->debug('Interval start: ' . $availabilityInterval->getStart() . ', interval end: ' . $availabilityInterval->getEnd(), ['app' => 'calendar-appointments']);
50+
}
4051
$increment = $config->getIncrement();
4152
$length = $config->getLength();
4253
$slots = [];
@@ -50,6 +61,7 @@ public function extrapolate(AppointmentConfig $config,
5061
}
5162
}
5263

64+
$this->logger->debug('Slots after extrapolating:' . count($slots), ['app' => 'calendar-appointments']);
5365
return $slots;
5466
}
5567
}

‎tests/php/unit/Service/Appointments/AvailabilityGeneratorTest.php

+6-7
Original file line numberDiff line numberDiff line change
@@ -34,14 +34,12 @@
3434
use OCP\AppFramework\Utility\ITimeFactory;
3535
use OCP\Calendar\ICalendarQuery;
3636
use PHPUnit\Framework\MockObject\MockObject;
37+
use Psr\Log\LoggerInterface;
3738

3839
class AvailabilityGeneratorTest extends TestCase {
39-
/** @var ITimeFactory|MockObject */
40-
private $timeFactory;
41-
42-
/** @var AvailabilityGenerator */
43-
private $generator;
44-
40+
private ITimeFactory|MockObject $timeFactory;
41+
private MockObject|LoggerInterface $logger;
42+
private AvailabilityGenerator $generator;
4543
protected function setUp(): void {
4644
parent::setUp();
4745

@@ -50,9 +48,10 @@ protected function setUp(): void {
5048
}
5149

5250
$this->timeFactory = $this->createMock(ITimeFactory::class);
53-
51+
$this->logger = $this->createMock(LoggerInterface::class);
5452
$this->generator = new AvailabilityGenerator(
5553
$this->timeFactory,
54+
$this->logger,
5655
);
5756
}
5857

‎tests/php/unit/Service/Appointments/DailyLimitFilterTest.php

+6-5
Original file line numberDiff line numberDiff line change
@@ -32,16 +32,15 @@
3232
use OCP\Calendar\ICalendarQuery;
3333
use OCP\Calendar\IManager;
3434
use PHPUnit\Framework\MockObject\MockObject;
35+
use Psr\Log\LoggerInterface;
3536

3637
/**
3738
* @requires OCP\Calendar\ICalendarQuery::newQuery
3839
*/
3940
class DailyLimitFilterTest extends TestCase {
40-
/** @var IManager|MockObject */
41-
private $manager;
42-
43-
/** @var DailyLimitFilter */
44-
private $filter;
41+
private IManager|MockObject $manager;
42+
private MockObject|LoggerInterface $logger;
43+
private DailyLimitFilter $filter;
4544

4645
protected function setUp(): void {
4746
parent::setUp();
@@ -51,9 +50,11 @@ protected function setUp(): void {
5150
}
5251

5352
$this->manager = $this->createMock(IManager::class);
53+
$this->logger = $this->createMock(LoggerInterface::class);
5454

5555
$this->filter = new DailyLimitFilter(
5656
$this->manager,
57+
$this->logger,
5758
);
5859
}
5960

‎tests/php/unit/Service/Appointments/SlotExtrapolatorTest.php

+5-1
Original file line numberDiff line numberDiff line change
@@ -30,10 +30,13 @@
3030
use OCA\Calendar\Service\Appointments\Interval;
3131
use OCA\Calendar\Service\Appointments\SlotExtrapolator;
3232
use OCP\Calendar\ICalendarQuery;
33+
use Psr\Log\LoggerInterface;
34+
use Psr\Log\LoggerInterface\PHPUnit\Framework\MockObject\MockObject;
3335

3436
class SlotExtrapolatorTest extends TestCase {
3537
/** @var SlotExtrapolator */
3638
private $extrapolator;
39+
private MockObject|LoggerInterface $logger;
3740

3841
protected function setUp(): void {
3942
parent::setUp();
@@ -42,7 +45,8 @@ protected function setUp(): void {
4245
self::markTestIncomplete();
4346
}
4447

45-
$this->extrapolator = new SlotExtrapolator();
48+
$this->logger = $this->createMock(LoggerInterface::class);
49+
$this->extrapolator = new SlotExtrapolator($this->logger);
4650
}
4751

4852
public function testNoAvailability(): void {

0 commit comments

Comments
 (0)