From e98e967740e58cf429b76b187828e3e0625215a5 Mon Sep 17 00:00:00 2001 From: Tommy Carpenter Date: Thu, 5 Jul 2018 17:19:28 -0400 Subject: Bugfixes, add EELF error log func Change-Id: I159c9e663e8f17871862bb3ba42d8ea76fc2c05c Issue-ID: DCAEGEN2-581 Signed-off-by: Tommy Carpenter --- .gitignore | 2 + Changelog.md | 6 ++ app/app/config_binding_service/controller.py | 57 +++++++++--------- app/app/config_binding_service/logging.py | 86 ++++++++++++++++++++-------- app/app/main.py | 4 +- app/app/setup.py | 2 +- 6 files changed, 103 insertions(+), 54 deletions(-) diff --git a/.gitignore b/.gitignore index 4f07413..6b91aaa 100644 --- a/.gitignore +++ b/.gitignore @@ -1,4 +1,6 @@ .pytest_cache/ +run_tests.sh +run_tests_https.sh xunit-results.xml .DS_Store # Byte-compiled / optimized / DLL files diff --git a/Changelog.md b/Changelog.md index d9c311e..e7e2f0a 100644 --- a/Changelog.md +++ b/Changelog.md @@ -4,6 +4,12 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](http://keepachangelog.com/) and this project adheres to [Semantic Versioning](http://semver.org/). +## [2.2.1] - 7/5/2018 +* Fix bug where healthcheck call was not in the audit log +* Add service_component_name into the audit record message field on audit calls +* Rename "log.log" to "audit.log" +* Add EELF compliant "error.log" + ## [2.2.0] - 6/26/2018 * Productionalize by moving to NGINX+UWSGI. Flask was not meant to be run as a production server * This is towards HTTPS support, which will now be done via NGINX reverse proxying instead of in the application code itself diff --git a/app/app/config_binding_service/controller.py b/app/app/config_binding_service/controller.py index ec1fb86..acd9447 100644 --- a/app/app/config_binding_service/controller.py +++ b/app/app/config_binding_service/controller.py @@ -22,7 +22,7 @@ import connexion import uuid from flask import Response from config_binding_service import client, get_consul_uri -from config_binding_service.logging import LOGGER, audit, utc +from config_binding_service.logging import audit, utc, error def _get_helper(json_expecting_func, **kwargs): @@ -37,46 +37,43 @@ def _get_helper(json_expecting_func, **kwargs): except client.CantGetConfig as exc: response, status_code, mimetype = exc.response, exc.code, "text/plain" except Exception as exc: - LOGGER.error(exc) - response, status_code, mimetype = "Unknown error, please report", 500, "text/plain" + response, status_code, mimetype = "Unknown error", 500, "text/plain" return response, status_code, mimetype def _get_or_generate_xer(raw_request): """get or generate the transaction id""" - rid = raw_request.headers.get("x-onap-requestid", None) - if rid is None: + xer = raw_request.headers.get("x-onap-requestid", None) + if xer is None: # some components are still using the old name - rid = raw_request.headers.get("x-ecomp-requestid", None) - if rid is None: + xer = raw_request.headers.get("x-ecomp-requestid", None) + if xer is None: # the user did NOT supply a request id, generate one - rid = str(uuid.uuid4()) - return rid + xer = str(uuid.uuid4()) + return xer def bind_all(service_component_name): """ Get all the keys in Consul for this SCN, and bind the config """ - rid = _get_or_generate_xer(connexion.request) + xer = _get_or_generate_xer(connexion.request) bts = utc() response, status_code, mimetype = _get_helper(client.resolve_all, service_component_name=service_component_name) - audit(connexion.request, bts, rid, status_code, __name__) + audit(connexion.request, bts, xer, status_code, __name__, "called for component {0}".format(service_component_name)) # Even though some older components might be using the ecomp name, we return the proper one - return Response(response=response, status=status_code, mimetype=mimetype, headers={"x-onap-requestid": rid}) + return Response(response=response, status=status_code, mimetype=mimetype, headers={"x-onap-requestid": xer}) def bind_config_for_scn(service_component_name): """ Bind just the config for this SCN """ - print(connexion) - print(connexion.request) - rid = _get_or_generate_xer(connexion.request) + xer = _get_or_generate_xer(connexion.request) bts = utc() response, status_code, mimetype = _get_helper(client.resolve, service_component_name=service_component_name) - audit(connexion.request, bts, rid, status_code, __name__) - return Response(response=response, status=status_code, mimetype=mimetype, headers={"x-onap-requestid": rid}) + audit(connexion.request, bts, xer, status_code, __name__, "called for component {0}".format(service_component_name)) + return Response(response=response, status=status_code, mimetype=mimetype, headers={"x-onap-requestid": xer}) def get_key(key, service_component_name): @@ -84,22 +81,26 @@ def get_key(key, service_component_name): Get a single key k of the form service_component_name:k from Consul. Should not be used and will return a BAD REQUEST for k=policies because it's a complex object """ - rid = _get_or_generate_xer(connexion.request) + xer = _get_or_generate_xer(connexion.request) bts = utc() response, status_code, mimetype = _get_helper(client.get_key, key=key, service_component_name=service_component_name) - audit(connexion.request, bts, rid, status_code, __name__) - return Response(response=response, status=status_code, mimetype=mimetype, headers={"x-onap-requestid": rid}) + audit(connexion.request, bts, xer, status_code, __name__, "called for component {0}".format(service_component_name)) + return Response(response=response, status=status_code, mimetype=mimetype, headers={"x-onap-requestid": xer}) def healthcheck(): """ CBS Healthcheck """ - LOGGER.info("healthcheck called") - res = requests.get( - "{0}/v1/catalog/service/config_binding_service".format(get_consul_uri())) - if res.status_code == 200: - return Response(response="CBS is alive and Consul connection OK", - status=200) - return Response(response="CBS is alive but cannot reach Consul", - status=503) + xer = _get_or_generate_xer(connexion.request) + bts = utc() + res = requests.get("{0}/v1/catalog/service/config_binding_service".format(get_consul_uri())) + status = res.status_code + if status == 200: + response = "CBS is alive and Consul connection OK" + else: + response = "CBS is alive but cannot reach Consul" + # treating this as a WARN because this could be a temporary network glitch. Also per EELF guidelines this is a 200 ecode (availability) + error(connexion.request, xer, "WARN", 200, tgt_entity="Consul", tgt_path="/v1/catalog/service/config_binding_service", msg=response) + audit(connexion.request, bts, xer, status, __name__, msg=response) + return Response(response=response, status=status) diff --git a/app/app/config_binding_service/logging.py b/app/app/config_binding_service/logging.py index f5cd6af..7966e2f 100644 --- a/app/app/config_binding_service/logging.py +++ b/app/app/config_binding_service/logging.py @@ -16,13 +16,15 @@ # # ECOMP is a trademark and service mark of AT&T Intellectual Property. -from logging import getLogger, StreamHandler, Formatter +from logging import getLogger, Formatter from logging.handlers import RotatingFileHandler from os import makedirs import datetime LOGGER = getLogger("defaultlogger") +_AUDIT_LOGGER = getLogger("defaultlogger") +_ERROR_LOGGER = getLogger("defaultlogger") def _create_logger(name, logfile): @@ -36,23 +38,28 @@ def _create_logger(name, logfile): maxBytes=10000000, backupCount=2) # 10 meg with one backup.. formatter = Formatter('%(message)s') file_handler.setFormatter(formatter) - stream_handler = StreamHandler() - stream_handler.setFormatter(formatter) logger.setLevel("DEBUG") logger.addHandler(file_handler) - logger.addHandler(stream_handler) return logger -def create_logger(): +def create_loggers(): """ Public method to set the global logger, launched from Run """ - LOGFILE = "/opt/logs/log.log" makedirs("/opt/logs", exist_ok=True) - open(LOGFILE, 'a').close() # this is like "touch" - global LOGGER - LOGGER = _create_logger("config_binding_service", LOGFILE) + + # create the audit log + aud_file = "/opt/logs/audit.log" + open(aud_file, 'a').close() # this is like "touch" + global _AUDIT_LOGGER + _AUDIT_LOGGER = _create_logger("config_binding_service_audit", aud_file) + + # create the error log + err_file = "/opt/logs/error.log" + open(err_file, 'a').close() # this is like "touch" + global _ERROR_LOGGER + _ERROR_LOGGER = _create_logger("config_binding_service_error", err_file) def utc(): @@ -65,23 +72,23 @@ def audit(raw_request, bts, xer, rcode, calling_mod, msg="n/a"): write an EELF audit record per https://wiki.onap.org/download/attachments/1015849/ONAP%20application%20logging%20guidelines.pdf?api=v2 %The audit fields implemented: - 1 BeginTimestamp Implemented (bts) - 2 EndTimestamp Auto Injected when this is called - 3 RequestID Implemented (xer) - 7 serviceName Implemented (from Req) - 9 StatusCode Auto injected based on rcode - 10 ResponseCode Implemented (rcode) - 15 Server IP address Implemented (from Req) - 16 ElapsedTime Auto Injected (milliseconds) - 18 ClientIPaddress Implemented (from Req) - 19 class name Implemented (mod), though docs say OOP, I am using the python module here - 20 Unused ...implemented.... - 21-25 Custom n/a - 26 detailMessage Implemented (msg) + 1 BeginTimestamp Implemented (bts) + 2 EndTimestamp Auto Injected when this is called + 3 RequestID Implemented (xer) + 7 serviceName Implemented (from Req) + 9 StatusCode Auto injected based on rcode + 10 ResponseCode Implemented (rcode) + 15 Server IP address Implemented (from Req) + 16 ElapsedTime Auto Injected (milliseconds) + 18 ClientIPaddress Implemented (from Req) + 19 class name Implemented (mod), though docs say OOP, I am using the python module here + 20 Unused ...implemented.... + 21-25 Custom n/a + 26 detailMessage Implemented (msg) """ ets = utc() - LOGGER.info("{bts}|{ets}|{xer}||||{path}||{status}|{rcode}|||||{servip}|{et}||{clientip}|{calling_mod}|||||||{msg}".format( + _AUDIT_LOGGER.info("{bts}|{ets}|{xer}||||{path}||{status}|{rcode}|||||{servip}|{et}||{clientip}|{calling_mod}|||||||{msg}".format( bts=bts.isoformat(), ets=ets.isoformat(), xer=xer, rcode=rcode, @@ -92,3 +99,36 @@ def audit(raw_request, bts, xer, rcode, calling_mod, msg="n/a"): clientip=raw_request.remote_addr, calling_mod=calling_mod, msg=msg )) + + +def error(raw_request, xer, severity, ecode, tgt_entity="n/a", tgt_path="n/a", msg="n/a", adv_msg="n/a"): + """ + write an EELF error record per + the error fields implemented: + + 1 Timestamp Auto Injected when this is called + 2 RequestID Implemented (xer) + 4 ServiceName Implemented (from Req) + 6 TargetEntity Implemented (tgt_entity) + 7 TargetServiceName Implemented (tgt_path)/ + 8 ErrorCategory Implemented (severity) + 9. ErrorCode Implemented (ecode) + 10 ErrorDescription Implemented (msg) + 11. detailMessage Implemented (adv_msg) + + Not implemented: + 3 ThreadID - n/a + 5 PartnerName - nothing in the request tells me this + """ + ets = utc() + + _ERROR_LOGGER.error("{ets}|{xer}||{path}||{tge}|{tgp}|{sev}|{ecode}|{msg}|{amsg}".format( + ets=ets, + xer=xer, + path=raw_request.path.split("/")[1], + tge=tgt_entity, + tgp=tgt_path, + sev=severity, + ecode=ecode, + msg=msg, + amsg=adv_msg)) diff --git a/app/app/main.py b/app/app/main.py index 6cedc4d..dd71ccf 100755 --- a/app/app/main.py +++ b/app/app/main.py @@ -19,11 +19,11 @@ # ECOMP is a trademark and service mark of AT&T Intellectual Property. import connexion -from config_binding_service.logging import create_logger +from config_binding_service.logging import create_loggers # Entrypoint When in uwsgi # This create logger call used to be in the main block, but when moving to NGINX+uwsgi, this had to change. See https://hub.docker.com/r/tiangolo/uwsgi-nginx-flask/ -create_logger() +create_loggers() app = connexion.App(__name__, specification_dir='.') app.add_api('swagger.yaml', arguments={'title': 'Config Binding Service'}) diff --git a/app/app/setup.py b/app/app/setup.py index df59069..7b8c7ca 100644 --- a/app/app/setup.py +++ b/app/app/setup.py @@ -20,7 +20,7 @@ from setuptools import setup, find_packages setup( name='config_binding_service', - version='2.2.0', + version='2.2.1', packages=find_packages(exclude=["tests.*", "tests"]), author="Tommy Carpenter", author_email="tommy@research.att.com", -- cgit 1.2.3-korg