From 9374adaa4632ed4e477f875cf036f8bb364d7707 Mon Sep 17 00:00:00 2001 From: Emmanuel Garette Date: Wed, 21 Oct 2020 08:45:12 +0200 Subject: [PATCH 01/14] do not create db_upgrade.log during migrations --- lemur/migrations/versions/c301c59688d2_.py | 21 ++++++++++----------- 1 file changed, 10 insertions(+), 11 deletions(-) diff --git a/lemur/migrations/versions/c301c59688d2_.py b/lemur/migrations/versions/c301c59688d2_.py index 669c934f..8712d60c 100644 --- a/lemur/migrations/versions/c301c59688d2_.py +++ b/lemur/migrations/versions/c301c59688d2_.py @@ -35,11 +35,11 @@ from lemur.common import utils import time import datetime -log_file = open('db_upgrade.log', 'a') - +import logging +log = logging.getLogger(__name__) 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 +50,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 +68,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 +94,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.info("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 +105,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(): From 2c1e7b19a225ad71e4a6802fd293469c5601d3d7 Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 17:59:58 -0700 Subject: [PATCH 02/14] 10x 10s delay might be too long for the load balancer request --- lemur/plugins/lemur_digicert/plugin.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lemur/plugins/lemur_digicert/plugin.py b/lemur/plugins/lemur_digicert/plugin.py index ec3a0792..d8e88fa3 100644 --- a/lemur/plugins/lemur_digicert/plugin.py +++ b/lemur/plugins/lemur_digicert/plugin.py @@ -234,7 +234,7 @@ def handle_cis_response(response): return response.json() -@retry(stop_max_attempt_number=10, wait_fixed=10000) +@retry(stop_max_attempt_number=10, wait_fixed=1000) def get_certificate_id(session, base_url, order_id): """Retrieve certificate order id from Digicert API.""" order_url = "{0}/services/v2/order/certificate/{1}".format(base_url, order_id) @@ -245,7 +245,7 @@ def get_certificate_id(session, base_url, order_id): return response_data["certificate"]["id"] -@retry(stop_max_attempt_number=10, wait_fixed=10000) +@retry(stop_max_attempt_number=10, wait_fixed=1000) def get_cis_certificate(session, base_url, order_id): """Retrieve certificate order id from Digicert API, including the chain""" certificate_url = "{0}/platform/cis/certificate/{1}/download".format(base_url, order_id) From d233490c8aeb6996bb8fc936c9c86f3614fce142 Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 18:01:14 -0700 Subject: [PATCH 03/14] simple retry --- lemur/plugins/lemur_entrust/plugin.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index ffb5765d..4700c022 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -200,6 +200,7 @@ class EntrustIssuerPlugin(IssuerPlugin): return cert, chain, external_id + @retry(stop_max_attempt_number=3, wait_fixed=1000) def revoke_certificate(self, certificate, comments): """Revoke an Entrust certificate.""" base_url = current_app.config.get("ENTRUST_URL") @@ -216,6 +217,7 @@ class EntrustIssuerPlugin(IssuerPlugin): metrics.send("entrust_revoke_certificate", "counter", 1) return handle_response(response) + @retry(stop_max_attempt_number=3, wait_fixed=1000) def deactivate_certificate(self, certificate): """Deactivates an Entrust certificate.""" base_url = current_app.config.get("ENTRUST_URL") From 75bc3a5b20d6d0efcf0da236daf301fe29b12bdb Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 18:02:05 -0700 Subject: [PATCH 04/14] refactoring and adding retry --- lemur/plugins/lemur_entrust/plugin.py | 26 +++++++++++++++++++------- 1 file changed, 19 insertions(+), 7 deletions(-) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index 4700c022..52860049 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -121,6 +121,24 @@ def handle_response(my_response): else: # return data from the response return d +@retry(stop_max_attempt_number=3, wait_fixed=5000) +def get_certificate_order(session, url, data): + """ + Helper function place a cert order and downloading it + :param session: + :param url: Entrust endpoint url + :param data: CSR, and the required order details, such as validity length + :return: the cert chain + :raise Exception: + """ + try: + response = session.post(url, json=data, timeout=(15, 40)) + except requests.exceptions.Timeout: + raise Exception("Timeout for POST") + except requests.exceptions.RequestException as e: + raise Exception(f"Error for POST {e}") + + return handle_response(response) class EntrustIssuerPlugin(IssuerPlugin): @@ -178,14 +196,8 @@ class EntrustIssuerPlugin(IssuerPlugin): data = process_options(issuer_options) data["csr"] = csr - try: - response = self.session.post(url, json=data, timeout=(15, 40)) - except requests.exceptions.Timeout: - raise Exception("Timeout for POST") - except requests.exceptions.RequestException as e: - raise Exception(f"Error for POST {e}") + response_dict = get_certificate_order(self.session, url, data) - response_dict = handle_response(response) external_id = response_dict['trackingId'] cert = response_dict['endEntityCert'] if len(response_dict['chainCerts']) < 2: From 6891077501a9ca418b6747f0b13d57bc08a79759 Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 18:02:35 -0700 Subject: [PATCH 05/14] readability --- lemur/plugins/lemur_entrust/plugin.py | 22 ++++++++++++---------- 1 file changed, 12 insertions(+), 10 deletions(-) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index 52860049..0e769093 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -100,27 +100,29 @@ def handle_response(my_response): } try: - d = json.loads(my_response.content) + data = json.loads(my_response.content) except ValueError: # catch an empty jason object here - d = {'response': 'No detailed message'} - s = my_response.status_code - if s > 399: - raise Exception(f"ENTRUST error: {msg.get(s, s)}\n{d['errors']}") + data = {'response': 'No detailed message'} + status_code = my_response.status_code + if status_code > 399: + raise Exception(f"ENTRUST error: {msg.get(status_code, status_code)}\n{data['errors']}") log_data = { "function": f"{__name__}.{sys._getframe().f_code.co_name}", "message": "Response", - "status": s, - "response": d + "status": status_code, + "response": data } current_app.logger.info(log_data) - if d == {'response': 'No detailed message'}: + if data == {'response': 'No detailed message'}: # status if no data - return s + return status_code else: # return data from the response - return d + return data + + @retry(stop_max_attempt_number=3, wait_fixed=5000) def get_certificate_order(session, url, data): """ From 7e573d6d517d7f6189ff005ed072f321627b7b6f Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 18:02:54 -0700 Subject: [PATCH 06/14] fixing typo --- lemur/plugins/lemur_entrust/plugin.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index 0e769093..c785acc1 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -87,7 +87,7 @@ def process_options(options): def handle_response(my_response): """ Helper function for parsing responses from the Entrust API. - :param content: + :param my_response: :return: :raise Exception: """ msg = { From 9957120a7fd2c0befef39f166c6292f5b8f83e86 Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 18:03:07 -0700 Subject: [PATCH 07/14] adding missing import --- lemur/plugins/lemur_entrust/plugin.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index c785acc1..02e0a2be 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -1,9 +1,9 @@ - import arrow import requests import json import sys from flask import current_app +from retrying import retry from lemur.plugins import lemur_entrust as entrust from lemur.plugins.bases import IssuerPlugin, SourcePlugin From 0e02abbb3791cbd844cd916812a99896c6823fce Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 18:03:27 -0700 Subject: [PATCH 08/14] Entrust just looks into CSR for RSA/EC key type --- lemur/plugins/lemur_entrust/plugin.py | 1 - 1 file changed, 1 deletion(-) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index 02e0a2be..fcb3e14f 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -78,7 +78,6 @@ def process_options(options): "eku": "SERVER_AND_CLIENT_AUTH", "certType": product_type, "certExpiryDate": validity_end, - # "keyType": "RSA", Entrust complaining about this parameter "tracking": tracking_data } return data From f6554a9a1e79b9a3e688ba59438708b559efd835 Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Fri, 23 Oct 2020 18:03:55 -0700 Subject: [PATCH 09/14] typo, fixing abstract class complaints --- lemur/plugins/lemur_entrust/plugin.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index fcb3e14f..8bb0710c 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -259,7 +259,7 @@ class EntrustIssuerPlugin(IssuerPlugin): def get_ordered_certificate(self, order_id): raise NotImplementedError("Not implemented\n", self, order_id) - def canceled_ordered_certificate(self, pending_cert, **kwargs): + def cancel_ordered_certificate(self, pending_cert, **kwargs): raise NotImplementedError("Not implemented\n", self, pending_cert, **kwargs) From d7478a5c5cb00dc619e7f8bc7afc2780a1cb3e1a Mon Sep 17 00:00:00 2001 From: Emmanuel Garette Date: Sun, 25 Oct 2020 19:24:17 +0100 Subject: [PATCH 10/14] use an alternative logger for the upgrade --- docs/administration.rst | 7 +++++++ lemur/manage.py | 1 + lemur/migrations/versions/1db4f82bc780_.py | 16 ++++++++++++--- lemur/migrations/versions/c301c59688d2_.py | 23 +++++++++++++++++----- 4 files changed, 39 insertions(+), 8 deletions(-) diff --git a/docs/administration.rst b/docs/administration.rst index c2f20362..62a22dd1 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 8712d60c..d1a30650 100644 --- a/lemur/migrations/versions/c301c59688d2_.py +++ b/lemur/migrations/versions/c301c59688d2_.py @@ -31,12 +31,25 @@ 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 + +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) -import logging -log = logging.getLogger(__name__) def upgrade(): log.info("\n*** Starting new run(%s) ***\n" % datetime.datetime.now()) @@ -94,9 +107,9 @@ def update_key_type(): try: cert_key_type = utils.get_key_type_from_certificate(body) except ValueError as e: - log.info("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.info("Processing certificate - ID: %s key_type: %s\n" % (cert_id, cert_key_type)) + log.error("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" ) From 79647e33724ab107812737b5fe8647c8f7a2dfbd Mon Sep 17 00:00:00 2001 From: Emmanuel Garette Date: Tue, 27 Oct 2020 20:35:36 +0100 Subject: [PATCH 11/14] add reference to LOG_UPGRADE_FILE in toplevel comment --- lemur/migrations/versions/c301c59688d2_.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/lemur/migrations/versions/c301c59688d2_.py b/lemur/migrations/versions/c301c59688d2_.py index d1a30650..f4656f20 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 From e9824a6808f4007f76df26427a4a10d76ab1b031 Mon Sep 17 00:00:00 2001 From: Emmanuel Garette Date: Tue, 27 Oct 2020 20:38:00 +0100 Subject: [PATCH 12/14] change the log level to info if upgrade is successful --- lemur/migrations/versions/c301c59688d2_.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lemur/migrations/versions/c301c59688d2_.py b/lemur/migrations/versions/c301c59688d2_.py index f4656f20..4da91b7b 100644 --- a/lemur/migrations/versions/c301c59688d2_.py +++ b/lemur/migrations/versions/c301c59688d2_.py @@ -110,7 +110,7 @@ def update_key_type(): except ValueError as e: log.error("Error in processing certificate - ID: %s Error: %s \n" % (cert_id, str(e))) else: - log.error("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" ) From c6a803489041f0e8564889af62d6b21d072ea459 Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Tue, 27 Oct 2020 16:13:05 -0700 Subject: [PATCH 13/14] language --- lemur/plugins/lemur_entrust/plugin.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lemur/plugins/lemur_entrust/plugin.py b/lemur/plugins/lemur_entrust/plugin.py index 8bb0710c..d3324db0 100644 --- a/lemur/plugins/lemur_entrust/plugin.py +++ b/lemur/plugins/lemur_entrust/plugin.py @@ -123,9 +123,9 @@ def handle_response(my_response): @retry(stop_max_attempt_number=3, wait_fixed=5000) -def get_certificate_order(session, url, data): +def order_and_download_certificate(session, url, data): """ - Helper function place a cert order and downloading it + Helper function to place a certificacte order and download it :param session: :param url: Entrust endpoint url :param data: CSR, and the required order details, such as validity length @@ -197,7 +197,7 @@ class EntrustIssuerPlugin(IssuerPlugin): data = process_options(issuer_options) data["csr"] = csr - response_dict = get_certificate_order(self.session, url, data) + response_dict = order_and_download_certificate(self.session, url, data) external_id = response_dict['trackingId'] cert = response_dict['endEntityCert'] From c0bf111cb940dce4d1687558221b735631cdbd41 Mon Sep 17 00:00:00 2001 From: Hossein Shafagh Date: Wed, 28 Oct 2020 15:02:22 -0700 Subject: [PATCH 14/14] updating notification contact for travis --- .travis.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.travis.yml b/.travis.yml index 129d774b..67a1d0b1 100644 --- a/.travis.yml +++ b/.travis.yml @@ -47,4 +47,4 @@ after_success: notifications: email: - ccastrapel@netflix.com + lemur@netflix.com