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>

8 files changed, 69 insertions, 56 deletions

diff --git a/tests/Integration/Framework/ImapTestAccount.php b/tests/Integration/Framework/ImapTestAccount.php
index c87db9dbe..0189884e1 100644
--- a/tests/Integration/Framework/ImapTestAccount.php
+++ b/tests/Integration/Framework/ImapTestAccount.php
@@ -26,6 +26,7 @@ use OCA\Mail\Account;
 use OCA\Mail\Db\MailAccount;
 use OCA\Mail\IMAP\MailboxSync;
 use OCA\Mail\Service\AccountService;
+use Psr\Log\NullLogger;
 
 trait ImapTestAccount {
 
@@ -63,7 +64,7 @@ trait ImapTestAccount {
 
 		/** @var MailboxSync $mbSync */
 		$mbSync = OC::$server->query(MailboxSync::class);
-		$mbSync->sync(new Account($mailAccount));
+		$mbSync->sync(new Account($mailAccount), new NullLogger());
 
 		return $acc;
 	}
diff --git a/tests/Unit/IMAP/MailboxSyncTest.php b/tests/Unit/IMAP/MailboxSyncTest.php
index c8b26b859..645c9b628 100644
--- a/tests/Unit/IMAP/MailboxSyncTest.php
+++ b/tests/Unit/IMAP/MailboxSyncTest.php
@@ -1,4 +1,7 @@
 <?php
+
+declare(strict_types=1);
+
 /**
  * @copyright 2019 Christoph Wurst <christoph@winzerhof-wurst.at>
  *
@@ -35,8 +38,8 @@ use OCA\Mail\IMAP\FolderMapper;
 use OCA\Mail\IMAP\IMAPClientFactory;
 use OCA\Mail\IMAP\MailboxSync;
 use OCP\AppFramework\Utility\ITimeFactory;
-use OCP\ILogger;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\NullLogger;
 
 class MailboxSyncTest extends TestCase {
 
@@ -55,9 +58,6 @@ class MailboxSyncTest extends TestCase {
 	/** @var TimeFactory|MockObject */
 	private $timeFactory;
 
-	/** @var ILogger|MockObject */
-	private $logger;
-
 	/** @var MailboxSync */
 	private $sync;
 
@@ -69,15 +69,13 @@ class MailboxSyncTest extends TestCase {
 		$this->mailAccountMapper = $this->createMock(MailAccountMapper::class);
 		$this->imapClientFactory = $this->createMock(IMAPClientFactory::class);
 		$this->timeFactory = $this->createMock(ITimeFactory::class);
-		$this->logger = $this->createMock(ILogger::class);
 
 		$this->sync = new MailboxSync(
 			$this->mailboxMapper,
 			$this->folderMapper,
 			$this->mailAccountMapper,
 			$this->imapClientFactory,
-			$this->timeFactory,
-			$this->logger
+			$this->timeFactory
 		);
 	}
 
@@ -90,7 +88,7 @@ class MailboxSyncTest extends TestCase {
 		$this->imapClientFactory->expects($this->never())
 			->method('getClient');
 
-		$this->sync->sync($account);
+		$this->sync->sync($account, new NullLogger());
 	}
 
 	public function testSync() {
@@ -119,6 +117,6 @@ class MailboxSyncTest extends TestCase {
 			->method('detectFolderSpecialUse')
 			->with($folders);
 
-		$this->sync->sync($account);
+		$this->sync->sync($account, new NullLogger());
 	}
 }
diff --git a/tests/Unit/IMAP/Threading/ThreadBuilderTest.php b/tests/Unit/IMAP/Threading/ThreadBuilderTest.php
index a7581eaab..906939b89 100644
--- a/tests/Unit/IMAP/Threading/ThreadBuilderTest.php
+++ b/tests/Unit/IMAP/Threading/ThreadBuilderTest.php
@@ -31,12 +31,17 @@ use OCA\Mail\IMAP\Threading\Message;
 use OCA\Mail\IMAP\Threading\ThreadBuilder;
 use OCA\Mail\Support\PerformanceLogger;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\LoggerInterface;
+use Psr\Log\NullLogger;
 
 class ThreadBuilderTest extends TestCase {
 
 	/** @var PerformanceLogger|MockObject */
 	private $performanceLogger;
 
+	/** @var LoggerInterface */
+	private $logger;
+
 	/** @var ThreadBuilder */
 	private $builder;
 
@@ -44,6 +49,7 @@ class ThreadBuilderTest extends TestCase {
 		parent::setUp();
 
 		$this->performanceLogger = $this->createMock(PerformanceLogger::class);
+		$this->logger = new NullLogger();
 
 		$this->builder = new ThreadBuilder(
 			$this->performanceLogger
@@ -67,7 +73,7 @@ class ThreadBuilderTest extends TestCase {
 	public function testBuildEmpty(): void {
 		$messages = [];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals([], $result);
 	}
@@ -79,7 +85,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('s3', 'id3', []),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -106,7 +112,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re:s1', 'id2', ['id1']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -130,7 +136,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('s2', 'id2', ['id1']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -154,7 +160,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re:s1', 'id2', []),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -184,7 +190,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('s3', 'id3', ['id2']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -222,7 +228,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re:s1', 'id4', ['id3']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -266,7 +272,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re:s1', 'id7', ['id1', 'id3']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -322,7 +328,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re:s1', 'id7', ['id3']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -368,7 +374,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('s2', 'id2', ['id1']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -393,7 +399,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('s3', 'id3', ['id1']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -421,7 +427,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re:s2', 'id3', ['id1']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -457,7 +463,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re: Sub', '<msg5@mail.host>', ['<msg1@mail.host>', '<msg2@mail.host>', '<msg3@mail.host>', '<msg4@mail.host>']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
@@ -511,7 +517,7 @@ class ThreadBuilderTest extends TestCase {
 			new Message('Re: Sub', '<o2re1@mail.host>', ['<o2@mail.host>']),
 		];
 
-		$result = $this->builder->build($messages);
+		$result = $this->builder->build($messages, $this->logger);
 
 		$this->assertEquals(
 			[
diff --git a/tests/Unit/Listener/DeleteDraftListenerTest.php b/tests/Unit/Listener/DeleteDraftListenerTest.php
index 045214368..0f9e10638 100644
--- a/tests/Unit/Listener/DeleteDraftListenerTest.php
+++ b/tests/Unit/Listener/DeleteDraftListenerTest.php
@@ -1,4 +1,7 @@
 <?php
+
+declare(strict_types=1);
+
 /**
  * @copyright 2019 Christoph Wurst <christoph@winzerhof-wurst.at>
  *
@@ -39,8 +42,8 @@ use OCA\Mail\Model\RepliedMessageData;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
 use OCP\EventDispatcher\IEventListener;
-use OCP\ILogger;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\LoggerInterface;
 
 class DeleteDraftListenerTest extends TestCase {
 
@@ -56,7 +59,7 @@ class DeleteDraftListenerTest extends TestCase {
 	/** @var MailboxSync|MockObject */
 	private $mailboxSync;
 
-	/** @var ILogger|MockObject */
+	/** @var LoggerInterface|MockObject */
 	private $logger;
 
 	/** @var IEventListener */
@@ -69,7 +72,7 @@ class DeleteDraftListenerTest extends TestCase {
 		$this->mailboxMapper = $this->createMock(MailboxMapper::class);
 		$this->messageMapper = $this->createMock(MessageMapper::class);
 		$this->mailboxSync = $this->createMock(MailboxSync::class);
-		$this->logger = $this->createMock(ILogger::class);
+		$this->logger = $this->createMock(LoggerInterface::class);
 
 		$this->listener = new DeleteDraftListener(
 			$this->imapClientFactory,
@@ -101,7 +104,7 @@ class DeleteDraftListenerTest extends TestCase {
 		$this->messageMapper->expects($this->never())
 			->method('addFlag');
 		$this->logger->expects($this->never())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
@@ -143,7 +146,7 @@ class DeleteDraftListenerTest extends TestCase {
 			);
 		$this->mailboxSync->expects($this->once())
 			->method('sync')
-			->with($account, true);
+			->with($account, $this->logger, true);
 		$this->mailboxMapper->expects($this->at(1))
 			->method('findSpecial')
 			->with($account, 'drafts')
@@ -160,7 +163,7 @@ class DeleteDraftListenerTest extends TestCase {
 			->method('expunge')
 			->with('Drafts');
 		$this->logger->expects($this->never())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
@@ -178,7 +181,7 @@ class DeleteDraftListenerTest extends TestCase {
 		$this->messageMapper->expects($this->never())
 			->method('addFlag');
 		$this->logger->expects($this->never())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
@@ -229,7 +232,7 @@ class DeleteDraftListenerTest extends TestCase {
 			->method('expunge')
 			->with('Drafts');
 		$this->logger->expects($this->never())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
diff --git a/tests/Unit/Listener/DraftMailboxCreatorListenerTest.php b/tests/Unit/Listener/DraftMailboxCreatorListenerTest.php
index b06063908..a7c1bb1dd 100644
--- a/tests/Unit/Listener/DraftMailboxCreatorListenerTest.php
+++ b/tests/Unit/Listener/DraftMailboxCreatorListenerTest.php
@@ -37,8 +37,8 @@ use OCA\Mail\Listener\DraftMailboxCreatorListener;
 use OCA\Mail\Model\NewMessageData;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
-use OCP\ILogger;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\LoggerInterface;
 
 class DraftMailboxCreatorListenerTest extends TestCase {
 
@@ -51,7 +51,7 @@ class DraftMailboxCreatorListenerTest extends TestCase {
 	/** @var MailboxSync|MockObject */
 	private $mailboxSync;
 
-	/** @var ILogger|MockObject */
+	/** @var LoggerInterface|MockObject */
 	private $logger;
 
 	/** @var DraftMailboxCreatorListener */
@@ -63,7 +63,7 @@ class DraftMailboxCreatorListenerTest extends TestCase {
 		$this->mailboxMapper = $this->createMock(MailboxMapper::class);
 		$this->imapClientFactory = $this->createMock(IMAPClientFactory::class);
 		$this->mailboxSync = $this->createMock(MailboxSync::class);
-		$this->logger = $this->createMock(ILogger::class);
+		$this->logger = $this->createMock(LoggerInterface::class);
 
 		$this->listener = new DraftMailboxCreatorListener(
 			$this->mailboxMapper,
@@ -106,7 +106,7 @@ class DraftMailboxCreatorListenerTest extends TestCase {
 			->with($account, 'drafts')
 			->willReturn($mailbox);
 		$this->logger->expects($this->never())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
@@ -147,9 +147,9 @@ class DraftMailboxCreatorListenerTest extends TestCase {
 			);
 		$this->mailboxSync->expects($this->once())
 			->method('sync')
-			->with($account, true);
+			->with($account, $this->logger, true);
 		$this->logger->expects($this->never())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
diff --git a/tests/Unit/Listener/SaveSentMessageListenerTest.php b/tests/Unit/Listener/SaveSentMessageListenerTest.php
index 85da65b6f..8ae29bb3e 100644
--- a/tests/Unit/Listener/SaveSentMessageListenerTest.php
+++ b/tests/Unit/Listener/SaveSentMessageListenerTest.php
@@ -39,11 +39,11 @@ use OCA\Mail\Listener\SaveSentMessageListener;
 use OCA\Mail\Model\IMessage;
 use OCA\Mail\Model\NewMessageData;
 use OCA\Mail\Model\RepliedMessageData;
-use OCA\TwoFactorAdmin\Listener\IListener;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
-use OCP\ILogger;
+use OCP\EventDispatcher\IEventListener;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\LoggerInterface;
 
 class SaveSentMessageListenerTest extends TestCase {
 
@@ -59,10 +59,10 @@ class SaveSentMessageListenerTest extends TestCase {
 	/** @var MailboxSync|MockObject */
 	private $mailboxSync;
 
-	/** @var ILogger|MockObject */
+	/** @var LoggerInterface|MockObject */
 	private $logger;
 
-	/** @var IListener */
+	/** @var IEventListener */
 	private $listener;
 
 	protected function setUp(): void {
@@ -72,7 +72,7 @@ class SaveSentMessageListenerTest extends TestCase {
 		$this->imapClientFactory = $this->createMock(IMAPClientFactory::class);
 		$this->messageMapper = $this->createMock(MessageMapper::class);
 		$this->mailboxSync = $this->createMock(MailboxSync::class);
-		$this->logger = $this->createMock(ILogger::class);
+		$this->logger = $this->createMock(LoggerInterface::class);
 
 		$this->listener = new SaveSentMessageListener(
 			$this->mailboxMapper,
@@ -121,6 +121,7 @@ class SaveSentMessageListenerTest extends TestCase {
 			->method('getClient')
 			->with($account)
 			->willReturn($client);
+		$exception = new \Horde_Imap_Client_Exception();
 		$client->expects($this->once())
 			->method('createMailbox')
 			->with(
@@ -131,14 +132,13 @@ class SaveSentMessageListenerTest extends TestCase {
 					],
 				]
 			)
-			->willThrowException(new \Horde_Imap_Client_Exception());
+			->willThrowException($exception);
 		$this->logger->expects($this->once())
-			->method('logException')
+			->method('warning')
 			->with(
-				$this->anything(),
+				'Could not create sent mailbox: ',
 				$this->equalTo([
-					'message' => 'Could not create sent mailbox: ',
-					'level' => ILogger::WARN,
+					'exception' => $exception,
 				])
 			);
 
diff --git a/tests/Unit/Listener/TrashMailboxCreatorListenerTest.php b/tests/Unit/Listener/TrashMailboxCreatorListenerTest.php
index 4ccc572a8..b54d93fb4 100644
--- a/tests/Unit/Listener/TrashMailboxCreatorListenerTest.php
+++ b/tests/Unit/Listener/TrashMailboxCreatorListenerTest.php
@@ -35,8 +35,8 @@ use OCA\Mail\IMAP\MailboxSync;
 use OCA\Mail\Listener\TrashMailboxCreatorListener;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\Event;
-use OCP\ILogger;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\LoggerInterface;
 
 class TrashMailboxCreatorListenerTest extends TestCase {
 
@@ -49,7 +49,7 @@ class TrashMailboxCreatorListenerTest extends TestCase {
 	/** @var MailboxSync|MockObject */
 	private $mailboxSync;
 
-	/** @var ILogger|MockObject */
+	/** @var LoggerInterface|MockObject */
 	private $logger;
 
 	/** @var TrashMailboxCreatorListener */
@@ -61,7 +61,7 @@ class TrashMailboxCreatorListenerTest extends TestCase {
 		$this->mailboxMapper = $this->createMock(MailboxMapper::class);
 		$this->imapClientFactory = $this->createMock(IMAPClientFactory::class);
 		$this->mailboxSync = $this->createMock(MailboxSync::class);
-		$this->logger = $this->createMock(ILogger::class);
+		$this->logger = $this->createMock(LoggerInterface::class);
 
 		$this->listener = new TrashMailboxCreatorListener(
 			$this->mailboxMapper,
@@ -125,7 +125,7 @@ class TrashMailboxCreatorListenerTest extends TestCase {
 			)
 			->willThrowException(new \Horde_Imap_Client_Exception());
 		$this->logger->expects($this->once())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
@@ -157,12 +157,11 @@ class TrashMailboxCreatorListenerTest extends TestCase {
 					],
 				]
 			);
-		$mailbox = new Mailbox();
 		$this->mailboxSync->expects($this->once())
 			->method('sync')
-			->with($account, true);
+			->with($account, $this->logger, true);
 		$this->logger->expects($this->never())
-			->method('logException');
+			->method('error');
 
 		$this->listener->handle($event);
 	}
diff --git a/tests/Unit/Service/MailManagerTest.php b/tests/Unit/Service/MailManagerTest.php
index eaac0a94e..d5cece922 100644
--- a/tests/Unit/Service/MailManagerTest.php
+++ b/tests/Unit/Service/MailManagerTest.php
@@ -41,6 +41,7 @@ use OCA\Mail\Service\MailManager;
 use OCP\AppFramework\Db\DoesNotExistException;
 use OCP\EventDispatcher\IEventDispatcher;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\LoggerInterface;
 
 class MailManagerTest extends TestCase {
 
@@ -68,6 +69,9 @@ class MailManagerTest extends TestCase {
 	/** @var MailManager */
 	private $manager;
 
+	/** @var MockObject|LoggerInterface */
+	private $logger;
+
 	protected function setUp(): void {
 		parent::setUp();
 
@@ -78,6 +82,7 @@ class MailManagerTest extends TestCase {
 		$this->dbMessageMapper = $this->createMock(DbMessageMapper::class);
 		$this->mailboxSync = $this->createMock(MailboxSync::class);
 		$this->eventDispatcher = $this->createMock(IEventDispatcher::class);
+		$this->logger = $this->createMock(LoggerInterface::class);
 
 		$this->manager = new MailManager(
 			$this->imapClientFactory,
@@ -86,7 +91,8 @@ class MailManagerTest extends TestCase {
 			$this->folderMapper,
 			$this->imapMessageMapper,
 			$this->dbMessageMapper,
-			$this->eventDispatcher
+			$this->eventDispatcher,
+			$this->logger
 		);
 	}