diff --git a/docs/administration.rst b/docs/administration.rst index 724b136f..5cece1c8 100644 --- a/docs/administration.rst +++ b/docs/administration.rst @@ -28,6 +28,13 @@ Basic Configuration LOG_FILE = "/logs/lemur/lemur-test.log" +.. data:: LOG_UPGRADE_FILE + :noindex: + + :: + + LOG_UPGRADE_FILE = "/logs/lemur/db_upgrade.log" + .. data:: DEBUG :noindex: diff --git a/lemur/manage.py b/lemur/manage.py index e53f8bd6..bff97535 100755 --- a/lemur/manage.py +++ b/lemur/manage.py @@ -120,6 +120,7 @@ METRIC_PROVIDERS = [] LOG_LEVEL = "DEBUG" LOG_FILE = "lemur.log" +LOG_UPGRADE_FILE = "db_upgrade.log" # Database diff --git a/lemur/migrations/versions/1db4f82bc780_.py b/lemur/migrations/versions/1db4f82bc780_.py index e6fb47f0..00b83ceb 100644 --- a/lemur/migrations/versions/1db4f82bc780_.py +++ b/lemur/migrations/versions/1db4f82bc780_.py @@ -10,11 +10,21 @@ Create Date: 2018-08-03 12:56:44.565230 revision = "1db4f82bc780" down_revision = "3adfdd6598df" -import logging - from alembic import op -log = logging.getLogger(__name__) +from flask import current_app +from logging import Formatter, FileHandler, getLogger + +log = getLogger(__name__) +handler = FileHandler(current_app.config.get("LOG_UPGRADE_FILE", "db_upgrade.log")) +handler.setFormatter( + Formatter( + "%(asctime)s %(levelname)s: %(message)s " "[in %(pathname)s:%(lineno)d]" + ) +) +handler.setLevel(current_app.config.get("LOG_LEVEL", "DEBUG")) +log.setLevel(current_app.config.get("LOG_LEVEL", "DEBUG")) +log.addHandler(handler) def upgrade(): diff --git a/lemur/migrations/versions/c301c59688d2_.py b/lemur/migrations/versions/c301c59688d2_.py index 669c934f..4da91b7b 100644 --- a/lemur/migrations/versions/c301c59688d2_.py +++ b/lemur/migrations/versions/c301c59688d2_.py @@ -7,8 +7,9 @@ the rest of the keys, the certificate body is parsed to determine the exact key_type information. Each individual DB change is explicitly committed, and the respective -log is added to a file named db_upgrade.log in the current working -directory. Any error encountered while parsing a certificate will +log is added to a file configured in LOG_UPGRADE_FILE or, by default, +to a file named db_upgrade.log in the current working directory. +Any error encountered while parsing a certificate will also be logged along with the certificate ID. If faced with any issue while running this upgrade, there is no harm in re-running the upgrade. Each run processes only rows for which key_type information is not yet @@ -31,15 +32,28 @@ down_revision = '434c29e40511' from alembic import op from sqlalchemy.sql import text -from lemur.common import utils import time import datetime +from flask import current_app -log_file = open('db_upgrade.log', 'a') +from logging import Formatter, FileHandler, getLogger + +from lemur.common import utils + +log = getLogger(__name__) +handler = FileHandler(current_app.config.get("LOG_UPGRADE_FILE", "db_upgrade.log")) +handler.setFormatter( + Formatter( + "%(asctime)s %(levelname)s: %(message)s " "[in %(pathname)s:%(lineno)d]" + ) +) +handler.setLevel(current_app.config.get("LOG_LEVEL", "DEBUG")) +log.setLevel(current_app.config.get("LOG_LEVEL", "DEBUG")) +log.addHandler(handler) def upgrade(): - log_file.write("\n*** Starting new run(%s) ***\n" % datetime.datetime.now()) + log.info("\n*** Starting new run(%s) ***\n" % datetime.datetime.now()) start_time = time.time() # Update RSA keys using the key length information @@ -50,8 +64,7 @@ def upgrade(): # Process remaining certificates. Though below method does not make any assumptions, most of the remaining ones should be ECC certs. update_key_type() - log_file.write("--- Total %s seconds ---\n" % (time.time() - start_time)) - log_file.close() + log.info("--- Total %s seconds ---\n" % (time.time() - start_time)) def downgrade(): @@ -69,18 +82,18 @@ def downgrade(): def update_key_type_rsa(bits): - log_file.write("Processing certificate with key type RSA %s\n" % bits) + log.info("Processing certificate with key type RSA %s\n" % bits) stmt = text( f"update certificates set key_type='RSA{bits}' where bits={bits} and not_after > CURRENT_DATE - 31 and key_type is null" ) - log_file.write("Query: %s\n" % stmt) + log.info("Query: %s\n" % stmt) start_time = time.time() op.execute(stmt) commit() - log_file.write("--- %s seconds ---\n" % (time.time() - start_time)) + log.info("--- %s seconds ---\n" % (time.time() - start_time)) def update_key_type(): @@ -95,9 +108,9 @@ def update_key_type(): try: cert_key_type = utils.get_key_type_from_certificate(body) except ValueError as e: - log_file.write("Error in processing certificate - ID: %s Error: %s \n" % (cert_id, str(e))) + log.error("Error in processing certificate - ID: %s Error: %s \n" % (cert_id, str(e))) else: - log_file.write("Processing certificate - ID: %s key_type: %s\n" % (cert_id, cert_key_type)) + log.info("Processing certificate - ID: %s key_type: %s\n" % (cert_id, cert_key_type)) stmt = text( "update certificates set key_type=:key_type where id=:id" ) @@ -106,7 +119,7 @@ def update_key_type(): commit() - log_file.write("--- %s seconds ---\n" % (time.time() - start_time)) + log.info("--- %s seconds ---\n" % (time.time() - start_time)) def commit():