Skip to content
77 changes: 48 additions & 29 deletions sdk/ai/azure-ai-projects/azure/ai/projects/_patch.py
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,8 @@
from .models._patch import _BETA_OPERATION_FEATURE_HEADERS, _FOUNDRY_FEATURES_HEADER_NAME, _has_header_case_insensitive

logger = logging.getLogger(__name__)
_OPENAI_TRANSPORT_LOGGER_NAME = "azure.ai.projects.openai_transport"
_OPENAI_TRANSPORT_LOGGER = logging.getLogger(_OPENAI_TRANSPORT_LOGGER_NAME)
Comment thread
howieleung marked this conversation as resolved.
Outdated


# ---------------------------------------------------------------------------
Expand Down Expand Up @@ -160,7 +162,7 @@ def __init__(
azure_logger = logging.getLogger("azure")
azure_logger.setLevel(logging.DEBUG)
console_handler = logging.StreamHandler(stream=sys.stdout)
console_handler.addFilter(_AuthSecretsFilter())
# console_handler.addFilter(_AuthSecretsFilter())
Comment thread
Copilot marked this conversation as resolved.
Outdated
azure_logger.addHandler(console_handler)
# Exclude detailed logs for network calls associated with getting Entra ID token.
logging.getLogger("azure.identity").setLevel(logging.ERROR)
Expand All @@ -169,6 +171,10 @@ def __init__(
# (which are implemented as a separate logging policy)
logging.getLogger("azure.core.pipeline.policies.http_logging_policy").setLevel(logging.ERROR)

openai_transport_logger = logging.getLogger(_OPENAI_TRANSPORT_LOGGER_NAME)
openai_transport_logger.setLevel(logging.DEBUG)
openai_transport_logger.propagate = False
openai_transport_logger.addHandler(console_handler)
kwargs.setdefault("logging_enable", self._console_logging_enabled)

self._kwargs = kwargs.copy()
Expand Down Expand Up @@ -203,9 +209,10 @@ def _get_openai_http_client(self, kwargs: dict):
"""
if "http_client" in kwargs:
return kwargs.pop("http_client")
if self._console_logging_enabled:
return httpx.Client(transport=_OpenAILoggingTransport())
return None
logging_kwargs = getattr(self, "_kwargs", {})
return httpx.Client(
transport=_OpenAILoggingTransport(logging_enabled=logging_kwargs.get("logging_enable", False))
)
Comment thread
howieleung marked this conversation as resolved.
Outdated

@distributed_trace
def get_openai_client(
Expand Down Expand Up @@ -242,7 +249,7 @@ def get_openai_client(
base_url = _resolve_openai_base_url(self._config, agent_name, kwargs)
default_query = _resolve_openai_query_params(self._config, agent_name, kwargs)

logger.debug( # pylint: disable=specify-parameter-names-in-call
_OPENAI_TRANSPORT_LOGGER.debug( # pylint: disable=specify-parameter-names-in-call
"[get_openai_client] Creating OpenAI client using Entra ID authentication, base_url = `%s`", # pylint: disable=line-too-long
base_url,
)
Expand Down Expand Up @@ -301,23 +308,29 @@ def filter(self, record: logging.LogRecord) -> bool:


class _OpenAILoggingTransport(httpx.HTTPTransport):
"""Custom HTTP transport that logs OpenAI API requests and responses to the console.
"""Custom HTTP transport that logs OpenAI API requests and responses.

This transport wraps httpx.HTTPTransport to intercept all HTTP traffic and print
detailed request/response information for debugging purposes. It automatically
This transport wraps httpx.HTTPTransport to intercept all HTTP traffic and emit
detailed request/response information through a dedicated logger. It automatically
redacts sensitive authorization headers and handles various content types including
multipart form data (file uploads).

Used internally by AIProjectClient when console logging is enabled via the
AZURE_AI_PROJECTS_CONSOLE_LOGGING environment variable.
"""

def __init__(self, *, logging_enabled: bool) -> None:
super().__init__()
self._logging_enabled = logging_enabled

def _sanitize_auth_header(self, headers) -> None:
"""Sanitize authorization and api-key headers by redacting sensitive information.

:param headers: Dictionary of HTTP headers to sanitize
:type headers: dict
"""
if self._logging_enabled:
return
Comment thread
howieleung marked this conversation as resolved.

if "authorization" in headers:
auth_value = headers["authorization"]
Expand All @@ -328,7 +341,7 @@ def _sanitize_auth_header(self, headers) -> None:

def handle_request(self, request: httpx.Request) -> httpx.Response:
"""
Log HTTP request and response details to console, in a nicely formatted way,
Log HTTP request and response details using the dedicated transport logger,
for OpenAI / Azure OpenAI clients.

:param request: The HTTP request to handle and log
Expand All @@ -338,31 +351,34 @@ def handle_request(self, request: httpx.Request) -> httpx.Response:
:rtype: httpx.Response
"""

print(f"\n==> Request:\n{request.method} {request.url}")
_OPENAI_TRANSPORT_LOGGER.debug("\n==> Request:\n%s %s", request.method, request.url)
Comment thread
howieleung marked this conversation as resolved.
Outdated
headers = dict(request.headers)
self._sanitize_auth_header(headers)
print("Headers:")
_OPENAI_TRANSPORT_LOGGER.debug("Headers:")
for key, value in sorted(headers.items()):
print(f" {key}: {value}")
_OPENAI_TRANSPORT_LOGGER.debug(" %s: %s", key, value)
Comment thread
howieleung marked this conversation as resolved.
Outdated

self._log_request_body(request)

response = super().handle_request(request)

print(f"\n<== Response:\n{response.status_code} {response.reason_phrase}")
print("Headers:")
_OPENAI_TRANSPORT_LOGGER.debug("\n<== Response:\n%s %s", response.status_code, response.reason_phrase)
_OPENAI_TRANSPORT_LOGGER.debug("Headers:")
for key, value in sorted(dict(response.headers).items()):
print(f" {key}: {value}")
_OPENAI_TRANSPORT_LOGGER.debug(" %s: %s", key, value)
Comment thread
howieleung marked this conversation as resolved.
Outdated

content = response.read()
if content is None or content == b"":
print("Body: [No content]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [No content]")
else:
try:
print(f"Body:\n {content.decode('utf-8')}")
except Exception: # pylint: disable=broad-exception-caught
print(f"Body (raw):\n {content!r}")
print("\n")
if self._logging_enabled:
try:
_OPENAI_TRANSPORT_LOGGER.debug("Body:\n %s", content.decode("utf-8"))
except Exception: # pylint: disable=broad-exception-caught
_OPENAI_TRANSPORT_LOGGER.debug("Body (raw):\n %r", content)
else:
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Content exists]")
_OPENAI_TRANSPORT_LOGGER.debug("\n")

return response

Expand All @@ -376,29 +392,32 @@ def _log_request_body(self, request: httpx.Request) -> None:
# Check content-type header to identify file uploads
content_type = request.headers.get("content-type", "").lower()
if "multipart/form-data" in content_type:
print("Body: [Multipart form data - file upload, not logged]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Multipart form data - file upload, not logged]")
return

# Safely check if content exists without accessing it
if not hasattr(request, "content"):
print("Body: [No content attribute]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [No content attribute]")
return

# Very careful content access - wrap in try-catch immediately
try:
content = request.content
except Exception as access_error: # pylint: disable=broad-exception-caught
print(f"Body: [Cannot access content: {access_error}]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Cannot access content: %s]", access_error)
return

if content is None or content == b"":
print("Body: [No content]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [No content]")
return

try:
print(f"Body:\n {content.decode('utf-8')}")
except Exception: # pylint: disable=broad-exception-caught
print(f"Body (raw):\n {content!r}")
if self._logging_enabled:
try:
_OPENAI_TRANSPORT_LOGGER.debug("Body:\n %s", content.decode("utf-8"))
except Exception: # pylint: disable=broad-exception-caught
_OPENAI_TRANSPORT_LOGGER.debug("Body (raw):\n %r", content)
else:
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Content exists]")


__all__: List[str] = [
Expand Down
8 changes: 8 additions & 0 deletions sdk/ai/azure-ai-projects/azure/ai/projects/_patch.pyi
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ Azure-specific grader types in addition to the standard OpenAI graders.

import logging
from typing import Any, Iterable, List, Union, Optional
import httpx
from httpx import Timeout
from openai import NotGiven, Omit, OpenAI as OpenAIClient
from openai._types import Body, Query, Headers
Expand Down Expand Up @@ -101,13 +102,20 @@ class OpenAI(OpenAIClient):

class AIProjectClient(AIProjectClientGenerated):
telemetry: TelemetryOperations
_console_logging_enabled: bool
_kwargs: dict[str, Any]
_custom_user_agent: Optional[str]
Comment thread
howieleung marked this conversation as resolved.
Outdated
def get_openai_client(
self, agent_name: Optional[str] = None, **kwargs: Any # pylint: disable=unused-argument
) -> OpenAI: ...

# To make mypy happy... otherwise imports of the below result in mypy "attr-defined" error
class _AuthSecretsFilter(logging.Filter): ...

class _OpenAILoggingTransport:
def __init__(self, *, logging_enabled: bool) -> None: ...
def handle_request(self, request: httpx.Request) -> httpx.Response: ...

def _resolve_openai_base_url(config: Any, agent_name: Optional[str], kwargs: dict) -> str: ...
def _resolve_openai_query_params(config: Any, agent_name: Optional[str], kwargs: dict) -> dict: ...
def _resolve_openai_default_headers(agent_name: Optional[str], kwargs: dict) -> dict: ...
Expand Down
61 changes: 38 additions & 23 deletions sdk/ai/azure-ai-projects/azure/ai/projects/aio/_patch.py
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,8 @@
from .operations import TelemetryOperations

logger = logging.getLogger(__name__)
_OPENAI_TRANSPORT_LOGGER_NAME = "azure.ai.projects.openai_transport"
_OPENAI_TRANSPORT_LOGGER = logging.getLogger(_OPENAI_TRANSPORT_LOGGER_NAME)


class AIProjectClient(AIProjectClientGenerated): # pylint: disable=too-many-instance-attributes
Expand Down Expand Up @@ -135,9 +137,10 @@ def _get_openai_http_client(self, kwargs: dict):
"""
if "http_client" in kwargs:
return kwargs.pop("http_client")
if self._console_logging_enabled:
return httpx.AsyncClient(transport=_OpenAILoggingTransport())
return None
logging_kwargs = getattr(self, "_kwargs", {})
return httpx.AsyncClient(
transport=_OpenAILoggingTransport(logging_enabled=logging_kwargs.get("logging_enable", False))
)
Comment thread
howieleung marked this conversation as resolved.
Outdated

@distributed_trace
def get_openai_client(
Expand Down Expand Up @@ -222,12 +225,18 @@ class _OpenAILoggingTransport(httpx.AsyncHTTPTransport):
AZURE_AI_PROJECTS_CONSOLE_LOGGING environment variable.
"""

def __init__(self, *, logging_enabled: bool) -> None:
super().__init__()
self._logging_enabled = logging_enabled

def _sanitize_auth_header(self, headers):
"""Sanitize authorization and api-key headers by redacting sensitive information.

:param headers: Dictionary of HTTP headers to sanitize
:type headers: dict
"""
if self._logging_enabled:
return
Comment thread
howieleung marked this conversation as resolved.

if "authorization" in headers:
auth_value = headers["authorization"]
Expand All @@ -248,31 +257,34 @@ async def handle_async_request(self, request: httpx.Request) -> httpx.Response:
:rtype: httpx.Response
"""

print(f"\n==> Request:\n{request.method} {request.url}")
_OPENAI_TRANSPORT_LOGGER.debug("\n==> Request:\n%s %s", request.method, request.url)
Comment thread
howieleung marked this conversation as resolved.
Outdated
headers = dict(request.headers)
self._sanitize_auth_header(headers)
print("Headers:")
_OPENAI_TRANSPORT_LOGGER.debug("Headers:")
for key, value in sorted(headers.items()):
print(f" {key}: {value}")
_OPENAI_TRANSPORT_LOGGER.debug(" %s: %s", key, value)
Comment thread
Copilot marked this conversation as resolved.
Outdated

self._log_request_body(request)

response = await super().handle_async_request(request)

print(f"\n<== Response:\n{response.status_code} {response.reason_phrase}")
print("Headers:")
_OPENAI_TRANSPORT_LOGGER.debug("\n<== Response:\n%s %s", response.status_code, response.reason_phrase)
_OPENAI_TRANSPORT_LOGGER.debug("Headers:")
for key, value in sorted(dict(response.headers).items()):
print(f" {key}: {value}")
_OPENAI_TRANSPORT_LOGGER.debug(" %s: %s", key, value)

content = await response.aread()
if content is None or content == b"":
print("Body: [No content]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [No content]")
else:
try:
print(f"Body:\n {content.decode('utf-8')}")
except Exception: # pylint: disable=broad-exception-caught
print(f"Body (raw):\n {content!r}")
print("\n")
if self._logging_enabled:
try:
_OPENAI_TRANSPORT_LOGGER.debug("Body:\n %s", content.decode("utf-8"))
except Exception: # pylint: disable=broad-exception-caught
_OPENAI_TRANSPORT_LOGGER.debug("Body (raw):\n %r", content)
else:
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Content exists]")
_OPENAI_TRANSPORT_LOGGER.debug("\n")

return response

Expand All @@ -286,29 +298,32 @@ def _log_request_body(self, request: httpx.Request) -> None:
# Check content-type header to identify file uploads
content_type = request.headers.get("content-type", "").lower()
if "multipart/form-data" in content_type:
print("Body: [Multipart form data - file upload, not logged]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Multipart form data - file upload, not logged]")
return

# Safely check if content exists without accessing it
if not hasattr(request, "content"):
print("Body: [No content attribute]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [No content attribute]")
return

# Very careful content access - wrap in try-catch immediately
try:
content = request.content
except Exception as access_error: # pylint: disable=broad-exception-caught
print(f"Body: [Cannot access content: {access_error}]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Cannot access content: %s]", access_error)
return

if content is None or content == b"":
print("Body: [No content]")
_OPENAI_TRANSPORT_LOGGER.debug("Body: [No content]")
return

try:
print(f"Body:\n {content.decode('utf-8')}")
except Exception: # pylint: disable=broad-exception-caught
print(f"Body (raw):\n {content!r}")
if self._logging_enabled:
try:
_OPENAI_TRANSPORT_LOGGER.debug("Body:\n %s", content.decode("utf-8"))
except Exception: # pylint: disable=broad-exception-caught
_OPENAI_TRANSPORT_LOGGER.debug("Body (raw):\n %r", content)
else:
_OPENAI_TRANSPORT_LOGGER.debug("Body: [Content exists]")


__all__: List[str] = ["AIProjectClient"] # Add all objects you want publicly available to users at this package level
Expand Down
7 changes: 7 additions & 0 deletions sdk/ai/azure-ai-projects/azure/ai/projects/aio/_patch.pyi
Original file line number Diff line number Diff line change
Expand Up @@ -100,10 +100,17 @@ class AsyncOpenAI(AsyncOpenAIClient):

class AIProjectClient(AIProjectClientGenerated):
telemetry: TelemetryOperations
_console_logging_enabled: bool
_kwargs: dict[str, Any]
_custom_user_agent: Optional[str]
def get_openai_client(
self, agent_name: Optional[str] = None, **kwargs: Any # pylint: disable=unused-argument
) -> AsyncOpenAI: ...

class _OpenAILoggingTransport:
def __init__(self, *, logging_enabled: bool) -> None: ...
async def handle_async_request(self, request: Any) -> Any: ...

# To make mypy happy... otherwise imports of the below result in mypy "attr-defined" error
__all__: List[str] = ["AIProjectClient"]

Expand Down
14 changes: 14 additions & 0 deletions sdk/ai/azure-ai-projects/samples/logs/log_utils.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
# ------------------------------------
# Copyright (c) Microsoft Corporation.
# Licensed under the MIT License.
# ------------------------------------

from datetime import datetime
from pathlib import Path
from tempfile import gettempdir


def create_timestamped_temp_log_file(script_path: str | Path) -> Path:
Comment thread
Copilot marked this conversation as resolved.
Outdated
script_path = Path(script_path)
timestamp = datetime.now().strftime("%Y%m%d_%H%M%S")
return Path(gettempdir()) / f"{script_path.stem}_{timestamp}.log"
Loading
Loading