Skip to content
Merged
Show file tree
Hide file tree
Changes from 5 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
3 changes: 2 additions & 1 deletion src/openai/_base_client.py
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@
HttpxRequestFiles,
ModelBuilderProtocol,
)
from ._utils import is_dict, is_list, asyncify, is_given, lru_cache, is_mapping
from ._utils import APIKeyFilter, is_dict, is_list, asyncify, is_given, lru_cache, is_mapping
from ._compat import model_copy, model_dump
from ._models import GenericModel, FinalRequestOptions, validate_type, construct_type
from ._response import (
Expand Down Expand Up @@ -90,6 +90,7 @@
from ._legacy_response import LegacyAPIResponse

log: logging.Logger = logging.getLogger(__name__)
log.addFilter(APIKeyFilter())

# TODO: make base page type vars covariant
SyncPageT = TypeVar("SyncPageT", bound="BaseSyncPage[Any]")
Expand Down
1 change: 1 addition & 0 deletions src/openai/_utils/__init__.py
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
from ._logs import APIKeyFilter as APIKeyFilter
from ._sync import asyncify as asyncify
from ._proxy import LazyProxy as LazyProxy
from ._utils import (
Expand Down
14 changes: 14 additions & 0 deletions src/openai/_utils/_logs.py
Original file line number Diff line number Diff line change
@@ -1,5 +1,7 @@
import os
import logging
from typing import Any, Dict
from typing_extensions import override

logger: logging.Logger = logging.getLogger("openai")
httpx_logger: logging.Logger = logging.getLogger("httpx")
Expand All @@ -23,3 +25,15 @@ def setup_logging() -> None:
_basic_config()
logger.setLevel(logging.INFO)
httpx_logger.setLevel(logging.INFO)


class APIKeyFilter(logging.Filter):
@override
def filter(self, record: logging.LogRecord) -> bool:
if isinstance(record.args, dict) and "headers" in record.args:
if isinstance(record.args["headers"], dict):
logged_headers: Dict[str, Any] = record.args["headers"]
for header in logged_headers:
if header.lower() in ["api-key", "authorization"]:
logged_headers[header] = "<redacted>"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: we have an is_dict() header that would make this slightly cleaner imo

Suggested change
if isinstance(record.args, dict) and "headers" in record.args:
if isinstance(record.args["headers"], dict):
logged_headers: Dict[str, Any] = record.args["headers"]
for header in logged_headers:
if header.lower() in ["api-key", "authorization"]:
logged_headers[header] = "<redacted>"
if is_dict(record.args) and "headers" in record.args and is_dict(record.args["headers"]):
headers = record.args["headers"]
for header in headers:
if str(header).lower() in ["api-key", "authorization"]:
headers[header] = "<redacted>"

and from ._utils import is_dict.

also a minor micro optimisation but I think we should extract the list of headers, e.g.

SENSITIVE_HEADERS = {"api-key", "authorization"}

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

also I haven't actually written a log filter before, is it bad that this mutates the original headers arg? i.e. should it be this?

            headers = record.args["headers"] = {**record.args["headers"]}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Updated with your revisions, thanks! The logging docs for filter permits in-place modification:

If deemed appropriate, the record may be modified in-place.

return True
92 changes: 92 additions & 0 deletions tests/test_utils/test_logging.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,92 @@
import logging
from typing import Any, Dict, cast

import pytest

from openai._utils import APIKeyFilter


@pytest.fixture
def logger_with_filter() -> logging.Logger:
logger = logging.getLogger("test_logger")
logger.setLevel(logging.DEBUG)
logger.addFilter(APIKeyFilter())
return logger


def test_keys_redacted(logger_with_filter: logging.Logger, caplog: pytest.LogCaptureFixture) -> None:
with caplog.at_level(logging.DEBUG):
logger_with_filter.debug(
"Request options: %s",
{
"method": "post",
"url": "chat/completions",
"headers": {"api-key": "12345", "Authorization": "Bearer token"}
},
)

log_record = cast(Dict[str, Any], caplog.records[0].args)
assert log_record["method"] == "post"
assert log_record["url"] == "chat/completions"
assert log_record["headers"]["api-key"] == "<redacted>"
assert log_record["headers"]["Authorization"] == "<redacted>"


def test_keys_redacted_case_insensitive(logger_with_filter: logging.Logger, caplog: pytest.LogCaptureFixture) -> None:
with caplog.at_level(logging.DEBUG):
logger_with_filter.debug(
"Request options: %s",
{
"method": "post",
"url": "chat/completions",
"headers": {"Api-key": "12345", "authorization": "Bearer token"}
},
)

log_record = cast(Dict[str, Any], caplog.records[0].args)
assert log_record["method"] == "post"
assert log_record["url"] == "chat/completions"
assert log_record["headers"]["Api-key"] == "<redacted>"
assert log_record["headers"]["authorization"] == "<redacted>"


def test_no_headers(logger_with_filter: logging.Logger, caplog: pytest.LogCaptureFixture) -> None:
with caplog.at_level(logging.DEBUG):
logger_with_filter.debug(
"Request options: %s",
{
"method": "post",
"url": "chat/completions"
},
)

log_record = cast(Dict[str, Any], caplog.records[0].args)
assert log_record["method"] == "post"
assert log_record["url"] == "chat/completions"
assert "api-key" not in log_record
assert "Authorization" not in log_record


def test_headers_without_sensitive_info(logger_with_filter: logging.Logger, caplog: pytest.LogCaptureFixture) -> None:
with caplog.at_level(logging.DEBUG):
logger_with_filter.debug(
"Request options: %s",
{
"method": "post",
"url": "chat/completions",
"headers": {"custom": "value"}
}
)

log_record = cast(Dict[str, Any], caplog.records[0].args)
assert log_record["method"] == "post"
assert log_record["url"] == "chat/completions"
assert log_record["headers"] == {"custom": "value"}


def test_standard_debug_msg(logger_with_filter: logging.Logger, caplog: pytest.LogCaptureFixture) -> None:
with caplog.at_level(logging.DEBUG):
logger_with_filter.debug(
"Sending HTTP Request: %s %s", "POST", "chat/completions"
)
assert caplog.messages[0] == "Sending HTTP Request: POST chat/completions"