Revize 5e31b492

Re #8570 - Messages logging

src/config/configuration.py

@@ -74 +74 @@
                         filemode='a+',
                         format=LOG_FORMAT,
                         level=logging.DEBUG)
+
+    # TODO check is 'valid'
+    log = logging.getLogger('werkzeug')
+    log.disabled = True

src/config/connection_provider.py

@@ -6 +6 @@
 from src.config.configuration import Configuration
 from src.db.init_queries import DEFAULT_VALUES_SQL
 from src.db.setup_database import SCHEMA_SQL
+from src.utils.logger import Logger
 
 
 class ConnectionProvider(Module):
@@ -21 +22 @@
         :param configuration: Configuration class with application config data
         :return: connection singleton
         """
-        co = sqlite3.connect(database=configuration.connection_string, check_same_thread=False)
-        cu = co.cursor()
-        cu.executescript(SCHEMA_SQL)  # TODO change setup_database not to drop tables if they exist
-        cu.executescript(DEFAULT_VALUES_SQL)
+
+        Logger.debug(f"Creating a database connection [{configuration.connection_string}].")
+
+        try:
+            co = sqlite3.connect(database=configuration.connection_string, check_same_thread=False)
+            cu = co.cursor()
+            cu.executescript(SCHEMA_SQL)  # TODO change setup_database not to drop tables if they exist
+            cu.executescript(DEFAULT_VALUES_SQL)
+        except sqlite3.Error as e:
+            Logger.error(f"Unknown error during database setting.")
+            raise e
+
         return co

src/controllers/certificates_controller.py

@@ -17 +17 @@
     CertificateStatusInvalidException, CertificateNotFoundException, CertificateAlreadyRevokedException
 #  responsibility.
 from src.services.key_service import KeyService
+from src.utils.logger import Logger
+from src.utils.util import dict_to_string
 
 TREE_NODE_TYPE_COUNT = 3
 
@@ -67 +69 @@
 
         :rtype: CreatedResponse
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}")
+
         required_keys = {SUBJECT, USAGE, VALIDITY_DAYS}                             # required fields of the POST req
 
         if request.is_json:                                                         # accept JSON only
             body = request.get_json()
+
+            Logger.info(f"\n\tRequest body:"
+                        f"\n{dict_to_string(body)}")
+
             if not all(k in body for k in required_keys):                           # verify that all keys are present
+                Logger.error(f"Invalid request, missing parameters")
                 return E_MISSING_PARAMETERS, C_BAD_REQUEST
 
             if not isinstance(body[VALIDITY_DAYS], int):                            # type checking
+                Logger.error(f"Invalid request, wrong parameter '{VALIDITY_DAYS}'.")
                 return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
             subject = Subject.from_dict(body[SUBJECT])                              # generate Subject from passed dict
 
             if subject is None:                                                     # if the format is incorrect
+                Logger.error(f"Invalid request, wrong parameter '{SUBJECT}'.")
                 return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
             usages_dict = {}
 
             if not isinstance(body[USAGE], dict):                                   # type checking
+                Logger.error(f"Invalid request, wrong parameter '{USAGE}'.")
                 return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
             for k, v in body[USAGE].items():                                        # for each usage
                 if k not in CertController.KEY_MAP:                                 # check that it is a valid usage
+                    Logger.error(f"Invalid request, wrong parameter '{USAGE}'[{k}].")
                     return E_WRONG_PARAMETERS, C_BAD_REQUEST                        # and throw if it is not
                 usages_dict[CertController.KEY_MAP[k]] = v                          # otherwise translate key and set
 
@@ -105 +120 @@
                 issuer = self.certificate_service.get_certificate(body[CA])              # get base issuer info
 
                 if issuer is None:                                                  # if such issuer does not exist
+                    Logger.error(f"No certificate authority with such unique ID exists 'ID = {key.private_key_id}'.")
                     self.key_service.delete_key(key.private_key_id)                      # free
                     return E_NO_ISSUER_FOUND, C_BAD_REQUEST                         # and throw
 
                 issuer_key = self.key_service.get_key(issuer.private_key_id)             # get issuer's key, which must exist
 
                 if issuer_key is None:                                              # if it does not
+                    Logger.error(f"Internal server error (corrupted database).")
                     self.key_service.delete_key(key.private_key_id)                      # free
                     return E_CORRUPTED_DATABASE, C_INTERNAL_SERVER_ERROR            # and throw
 
@@ -131 +148 @@
                 return {"success": True,
                         "data": cert.certificate_id}, C_CREATED_SUCCESSFULLY
             else:                                                                   # if this fails, then
+                Logger.error(f"Internal error: The certificate could not have been created.")
                 self.key_service.delete_key(key.private_key_id)                          # free
                 return {"success": False,                                           # and wonder what the cause is,
                         "data": "Internal error: The certificate could not have been created."}, C_BAD_REQUEST
                                                                                     # as obj/None carries only one bit
                                                                                     # of error information
         else:
+            Logger.error(f"The request must be JSON-formatted.")
             return E_NOT_JSON_FORMAT, C_BAD_REQUEST                                 # throw in case of non-JSON format
 
     def get_certificate_by_id(self, id):
@@ -149 +168 @@
 
         :rtype: PemResponse
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
         try:
             v = int(id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         cert = self.certificate_service.get_certificate(v)
 
         if cert is None:
+            Logger.error(f"No such certificate found 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NO_DATA
         else:
             return {"success": True, "data": cert.pem_data}, C_SUCCESS
@@ -171 +196 @@
 
         :rtype: CertificateResponse
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
+
         try:
             v = int(id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         cert = self.certificate_service.get_certificate(v)
 
         if cert is None:
+            Logger.error(f"No such certificate found 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NO_DATA
         else:
             data = self.cert_to_dict_full(cert)
@@ -196 +228 @@
 
         :rtype: CertificateListResponse
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}")
+
         targets = {ROOT_CA_ID, INTERMEDIATE_CA_ID, CERTIFICATE_ID}                  # all targets
         issuer_id = -1
 
@@ -207 +243 @@
                 try:
                     data = {FILTERING: json.loads(request.args[FILTERING])}
                 except JSONDecodeError:
+                    Logger.error(f"The request must be JSON-formatted.")
                     return E_NOT_JSON_FORMAT, C_BAD_REQUEST
 
+            Logger.info(f"\n\tRequest body:"
+                        f"\n{dict_to_string(data)}")
+
             if FILTERING in data:                                                   # if the 'filtering' field exists
                 if isinstance(data[FILTERING], dict):                               # and it is also a 'dict'
                     if CA in data[FILTERING]:                                       # containing 'CA'
@@ -219 +259 @@
                                 targets.remove(ROOT_CA_ID)
                                 targets.remove(INTERMEDIATE_CA_ID)
                         else:
+                            Logger.error(f"Invalid request, wrong parameters '{FILTERING}.{CA}'.")
                             return E_WRONG_PARAMETERS, C_BAD_REQUEST
                     if ISSUED_BY in data[FILTERING]:                                # containing 'issuedby'
                         if isinstance(data[FILTERING][ISSUED_BY], int):             # which is an 'int'
                             issuer_id = data[FILTERING][ISSUED_BY]                  # then get its children only
                 else:
+                    Logger.error(f"Invalid request, wrong parameters '{FILTERING}'.")
                     return E_WRONG_PARAMETERS, C_BAD_REQUEST
             if issuer_id >= 0:                                                      # if filtering by an issuer
                 try:
                     children = self.certificate_service.get_certificates_issued_by(issuer_id)  # get his children
                 except CertificateNotFoundException:                                # if id does not exist
+                    Logger.error(f"No such certificate found 'ID = {issuer_id}'.")
                     return E_NO_CERTIFICATES_FOUND, C_NOT_FOUND                     # throw
 
                 certs = [child for child in children if child.type_id in targets]
@@ -246 +289 @@
             certs = self.certificate_service.get_certificates()                     # if no params, fetch everything
 
         if certs is None:
+            Logger.error(f"Internal server error (unknown origin).")
             return E_GENERAL_ERROR, C_INTERNAL_SERVER_ERROR
         elif len(certs) == 0:
+            # TODO check log level
+            Logger.warning(f"No such certificate found (empty list).")
             return E_NO_CERTIFICATES_FOUND, C_NO_DATA
         else:
             ret = []
             for c in certs:
                 data = self.cert_to_dict_partial(c)
                 if data is None:
+                    Logger.error(f"Internal server error (corrupted database).")
                     return E_CORRUPTED_DATABASE, C_INTERNAL_SERVER_ERROR
                 ret.append(
                     data
@@ -270 +317 @@
 
         :rtype: PemResponse
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
+
         try:
             v = int(id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         cert = self.certificate_service.get_certificate(v)
 
         if cert is None:
+            Logger.error(f"No such certificate found 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NO_DATA
 
         trust_chain = self.certificate_service.get_chain_of_trust(cert.parent_id, exclude_root=False)
         if trust_chain is None or len(trust_chain) == 0:
+            Logger.error(f"No such certificate found (empty list).")
             return E_NO_CERTIFICATES_FOUND, C_NO_DATA
 
         return {"success": True, "data": trust_chain[-1].pem_data}, C_SUCCESS
@@ -297 +352 @@
         :rtype: PemResponse
         """
 
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
+
         try:
             v = int(id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         cert = self.certificate_service.get_certificate(v)
 
         if cert is None:
+            Logger.error(f"No such certificate found 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NO_DATA
 
         if cert.parent_id is None:
+            Logger.error(f"Parent ID is empty in certificate 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NO_DATA
 
         trust_chain = self.certificate_service.get_chain_of_trust(cert.parent_id)
@@ -329 +391 @@
 
         :rtype: SuccessResponse | ErrorResponse (see OpenAPI definition)
         """
-        required_keys = {STATUS}  # required keys
 
-        # try to parse certificate identifier -> if it is not int return error 400
-        try:
-            identifier = int(id)
-        except ValueError:
-            return E_WRONG_PARAMETERS, C_BAD_REQUEST
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
+
+        required_keys = {STATUS}  # required keys
 
         # check if the request contains a JSON body
         if request.is_json:
             request_body = request.get_json()
+
+            Logger.info(f"\n\tRequest body:"
+                        f"\n{dict_to_string(request_body)}")
+
+            # try to parse certificate identifier -> if it is not int return error 400
+            try:
+                identifier = int(id)
+            except ValueError:
+                Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
+                return E_WRONG_PARAMETERS, C_BAD_REQUEST
+
             # verify that all required keys are present
             if not all(k in request_body for k in required_keys):
+                Logger.error(f"Invalid request, missing parameters.")
                 return E_MISSING_PARAMETERS, C_BAD_REQUEST
 
             # get status and reason from the request
@@ -352 +425 @@
                 self.certificate_service.set_certificate_revocation_status(identifier, status, reason)
             except (RevocationReasonInvalidException, CertificateStatusInvalidException):
                 # these exceptions are thrown in case invalid status or revocation reason is passed to the controller
+                Logger.error(f"Invalid request, wrong parameters.")
                 return E_WRONG_PARAMETERS, C_BAD_REQUEST
             except CertificateAlreadyRevokedException:
+                Logger.error(f"Certificate is already revoked 'ID = {identifier}'.")
                 return E_NO_CERTIFICATE_ALREADY_REVOKED, C_BAD_REQUEST
             except CertificateNotFoundException:
+                Logger.error(f"No such certificate found 'ID = {identifier}'.")
                 return E_NO_CERTIFICATES_FOUND, C_NOT_FOUND
             return {"success": True,
                     "data": "Certificate status updated successfully."}, C_SUCCESS
         # throw an error in case the request does not contain a json body
         else:
+            Logger.error(f"The request must be JSON-formatted.")
             return E_NOT_JSON_FORMAT, C_BAD_REQUEST
 
     def cert_to_dict_partial(self, c):
@@ -369 +446 @@
         :param c: target cert
         :return: certificate dict (compliant with some parts of the REST API)
         """
+
+        # TODO check log
+        Logger.debug(f"Function launched.")
+
         c_issuer = self.certificate_service.get_certificate(c.parent_id)
         if c_issuer is None:
             return None
@@ -392 +473 @@
         :param c: target cert
         :return: certificate dict (compliant with some parts of the REST API)
         """
+
+        Logger.info(f"Function launched.")
+
         subj = self.certificate_service.get_subject_from_certificate(c)
         c_issuer = self.certificate_service.get_certificate(c.parent_id)
         if c_issuer is None:
@@ -415 +499 @@
         :rtype: PemResponse
         """
 
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
+
         # try to parse the supplied ID
         try:
             v = int(id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         # find a certificate using the given ID
         cert = self.certificate_service.get_certificate(v)
 
         if cert is None:
+            Logger.error(f"No such certificate found 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NOT_FOUND
         else:
             # certificate exists, fetch it's private key
             private_key = self.key_service.get_key(cert.private_key_id)
             if cert is None:
+                Logger.error(f"Internal server error (certificate's private key cannot be found).")
                 return E_NO_CERT_PRIVATE_KEY_FOUND, C_INTERNAL_SERVER_ERROR
             else:
                 return {"success": True, "data": private_key.private_key}, C_SUCCESS
@@ -444 +535 @@
         :rtype: PemResponse
         """
 
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
+
         # try to parse the supplied ID
         try:
             v = int(id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         # find a certificate using the given ID
         cert = self.certificate_service.get_certificate(v)
 
         if cert is None:
+            Logger.error(f"No such certificate found 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NOT_FOUND
         else:
             return {"success": True, "data": self.certificate_service.get_public_key_from_certificate(cert)}, C_SUCCESS
@@ -464 +561 @@
         :param id: target certificate ID
         :rtype: DeleteResponse
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {id}")
+
         try:
             v = int(id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         try:
             self.certificate_service.delete_certificate(v)
         except CertificateNotFoundException:
+            Logger.error(f"No such certificate found 'ID = {v}'.")
             return E_NO_CERTIFICATES_FOUND, C_NOT_FOUND
         except DatabaseException:
+            Logger.error(f"Internal server error (corrupted database).")
             return E_CORRUPTED_DATABASE, C_INTERNAL_SERVER_ERROR
         except CertificateStatusInvalidException or RevocationReasonInvalidException or UnknownException:
+            Logger.error(f"Internal server error (unknown origin).")
             return E_GENERAL_ERROR, C_INTERNAL_SERVER_ERROR
 
         return {"success": True, "data": "The certificate and its descendants have been successfully deleted."}

src/controllers/crl_ocsp_controller.py

@@ -1 @@
-from flask import Response
+from flask import Response, request
 from injector import inject
 import base64
 
@@ -6 +6 @@
 from src.exceptions.private_key_not_found_exception import PrivateKeyNotFoundException
 from src.services.crl_ocsp.crl_ocsp_service import CrlOcspService
 from src.controllers.return_codes import *
+from src.utils.logger import Logger
 
 E_WRONG_PARAMETERS = {"success": False, "data": "Invalid request, wrong parameters."}
 E_NO_CERTIFICATES_FOUND = {"success": False, "data": "No such certificate found."}
@@ -23 +24 @@
         :param ca_id: certificate authority whose CRL is requested
         :return: download response / error
         """
+
+        # TODO check log
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {ca_id}")
+
         # convert id from string to int
         try:
             identifier = int(ca_id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{ca_id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         # generate the CRL
         try:
             crl = self.crl_service.generate_crl_response(identifier)
         except CertificateNotFoundException:
+            Logger.error(f"No such certificate found 'ID = {identifier}'.")
             return E_NO_CERTIFICATES_FOUND, C_NOT_FOUND
 
         return Response(crl, mimetype="application/x-x509-ca-cert",
@@ -45 +54 @@
         :param base64_der_ocsp_request: encoded request
         :return: DER OCSP response
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {ca_id}")
+
         return self.get_ocsp_from_der(ca_id, base64.b64decode(base64_der_ocsp_request))
 
     def get_ocsp_from_der(self, ca_id, der_ocsp_request):
@@ -54 +68 @@
         :param der_ocsp_request: encoded request
         :return: DER OCSP response
         """
+
+        Logger.info(f"\n\t{request.referrer}"
+                    f"\n\t{request.method}   {request.path}   {request.scheme}"
+                    f"\n\tCertificate ID = {ca_id}")
+
         if len(der_ocsp_request) == 0:
+            Logger.error(f"Invalid request, wrong parameters 'der_ocsp_request'.")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         try:
             ca_id = int(ca_id)
         except ValueError:
+            Logger.error(f"Invalid request, wrong parameters 'id'[{ca_id}].")
             return E_WRONG_PARAMETERS, C_BAD_REQUEST
 
         try:
             ocsp_response = self.crl_service.generate_ocsp_response(ca_id, der_ocsp_request)
         except CertificateNotFoundException:
+            Logger.error(f"No such certificate found 'ID = {ca_id}'.")
             return E_NO_CERTIFICATES_FOUND, C_NOT_FOUND
 
         return Response(ocsp_response, mimetype="application/ocsp-response")

src/dao/certificate_repository.py

@@ -5 +5 @@
 from injector import inject
 from src.constants import *
 from src.model.certificate import Certificate
+from src.utils.logger import Logger
 
 
 class CertificateRepository:

src/db/setup_database.py

@@ -2 +2 @@
 
 from src.constants import DATABASE_FILE_LOCATION
 from src.db.init_queries import SCHEMA_SQL, DEFAULT_VALUES_SQL
+from src.utils.logger import Logger
 
 
 def setup_database():
-    co = sqlite3.connect(DATABASE_FILE_LOCATION.shortest_relative_path())
-    cu = co.cursor()
-    cu.executescript(SCHEMA_SQL)
-    cu.executescript(DEFAULT_VALUES_SQL)
+    Logger.debug(f"Database is setting.")
+
+    try:
+        co = sqlite3.connect(DATABASE_FILE_LOCATION.shortest_relative_path())
+        cu = co.cursor()
+        cu.executescript(SCHEMA_SQL)
+        cu.executescript(DEFAULT_VALUES_SQL)
+    except sqlite3.Error as e:
+        Logger.error(f"Unknown error during database setting.")
+        raise e
+
+    return co
 
 
 if __name__ == '__main__':