From: Tommy Carpenter Date: Thu, 14 Nov 2019 20:54:49 +0000 (-0500) Subject: Use the RIC logging lib X-Git-Tag: 2.0.0~1^2^2~3 X-Git-Url: https://gerrit.o-ran-sc.org/r/gitweb?a=commitdiff_plain;h=aa4ffa78f3e6a9430cc9ae9933165e58105c9d65;p=ric-plt%2Fa1.git Use the RIC logging lib Signed-off-by: Tommy Carpenter Change-Id: Ia28c7d929907a8782327ad45c797790ba89e7bbf --- diff --git a/.gitignore b/.gitignore index 5e125ef..fb1708b 100644 --- a/.gitignore +++ b/.gitignore @@ -1,4 +1,6 @@ +# misc cruft *.log +integration_tests/log.txt NOTES.txt rmr/* docs_and_diagrams/ @@ -7,6 +9,7 @@ docs_and_diagrams/ .tox docs/_build/ +# standard python ignore template .pytest_cache/ xunit-results.xml .DS_Store diff --git a/a1/__init__.py b/a1/__init__.py index 6212289..818ed1a 100644 --- a/a1/__init__.py +++ b/a1/__init__.py @@ -1,3 +1,6 @@ +""" +contains the app; broken out here for ease of unit testing +""" # ================================================================================== # Copyright (c) 2019 Nokia # Copyright (c) 2018-2019 AT&T Intellectual Property. @@ -14,23 +17,8 @@ # See the License for the specific language governing permissions and # limitations under the License. # ================================================================================== -import logging import connexion -def get_module_logger(mod_name): - """ - To use this, do logger = get_module_logger(__name__) - """ - logger = logging.getLogger(mod_name) - handler = logging.StreamHandler() - formatter = logging.Formatter( - '%(asctime)s [%(name)-12s] %(levelname)-8s %(message)s') - handler.setFormatter(formatter) - logger.addHandler(handler) - logger.setLevel(logging.DEBUG) - return logger - - -app = connexion.App(__name__, specification_dir='.') -app.add_api('openapi.yaml', arguments={'title': 'My Title'}) +app = connexion.App(__name__, specification_dir=".") +app.add_api("openapi.yaml", arguments={"title": "My Title"}) diff --git a/a1/a1rmr.py b/a1/a1rmr.py index 38f8373..98e3f8e 100644 --- a/a1/a1rmr.py +++ b/a1/a1rmr.py @@ -23,11 +23,11 @@ import time import json from threading import Thread from rmr import rmr, helpers -from a1 import get_module_logger +from mdclogpy import Logger from a1 import data from a1.exceptions import PolicyTypeNotFound, PolicyInstanceNotFound -logger = get_module_logger(__name__) +mdc_logger = Logger(name=__name__) RETRY_TIMES = int(os.environ.get("A1_RMR_RETRY_TIMES", 4)) @@ -53,7 +53,7 @@ class _RmrLoop: if init_func_override: self.mrc = init_func_override() else: - logger.debug("Waiting for rmr to initialize..") + mdc_logger.debug("Waiting for rmr to initialize..") # rmr.RMRFL_MTCALL puts RMR into a multithreaded mode, where a receiving thread populates an # internal ring of messages, and receive calls read from that # currently the size is 2048 messages, so this is fine for the foreseeable future @@ -76,7 +76,7 @@ class _RmrLoop: - clean up the database (eg delete the instance) under certain conditions based on those statuses (NOT DONE YET) """ # loop forever - logger.debug("Work loop starting") + mdc_logger.debug("Work loop starting") while self.keep_going: # send out all messages waiting for us @@ -90,10 +90,12 @@ class _RmrLoop: pre_send_summary = rmr.message_summary(sbuf) sbuf = rmr.rmr_send_msg(self.mrc, sbuf) # send post_send_summary = rmr.message_summary(sbuf) - logger.debug("Pre-send summary: %s, Post-send summary: %s", pre_send_summary, post_send_summary) + mdc_logger.debug( + "Pre-send summary: {0}, Post-send summary: {1}".format(pre_send_summary, post_send_summary) + ) rmr.rmr_free_msg(sbuf) # free if post_send_summary["message state"] == 0 and post_send_summary["message status"] == "RMR_OK": - logger.debug("Message sent successfully!") + mdc_logger.debug("Message sent successfully!") break # read our mailbox and update statuses @@ -103,9 +105,9 @@ class _RmrLoop: pti = pay["policy_type_id"] pii = pay["policy_instance_id"] data.set_policy_instance_status(pti, pii, pay["handler_id"], pay["status"]) - except (PolicyTypeNotFound, PolicyInstanceNotFound, KeyError, json.decoder.JSONDecodeError): + except (PolicyTypeNotFound, PolicyInstanceNotFound, KeyError, TypeError, json.decoder.JSONDecodeError): # TODO: in the future we may also have to catch SDL errors - logger.debug(("Dropping malformed or non applicable message", msg)) + mdc_logger.debug("Dropping malformed or non applicable message: {0}".format(msg)) # TODO: what's a reasonable sleep time? we don't want to hammer redis too much, and a1 isn't a real time component self.last_ran = time.time() diff --git a/a1/controller.py b/a1/controller.py index 6f21830..5fca23e 100644 --- a/a1/controller.py +++ b/a1/controller.py @@ -22,11 +22,11 @@ from flask import Response from jsonschema import validate from jsonschema.exceptions import ValidationError import connexion -from a1 import get_module_logger +from mdclogpy import Logger from a1 import a1rmr, exceptions, data -logger = get_module_logger(__name__) +mdc_logger = Logger(name=__name__) def _try_func_return(func): @@ -41,7 +41,7 @@ def _try_func_return(func): return "", 404 except BaseException as exc: # catch all, should never happen... - logger.exception(exc) + mdc_logger.exception(exc) return Response(status=500) diff --git a/a1/data.py b/a1/data.py index d25f519..a98be5c 100644 --- a/a1/data.py +++ b/a1/data.py @@ -1,3 +1,11 @@ +""" +Represents A1s database and database access functions. +In the future, this may change to use a different backend, possibly dramatically. +Hopefully, the access functions are a good api so nothing else has to change when this happens + +For now, the database is in memory. +We use dict data structures (KV) with the expectation of having to move this into Redis +""" # ================================================================================== # Copyright (c) 2019 Nokia # Copyright (c) 2018-2019 AT&T Intellectual Property. @@ -14,23 +22,14 @@ # See the License for the specific language governing permissions and # limitations under the License. # ================================================================================== - -""" -Represents A1s database and database access functions. -In the future, this may change to use a different backend, possibly dramatically. -Hopefully, the access functions are a good api so nothing else has to change when this happens - -For now, the database is in memory. -We use dict data structures (KV) with the expectation of having to move this into Redis -""" import os import time from threading import Thread import msgpack +from mdclogpy import Logger from a1.exceptions import PolicyTypeNotFound, PolicyInstanceNotFound, PolicyTypeAlreadyExists, CantDeleteNonEmptyType -from a1 import get_module_logger -logger = get_module_logger(__name__) +mdc_logger = Logger(name=__name__) INSTANCE_DELETE_NO_RESP_TTL = int(os.environ.get("INSTANCE_DELETE_NO_RESP_TTL", 5)) @@ -182,8 +181,7 @@ def _delete_after(policy_type_id, policy_instance_id, ttl): _clear_handlers(policy_type_id, policy_instance_id) # delete all the handlers SDL.delete(_generate_instance_key(policy_type_id, policy_instance_id)) # delete instance SDL.delete(_generate_instance_metadata_key(policy_type_id, policy_instance_id)) # delete instance metadata - logger.debug("type %s instance %s deleted", policy_type_id, policy_instance_id) - raise PolicyInstanceNotFound() + mdc_logger.debug("type {0} instance {1} deleted".format(policy_type_id, policy_instance_id)) # Types diff --git a/a1/run.py b/a1/run.py index c15b644..feaada3 100644 --- a/a1/run.py +++ b/a1/run.py @@ -18,20 +18,21 @@ A1 entrypoint # limitations under the License. # ================================================================================== from gevent.pywsgi import WSGIServer -from a1 import get_module_logger, app +from mdclogpy import Logger +from a1 import app from a1 import a1rmr -logger = get_module_logger(__name__) +mdc_logger = Logger(name=__name__) def main(): """Entrypoint""" # start rmr thread - logger.debug("Initializing rmr thread. A1s webserver will not start until rmr initialization is complete.") + mdc_logger.debug("Initializing rmr thread. A1s webserver will not start until rmr initialization is complete.") a1rmr.start_rmr_thread() # start webserver - logger.debug("Starting gevent server") + mdc_logger.debug("Starting gevent server") http_server = WSGIServer(("", 10000), app) http_server.serve_forever() diff --git a/docs/release-notes.rst b/docs/release-notes.rst index daaa241..42c2756 100644 --- a/docs/release-notes.rst +++ b/docs/release-notes.rst @@ -35,6 +35,7 @@ and this project adheres to `Semantic Versioning `__. * Changes the API for ../status to return a richer structure * Clean up unused items in the integration tests helm chart * Removed "RMR_RCV_RETRY_INTERVAL" leftovers since this isn't used anymore + * Uses the standard RIC logging library [1.0.4] ------- diff --git a/integration_tests/getlogs.sh b/integration_tests/getlogs.sh index b952047..668ab2b 100755 --- a/integration_tests/getlogs.sh +++ b/integration_tests/getlogs.sh @@ -1,5 +1,4 @@ #!/bin/sh -kubectl get pods --namespace=default | awk '{ print $1 }' | egrep '^a1-a1mediator-' | xargs kubectl logs -kubectl get pods --namespace=default | awk '{ print $1 }' | egrep '^testreceiver-' | xargs -I X kubectl logs X testreceiver -kubectl get pods --namespace=default | awk '{ print $1 }' | egrep '^testreceiver-' | xargs -I X kubectl logs X delayreceiver - +kubectl get pods --namespace=default | awk '{ print $1 }' | egrep '^a1-a1mediator-' | xargs kubectl logs > log.txt 2>&1 +kubectl get pods --namespace=default | awk '{ print $1 }' | egrep '^testreceiver-' | xargs -I X kubectl logs X testreceiver >> log.txt 2>&1 +kubectl get pods --namespace=default | awk '{ print $1 }' | egrep '^testreceiver-' | xargs -I X kubectl logs X delayreceiver >> log.txt 2>&1 diff --git a/install_deps.sh b/integration_tests/install_deps.sh similarity index 100% rename from install_deps.sh rename to integration_tests/install_deps.sh diff --git a/setup.py b/setup.py index 2263cc4..d20a50f 100644 --- a/setup.py +++ b/setup.py @@ -25,6 +25,6 @@ setup( url="https://gerrit.o-ran-sc.org/r/admin/repos/ric-plt/a1", entry_points={"console_scripts": ["run.py=a1.run:main"]}, # we require jsonschema, should be in that list, but connexion already requires a specific version of it - install_requires=["requests", "Flask", "connexion[swagger-ui]", "gevent", "msgpack", "rmr>=1.0.0"], + install_requires=["requests", "Flask", "connexion[swagger-ui]", "gevent", "msgpack", "rmr>=1.0.0", "mdclogpy"], package_data={"a1": ["openapi.yaml"]}, ) diff --git a/tests/test_controller.py b/tests/test_controller.py index 26e6e63..0d31274 100644 --- a/tests/test_controller.py +++ b/tests/test_controller.py @@ -57,8 +57,10 @@ def _fake_dequeue_deleted(): new_msgs.append(fake_msg) # insert a bad one with a malformed body to make sure we keep going - fake_msg = {"payload": "asdf"} - new_msgs.append(fake_msg) + new_msgs.append({"payload": "asdf"}) + + # not even a json + new_msgs.append("asdf") pay = b'{"policy_type_id": 20000, "policy_instance_id": "admission_control_policy", "handler_id": "test_receiver", "status": "DELETED"}' fake_msg = {"payload": pay} diff --git a/tox-integration.ini b/tox-integration.ini index 4c25f71..81f3bb7 100644 --- a/tox-integration.ini +++ b/tox-integration.ini @@ -50,8 +50,8 @@ commands= # run apache bench ab -n 100 -c 10 -v 4 http://localhost:10000/a1-p/healthcheck commands_post= -# echo "log collection" -# integration_tests/getlogs.sh + echo "log collection" + integration_tests/getlogs.sh echo "teardown" helm delete testreceiver helm del --purge testreceiver