Merge branch 'master' into ecc_changes

.travis.yml

@@ -47,4 +47,4 @@ after_success:
 
 notifications:
   email:
-    ccastrapel@netflix.com
+    lemur@netflix.com

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:
 

lemur/manage.py

@@ -120,6 +120,7 @@ METRIC_PROVIDERS = []
 
 LOG_LEVEL = "DEBUG"
 LOG_FILE = "lemur.log"
+LOG_UPGRADE_FILE = "db_upgrade.log"
 
 
 # Database

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():

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
+log is added to a file configured in LOG_UPGRADE_FILE or, by default,
-directory. Any error encountered while parsing a certificate will
+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.info("--- Total %s seconds ---\n" % (time.time() - start_time))
-    log_file.close()
 
 
 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():

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)

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
@@ -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
@@ -87,7 +86,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 = {
@@ -100,27 +99,47 @@ 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'}
+        data = {'response': 'No detailed message'}
-    s = my_response.status_code
+    status_code = my_response.status_code
-    if s > 399:
+    if status_code > 399:
-        raise Exception(f"ENTRUST error: {msg.get(s, s)}\n{d['errors']}")
+        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,
+        "status": status_code,
-        "response": d
+        "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 order_and_download_certificate(session, url, data):
+    """
+    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
+    :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 +197,8 @@ class EntrustIssuerPlugin(IssuerPlugin):
         data = process_options(issuer_options)
         data["csr"] = csr
 
-        try:
+        response_dict = order_and_download_certificate(self.session, url, data)
-            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 = handle_response(response)
         external_id = response_dict['trackingId']
         cert = response_dict['endEntityCert']
         if len(response_dict['chainCerts']) < 2:
@@ -200,6 +213,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 +230,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")
@@ -244,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)