diff --git a/src/instana/instrumentation/logging.py b/src/instana/instrumentation/logging.py index 5cddea0b4..33877fbbd 100644 --- a/src/instana/instrumentation/logging.py +++ b/src/instana/instrumentation/logging.py @@ -8,7 +8,7 @@ from collections.abc import Mapping from ..log import logger -from ..util.traceutils import get_active_tracer +from ..util.traceutils import get_tracer_tuple, tracing_is_off @wrapt.patch_function_wrapper('logging', 'Logger._log') @@ -17,33 +17,34 @@ def log_with_instana(wrapped, instance, argv, kwargs): # argv[1] = message # argv[2] = args for message try: - active_tracer = get_active_tracer() + tracer, parent_span, _ = get_tracer_tuple() # Only needed if we're tracing and serious log - if active_tracer and argv[0] >= logging.WARN: - - msg = str(argv[1]) - args = argv[2] - if args and len(args) == 1 and isinstance(args[0], Mapping) and args[0]: - args = args[0] - - # get the formatted log message - msg = msg % args - - # get additional information if an exception is being handled - parameters = None - (t, v, tb) = sys.exc_info() - if t is not None and v is not None: - parameters = '{} {}'.format(t , v) - - # create logging span - with active_tracer.start_active_span('log', child_of=active_tracer.active_span) as scope: - scope.span.log_kv({ 'message': msg }) - if parameters is not None: - scope.span.log_kv({ 'parameters': parameters }) - # extra tags for an error - if argv[0] >= logging.ERROR: - scope.span.mark_as_errored() + if tracing_is_off() or argv[0] < logging.WARN: + return wrapped(*argv, **kwargs) + + msg = str(argv[1]) + args = argv[2] + if args and len(args) == 1 and isinstance(args[0], Mapping) and args[0]: + args = args[0] + + # get the formatted log message + msg = msg % args + + # get additional information if an exception is being handled + parameters = None + (t, v, tb) = sys.exc_info() + if t is not None and v is not None: + parameters = '{} {}'.format(t , v) + + # create logging span + with tracer.start_active_span('log', child_of=parent_span) as scope: + scope.span.log_kv({ 'message': msg }) + if parameters is not None: + scope.span.log_kv({ 'parameters': parameters }) + # extra tags for an error + if argv[0] >= logging.ERROR: + scope.span.mark_as_errored() except Exception: logger.debug('log_with_instana:', exc_info=True) diff --git a/tests/clients/test_logging.py b/tests/clients/test_logging.py index c60e8d92c..d107c0fdf 100644 --- a/tests/clients/test_logging.py +++ b/tests/clients/test_logging.py @@ -3,7 +3,7 @@ import logging import unittest -from instana.singletons import tracer +from instana.singletons import agent, tracer class TestLogging(unittest.TestCase): @@ -14,8 +14,8 @@ def setUp(self): self.logger = logging.getLogger('unit test') def tearDown(self): - """ Do nothing for now """ - return None + """ Ensure that allow_exit_as_root has the default value """ + agent.options.allow_exit_as_root = False def test_no_span(self): with tracer.start_active_span('test'): @@ -58,3 +58,19 @@ def test_parameters(self): self.assertIsNotNone(spans[0].data["log"].get('parameters')) + def test_no_root_exit_span(self): + agent.options.allow_exit_as_root = True + self.logger.info('info message') + + spans = self.recorder.queued_spans() + self.assertEqual(0, len(spans)) + + def test_root_exit_span(self): + agent.options.allow_exit_as_root = True + self.logger.warning('foo %s', 'bar') + + spans = self.recorder.queued_spans() + self.assertEqual(1, len(spans)) + self.assertEqual(2, spans[0].k) + + self.assertEqual('foo bar', spans[0].data["log"].get('message'))