Add debug output to sync processes triggered via the CLI

Just like a CLI priority inbox model training gives all the details, we
want to have the same to diagnose slow/faulty account syncs. This
changes the console logger adapter for the PSR logger and adds it to the
sync process.

Signed-off-by: Christoph Wurst <christoph@winzerhof-wurst.at>

5 files changed, 38 insertions, 41 deletions

diff --git a/lib/Listener/AccountSynchronizedThreadUpdaterListener.php b/lib/Listener/AccountSynchronizedThreadUpdaterListener.php
index e248c6b47..f681f7d89 100644
--- a/lib/Listener/AccountSynchronizedThreadUpdaterListener.php
+++ b/lib/Listener/AccountSynchronizedThreadUpdaterListener.php
@@ -33,11 +33,11 @@ use OCA\Mail\IMAP\Threading\DatabaseMessage;
 use OCA\Mail\IMAP\Threading\ThreadBuilder;
 use OCP\EventDispatcher\Event;
 use OCP\EventDispatcher\IEventListener;
-use OCP\ILogger;
 use function array_chunk;
 use function iterator_to_array;
 
 class AccountSynchronizedThreadUpdaterListener implements IEventListener {
+	private const WRITE_IDS_CHUNK_SIZE = 500;
 
 	/** @var MessageMapper */
 	private $mapper;
@@ -45,15 +45,10 @@ class AccountSynchronizedThreadUpdaterListener implements IEventListener {
 	/** @var ThreadBuilder */
 	private $builder;
 
-	/** @var ILogger */
-	private $logger;
-
 	public function __construct(MessageMapper $mapper,
-								ThreadBuilder $builder,
-								ILogger $logger) {
+								ThreadBuilder $builder) {
 		$this->mapper = $mapper;
 		$this->builder = $builder;
-		$this->logger = $logger;
 	}
 
 	public function handle(Event $event): void {
@@ -63,14 +58,17 @@ class AccountSynchronizedThreadUpdaterListener implements IEventListener {
 		}
 
 		$accountId = $event->getAccount()->getId();
+		$logger = $event->getLogger();
 		$messages = $this->mapper->findThreadingData($event->getAccount());
-		$this->logger->debug("Account $accountId has " . count($messages) . " messages for threading");
-		$threads = $this->builder->build($messages);
-		$this->logger->debug("Account $accountId has " . count($threads) . " threads");
+		$logger->debug("Account $accountId has " . count($messages) . " messages for threading");
+		$threads = $this->builder->build($messages, $logger);
+		$logger->debug("Account $accountId has " . count($threads) . " threads");
 		$flattened = iterator_to_array($this->flattenThreads($threads), false);
-		$this->logger->debug("Account $accountId has " . count($flattened) . " messages with a new thread ID");
-		foreach (array_chunk($flattened, 500) as $chunk) {
+		$logger->debug("Account $accountId has " . count($flattened) . " messages with a new thread IDs");
+		foreach (array_chunk($flattened, self::WRITE_IDS_CHUNK_SIZE) as $chunk) {
 			$this->mapper->writeThreadIds($chunk);
+
+			$logger->debug("Chunk of " . self::WRITE_IDS_CHUNK_SIZE . " messages updated");
 		}
 	}
 
diff --git a/lib/Listener/DeleteDraftListener.php b/lib/Listener/DeleteDraftListener.php
index 9758a0fa0..3f701aa8f 100644
--- a/lib/Listener/DeleteDraftListener.php
+++ b/lib/Listener/DeleteDraftListener.php
@@ -39,7 +39,7 @@ use OCA\Mail\IMAP\MessageMapper;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
 use OCP\EventDispatcher\IEventListener;
-use OCP\ILogger;
+use Psr\Log\LoggerInterface;
 
 class DeleteDraftListener implements IEventListener {
 
@@ -55,14 +55,14 @@ class DeleteDraftListener implements IEventListener {
 	/** @var MailboxSync */
 	private $mailboxSync;
 
-	/** @var ILogger */
+	/** @var LoggerInterface */
 	private $logger;
 
 	public function __construct(IMAPClientFactory $imapClientFactory,
 								MailboxMapper $mailboxMapper,
 								MessageMapper $messageMapper,
 								MailboxSync $mailboxSync,
-								ILogger $logger) {
+								LoggerInterface $logger) {
 		$this->imapClientFactory = $imapClientFactory;
 		$this->mailboxMapper = $mailboxMapper;
 		$this->messageMapper = $messageMapper;
@@ -94,16 +94,16 @@ class DeleteDraftListener implements IEventListener {
 				Horde_Imap_Client::FLAG_DELETED
 			);
 		} catch (Horde_Imap_Client_Exception $e) {
-			$this->logger->logException($e, [
-				'message' => 'Could not flag draft as deleted'
+			$this->logger->error('Could not flag draft as deleted', [
+				'exception' => $e,
 			]);
 		}
 
 		try {
 			$client->expunge($draftsMailbox->getName());
 		} catch (Horde_Imap_Client_Exception $e) {
-			$this->logger->logException($e, [
-				'message' => 'Could not expunge drafts folder'
+			$this->logger->error('Could not expunge drafts folder', [
+				'exception' => $e,
 			]);
 		}
 	}
@@ -134,12 +134,12 @@ class DeleteDraftListener implements IEventListener {
 				]
 			);
 		} catch (Horde_Imap_Client_Exception $e) {
-			$this->logger->logException($e, [
-				'message' => 'Could not create drafts mailbox',
+			$this->logger->error('Could not create drafts mailbox', [
+				'exception' => $e,
 			]);
 		}
 
 		// TODO: find a more elegant solution for updating the mailbox cache
-		$this->mailboxSync->sync($account, true);
+		$this->mailboxSync->sync($account, $this->logger,true);
 	}
 }
diff --git a/lib/Listener/DraftMailboxCreatorListener.php b/lib/Listener/DraftMailboxCreatorListener.php
index 384a39221..f4d915e81 100644
--- a/lib/Listener/DraftMailboxCreatorListener.php
+++ b/lib/Listener/DraftMailboxCreatorListener.php
@@ -34,7 +34,7 @@ use OCA\Mail\IMAP\MailboxSync;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
 use OCP\EventDispatcher\IEventListener;
-use OCP\ILogger;
+use Psr\Log\LoggerInterface;
 
 class DraftMailboxCreatorListener implements IEventListener {
 
@@ -47,13 +47,13 @@ class DraftMailboxCreatorListener implements IEventListener {
 	/** @var MailboxSync */
 	private $mailboxSync;
 
-	/** @var ILogger */
+	/** @var LoggerInterface */
 	private $logger;
 
 	public function __construct(MailboxMapper $mailboxMapper,
 								IMAPClientFactory $imapClientFactory,
 								MailboxSync $mailboxSync,
-								ILogger $logger) {
+								LoggerInterface $logger) {
 		$this->mailboxMapper = $mailboxMapper;
 		$this->imapClientFactory = $imapClientFactory;
 		$this->mailboxSync = $mailboxSync;
@@ -88,12 +88,12 @@ class DraftMailboxCreatorListener implements IEventListener {
 				]
 			);
 		} catch (Horde_Imap_Client_Exception $e) {
-			$this->logger->logException($e, [
-				'message' => 'Could not create drafts mailbox',
+			$this->logger->error('Could not create drafts mailbox', [
+				'exception' => $e,
 			]);
 		}
 
 		// TODO: find a more elegant solution for updating the mailbox cache
-		$this->mailboxSync->sync($account, true);
+		$this->mailboxSync->sync($account, $this->logger,true);
 	}
 }
diff --git a/lib/Listener/SaveSentMessageListener.php b/lib/Listener/SaveSentMessageListener.php
index ed093d222..aa43eb6fc 100644
--- a/lib/Listener/SaveSentMessageListener.php
+++ b/lib/Listener/SaveSentMessageListener.php
@@ -37,7 +37,7 @@ use OCA\Mail\IMAP\MessageMapper;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
 use OCP\EventDispatcher\IEventListener;
-use OCP\ILogger;
+use Psr\Log\LoggerInterface;
 
 class SaveSentMessageListener implements IEventListener {
 
@@ -53,14 +53,14 @@ class SaveSentMessageListener implements IEventListener {
 	/** @var MailboxSync */
 	private $mailboxSync;
 
-	/** @var ILogger */
+	/** @var LoggerInterface */
 	private $logger;
 
 	public function __construct(MailboxMapper $mailboxMapper,
 								IMAPClientFactory $imapClientFactory,
 								MessageMapper $messageMapper,
 								MailboxSync $mailboxSync,
-								ILogger $logger) {
+								LoggerInterface $logger) {
 		$this->mailboxMapper = $mailboxMapper;
 		$this->imapClientFactory = $imapClientFactory;
 		$this->messageMapper = $messageMapper;
@@ -113,14 +113,13 @@ class SaveSentMessageListener implements IEventListener {
 		} catch (Horde_Imap_Client_Exception $e) {
 			// Let's assume this error is caused because the mailbox already exists,
 			// caused by concurrent requests or out-of-sync mailbox cache
-			$this->logger->logException($e, [
-				'message' => 'Could not create sent mailbox: ' . $e->getMessage(),
-				'level' => ILogger::WARN,
+			$this->logger->warning('Could not create sent mailbox: ' . $e->getMessage(), [
+				'exception' => $e,
 			]);
 		}
 
 		// TODO: find a more elegant solution for updating the mailbox cache
-		$this->mailboxSync->sync($account, true);
+		$this->mailboxSync->sync($account, $this->logger,true);
 
 		return $this->mailboxMapper->findSpecial($account, 'sent');
 	}
diff --git a/lib/Listener/TrashMailboxCreatorListener.php b/lib/Listener/TrashMailboxCreatorListener.php
index a4cb09336..3a57e2b4d 100644
--- a/lib/Listener/TrashMailboxCreatorListener.php
+++ b/lib/Listener/TrashMailboxCreatorListener.php
@@ -34,7 +34,7 @@ use OCA\Mail\IMAP\MailboxSync;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
 use OCP\EventDispatcher\IEventListener;
-use OCP\ILogger;
+use Psr\Log\LoggerInterface;
 
 class TrashMailboxCreatorListener implements IEventListener {
 
@@ -47,13 +47,13 @@ class TrashMailboxCreatorListener implements IEventListener {
 	/** @var MailboxSync */
 	private $mailboxSync;
 
-	/** @var ILogger */
+	/** @var LoggerInterface */
 	private $logger;
 
 	public function __construct(MailboxMapper $mailboxMapper,
 								IMAPClientFactory $imapClientFactory,
 								MailboxSync $mailboxSync,
-								ILogger $logger) {
+								LoggerInterface $logger) {
 		$this->mailboxMapper = $mailboxMapper;
 		$this->imapClientFactory = $imapClientFactory;
 		$this->mailboxSync = $mailboxSync;
@@ -92,10 +92,10 @@ class TrashMailboxCreatorListener implements IEventListener {
 			);
 
 			// TODO: find a more elegant solution for updating the mailbox cache
-			$this->mailboxSync->sync($account, true);
+			$this->mailboxSync->sync($account, $this->logger,true);
 		} catch (Horde_Imap_Client_Exception $e) {
-			$this->logger->logException($e, [
-				'message' => 'Could not creat trash mailbox',
+			$this->logger->error('Could not creat trash mailbox', [
+				'exception' => $e,
 			]);
 		}
 	}