Skip to content

Commit 0569eb5

Browse files
Copilotsaurabhrb
andcommitted
feat: add opt-in local file logging of HTTP request/response diagnostics
Co-authored-by: saurabhrb <32964911+saurabhrb@users.noreply.github.com>
1 parent cba7b3a commit 0569eb5

7 files changed

Lines changed: 536 additions & 5 deletions

File tree

src/PowerPlatform/Dataverse/core/_http.py

Lines changed: 35 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -12,10 +12,13 @@
1212
from __future__ import annotations
1313

1414
import time
15-
from typing import Any, Optional
15+
from typing import TYPE_CHECKING, Any, Optional
1616

1717
import requests
1818

19+
if TYPE_CHECKING:
20+
from ._http_logger import _HttpLogger
21+
1922

2023
class _HttpClient:
2124
"""
@@ -34,6 +37,9 @@ class _HttpClient:
3437
When provided, all requests use this session (enabling TCP/TLS reuse).
3538
When ``None``, each request uses ``requests.request()`` directly.
3639
:type session: :class:`requests.Session` | None
40+
:param logger: Optional HTTP diagnostics logger. When provided, all requests,
41+
responses, and transport errors are logged with automatic header redaction.
42+
:type logger: ~PowerPlatform.Dataverse.core._http_logger._HttpLogger | None
3743
"""
3844

3945
def __init__(
@@ -42,11 +48,13 @@ def __init__(
4248
backoff: Optional[float] = None,
4349
timeout: Optional[float] = None,
4450
session: Optional[requests.Session] = None,
51+
logger: Optional["_HttpLogger"] = None,
4552
) -> None:
4653
self.max_attempts = retries if retries is not None else 5
4754
self.base_delay = backoff if backoff is not None else 0.5
4855
self.default_timeout: Optional[float] = timeout
4956
self._session = session
57+
self._logger = logger
5058

5159
def _request(self, method: str, url: str, **kwargs: Any) -> requests.Response:
5260
"""
@@ -73,12 +81,36 @@ def _request(self, method: str, url: str, **kwargs: Any) -> requests.Response:
7381
m = (method or "").lower()
7482
kwargs["timeout"] = 120 if m in ("post", "delete") else 10
7583

84+
# Log outbound request once (before retry loop)
85+
if self._logger is not None:
86+
self._logger.log_request(
87+
method,
88+
url,
89+
headers=kwargs.get("headers"),
90+
body=kwargs.get("json") or kwargs.get("data"),
91+
)
92+
7693
# Small backoff retry on network errors only
7794
requester = self._session.request if self._session is not None else requests.request
7895
for attempt in range(self.max_attempts):
7996
try:
80-
return requester(method, url, **kwargs)
81-
except requests.exceptions.RequestException:
97+
t0 = time.monotonic()
98+
resp = requester(method, url, **kwargs)
99+
elapsed_ms = (time.monotonic() - t0) * 1000
100+
101+
if self._logger is not None:
102+
self._logger.log_response(
103+
method,
104+
url,
105+
status_code=resp.status_code,
106+
headers=dict(resp.headers),
107+
body=resp.text,
108+
elapsed_ms=elapsed_ms,
109+
)
110+
return resp
111+
except requests.exceptions.RequestException as exc:
112+
if self._logger is not None:
113+
self._logger.log_error(method, url, exc)
82114
if attempt == self.max_attempts - 1:
83115
raise
84116
delay = self.base_delay * (2**attempt)
Lines changed: 119 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,119 @@
1+
# Copyright (c) Microsoft Corporation.
2+
# Licensed under the MIT license.
3+
4+
"""
5+
Internal HTTP logger that writes redacted request/response diagnostics to local files.
6+
"""
7+
8+
from __future__ import annotations
9+
10+
import json as _json
11+
import logging
12+
import os
13+
import uuid
14+
from datetime import datetime, timezone
15+
from logging.handlers import RotatingFileHandler
16+
from typing import Any, Dict, Optional
17+
18+
from .log_config import LogConfig
19+
20+
21+
class _HttpLogger:
22+
"""Structured HTTP diagnostic logger with automatic header redaction."""
23+
24+
def __init__(self, config: LogConfig) -> None:
25+
self._config = config
26+
self._redacted = {h.lower() for h in config.redacted_headers}
27+
28+
# Ensure folder exists
29+
os.makedirs(config.log_folder, exist_ok=True)
30+
31+
# Build timestamped filename
32+
ts = datetime.now(timezone.utc).strftime("%Y%m%d_%H%M%S")
33+
filename = f"{config.log_file_prefix}_{ts}.log"
34+
filepath = os.path.join(config.log_folder, filename)
35+
36+
# Create a dedicated named logger (not root) to avoid side effects
37+
logger_name = f"PowerPlatform.Dataverse.http.{uuid.uuid4().hex[:8]}"
38+
self._logger = logging.getLogger(logger_name)
39+
self._logger.setLevel(getattr(logging, config.log_level.upper(), logging.DEBUG))
40+
self._logger.propagate = False # don't bubble to root
41+
42+
handler = RotatingFileHandler(
43+
filepath,
44+
maxBytes=config.max_file_bytes,
45+
backupCount=config.backup_count,
46+
encoding="utf-8",
47+
)
48+
formatter = logging.Formatter(
49+
"[%(asctime)s] %(levelname)s %(message)s",
50+
datefmt="%Y-%m-%dT%H:%M:%S%z",
51+
)
52+
handler.setFormatter(formatter)
53+
self._logger.addHandler(handler)
54+
55+
def log_request(
56+
self,
57+
method: str,
58+
url: str,
59+
headers: Optional[Dict[str, str]] = None,
60+
body: Any = None,
61+
) -> None:
62+
"""Log an outbound HTTP request."""
63+
safe_headers = self._redact_headers(headers or {})
64+
body_text = self._truncate_body(body)
65+
lines = [
66+
f">>> REQUEST {method.upper()} {url}",
67+
f" Headers: {safe_headers}",
68+
]
69+
if body_text:
70+
lines.append(f" Body: {body_text}")
71+
self._logger.debug("\n".join(lines))
72+
73+
def log_response(
74+
self,
75+
method: str,
76+
url: str,
77+
status_code: int,
78+
headers: Optional[Dict[str, str]] = None,
79+
body: Any = None,
80+
elapsed_ms: Optional[float] = None,
81+
) -> None:
82+
"""Log an inbound HTTP response."""
83+
safe_headers = self._redact_headers(headers or {})
84+
body_text = self._truncate_body(body)
85+
elapsed_str = f" ({elapsed_ms:.1f}ms)" if elapsed_ms is not None else ""
86+
lines = [
87+
f"<<< RESPONSE {status_code} {method.upper()} {url}{elapsed_str}",
88+
f" Headers: {safe_headers}",
89+
]
90+
if body_text:
91+
lines.append(f" Body: {body_text}")
92+
self._logger.debug("\n".join(lines))
93+
94+
def log_error(self, method: str, url: str, error: Exception) -> None:
95+
"""Log an HTTP transport error."""
96+
self._logger.error(f"!!! ERROR {method.upper()} {url} - {type(error).__name__}: {error}")
97+
98+
def _redact_headers(self, headers: Dict[str, str]) -> Dict[str, str]:
99+
return {k: ("[REDACTED]" if k.lower() in self._redacted else v) for k, v in headers.items()}
100+
101+
def _truncate_body(self, body: Any) -> str:
102+
if body is None:
103+
return ""
104+
if isinstance(body, (bytes, bytearray)):
105+
text = body.decode("utf-8", errors="replace")
106+
elif not isinstance(body, str):
107+
try:
108+
text = _json.dumps(body, default=str, ensure_ascii=False)
109+
except (TypeError, ValueError):
110+
text = str(body)
111+
else:
112+
text = body
113+
114+
limit = self._config.max_body_bytes
115+
if limit == 0:
116+
return ""
117+
if len(text) > limit:
118+
return text[:limit] + f"... [truncated, {len(text)} bytes total]"
119+
return text

src/PowerPlatform/Dataverse/core/config.py

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,10 @@
1212
from __future__ import annotations
1313

1414
from dataclasses import dataclass
15-
from typing import Optional
15+
from typing import TYPE_CHECKING, Optional
16+
17+
if TYPE_CHECKING:
18+
from .log_config import LogConfig
1619

1720

1821
@dataclass(frozen=True)
@@ -28,6 +31,10 @@ class DataverseConfig:
2831
:type http_backoff: :class:`float` or None
2932
:param http_timeout: Optional request timeout in seconds. Reserved for future use.
3033
:type http_timeout: :class:`float` or None
34+
:param log_config: Optional local HTTP diagnostics logging configuration.
35+
When provided, all HTTP requests and responses are logged to timestamped
36+
``.log`` files with automatic redaction of sensitive headers.
37+
:type log_config: ~PowerPlatform.Dataverse.core.log_config.LogConfig or None
3138
"""
3239

3340
language_code: int = 1033
@@ -37,6 +44,8 @@ class DataverseConfig:
3744
http_backoff: Optional[float] = None
3845
http_timeout: Optional[float] = None
3946

47+
log_config: Optional["LogConfig"] = None
48+
4049
@classmethod
4150
def from_env(cls) -> "DataverseConfig":
4251
"""
@@ -51,4 +60,5 @@ def from_env(cls) -> "DataverseConfig":
5160
http_retries=None,
5261
http_backoff=None,
5362
http_timeout=None,
63+
log_config=None,
5464
)
Lines changed: 64 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,64 @@
1+
# Copyright (c) Microsoft Corporation.
2+
# Licensed under the MIT license.
3+
4+
"""
5+
Local file logging configuration for Dataverse SDK HTTP diagnostics.
6+
7+
Provides :class:`LogConfig`, an opt-in configuration for writing request/response
8+
traces to ``.log`` files with automatic header redaction and timestamped filenames.
9+
"""
10+
11+
from __future__ import annotations
12+
13+
from dataclasses import dataclass, field
14+
from typing import FrozenSet
15+
16+
__all__ = ["LogConfig"]
17+
18+
# Headers whose values must never appear in log files
19+
_DEFAULT_REDACTED_HEADERS: FrozenSet[str] = frozenset(
20+
{
21+
"authorization",
22+
"proxy-authorization",
23+
"x-ms-authorization-auxiliary",
24+
"ocp-apim-subscription-key",
25+
}
26+
)
27+
28+
29+
def _default_redacted_headers() -> FrozenSet[str]:
30+
return _DEFAULT_REDACTED_HEADERS
31+
32+
33+
@dataclass(frozen=True)
34+
class LogConfig:
35+
"""
36+
Configuration for local HTTP diagnostics logging.
37+
38+
When provided to :class:`~PowerPlatform.Dataverse.client.DataverseClient` via
39+
:class:`~PowerPlatform.Dataverse.core.config.DataverseConfig`, every HTTP request
40+
and response is logged to timestamped ``.log`` files in the specified folder.
41+
Sensitive headers (e.g. ``Authorization``) are automatically redacted.
42+
43+
:param log_folder: Directory path for log files. Created automatically if missing.
44+
Default: ``"./dataverse_logs"``
45+
:param log_file_prefix: Filename prefix. Timestamp is appended automatically.
46+
Default: ``"dataverse"`` → ``dataverse_20260310_143022.log``
47+
:param max_body_bytes: Maximum bytes of request/response body to capture.
48+
``0`` disables body logging. Default: ``4096``.
49+
:param redacted_headers: Header names (case-insensitive) whose values are
50+
replaced with ``"[REDACTED]"`` in logs. Defaults include
51+
``Authorization``, ``Proxy-Authorization``, etc.
52+
:param log_level: Python logging level name. Default: ``"DEBUG"``.
53+
:param max_file_bytes: Max size per log file before rotation (bytes).
54+
Default: ``10_485_760`` (10 MB).
55+
:param backup_count: Number of rotated backup files to keep. Default: ``5``.
56+
"""
57+
58+
log_folder: str = "./dataverse_logs"
59+
log_file_prefix: str = "dataverse"
60+
max_body_bytes: int = 4096
61+
redacted_headers: FrozenSet[str] = field(default_factory=_default_redacted_headers)
62+
log_level: str = "DEBUG"
63+
max_file_bytes: int = 10_485_760 # 10 MB
64+
backup_count: int = 5

src/PowerPlatform/Dataverse/data/_odata.py

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -143,13 +143,18 @@ def __init__(
143143
"PowerPlatform.Dataverse.core.config", fromlist=["DataverseConfig"]
144144
).DataverseConfig.from_env()
145145
)
146+
_log = None
147+
if self.config.log_config is not None:
148+
from ..core._http_logger import _HttpLogger
149+
150+
_log = _HttpLogger(self.config.log_config)
146151
self._http = _HttpClient(
147152
retries=self.config.http_retries,
148153
backoff=self.config.http_backoff,
149154
timeout=self.config.http_timeout,
150155
session=session,
156+
logger=_log,
151157
)
152-
# Cache: normalized table_schema_name (lowercase) -> entity set name (plural) resolved from metadata
153158
self._logical_to_entityset_cache: dict[str, str] = {}
154159
# Cache: normalized table_schema_name (lowercase) -> primary id attribute (e.g. accountid)
155160
self._logical_primaryid_cache: dict[str, str] = {}

0 commit comments

Comments
 (0)