Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
29 changes: 27 additions & 2 deletions README.rst
Original file line number Diff line number Diff line change
Expand Up @@ -151,10 +151,35 @@ General
logger = logging.getLogger("cli.logger")
logger.info('hi')

**Notes**: - All loggers set up and created before the initialization of the Cloud Foundry logging library will
be left untouched. - When using Flask and Sanic with the logging library a before and
**Notes**: All loggers set up and created before the initialization of the Cloud Foundry logging library will
be left untouched. When using Flask and Sanic with the logging library before and
after request middleware is attached, and it will capture response times for each request.

Setting and getting correlation ID
""""""""""""""""""""""""""""""""""

When using cf_logging in a web application you don't need to set the correlation ID, because the logging library will fetch it from the HTTP headers and set it.
For non web applications you could set the correlation ID manually, so that the log entries can be filtered later on based on the correlation_id.

Setting and getting the correlation_id can be done via:

.. code:: python

cf_logging.FRAMEWORK.context.get_correlation_id()
cf_logging.FRAMEWORK.context.set_correlation_id(value)

Whenever a correlation id is set after initializing cf_logging without a specific framework (ex: cf_logging.init()) - this same correlation ID would be used for each log record.

If you need a *thread safe* correlation ID, you can reuse the ``cf_logging.job_loffing.framework.JobFramework`` and provide your own context implementation that is *thread safe*.

If you need to get the correlation_id in a web application, take into account the framework you are using.
In async frameworks like Sanic and Falcon the context is stored into the request object and you need to provide the request to the call:

.. code:: python

cf_logging.FRAMEWORK.context.get_correlation_id(request)


Logging sensitive data
^^^^^^^^^^^^^^^^^^^^^^

Expand Down
8 changes: 4 additions & 4 deletions sap/cf_logging/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,11 @@

from sap.cf_logging import defaults
from sap.cf_logging.core.constants import REQUEST_KEY, RESPONSE_KEY
from sap.cf_logging.record.request_log_record import RequestWebRecord
from sap.cf_logging.record.simple_log_record import SimpleLogRecord
from sap.cf_logging.core.framework import Framework
from sap.cf_logging.formatters.json_formatter import JsonFormatter
from sap.cf_logging.job_logging.framework import JobFramework
from sap.cf_logging.record.request_log_record import RequestWebRecord
from sap.cf_logging.record.simple_log_record import SimpleLogRecord

__version__ = '3.2.0'

Expand All @@ -34,7 +35,6 @@ def makeRecord(self, name, level, fn, lno, msg, msgargs, exc_info,
return cls(extra, FRAMEWORK, name, level, fn, lno, msg, msgargs, exc_info,
func, *args, **kwargs)


def init(cfl_framework=None, level=defaults.DEFAULT_LOGGING_LEVEL):
""" Initialize function. It sets up the logging library to output JSON
formatted messages.
Expand All @@ -50,7 +50,7 @@ def init(cfl_framework=None, level=defaults.DEFAULT_LOGGING_LEVEL):
raise TypeError('expecting framework of type {}'.format(Framework.__name__))

_SETUP_DONE = True
FRAMEWORK = cfl_framework
FRAMEWORK = cfl_framework or JobFramework()

logging.setLoggerClass(CfLogger)

Expand Down
13 changes: 13 additions & 0 deletions sap/cf_logging/core/context.py
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
""" Module Context """

_CORRELATION_ID_KEY = 'correlation_id'

class Context(object):
""" Class for getting and setting context variables """
Expand All @@ -11,3 +12,15 @@ def set(self, key, value, request):
def get(self, key, request):
""" Get session variable """
raise NotImplementedError

def get_correlation_id(self, request=None):
""" Gets the current correlation_id. Ensure that you are calling this method in the
appropriate location of your code having in mind which framework you are using. """

return self.get(_CORRELATION_ID_KEY, request)

def set_correlation_id(self, value, request=None):
""" Sets the current correlation_id. Ensure that you are calling this method in the
appropriate location of your code having in mind which framework you are using. """

return self.set(_CORRELATION_ID_KEY, value, request)
2 changes: 1 addition & 1 deletion sap/cf_logging/falcon_logging/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ def process_request(self, request, response): # pylint: disable=unused-argument
"""
framework = cf_logging.FRAMEWORK
cid = framework.request_reader.get_correlation_id(request)
framework.context.set('correlation_id', cid, request)
framework.context.set_correlation_id(cid, request)
framework.context.set('request_started_at', datetime.utcnow(), request)
request.log = lambda msg, lvl=logging.INFO, extra={}: logging.getLogger(
self._logger_name).log(lvl, msg, extra=extra.update({REQUEST_KEY: request}) or extra)
Expand Down
2 changes: 1 addition & 1 deletion sap/cf_logging/flask_logging/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ def before_request(wrapped):
def _wrapper():
framework = cf_logging.FRAMEWORK
cid = framework.request_reader.get_correlation_id(request)
framework.context.set('correlation_id', cid, request)
framework.context.set_correlation_id(cid, request)
framework.context.set('request_started_at', datetime.utcnow(), request)
return wrapped()
return _wrapper
Expand Down
Empty file.
15 changes: 15 additions & 0 deletions sap/cf_logging/job_logging/context.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,15 @@
""" Job logging context - used by the logging package to keep log data """
from sap.cf_logging.core.context import Context


class JobContext(Context):
""" Stores logging context in dict """

def __init__(self):
self._mem_store = {}

def set(self, key, value, request):
self._mem_store[key] = value

def get(self, key, request):
return self._mem_store[key] if key in self._mem_store else None
20 changes: 20 additions & 0 deletions sap/cf_logging/job_logging/framework.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
""" Framework to be used by worker/job running applications """
from sap.cf_logging.core.framework import Framework
from sap.cf_logging.job_logging.context import JobContext
from sap.cf_logging.core.request_reader import RequestReader
from sap.cf_logging.core.response_reader import ResponseReader

JOB_FRAMEWORK_NAME = 'job.framework'


class JobFramework(Framework):
""" Simple framework using default request and response readers.
Uses JobContext to keeping properties in memory """

def __init__(self, context=None):
super(JobFramework, self).__init__(
JOB_FRAMEWORK_NAME,
context or JobContext(),
RequestReader(),
ResponseReader()
)
7 changes: 2 additions & 5 deletions sap/cf_logging/record/simple_log_record.py
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
""" Module SimpleLogRecord """
import logging
from datetime import datetime
from sap.cf_logging import defaults
from sap.cf_logging.core.constants import REQUEST_KEY, RESPONSE_KEY
from sap.cf_logging.record import application_info
from sap.cf_logging.record import util
Expand All @@ -26,11 +27,7 @@ def __init__(self, extra, framework, *args, **kwargs):

request = extra[REQUEST_KEY] if extra and REQUEST_KEY in extra else None

correlation_id = None
if framework:
correlation_id = framework.context.get('correlation_id', request)

self.correlation_id = correlation_id or '-'
self.correlation_id = framework.context.get_correlation_id(request) or defaults.UNKNOWN

self.extra = dict((key, value) for key, value in extra.items()
if key not in _SKIP_ATTRIBUTES) if extra else {}
Expand Down
2 changes: 1 addition & 1 deletion sap/cf_logging/sanic_logging/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@ def before_request(wrapped):
@wraps(wrapped)
def _wrapper(request):
correlation_id = cf_logging.FRAMEWORK.request_reader.get_correlation_id(request)
cf_logging.FRAMEWORK.context.set('correlation_id', correlation_id, request)
cf_logging.FRAMEWORK.context.set_correlation_id(correlation_id, request)
cf_logging.FRAMEWORK.context.set('request_started_at', datetime.utcnow(), request)
return wrapped(request)

Expand Down
2 changes: 1 addition & 1 deletion tests/log_schemas.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@
'component_type': u.string(u.TEXT)
}

CLI_LOG_SCHEMA = u.extend(CF_ATTRIBUTES_SCHEMA, {
JOB_LOG_SCHEMA = u.extend(CF_ATTRIBUTES_SCHEMA, {
'type': {
'in': ['log'],
'in_error': 'Invalid "type" property'
Expand Down
22 changes: 0 additions & 22 deletions tests/test_cli_logging.py

This file was deleted.

6 changes: 3 additions & 3 deletions tests/test_falcon_logging.py
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@
from falcon_auth import FalconAuthMiddleware, BasicAuthBackend
from sap import cf_logging
from sap.cf_logging import falcon_logging
from tests.log_schemas import WEB_LOG_SCHEMA, CLI_LOG_SCHEMA
from tests.log_schemas import WEB_LOG_SCHEMA, JOB_LOG_SCHEMA
from tests.common_test_params import (
v_str, auth_basic, get_web_record_header_fixtures
)
Expand All @@ -15,7 +15,7 @@

# pylint: disable=protected-access, missing-docstring,too-few-public-methods

@pytest.yield_fixture(autouse=True)
@pytest.fixture(autouse=True)
def before_each():
""" enable all fields to be logged """
enable_sensitive_fields_logging()
Expand Down Expand Up @@ -110,7 +110,7 @@ def __init__(self, extra, expected):
def on_get(self, req, resp):
_, stream = config_root_logger('user.logging')
req.log('in route headers', extra=self.extra)
assert check_log_record(stream, CLI_LOG_SCHEMA, self.expected) == {}
assert check_log_record(stream, JOB_LOG_SCHEMA, self.expected) == {}

resp.set_header('Content-Type', 'text/plain')
resp.status = falcon.HTTP_200
Expand Down
6 changes: 3 additions & 3 deletions tests/test_flask_logging.py
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@
from flask import Response
from sap import cf_logging
from sap.cf_logging import flask_logging
from tests.log_schemas import WEB_LOG_SCHEMA, CLI_LOG_SCHEMA
from tests.log_schemas import WEB_LOG_SCHEMA, JOB_LOG_SCHEMA
from tests.common_test_params import v_str, v_num, auth_basic, get_web_record_header_fixtures
from tests.util import check_log_record, config_root_logger, enable_sensitive_fields_logging

Expand All @@ -24,7 +24,7 @@ def test_flask_requires_valid_app():
FIXTURE.append(({}, {'response_size_b': v_num(val=2)}))


@pytest.yield_fixture(autouse=True)
@pytest.fixture(autouse=True)
def before_each():
""" enable all fields to be logged """
enable_sensitive_fields_logging()
Expand Down Expand Up @@ -74,7 +74,7 @@ def _user_logging(headers, extra, expected):
def _logging_correlation_id_route():
logger, stream = config_root_logger('user.logging')
logger.info('in route headers', extra=extra)
assert check_log_record(stream, CLI_LOG_SCHEMA, expected) == {}
assert check_log_record(stream, JOB_LOG_SCHEMA, expected) == {}
return Response('ok')

_set_up_flask_logging(app)
Expand Down
44 changes: 44 additions & 0 deletions tests/test_job_logging.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,44 @@
""" Module to test the cf_logging library """
import logging
from json import JSONDecoder
import pytest
from json_validator.validator import JsonValidator
from sap import cf_logging
from tests.log_schemas import JOB_LOG_SCHEMA
from tests.util import config_root_logger

# pylint: disable=protected-access


@pytest.fixture(autouse=True)
def before_each():
""" reset logging framework """
cf_logging._SETUP_DONE = False


def test_log_in_expected_format():
""" Test the cf_logger as a standalone """
cf_logging.init(level=logging.DEBUG)
logger, stream = config_root_logger('cli.test')
logger.info('hi')
log_json = JSONDecoder().decode(stream.getvalue())
_, error = JsonValidator(JOB_LOG_SCHEMA).validate(log_json)

assert error == {}


def test_set_correlation_id():
""" Test setting correlation_id """
correlation_id = '1234'
cf_logging.init(level=logging.DEBUG)
cf_logging.FRAMEWORK.context.set_correlation_id(correlation_id)

logger, stream = config_root_logger('cli.test')
logger.info('hi')

log_json = JSONDecoder().decode(stream.getvalue())
_, error = JsonValidator(JOB_LOG_SCHEMA).validate(log_json)

assert error == {}
assert log_json['correlation_id'] == correlation_id
assert cf_logging.FRAMEWORK.context.get_correlation_id() == correlation_id
6 changes: 3 additions & 3 deletions tests/test_sanic_logging.py
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@
from sap import cf_logging

from sap.cf_logging import sanic_logging
from tests.log_schemas import WEB_LOG_SCHEMA, CLI_LOG_SCHEMA
from tests.log_schemas import WEB_LOG_SCHEMA, JOB_LOG_SCHEMA
from tests.common_test_params import v_str, v_num, get_web_record_header_fixtures
from tests.schema_util import extend
from tests.util import check_log_record, config_logger, enable_sensitive_fields_logging
Expand All @@ -22,7 +22,7 @@ def test_sanic_requires_valid_app():
FIXTURE = get_web_record_header_fixtures()
FIXTURE.append(({'no-content-length': '1'}, {'response_size_b': v_num(-1)}))

@pytest.yield_fixture(autouse=True)
@pytest.fixture(autouse=True)
def before_each():
""" enable all fields to be logged """
enable_sensitive_fields_logging()
Expand Down Expand Up @@ -85,7 +85,7 @@ async def _logging_correlation_id_route(request):
logger, stream = config_logger('user.logging')
new_extra = extend(extra, {'request': request}) if provide_request else extra
logger.info('in route headers', extra=new_extra)
assert check_log_record(stream, CLI_LOG_SCHEMA, expected) == {}
assert check_log_record(stream, JOB_LOG_SCHEMA, expected) == {}
return text('ok')

_set_up_sanic_logging(app)
Expand Down
5 changes: 4 additions & 1 deletion tests/unit/formatters/test_json_formatter.py
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
""" Tests json log formatting """
import json
import logging
from sap.cf_logging.job_logging.framework import JobFramework
from sap.cf_logging.record.simple_log_record import SimpleLogRecord
from sap.cf_logging.formatters.json_formatter import JsonFormatter

Expand All @@ -19,8 +20,10 @@ def test_non_json_serializable():
""" test json formatter handles non JSON serializable object """
class _MyClass(object): # pylint: disable=too-few-public-methods
pass

extra = {'cls': _MyClass()}
log_record = SimpleLogRecord(extra, None, 'name', LEVEL, FILE, LINE, 'msg', [], EXC_INFO)
framework = JobFramework()
log_record = SimpleLogRecord(extra, framework, 'name', LEVEL, FILE, LINE, 'msg', [], EXC_INFO)
record_object = json.loads(FORMATTER.format(log_record))
assert record_object.get('cls') is not None
assert 'MyClass' in record_object.get('cls')
2 changes: 1 addition & 1 deletion tests/unit/record/test_request_log_record.py
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@

FRAMEWORK = None

@pytest.yield_fixture(autouse=True)
@pytest.fixture(autouse=True)
def before_each_setup_mocks(mocker):
context = Context()
mocker.patch.object(context, 'get', return_value=None)
Expand Down