Merge pull request #169 from cisagov/CD-pe-reports-logging

Add centralized logging to file

setup.py

@@ -97,7 +97,7 @@ def get_version(version_file):
         "botocore == 1.24.10",
         "chevron == 0.14.0",
         "celery",
-        "click==8.0.3",
+        "click",
         "docopt",
         "glob2 == 0.7",
         "flask",

src/pe_mailer/email_reports.py

@@ -42,10 +42,15 @@
 from schema import And, Schema, SchemaError, Use
 import yaml
 
+# cisagov Libraries
+from pe_reports import CENTRAL_LOGGING_FILE
+
 from ._version import __version__
 from .pe_message import PEMessage
 from .stats_message import StatsMessage
 
+LOGGER = logging.getLogger(__name__)
+
 
 def get_emails_from_request(request):
     """Return the agency's correspondence email address(es).
@@ -75,7 +80,7 @@ def get_emails_from_request(request):
 
     for c in request["agency"]["contacts"]:
         if "type" not in c or "email" not in c or not c["email"].split():
-            logging.warning(
+            LOGGER.warning(
                 "Agency with ID %s has a contact that is missing an email and/or type attribute!",
                 id,
             )
@@ -85,7 +90,7 @@ def get_emails_from_request(request):
 
     # There should be zero or one distro email
     if len(distro_emails) > 1:
-        logging.warning("More than one DISTRO email address for agency with ID %s", id)
+        LOGGER.warning("More than one DISTRO email address for agency with ID %s", id)
 
     # Send to the distro email, else send to the technical emails.
     to_emails = distro_emails
@@ -94,7 +99,7 @@ def get_emails_from_request(request):
 
     # At this point to_emails should contain at least one email
     if not to_emails:
-        logging.error("No emails found for ID %s", id)
+        LOGGER.error("No emails found for ID %s", id)
 
     return to_emails
 
@@ -172,7 +177,7 @@ def get_requests_raw(db, query):
     try:
         requests = db.requests.find(query, projection)
     except TypeError:
-        logging.critical(
+        LOGGER.critical(
             "There was an error with the MongoDB query that retrieves the request documents",
             exc_info=True,
         )
@@ -263,7 +268,7 @@ def send_message(ses_client, message, counter=None):
     # Check for errors
     status_code = response["ResponseMetadata"]["HTTPStatusCode"]
     if status_code != 200:
-        logging.error("Unable to send message. Response from boto3 is: %s", response)
+        LOGGER.error("Unable to send message. Response from boto3 is: %s", response)
         raise UnableToSendError(response)
 
     if counter is not None:
@@ -311,7 +316,7 @@ def send_pe_reports(db, ses_client, pe_report_dir, to):
         cyhy_agencies = pe_requests.count()
         1 / cyhy_agencies
     except ZeroDivisionError:
-        logging.critical("No report data is found in %s", pe_report_dir)
+        LOGGER.critical("No report data is found in %s", pe_report_dir)
         sys.exit(1)
 
     agencies_emailed_pe_reports = 0
@@ -334,9 +339,9 @@ def send_pe_reports(db, ses_client, pe_report_dir, to):
 
             # At most one Cybex report and CSV should match
             if len(pe_report_filenames) > 1:
-                logging.warning("More than one PDF report found")
+                LOGGER.warning("More than one PDF report found")
             elif not pe_report_filenames:
-                logging.error("No PDF report found")
+                LOGGER.error("No PDF report found")
 
             if pe_report_filenames:
                 # We take the last filename since, if there happens to be more than
@@ -375,7 +380,7 @@ def send_pe_reports(db, ses_client, pe_report_dir, to):
 
     # Print out and log some statistics
     pe_stats_string = f"Out of {cyhy_agencies} agencies with Posture and Exposure reports, {agencies_emailed_pe_reports} ({100.0 * agencies_emailed_pe_reports / cyhy_agencies:.2f}%) were emailed."
-    logging.info(pe_stats_string)
+    LOGGER.info(pe_stats_string)
 
     return pe_stats_string
 
@@ -385,38 +390,38 @@ def send_reports(pe_report_dir, db_creds_file, summary_to=None, test_emails=None
     try:
         os.stat(pe_report_dir)
     except FileNotFoundError:
-        logging.critical("Directory to send reports does not exist")
+        LOGGER.critical("Directory to send reports does not exist")
         return 1
 
     try:
         db = db_from_config(db_creds_file)
     except OSError:
-        logging.critical("Database configuration file %s does not exist", db_creds_file)
+        LOGGER.critical("Database configuration file %s does not exist", db_creds_file)
         return 1
 
     except yaml.YAMLError:
-        logging.critical(
+        LOGGER.critical(
             "Database configuration file %s does not contain valid YAML",
             db_creds_file,
             exc_info=True,
         )
         return 1
     except KeyError:
-        logging.critical(
+        LOGGER.critical(
             "Database configuration file %s does not contain the expected keys",
             db_creds_file,
             exc_info=True,
         )
         return 1
     except pymongo.errors.ConnectionError:
-        logging.critical(
+        LOGGER.critical(
             "Unable to connect to the database server in %s",
             db_creds_file,
             exc_info=True,
         )
         return 1
     except pymongo.errors.InvalidName:
-        logging.critical(
+        LOGGER.critical(
             "The database in %s does not exist", db_creds_file, exc_info=True
         )
         return 1
@@ -441,13 +446,13 @@ def send_reports(pe_report_dir, db_creds_file, summary_to=None, test_emails=None
         try:
             send_message(ses_client, message)
         except (UnableToSendError, ClientError):
-            logging.error(
+            LOGGER.error(
                 "Unable to send cyhy-mailer report summary",
                 exc_info=True,
                 stack_info=True,
             )
     else:
-        logging.warning("Nothing was emailed.")
+        LOGGER.warning("Nothing was emailed.")
         print("Nothing was emailed.")
 
     # Stop logging and clean up
@@ -483,12 +488,16 @@ def main():
     # Assign validated arguments to variables
     log_level: str = validated_args["--log-level"]
 
-    # Set up logging
+    # Setup logging to central file
     logging.basicConfig(
-        format="%(asctime)-15s %(levelname)s %(message)s", level=log_level.upper()
+        filename=CENTRAL_LOGGING_FILE,
+        filemode="a",
+        format="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
+        datefmt="%m/%d/%Y %I:%M:%S",
+        level=log_level.upper(),
     )
 
-    logging.info("Sending Posture & Exposure Reports, Version : %s", __version__)
+    LOGGER.info("Sending Posture & Exposure Reports, Version : %s", __version__)
 
     send_reports(
         # TODO: Improve use of schema to validate arguments.

src/pe_mailer/message.py

@@ -5,9 +5,15 @@
 from email.mime.application import MIMEApplication
 from email.mime.multipart import MIMEMultipart
 from email.mime.text import MIMEText
-import logging
 import os.path
 
+# cisagov Libraries
+from pe_reports import app
+
+# Setup logging to central file
+
+LOGGER = app.config["LOGGER"]
+
 
 class Message(MIMEMultipart):
     """An email message sent from the CISA Cyber Assessments inbox.
@@ -83,26 +89,26 @@ def __init__(
         MIMEMultipart.__init__(self, "mixed")
 
         self["From"] = from_addr
-        logging.debug("Message to be sent from: %s", self["From"])
+        LOGGER.debug("Message to be sent from: %s", self["From"])
 
         self["To"] = ",".join(to_addrs)
-        logging.debug("Message to be sent to: %s", self["To"])
+        LOGGER.debug("Message to be sent to: %s", self["To"])
 
         if cc_addrs:
             self["CC"] = ",".join(cc_addrs)
-            logging.debug("Message to be sent as CC to: %s", self["CC"])
+            LOGGER.debug("Message to be sent as CC to: %s", self["CC"])
 
         if bcc_addrs:
             self["BCC"] = ",".join(bcc_addrs)
-            logging.debug("Message to be sent as BCC to: %s", self["BCC"])
+            LOGGER.debug("Message to be sent as BCC to: %s", self["BCC"])
 
         if reply_to_addr:
             self["Reply-To"] = reply_to_addr
-            logging.debug("Replies to be sent to: %s", self["Reply-To"])
+            LOGGER.debug("Replies to be sent to: %s", self["Reply-To"])
 
         if subject:
             self["Subject"] = subject
-            logging.debug("Message subject: %s", subject)
+            LOGGER.debug("Message subject: %s", subject)
 
         if html_body or text_body:
             self.attach_text_and_html_bodies(html_body, text_body)
@@ -129,14 +135,14 @@ def attach_text_and_html_bodies(self, html, text):
         # default version that is displayed, as long as the client supports it.
         if text:
             textBody.attach(MIMEText(text, "plain"))
-            logging.debug("Message plain-text body: %s", text)
+            LOGGER.debug("Message plain-text body: %s", text)
 
         if html:
             htmlPart = MIMEText(html, "html")
             # See https://en.wikipedia.org/wiki/MIME#Content-Disposition
             htmlPart.add_header("Content-Disposition", "inline")
             textBody.attach(htmlPart)
-            logging.debug("Message HTML body: %s", html)
+            LOGGER.debug("Message HTML body: %s", html)
 
         self.attach(textBody)
 
@@ -157,7 +163,7 @@ def attach_pdf(self, pdf_filename):
         _, filename = os.path.split(pdf_filename)
         part.add_header("Content-Disposition", "attachment", filename=filename)
         self.attach(part)
-        logging.debug("Message PDF attachment: %s", pdf_filename)
+        LOGGER.debug("Message PDF attachment: %s", pdf_filename)
 
     def attach_csv(self, csv_filename):
         """Attach a CSV file to this message.
@@ -175,4 +181,4 @@ def attach_csv(self, csv_filename):
         _, filename = os.path.split(csv_filename)
         part.add_header("Content-Disposition", "attachment", filename=filename)
         self.attach(part)
-        logging.debug("Message CSV attachment: %s", csv_filename)
+        LOGGER.debug("Message CSV attachment: %s", csv_filename)

src/pe_reports/__init__.py

@@ -39,6 +39,25 @@
 app.config["CELERY_BROKER_URL"] = "redis://localhost:6379/0"
 app.config["CELERY_RESULT_BACKEND"] = "redis://localhost:6379/0"
 
+CENTRAL_LOGGING_FILE = "pe_reports_logging.log"
+DEBUG = False
+# Setup Logging
+"""Set up logging and call the run_pe_script function."""
+if DEBUG is True:
+    level = "DEBUG"
+else:
+    level = "INFO"
+
+logging.basicConfig(
+    filename=CENTRAL_LOGGING_FILE,
+    filemode="a",
+    format="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
+    datefmt="%m/%d/%Y %I:%M:%S",
+    level=level,
+)
+
+app.config["LOGGER"] = logging.getLogger(__name__)
+
 # Creates a Celery object
 celery = Celery(app.name, broker=app.config["CELERY_BROKER_URL"])
 celery.conf.update(app.config)
@@ -63,4 +82,4 @@
 
 if __name__ == "__main__":
     logging.info("The program has started...")
-    app.run(host="127.0.0.1", debug=False, port=8000)
+    app.run(host="127.0.0.1", debug=DEBUG, port=8000)

src/pe_reports/conftest.py

@@ -0,0 +1 @@
+"""Conftest file for proper pytest functionality execution."""