[bug] Log error in case JSON parsing fails for decrypted doc

In addition to the UnicodeError exception in _process_decrypted_doc
function, we have added ValueError to the exception list so that we can
catch any error in JSON parsing, specially a 'NODATA' error that we were
getting with some of the emails.

This is in reference to issues -
https://github.com/pixelated/pixelated-user-agent/issues/908 &
https://github.com/pixelated/pixelated-user-agent/issues/981 - to ignore
documents that have this problem and not have Soledad try to sync them
again and again.

with @deniscostadsc

2 files changed, 31 insertions, 6 deletions

diff --git a/src/leap/bitmask/mail/incoming/service.py b/src/leap/bitmask/mail/incoming/service.py
index e1dde02a..e2baadbe 100644
--- a/src/leap/bitmask/mail/incoming/service.py
+++ b/src/leap/bitmask/mail/incoming/service.py
@@ -337,13 +337,14 @@ class IncomingMail(Service):
                        "1" if success else "0")
             return self._process_decrypted_doc(doc, decrdata)
 
-        def log_doc_id_and_raise_exception(failure):
+        def log_doc_id_and_call_errback(failure):
             logger.error(
-                '_decrypt_doc: Error decrypting document with ID %s' % doc.doc_id)
+                '_decrypt_doc: Error decrypting document with '
+                'ID %s' % doc.doc_id)
             self._errback(failure)
 
         d = self._keymanager.decrypt(doc.content[ENC_JSON_KEY], self._userid)
-        d.addErrback(log_doc_id_and_raise_exception)
+        d.addErrback(log_doc_id_and_call_errback)
         d.addCallback(process_decrypted)
         d.addCallback(lambda data: (doc, data))
         return d
@@ -368,9 +369,9 @@ class IncomingMail(Service):
         # the deferreds that would process an individual document
         try:
             msg = json_loads(data)
-        except UnicodeError as exc:
+        except (UnicodeError, ValueError) as exc:
             logger.error("Error while decrypting %s" % (doc.doc_id,))
-            logger.exception(exc)
+            logger.error(str(exc))
 
             # we flag the message as "with decrypting errors",
             # to avoid further decryption attempts during sync
diff --git a/tests/integration/mail/incoming/test_incoming_mail.py b/tests/integration/mail/incoming/test_incoming_mail.py
index daef0578..3633c73e 100644
--- a/tests/integration/mail/incoming/test_incoming_mail.py
+++ b/tests/integration/mail/incoming/test_incoming_mail.py
@@ -42,6 +42,7 @@ from leap.bitmask.mail.adaptors.soledad import cleanup_deferred_locks
 from leap.bitmask.mail.adaptors.soledad import SoledadMailAdaptor
 from leap.bitmask.mail.mail import MessageCollection
 from leap.bitmask.mail.mailbox_indexer import MailboxIndexer
+from leap.bitmask.mail import utils
 
 from leap.bitmask.mail.incoming.service import IncomingMail
 from leap.bitmask.mail.rfc3156 import MultipartEncrypted, PGPEncrypted
@@ -326,7 +327,7 @@ subject: independence of cyberspace
         d.addCallback(add_decrypted_header_called)
         return d
 
-    def test_log_error_if_decrypt_fails(self):
+    def testLogErrorIfDecryptFails(self):
 
         def assert_failure(_):
             mock_logger_error.assert_any_call('_decrypt_doc: '
@@ -346,6 +347,29 @@ subject: independence of cyberspace
             d.addCallback(assert_failure)
             return d
 
+    def testFlagMessageOnBadJsonWhileDecrypting(self):
+        doc = SoledadDocument()
+        doc.doc_id = '1'
+        doc.content = {'_enc_json': ''}
+
+        err = ValueError('No JSON object could be decoded')
+
+        def assert_failure():
+            mock_logger_error.assert_any_call(
+                'Error while decrypting 1')
+            mock_logger_error.assert_any_call(
+                'No JSON object could be decoded')
+            self.assertEquals(doc.content['errdecr'], True)
+
+        with patch.object(Logger, 'error') as mock_logger_error:
+            with patch.object(utils, 'json_loads') as mock_json_loader:
+                self.fetcher._update_incoming_message = Mock()
+                mock_json_loader.side_effect = err
+
+                self.fetcher._process_decrypted_doc(doc, '')
+
+                assert_failure()
+
     def testValidateSignatureFromEncryptedEmailFromAppleMail(self):
         enc_signed_file = os.path.join(
             HERE, 'rfc822.multi-encrypt-signed.message')