Merge pull request #1128 from django-helpdesk/catch_exceptions_on_precess_email_loop

Catch exceptions on precess email loop

.github/workflows/release_to_pypi.yml

@@ -26,7 +26,7 @@ jobs:
           python -m build
           twine check --strict dist/*
       - name: Publish distribution to PyPI
-        uses: pypa/gh-action-pypi-publish@master
+        uses: pypa/gh-action-pypi-publish@release/v1
         with:
           user: __token__
           password: ${{ secrets.PYPI_API_TOKEN }}

docs/configuration.rst

@@ -22,6 +22,13 @@ Before django-helpdesk will be much use, you need to do some basic configuration
  If you wish to use `celery` instead of cron, you must add 'django_celery_beat' to `INSTALLED_APPS` and add a periodic celery task through the Django admin.
 
    You will need to create a support queue, and associated login/host values, in the Django admin interface, in order for mail to be picked-up from the mail server and placed in the tickets table of your database. The values in the settings file alone, will not create the necessary values to trigger the get_email function.
+   
+   DEBUGGING EMAIL EXTRACTION
+   ==========================
+   You can run the management command manually from the command line with additional commands options:
+       **debug_to_stdout** - set this when manually running the command from a terminal so that additional debugging about which queues are being processed is written to stdout (console by default)
+   For example: 
+       **/path/to/helpdesksite/manage.py get_email --debug_to_stdout**
 
 4. If you wish to automatically escalate tickets based on their age, set up a cronjob to run the escalation command on a regular basis::
 

helpdesk/email.py

@@ -37,6 +37,7 @@ import socket
 import ssl
 import sys
 from time import ctime
+import traceback
 import typing
 from typing import List
 
@@ -56,11 +57,16 @@ STRIPPED_SUBJECT_STRINGS = [
 HTML_EMAIL_ATTACHMENT_FILENAME = _("email_html_body.html")
 
 
-def process_email(quiet=False):
+def process_email(quiet: bool = False, debug_to_stdout: bool = False):
+    if debug_to_stdout:
+        print("Extracting email into queues...")
+    q: Queue()  # Typing ahead of time for loop to make it more useful in an IDE
     for q in Queue.objects.filter(
             email_box_type__isnull=False,
             allow_email_submission=True):
-
+        log_msg = f"Processing queue: {q.slug} Email address: {q.email_address}..."
+        if debug_to_stdout:
+            print(log_msg)
         logger = logging.getLogger('django.helpdesk.queue.' + q.slug)
         logging_types = {
             'info': logging.INFO,
@@ -84,16 +90,24 @@ def process_email(quiet=False):
             logger.addHandler(log_file_handler)
         else:
             log_file_handler = None
-
-        try:
             if not q.email_box_last_check:
                 q.email_box_last_check = timezone.now() - timedelta(minutes=30)
-
+        try:
             queue_time_delta = timedelta(minutes=q.email_box_interval or 0)
             if (q.email_box_last_check + queue_time_delta) < timezone.now():
                 process_queue(q, logger=logger)
                 q.email_box_last_check = timezone.now()
                 q.save()
+                log_msg: str = f"Queue successfully processed: {q.slug}"
+                logger.info(log_msg)
+                if debug_to_stdout:
+                    print(log_msg)
+        except Exception as e:
+            logger.error(f"Queue processing failed: {q.slug} -- {e}", exc_info=True)
+            if debug_to_stdout:
+                print(f"Queue processing failed: {q.slug}")
+                print("-"*60)
+                traceback.print_exc(file=sys.stdout)
         finally:
             # we must close the file handler correctly if it's created
             try:
@@ -106,6 +120,8 @@ def process_email(quiet=False):
                     logger.removeHandler(log_file_handler)
             except Exception as e:
                 logging.exception(e)
+    if debug_to_stdout:
+        print("Email extraction into queues completed.")
 
 
 def pop3_sync(q, logger, server):
@@ -320,7 +336,7 @@ def imap_oauth_sync(q, logger, server):
 
 
 def process_queue(q, logger):
-    logger.info("***** %s: Begin processing mail for django-helpdesk" % ctime())
+    logger.info(f"***** {ctime()}: Begin processing mail for django-helpdesk queue: {q.title}")
 
     if q.socks_proxy_type and q.socks_proxy_host and q.socks_proxy_port:
         try:

helpdesk/management/commands/get_email.py

@@ -30,10 +30,18 @@ class Command(BaseCommand):
             default=False,
             help='Hide details about each queue/message as they are processed',
         )
+        parser.add_argument(
+            '--debug_to_stdout',
+            action='store_true',
+            dest='debug_to_stdout',
+            default=False,
+            help='Log additional messaging to stdout.',
+        )
 
     def handle(self, *args, **options):
         quiet = options.get('quiet', False)
-        process_email(quiet=quiet)
+        debug_to_stdout = options.get('debug_to_stdout', False)
+        process_email(quiet=quiet, debug_to_stdout=debug_to_stdout)
 
 
 if __name__ == '__main__':

helpdesk/tests/test_get_email.py

@@ -18,6 +18,7 @@ from helpdesk.models import FollowUp, FollowUpAttachment, IgnoreEmail, Queue, Ti
 from helpdesk.tests import utils
 import itertools
 import logging
+from mock.mock import patch
 from oauthlib.oauth2 import BackendApplicationClient
 import os
 from shutil import rmtree
@@ -335,12 +336,82 @@ class GetEmailCommonTests(TestCase):
             elif  att_retrieved.filename.endswith(email_att_filename):
                 email_attachment_found = True
             else:
-                print(f"\n\n%%%%%%   {att_retrieved}")
                 self.assertTrue(False, "Unexpected file in ticket attachments: %s" % att_retrieved.filename)
         self.assertTrue(email_attachment_found, "Email attachment file not found ticket attachments: %s" % (email_att_filename))
         self.assertTrue(inline_found, "Inline file not found in email: %s" % (inline_att_filename))
 
         
+    def test_email_with_txt_as_attachment(self):
+        """
+        Test an email with an txt extension email attachment to the email
+        """
+        email_message, _, _ = utils.generate_multipart_email(type_list=['plain'])
+        email_att_filename = 'test.txt'
+        file_part = utils.generate_file_mime_part("en_US", email_att_filename, "Testing a simple txt attachment.")
+        email_message.attach(file_part)
+        # Now send the part to the email workflow
+        extract_email_metadata(email_message.as_string(), self.queue_public, self.logger)
+
+        self.assertEqual(len(mail.outbox), 1)  # @UndefinedVariable
+
+        ticket = Ticket.objects.get()
+        followup = ticket.followup_set.get()
+        attachments = FollowUpAttachment.objects.filter(followup=followup)
+        self.assertEqual(len(attachments), 1)
+        attachment = attachments[0]
+        self.assertTrue(attachment.filename.endswith(email_att_filename), "The txt file not found in email: %s" % (email_att_filename))
+
+        
+class EmailTaskTests(TestCase):
+
+    def setUp(self):
+        self.num_queues = 5
+        self.exception_queues = [2, 4]
+        self.q_ids = []
+        for i in range(self.num_queues):
+            q = Queue.objects.create(
+                    title=f'Test{i+1}',
+                    slug=f'test{i+1}',
+                    email_box_type='local',
+                    allow_email_submission=True
+                )
+            self.q_ids.append(q.id)
+        self.logger = logging.getLogger('helpdesk')
+
+    def test_get_email_with_debug_to_stdout_option(self):
+        """Test debug_to_stdout option """
+        # Test get_email with debug_to_stdout set to True and also False, and verify
+        # handle receives debug_to_stdout option set properly
+        for debug_to_stdout in [True, False]:
+            with mock.patch.object(Command, 'handle', return_value=None) as mocked_handle:
+                call_command('get_email', "--debug_to_stdout") if debug_to_stdout else call_command('get_email')
+                mocked_handle.assert_called_once()
+                for _, kwargs in mocked_handle.call_args_list:
+                    self.assertEqual(debug_to_stdout, (kwargs['debug_to_stdout']))
+
+    @patch('helpdesk.email.process_queue')
+    def test_get_email_with_queue_failure(self, mocked_process_queue):
+        """Test all queues are processed if specified queues have exceptions"""
+        ret_values = [
+                Exception(f"Error Q{i};") if (i in self.exception_queues) else None for i in range(1, self.num_queues+1)
+            ]
+        mocked_process_queue.side_effect = ret_values
+        call_command(
+                'get_email',
+                '--debug_to_stdout',
+            )
+        self.assertEqual(mocked_process_queue.call_count, self.num_queues)
+        not_processed_count = Queue.objects.filter(
+            email_box_type__isnull=False,
+            allow_email_submission=True,
+            email_box_last_check__isnull=True).count()
+        self.assertEqual(
+            not_processed_count,
+            len(self.exception_queues),
+            "Incorrect number of queues that did not get processed due to a forced exception."
+            )
+
+
 class GetEmailParametricTemplate(object):
     """TestCase that checks basic email functionality across methods and socks configs."""