Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improved logging instrumentor #2718

Open
wants to merge 12 commits into
base: main
Choose a base branch
from
5 changes: 4 additions & 1 deletion CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
([#2624](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2624))
- `opentelemetry-instrumentation-django` Implement new semantic convention opt-in with stable http semantic conventions
([#2714](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2714))
- `opentelemetry-instrumentation-logging` Added the ability to set custom log field names
([#2718](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2718))

### Breaking changes

Expand Down Expand Up @@ -84,7 +86,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
([#2610](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2610))
- `opentelemetry-instrumentation-asgi` Bugfix: Middleware did not set status code attribute on duration metrics for non-recording spans.
([#2627](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2627))

- `opentelemetry-instrumentation-logging` Removed unnecessary calls in logging factory
([#2718](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/2718))

## Version 1.25.0/0.46b0 (2024-05-31)

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -53,7 +53,7 @@ async def async_gen():
yield it

async_gen_instance = async_gen()
agen = anext(async_gen_instance)
agen = anext(async_gen_instance) # noqa: F821
await asyncio.create_task(agen)

asyncio.run(main())
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,9 @@
# pylint: disable=empty-docstring,no-value-for-parameter,no-member,no-name-in-module

import logging # pylint: disable=import-self
from contextlib import suppress
from os import environ
from typing import Collection
from typing import Callable, Collection, Optional

from opentelemetry.instrumentation.instrumentor import BaseInstrumentor
from opentelemetry.instrumentation.logging.constants import (
Expand All @@ -29,9 +30,12 @@
OTEL_PYTHON_LOG_LEVEL,
)
from opentelemetry.instrumentation.logging.package import _instruments
from opentelemetry.sdk.resources import Resource
from opentelemetry.trace import (
INVALID_SPAN,
INVALID_SPAN_CONTEXT,
Span,
TracerProvider,
get_current_span,
get_tracer_provider,
)
Expand All @@ -49,7 +53,8 @@
class LoggingInstrumentor(BaseInstrumentor): # pylint: disable=empty-docstring
__doc__ = f"""An instrumentor for stdlib logging module.

This instrumentor injects tracing context into logging records and optionally sets the global logging format to the following:
This instrumentor injects tracing context into logging records and optionally
sets the global logging format to the following:

.. code-block::

Expand All @@ -61,9 +66,10 @@ def log_hook(span: Span, record: LogRecord):

Args:
tracer_provider: Tracer provider instance that can be used to fetch a tracer.
set_logging_format: When set to True, it calls logging.basicConfig() and sets a logging format.
logging_format: Accepts a string and sets it as the logging format when set_logging_format
is set to True.
set_logging_format: When set to True, it calls logging.basicConfig() and sets
a logging format.
logging_format: Accepts a string and sets it as the logging format when
set_logging_format is set to True.
log_level: Accepts one of the following values and sets the logging level to it.
logging.INFO
logging.DEBUG
Expand All @@ -75,78 +81,124 @@ def log_hook(span: Span, record: LogRecord):
See `BaseInstrumentor`
"""

_old_factory = None
_log_hook = None
_old_factory: Callable[..., logging.LogRecord] = None

def instrumentation_dependencies(self) -> Collection[str]:
"""Return python packages that the will be instrumented."""
return _instruments

def _instrument(self, **kwargs):
provider = kwargs.get("tracer_provider", None) or get_tracer_provider()
old_factory = logging.getLogRecordFactory()
LoggingInstrumentor._old_factory = old_factory
LoggingInstrumentor._log_hook = kwargs.get("log_hook", None)
# pylint: disable=R0914
def _instrument(
self,
tracer_provider: Optional[TracerProvider] = None,
log_hook: Optional[Callable[[Span, logging.LogRecord], None]] = None,
set_logging_format: Optional[bool] = None,
logging_format: Optional[str] = None,
log_level: Optional[str] = None,
trace_id_field: str = "otelTraceID",
span_id_field: str = "otelSpanID",
trace_sampled_field: str = "otelTraceSampled",
service_name_field: str = "otelServiceName",
**_kwargs,
) -> None:
"""Replace original log factory."""
if tracer_provider is None:
tracer_provider = get_tracer_provider()

service_name = self._get_service_name(tracer_provider)
old_factory = self._get_old_factory()

def record_factory(*args, **kwargs) -> logging.LogRecord:
"""Create log record and fill tracing info to the fields."""
record = old_factory(*args, **kwargs)

service_name = None
setattr(record, service_name_field, service_name)
setattr(record, trace_id_field, "0")
setattr(record, trace_sampled_field, False)
setattr(record, span_id_field, "0")

def record_factory(*args, **kwargs):
record = old_factory(*args, **kwargs)
span = get_current_span()
if span == INVALID_SPAN:
return record

record.otelSpanID = "0"
record.otelTraceID = "0"
record.otelTraceSampled = False
ctx = span.get_span_context()
if ctx == INVALID_SPAN_CONTEXT:
return record

nonlocal service_name
if service_name is None:
resource = getattr(provider, "resource", None)
if resource:
service_name = (
resource.attributes.get("service.name") or ""
)
else:
service_name = ""
setattr(record, trace_id_field, format(ctx.trace_id, "032x"))
setattr(record, trace_sampled_field, ctx.trace_flags.sampled)
setattr(record, span_id_field, format(ctx.span_id, "016x"))

record.otelServiceName = service_name
return record

def record_factory_with_hook(*args, **kwargs) -> logging.LogRecord:
"""Create record and call log hook."""
record = record_factory(*args, **kwargs)
span = get_current_span()
if span != INVALID_SPAN:
ctx = span.get_span_context()
if ctx != INVALID_SPAN_CONTEXT:
record.otelSpanID = format(ctx.span_id, "016x")
record.otelTraceID = format(ctx.trace_id, "032x")
record.otelTraceSampled = ctx.trace_flags.sampled
if callable(LoggingInstrumentor._log_hook):
try:
LoggingInstrumentor._log_hook( # pylint: disable=E1102
span, record
)
except Exception: # pylint: disable=W0703
pass

with suppress(Exception):
log_hook(span, record)
return record

logging.setLogRecordFactory(record_factory)
_factory = record_factory_with_hook if log_hook else record_factory
logging.setLogRecordFactory(_factory)

set_logging_format = kwargs.get(
"set_logging_format",
environ.get(OTEL_PYTHON_LOG_CORRELATION, "false").lower()
== "true",
)
if self._logging_format_is_enabled(set_logging_format):
self._set_logging_format(logging_format, log_level)

if set_logging_format:
log_format = kwargs.get(
"logging_format", environ.get(OTEL_PYTHON_LOG_FORMAT, None)
)
log_format = log_format or DEFAULT_LOGGING_FORMAT
def _uninstrument(self, **kwargs) -> None:
"""Turn back old log record factory."""
self._set_old_factory()

log_level = kwargs.get(
"log_level", LEVELS.get(environ.get(OTEL_PYTHON_LOG_LEVEL))
)
log_level = log_level or logging.INFO
@staticmethod
def _get_service_name(provider: TracerProvider) -> str:
"""Get service name from provider."""
resource: Optional[Resource] = getattr(provider, "resource", None)
if resource is None:
return ""

logging.basicConfig(format=log_format, level=log_level)
return resource.attributes.get("service.name", "")

def _uninstrument(self, **kwargs):
if LoggingInstrumentor._old_factory:
logging.setLogRecordFactory(LoggingInstrumentor._old_factory)
LoggingInstrumentor._old_factory = None
def _get_old_factory(self) -> Callable[..., logging.LogRecord]:
"""Get and store original log factory."""
old_factory = logging.getLogRecordFactory()
self.__class__._old_factory = old_factory
return old_factory

def _set_old_factory(self) -> None:
"""Set original log factory."""
old_factory = self.__class__._old_factory
if old_factory is None:
return

logging.setLogRecordFactory(old_factory)
self.__class__._old_factory = None

@staticmethod
def _logging_format_is_enabled(
set_logging_format: Optional[bool] = None,
) -> bool:
"""Check logging format is enabled."""
if set_logging_format is None:
env_value = environ.get(
OTEL_PYTHON_LOG_CORRELATION, "false"
).lower()
return env_value == "true"

return set_logging_format

@staticmethod
def _set_logging_format(
logging_format: Optional[str] = None,
log_level: Optional[str] = None,
) -> None:
"""Set logging format."""
if logging_format is None:
logging_format = environ.get(OTEL_PYTHON_LOG_FORMAT, None)
log_format = logging_format or DEFAULT_LOGGING_FORMAT

if log_level is None:
env_value = environ.get(OTEL_PYTHON_LOG_LEVEL, "")
log_level = LEVELS.get(env_value.lower())
log_level = log_level or logging.INFO

logging.basicConfig(format=log_format, level=log_level)
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,17 @@
- ``otelServiceName``
- ``otelTraceSampled``

You can also set your own keys for the fields by passing the parameters:

.. code-block::

LoggingInstrumentor(
trace_id_field="trace_id",
span_id_field="span_id",
trace_sampled_field="trace_sampled",
service_name_field="service_name",
)

The integration uses the following logging format by default:

.. code-block::
Expand Down