Merge pull request #34865 from nextcloud/enh/log-log-itip-message-response

Add logging to Scheduling Plugin

5 files changed, 23 insertions, 9 deletions

diff --git a/apps/dav/appinfo/v1/caldav.php b/apps/dav/appinfo/v1/caldav.php
index 1f55266a21f..24a81e9af94 100644
--- a/apps/dav/appinfo/v1/caldav.php
+++ b/apps/dav/appinfo/v1/caldav.php
@@ -110,7 +110,7 @@ if ($debugging) {
 
 $server->addPlugin(new \Sabre\DAV\Sync\Plugin());
 $server->addPlugin(new \Sabre\CalDAV\ICSExportPlugin());
-$server->addPlugin(new \OCA\DAV\CalDAV\Schedule\Plugin(\OC::$server->getConfig()));
+$server->addPlugin(new \OCA\DAV\CalDAV\Schedule\Plugin(\OC::$server->getConfig(), \OC::$server->get(LoggerInterface::class)));
 
 if ($sendInvitations) {
 	$server->addPlugin(\OC::$server->query(\OCA\DAV\CalDAV\Schedule\IMipPlugin::class));
diff --git a/apps/dav/lib/CalDAV/InvitationResponse/InvitationResponseServer.php b/apps/dav/lib/CalDAV/InvitationResponse/InvitationResponseServer.php
index e64c815753b..e92eae2d3f1 100644
--- a/apps/dav/lib/CalDAV/InvitationResponse/InvitationResponseServer.php
+++ b/apps/dav/lib/CalDAV/InvitationResponse/InvitationResponseServer.php
@@ -89,7 +89,7 @@ class InvitationResponseServer {
 		// calendar plugins
 		$this->server->addPlugin(new \OCA\DAV\CalDAV\Plugin());
 		$this->server->addPlugin(new \Sabre\CalDAV\ICSExportPlugin());
-		$this->server->addPlugin(new \OCA\DAV\CalDAV\Schedule\Plugin(\OC::$server->getConfig()));
+		$this->server->addPlugin(new \OCA\DAV\CalDAV\Schedule\Plugin(\OC::$server->getConfig(), \OC::$server->get(LoggerInterface::class)));
 		$this->server->addPlugin(new \Sabre\CalDAV\Subscriptions\Plugin());
 		$this->server->addPlugin(new \Sabre\CalDAV\Notifications\Plugin());
 		//$this->server->addPlugin(new \OCA\DAV\DAV\Sharing\Plugin($authBackend, \OC::$server->getRequest()));
diff --git a/apps/dav/lib/CalDAV/Schedule/Plugin.php b/apps/dav/lib/CalDAV/Schedule/Plugin.php
index ed160cac2c2..ac8521acfee 100644
--- a/apps/dav/lib/CalDAV/Schedule/Plugin.php
+++ b/apps/dav/lib/CalDAV/Schedule/Plugin.php
@@ -34,6 +34,7 @@ use OCA\DAV\CalDAV\CalDavBackend;
 use OCA\DAV\CalDAV\Calendar;
 use OCA\DAV\CalDAV\CalendarHome;
 use OCP\IConfig;
+use Psr\Log\LoggerInterface;
 use Sabre\CalDAV\ICalendar;
 use Sabre\DAV\INode;
 use Sabre\DAV\IProperties;
@@ -70,12 +71,14 @@ class Plugin extends \Sabre\CalDAV\Schedule\Plugin {
 
 	public const CALENDAR_USER_TYPE = '{' . self::NS_CALDAV . '}calendar-user-type';
 	public const SCHEDULE_DEFAULT_CALENDAR_URL = '{' . Plugin::NS_CALDAV . '}schedule-default-calendar-URL';
+	private LoggerInterface $logger;
 
 	/**
 	 * @param IConfig $config
 	 */
-	public function __construct(IConfig $config) {
+	public function __construct(IConfig $config, LoggerInterface $logger) {
 		$this->config = $config;
+		$this->logger = $logger;
 	}
 
 	/**
@@ -166,7 +169,7 @@ class Plugin extends \Sabre\CalDAV\Schedule\Plugin {
 	 * @inheritDoc
 	 */
 	public function scheduleLocalDelivery(ITip\Message $iTipMessage):void {
-		/** @var Component|null $vevent */
+		/** @var VEvent|null $vevent */
 		$vevent = $iTipMessage->message->VEVENT ?? null;
 
 		// Strip VALARMs from incoming VEVENT
@@ -175,12 +178,13 @@ class Plugin extends \Sabre\CalDAV\Schedule\Plugin {
 		}
 
 		parent::scheduleLocalDelivery($iTipMessage);
-
 		// We only care when the message was successfully delivered locally
+		// Log all possible codes returned from the parent method that mean something went wrong
+		// 3.7, 3.8, 5.0, 5.2
 		if ($iTipMessage->scheduleStatus !== '1.2;Message delivered locally') {
+			$this->logger->debug('Message not delivered locally with status: ' . $iTipMessage->scheduleStatus);
 			return;
 		}
-
 		// We only care about request. reply and cancel are properly handled
 		// by parent::scheduleLocalDelivery already
 		if (strcasecmp($iTipMessage->method, 'REQUEST') !== 0) {
@@ -196,26 +200,31 @@ class Plugin extends \Sabre\CalDAV\Schedule\Plugin {
 		$principalUri = $aclPlugin->getPrincipalByUri($iTipMessage->recipient);
 		$calendarUserType = $this->getCalendarUserTypeForPrincipal($principalUri);
 		if (strcasecmp($calendarUserType, 'ROOM') !== 0 && strcasecmp($calendarUserType, 'RESOURCE') !== 0) {
+			$this->logger->debug('Calendar user type is room or resource, not processing further');
 			return;
 		}
 
 		$attendee = $this->getCurrentAttendee($iTipMessage);
 		if (!$attendee) {
+			$this->logger->debug('No attendee set for scheduling message');
 			return;
 		}
 
 		// We only respond when a response was actually requested
 		$rsvp = $this->getAttendeeRSVP($attendee);
 		if (!$rsvp) {
+			$this->logger->debug('No RSVP requested for attendee ' . $attendee->getValue());
 			return;
 		}
 
 		if (!$vevent) {
+			$this->logger->debug('No VEVENT set to process on scheduling message');
 			return;
 		}
 
 		// We don't support autoresponses for recurrencing events for now
 		if (isset($vevent->RRULE) || isset($vevent->RDATE)) {
+			$this->logger->debug('VEVENT is a recurring event, autoresponding not supported');
 			return;
 		}
 
diff --git a/apps/dav/lib/Server.php b/apps/dav/lib/Server.php
index 437a425fcd3..a5833e5175f 100644
--- a/apps/dav/lib/Server.php
+++ b/apps/dav/lib/Server.php
@@ -171,7 +171,7 @@ class Server {
 		if ($this->requestIsForSubtree(['calendars', 'public-calendars', 'system-calendars', 'principals'])) {
 			$this->server->addPlugin(new \OCA\DAV\CalDAV\Plugin());
 			$this->server->addPlugin(new \OCA\DAV\CalDAV\ICSExportPlugin\ICSExportPlugin(\OC::$server->getConfig(), $logger));
-			$this->server->addPlugin(new \OCA\DAV\CalDAV\Schedule\Plugin(\OC::$server->getConfig()));
+			$this->server->addPlugin(new \OCA\DAV\CalDAV\Schedule\Plugin(\OC::$server->getConfig(), \OC::$server->get(LoggerInterface::class)));
 			if (\OC::$server->getConfig()->getAppValue('dav', 'sendInvitations', 'yes') === 'yes') {
 				$this->server->addPlugin(\OC::$server->query(\OCA\DAV\CalDAV\Schedule\IMipPlugin::class));
 			}
diff --git a/apps/dav/tests/unit/CalDAV/Schedule/PluginTest.php b/apps/dav/tests/unit/CalDAV/Schedule/PluginTest.php
index b651379c2bd..797023cdfae 100644
--- a/apps/dav/tests/unit/CalDAV/Schedule/PluginTest.php
+++ b/apps/dav/tests/unit/CalDAV/Schedule/PluginTest.php
@@ -57,6 +57,9 @@ class PluginTest extends TestCase {
 	/** @var IConfig|MockObject  */
 	private $config;
 
+	/** @var MockObject|LoggerInterface */
+	private $logger;
+
 	protected function setUp(): void {
 		parent::setUp();
 
@@ -70,12 +73,14 @@ class PluginTest extends TestCase {
 		$this->server->httpResponse = $response;
 		$this->server->xml = new Service();
 
-		$this->plugin = new Plugin($this->config);
+		$this->logger = $this->createMock(LoggerInterface::class);
+
+		$this->plugin = new Plugin($this->config, $this->logger);
 		$this->plugin->initialize($this->server);
 	}
 
 	public function testInitialize() {
-		$plugin = new Plugin($this->config);
+		$plugin = new Plugin($this->config, $this->logger);
 
 		$this->server->expects($this->exactly(10))
 			->method('on')