From f183e66fac6e23ef2856bccbaeeaafcdc38d1901 Mon Sep 17 00:00:00 2001 From: jasquat Date: Thu, 1 Sep 2022 13:01:23 -0400 Subject: [PATCH] added ability to add the process instance id to the spiff logs w/ burnettk --- poetry.lock | 6 +- pyproject.toml | 2 +- src/spiffworkflow_backend/config/__init__.py | 4 ++ .../load_database_models.py | 1 - .../services/logging_service.py | 67 +++++++++---------- .../services/process_instance_processor.py | 4 ++ 6 files changed, 43 insertions(+), 41 deletions(-) diff --git a/poetry.lock b/poetry.lock index 1667e978..58f7ff0e 100644 --- a/poetry.lock +++ b/poetry.lock @@ -1846,8 +1846,8 @@ pytz = "*" [package.source] type = "git" url = "https://github.com/sartography/SpiffWorkflow" -reference = "main" -resolved_reference = "0fa2048ef2d9dd5fe856f2e476df77966bdab892" +reference = "feature/centralized-logging" +resolved_reference = "ea360a901fe35408885e3c9797af07a2c6ced812" [[package]] name = "sqlalchemy" @@ -2157,7 +2157,7 @@ testing = ["pytest (>=6)", "pytest-checkdocs (>=2.4)", "pytest-flake8", "pytest- [metadata] lock-version = "1.1" python-versions = "^3.9" -content-hash = "e395233463dec69fa7870815ff342096d7de3ea8899c54eac61ba334ff0b1c73" +content-hash = "22c1b45f95769cf86303de8139a7be931a85d87d9e3c3f826e3af201a388df82" [metadata.files] alabaster = [ diff --git a/pyproject.toml b/pyproject.toml index 7b929aba..1e0f76f9 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -27,7 +27,7 @@ flask-marshmallow = "*" flask-migrate = "*" flask-restful = "*" werkzeug = "*" -spiffworkflow = {git = "https://github.com/sartography/SpiffWorkflow", rev = "main"} +spiffworkflow = {git = "https://github.com/sartography/SpiffWorkflow", rev = "feature/centralized-logging"} # spiffworkflow = {develop = true, path = "/home/jason/projects/github/sartography/SpiffWorkflow"} sentry-sdk = "1.9.0" sphinx-autoapi = "^1.8.4" diff --git a/src/spiffworkflow_backend/config/__init__.py b/src/spiffworkflow_backend/config/__init__.py index 3c033555..8fcbebca 100644 --- a/src/spiffworkflow_backend/config/__init__.py +++ b/src/spiffworkflow_backend/config/__init__.py @@ -1,5 +1,6 @@ """__init__.py.""" import os +import threading from flask.app import Flask from werkzeug.utils import ImportStringError @@ -58,3 +59,6 @@ def setup_config(app: Flask) -> None: raise ModuleNotFoundError( f"Cannot find config module: {env_config_module}" ) from exception + + thread_local_data = threading.local() + app.config['THREAD_LOCAL_DATA'] = thread_local_data diff --git a/src/spiffworkflow_backend/load_database_models.py b/src/spiffworkflow_backend/load_database_models.py index 81808090..2cab5bd9 100644 --- a/src/spiffworkflow_backend/load_database_models.py +++ b/src/spiffworkflow_backend/load_database_models.py @@ -24,7 +24,6 @@ from spiffworkflow_backend.models.process_instance import ( from spiffworkflow_backend.models.process_instance_report import ( ProcessInstanceReportModel, ) # noqa: F401 -from spiffworkflow_backend.models.spiff_logging import SpiffLoggingModel # noqa: F401 from spiffworkflow_backend.models.task_event import TaskEventModel # noqa: F401 from spiffworkflow_backend.models.user import UserModel # noqa: F401 from spiffworkflow_backend.models.user_group_assignment import ( diff --git a/src/spiffworkflow_backend/services/logging_service.py b/src/spiffworkflow_backend/services/logging_service.py index 068a3a93..64c84145 100644 --- a/src/spiffworkflow_backend/services/logging_service.py +++ b/src/spiffworkflow_backend/services/logging_service.py @@ -3,6 +3,7 @@ import json import logging import os import sys +import threading from typing import Any from typing import Optional @@ -83,25 +84,28 @@ class JsonFormatter(logging.Formatter): return json.dumps(message_dict, default=str) -def setup_logger_for_sql_statements(app: Flask) -> None: - """Setup_logger_for_sql_statements.""" - db_log_file_name = f"log/db_{app.env}.log" - db_handler_log_level = logging.INFO - db_logger_log_level = logging.DEBUG - db_handler = logging.FileHandler(db_log_file_name) - db_handler.setLevel(db_handler_log_level) - db_logger = logging.getLogger("sqlalchemy") - db_logger.propagate = False - db_logger.addHandler(db_handler) - db_logger.setLevel(db_logger_log_level) +class SpiffFilter(logging.Filter): + def __init__(self, app: Flask): + self.app = app + super().__init__() + + + def filter(self, record): + tld = self.app.config['THREAD_LOCAL_DATA'] + process_instance_id = '' + if hasattr(tld, 'process_instance_id'): + process_instance_id = tld.process_instance_id + record.process_instance_id = process_instance_id + return True def setup_logger(app: Flask) -> None: """Setup_logger.""" log_level = logging.DEBUG - handlers = [] + log_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') - log_formatter = logging._defaultFormatter # type: ignore + log_level = logging.DEBUG + log_formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') # the json formatter is nice for real environments but makes # debugging locally a little more difficult @@ -120,42 +124,33 @@ def setup_logger(app: Flask) -> None: ) log_formatter = json_formatter - if os.environ.get("IS_GUNICORN") == "true": - gunicorn_logger_error = logging.getLogger("gunicorn.error") - log_level = gunicorn_logger_error.level - ghandler = gunicorn_logger_error.handlers[0] - ghandler.setFormatter(log_formatter) - handlers.append(ghandler) - - gunicorn_logger_access = logging.getLogger("gunicorn.access") - log_level = gunicorn_logger_access.level - ghandler = gunicorn_logger_access.handlers[0] - ghandler.setFormatter(log_formatter) - handlers.append(ghandler) - - handler = logging.StreamHandler(sys.stdout) - handler.setLevel(log_level) - - handler.setFormatter(log_formatter) - handlers.append(handler) - - logging.basicConfig(handlers=handlers) - - setup_logger_for_sql_statements(app) + # make all loggers act the same + for name in logging.root.manager.loggerDict: + if 'spiff' not in name: + the_logger = logging.getLogger(name) + the_logger.setLevel(log_level) + for the_handler in the_logger.handlers: + the_handler.setFormatter(log_formatter) + the_handler.setLevel(log_level) spiff_logger = logging.getLogger("spiff.metrics") spiff_logger.setLevel(logging.DEBUG) # spiff_logger_handler = logging.StreamHandler(sys.stdout) spiff_formatter = logging.Formatter( - "%(asctime)s | %(levelname)s | %(message)s | %(action)s | %(task_type)s | %(process)s | %(processName)s" + "%(asctime)s | %(levelname)s | %(message)s | %(action)s | %(task_type)s | %(process)s | %(processName)s | %(process_instance_id)s" ) # spiff_logger_handler.setFormatter(spiff_formatter) # fh = logging.FileHandler('test.log') # spiff_logger_handler.setLevel(logging.DEBUG) # spiff_logger.addHandler(spiff_logger_handler) + + # if you add a handler to spiff, it will be used/inherited by spiff.metrics + # if you add a filter to the spiff logger directly (and not the handler), it will NOT be inherited by spiff.metrics + # so put filters on handlers. db_handler = DBHandler() db_handler.setLevel(logging.DEBUG) db_handler.setFormatter(spiff_formatter) + db_handler.addFilter(SpiffFilter(app)) spiff_logger.addHandler(db_handler) diff --git a/src/spiffworkflow_backend/services/process_instance_processor.py b/src/spiffworkflow_backend/services/process_instance_processor.py index 0d2ccb41..3475a2d0 100644 --- a/src/spiffworkflow_backend/services/process_instance_processor.py +++ b/src/spiffworkflow_backend/services/process_instance_processor.py @@ -1,5 +1,7 @@ """Process_instance_processor.""" import json +import logging +import threading import time from typing import Any from typing import Dict @@ -159,6 +161,8 @@ class ProcessInstanceProcessor: self, process_instance_model: ProcessInstanceModel, validate_only: bool = False ) -> None: """Create a Workflow Processor based on the serialized information available in the process_instance model.""" + current_app.config['THREAD_LOCAL_DATA'].process_instance_id = process_instance_model.id + self.process_instance_model = process_instance_model self.process_model_service = ProcessModelService() spec = None