From 450ee436778a8fc67022b4bad4d5e9873f91bd9d Mon Sep 17 00:00:00 2001
From: Ozzie Isaacs <ozzie.fernandez.isaacs@googlemail.com>
Date: Thu, 22 Apr 2021 19:14:56 +0200
Subject: [PATCH] Additional logging for emails

---
 cps/logger.py          |  6 +++---
 cps/services/worker.py |  3 ++-
 cps/static/js/table.js |  1 +
 cps/tasks/mail.py      | 14 +++++++++++---
 4 files changed, 17 insertions(+), 7 deletions(-)

diff --git a/cps/logger.py b/cps/logger.py
index b204de31..cd38e3d3 100644
--- a/cps/logger.py
+++ b/cps/logger.py
@@ -62,11 +62,11 @@ class _Logger(logging.Logger):
 
 
     def debug_no_auth(self, message, *args, **kwargs):
+        message = message.strip("\r\n")
         if message.startswith("send: AUTH"):
-            self.debug(message[:16], stacklevel=2, *args, **kwargs)
+            self.debug(message[:16], *args, **kwargs)
         else:
-            self.debug(message, stacklevel=2, *args, **kwargs)
-
+            self.debug(message, *args, **kwargs)
 
 
 def get(name=None):
diff --git a/cps/services/worker.py b/cps/services/worker.py
index 8433e408..1baf25fe 100644
--- a/cps/services/worker.py
+++ b/cps/services/worker.py
@@ -45,7 +45,7 @@ class ImprovedQueue(queue.Queue):
         with self.mutex:
             return list(self.queue)
 
-#Class for all worker tasks in the background
+# Class for all worker tasks in the background
 class WorkerThread(threading.Thread):
     _instance = None
 
@@ -69,6 +69,7 @@ class WorkerThread(threading.Thread):
     def add(cls, user, task):
         ins = cls.getInstance()
         ins.num += 1
+        log.debug("Add Task for user: {}: {}".format(user, task))
         ins.queue.put(QueuedTask(
             num=ins.num,
             user=user,
diff --git a/cps/static/js/table.js b/cps/static/js/table.js
index 97dee842..a15b2e45 100644
--- a/cps/static/js/table.js
+++ b/cps/static/js/table.js
@@ -640,6 +640,7 @@ function checkboxFormatter(value, row, index){
         return '<input type="checkbox" class="chk" data-pk="' + row.id + '" data-name="' + this.field + '" onchange="checkboxChange(this, ' + row.id + ', \'' + this.name + '\', ' + this.column + ')">';
 }
 
+/* Do some hiding disabling after user list is loaded */
 function loadSuccess() {
     var guest = $(".editable[data-name='name'][data-value='Guest']");
     guest.editable("disable");
diff --git a/cps/tasks/mail.py b/cps/tasks/mail.py
index 8d2d4188..e8b3ebf3 100644
--- a/cps/tasks/mail.py
+++ b/cps/tasks/mail.py
@@ -115,6 +115,7 @@ class TaskEmail(CalibreTask):
         self.results = dict()
 
     def prepare_message(self):
+        log.debug("prepare email message for sending")
         message = MIMEMultipart()
         message['to'] = self.recipent
         message['from'] = self.settings["mail_from"]
@@ -134,9 +135,9 @@ class TaskEmail(CalibreTask):
         return message
 
     def run(self, worker_thread):
-        # create MIME message
-        msg = self.prepare_message()
         try:
+            # create MIME message
+            msg = self.prepare_message()
             if self.settings['mail_server_type'] == 0:
                 self.send_standard_email(msg)
             else:
@@ -170,9 +171,11 @@ class TaskEmail(CalibreTask):
         # redirect output to logfile on python2 on python3 debugoutput is caught with overwritten
         # _print_debug function
         if sys.version_info < (3, 0):
+            log.debug("Redirect output on python2 for email")
             org_smtpstderr = smtplib.stderr
             smtplib.stderr = logger.StderrLogger('worker.smtp')
 
+        log.debug("Start send email")
         if use_ssl == 2:
             self.asyncSMTP = EmailSSL(self.settings["mail_server"], self.settings["mail_port"],
                                        timeout=timeout)
@@ -185,6 +188,7 @@ class TaskEmail(CalibreTask):
         if use_ssl == 1:
             self.asyncSMTP.starttls()
         if self.settings["mail_password"]:
+            log.debug("Login to email server")
             self.asyncSMTP.login(str(self.settings["mail_login"]), str(self.settings["mail_password"]))
 
         # Convert message to something to send
@@ -192,14 +196,15 @@ class TaskEmail(CalibreTask):
         gen = Generator(fp, mangle_from_=False)
         gen.flatten(msg)
 
+        log.debug("Sending email")
         self.asyncSMTP.sendmail(self.settings["mail_from"], self.recipent, fp.getvalue())
         self.asyncSMTP.quit()
         self._handleSuccess()
+        log.debug("Email send successfully")
 
         if sys.version_info < (3, 0):
             smtplib.stderr = org_smtpstderr
 
-
     def send_gmail_email(self, message):
         return gmail.send_messsage(self.settings.get('mail_gmail_token', None), message)
 
@@ -258,3 +263,6 @@ class TaskEmail(CalibreTask):
     @property
     def name(self):
         return "Email"
+
+    def __str__(self):
+        return "{}, {}".format(self.name, self.subject)