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
21 changes: 16 additions & 5 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -142,7 +142,7 @@ pip install azure-functions-logging

```python
import azure.functions as func
from azure_functions_logging import get_logger, inject_context, setup_logging
from azure_functions_logging import get_logger, logging_context, setup_logging

setup_logging()
logger = get_logger(__name__)
Expand All @@ -151,12 +151,23 @@ app = func.FunctionApp()

@app.route(route="hello")
def hello(req: func.HttpRequest, context: func.Context) -> func.HttpResponse:
inject_context(context) # binds invocation_id, function_name, cold_start
with logging_context(context): # binds invocation_id, function_name, cold_start; resets on exit
logger.info("Request received")
# {"level": "INFO", "invocation_id": "abc-123", "cold_start": true, ...}

logger.info("Request received")
# {"level": "INFO", "invocation_id": "abc-123", "cold_start": true, ...}
return func.HttpResponse("OK")
```

return func.HttpResponse("OK")
`logging_context` is the recommended primary pattern: it injects context on enter and **always** resets on exit (even when the handler raises), which prevents stale context from leaking into the next invocation on a reused worker.

For lower-level control or when integrating with custom middleware, `inject_context(context)` and `reset_context()` are exposed individually:

```python
inject_context(context)
try:
logger.info("Request received")
finally:
reset_context()
```

Start the Functions host locally (using the [e2e example app](examples/e2e_app)):
Expand Down
4 changes: 3 additions & 1 deletion src/azure_functions_logging/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@

from __future__ import annotations

from ._context import inject_context
from ._context import inject_context, logging_context, reset_context
from ._decorator import get_logging_metadata, with_context
from ._filters import RedactionFilter, SamplingFilter
from ._json_formatter import JsonFormatter
Expand All @@ -18,6 +18,8 @@
"get_logging_metadata",
"get_logger",
"inject_context",
"logging_context",
"reset_context",
"setup_logging",
"with_context",
]
Expand Down
42 changes: 42 additions & 0 deletions src/azure_functions_logging/_context.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,8 @@

from __future__ import annotations

from collections.abc import Iterator
from contextlib import contextmanager
import contextvars
import logging
from typing import Any
Expand Down Expand Up @@ -104,3 +106,43 @@ def inject_context(context: Any) -> None:
cold_start_var.set(_check_cold_start())
except Exception: # nosec B110 — Principle 3: context failures are silent
pass


def reset_context() -> None:
"""Clear every invocation context variable.

Call this after an invocation completes when you used ``inject_context()``
manually. Without resetting, contextvar values can leak across reused
Azure Functions worker invocations and across async/thread boundaries —
a subsequent log line may carry a stale ``invocation_id`` belonging to an
earlier request.

Safe to call repeatedly. Setting to ``None`` is the documented "absent"
state for every context field (matches ``ContextVar`` defaults).
"""
invocation_id_var.set(None)
function_name_var.set(None)
trace_id_var.set(None)
cold_start_var.set(None)


@contextmanager
def logging_context(context: Any) -> Iterator[None]:
"""Context manager wrapping ``inject_context`` + ``reset_context``.

Recommended pattern when handlers don't use the ``with_context`` decorator::

def handler(req, context):
with logging_context(context):
logger.info("processing")
...

Guarantees ``reset_context()`` runs even if the body raises, preventing
invocation context from leaking into subsequent invocations on the same
worker.
"""
inject_context(context)
try:
yield
finally:
reset_context()
27 changes: 7 additions & 20 deletions src/azure_functions_logging/_decorator.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,13 +13,7 @@
import inspect
from typing import Any, Callable, TypeVar, overload

from ._context import (
cold_start_var,
function_name_var,
inject_context,
invocation_id_var,
trace_id_var,
)
from ._context import inject_context, reset_context

_F = TypeVar("_F", bound=Callable[..., Any])

Expand All @@ -29,7 +23,9 @@


def _merge_toolkit_metadata(
fn: Callable[..., Any], namespace: str, payload: dict[str, Any],
fn: Callable[..., Any],
namespace: str,
payload: dict[str, Any],
) -> None:
"""Merge toolkit metadata into the convention attribute, preserving other namespaces."""
existing: dict[str, Any] = getattr(fn, _TOOLKIT_META_ATTR, {})
Expand All @@ -39,14 +35,6 @@ def _merge_toolkit_metadata(
setattr(fn, _TOOLKIT_META_ATTR, existing)


def _reset_context_vars() -> None:
"""Reset all invocation context variables to None."""
invocation_id_var.set(None)
function_name_var.set(None)
trace_id_var.set(None)
cold_start_var.set(None)


def _find_context_arg(
func: Callable[..., Any],
param: str,
Expand Down Expand Up @@ -82,7 +70,7 @@ def wrapper(*args: Any, **kwargs: Any) -> Any:
try:
return func(*args, **kwargs)
finally:
_reset_context_vars()
reset_context()

_merge_toolkit_metadata(wrapper, "logging", {"version": 1, "context_param": param})
return wrapper # type: ignore[return-value]
Expand All @@ -99,7 +87,7 @@ async def wrapper(*args: Any, **kwargs: Any) -> Any:
try:
return await func(*args, **kwargs)
finally:
_reset_context_vars()
reset_context()

_merge_toolkit_metadata(wrapper, "logging", {"version": 1, "context_param": param})
return wrapper # type: ignore[return-value]
Expand Down Expand Up @@ -157,7 +145,6 @@ def decorator(fn: _F) -> _F:
return decorator



def get_logging_metadata(func: Any) -> dict[str, Any] | None:
"""Return logging metadata if the function was decorated with ``with_context``.

Expand All @@ -168,4 +155,4 @@ def get_logging_metadata(func: Any) -> dict[str, Any] | None:
meta = toolkit_meta.get("logging")
if isinstance(meta, dict):
return meta
return None
return None
44 changes: 33 additions & 11 deletions src/azure_functions_logging/_host_config.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,8 +18,24 @@
}


def _resolve_host_level(value: object) -> int | None:
if not isinstance(value, str):
return None
return _HOST_LEVEL_TO_LOGGING.get(value.lower())


def warn_host_json_level_conflict(configured_level: int) -> None:
"""Warn when host.json suppresses logs below setup_logging level."""
"""Warn when any ``host.json`` ``logLevel`` entry suppresses logs below ``configured_level``.

Azure Functions honors category-specific keys under ``logging.logLevel``
(e.g. ``Function``, ``Function.<name>``, ``Host.Results``,
``Host.Aggregator``) in addition to ``default``. Inspecting only ``default``
misses the common case where ``default = Information`` while a specific
function category is set to ``Warning`` or ``None`` and silently drops the
user's logs.

This helper iterates every category and warns once per offending entry.
"""
host_path = Path.cwd() / "host.json"
if not host_path.exists():
return
Expand All @@ -30,24 +46,30 @@ def warn_host_json_level_conflict(configured_level: int) -> None:
return

try:
host_level = host_config["logging"]["logLevel"]["default"]
log_levels = host_config["logging"]["logLevel"]
except Exception:
return

if not isinstance(host_level, str):
if not isinstance(log_levels, dict):
return

resolved_level = _HOST_LEVEL_TO_LOGGING.get(host_level.lower())
if resolved_level is None:
return
configured_level_name = logging.getLevelName(configured_level)

for category, raw_level in log_levels.items():
if not isinstance(category, str):
continue
resolved_level = _resolve_host_level(raw_level)
if resolved_level is None:
continue
if resolved_level <= configured_level:
continue

if resolved_level > configured_level:
configured_level_name = logging.getLevelName(configured_level)
scope = "default" if category == "default" else f"category '{category}'"
warnings.warn(
(
f"host.json logLevel.default is set to '{host_level}' which is more restrictive "
f"than the configured level '{configured_level_name}'. Logs below '{host_level}' "
"will be suppressed by the Azure Functions host."
f"host.json logLevel for {scope} is set to '{raw_level}' which is more "
f"restrictive than the configured level '{configured_level_name}'. Logs "
f"below '{raw_level}' will be suppressed by the Azure Functions host."
),
stacklevel=3,
)
59 changes: 59 additions & 0 deletions tests/test_context.py
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,8 @@
function_name_var,
inject_context,
invocation_id_var,
logging_context,
reset_context,
trace_id_var,
)

Expand Down Expand Up @@ -170,3 +172,60 @@ def trace_context(self) -> object:
assert invocation_id_var.get() is None
assert function_name_var.get() is None
assert trace_id_var.get() is None


def test_reset_context_clears_all_contextvars() -> None:
invocation_id_var.set("inv-x")
function_name_var.set("fn-x")
trace_id_var.set("trace-x")
cold_start_var.set(True)

reset_context()

assert invocation_id_var.get() is None
assert function_name_var.get() is None
assert trace_id_var.get() is None
assert cold_start_var.get() is None


def test_reset_context_is_idempotent() -> None:
reset_context()
reset_context()

assert invocation_id_var.get() is None
assert cold_start_var.get() is None


def test_logging_context_sets_then_resets() -> None:
context = SimpleNamespace(
invocation_id="inv-cm",
function_name="fn-cm",
trace_context=SimpleNamespace(
trace_parent="00-cccccccccccccccccccccccccccccccc-2222222222222222-01"
),
)

with logging_context(context):
assert invocation_id_var.get() == "inv-cm"
assert function_name_var.get() == "fn-cm"
assert trace_id_var.get() == "cccccccccccccccccccccccccccccccc"
assert cold_start_var.get() is True

assert invocation_id_var.get() is None
assert function_name_var.get() is None
assert trace_id_var.get() is None
assert cold_start_var.get() is None


def test_logging_context_resets_even_when_body_raises() -> None:
context = SimpleNamespace(invocation_id="inv-raise", function_name="fn-raise")

with pytest.raises(RuntimeError, match="boom"):
with logging_context(context):
assert invocation_id_var.get() == "inv-raise"
raise RuntimeError("boom")

assert invocation_id_var.get() is None
assert function_name_var.get() is None
assert trace_id_var.get() is None
assert cold_start_var.get() is None
70 changes: 70 additions & 0 deletions tests/test_host_config.py
Original file line number Diff line number Diff line change
Expand Up @@ -143,3 +143,73 @@ def test_no_warning_when_host_level_is_unrecognized_string(
warn_host_json_level_conflict(logging.DEBUG)

assert len(warning_list) == 0


def test_warns_per_category_when_specific_category_is_more_restrictive(
tmp_path: Path,
monkeypatch: pytest.MonkeyPatch,
) -> None:
_write_host_json(
tmp_path / "host.json",
{
"logging": {
"logLevel": {
"default": "Information",
"Function.MyFunction": "Warning",
"Host.Results": "Error",
}
}
},
)
monkeypatch.chdir(tmp_path)

with warnings.catch_warnings(record=True) as warning_list:
warnings.simplefilter("always")
warn_host_json_level_conflict(logging.INFO)

messages = [str(w.message) for w in warning_list]
assert any("Function.MyFunction" in m and "'Warning'" in m for m in messages)
assert any("Host.Results" in m and "'Error'" in m for m in messages)
assert not any("default" in m for m in messages)


def test_no_warning_when_all_categories_permissive(
tmp_path: Path,
monkeypatch: pytest.MonkeyPatch,
) -> None:
_write_host_json(
tmp_path / "host.json",
{
"logging": {
"logLevel": {
"default": "Information",
"Function": "Debug",
"Host.Aggregator": "Trace",
}
}
},
)
monkeypatch.chdir(tmp_path)

with warnings.catch_warnings(record=True) as warning_list:
warnings.simplefilter("always")
warn_host_json_level_conflict(logging.INFO)

assert len(warning_list) == 0


def test_no_warning_when_log_level_block_is_not_a_dict(
tmp_path: Path,
monkeypatch: pytest.MonkeyPatch,
) -> None:
_write_host_json(
tmp_path / "host.json",
{"logging": {"logLevel": "Warning"}},
)
monkeypatch.chdir(tmp_path)

with warnings.catch_warnings(record=True) as warning_list:
warnings.simplefilter("always")
warn_host_json_level_conflict(logging.INFO)

assert len(warning_list) == 0
Loading
Loading