Search request/response headers should be DEBUG level, not INFO

[pamelafox]

Is your feature request related to a problem? Please describe.

We are seeing overly verbose output when using INFO level logging in our Python applications:

2024-01-19 20:24:10 (INFO) azure.core.pipeline.policies.http_logging_policy: Request URL: 'https://gptkb-ifvo2edlwe6vw.search.windows.net/indexes('gptkbindex')/docs/search.post.search?api-version=REDACTED'
Request method: 'POST'
Request headers:
    'Content-Type': 'application/json'
    'Content-Length': '27'
    'Accept': 'application/json'
    'x-ms-client-request-id': 'b399733a-b708-11ee-ae3d-002248c0058c'
    'User-Agent': 'azsdk-python-search-documents/11.4.0 Python/3.11.7 (Linux-6.2.0-1018-azure-x86_64-with-glibc2.36)'
    'Authorization': 'REDACTED'
A body is sent with the request
2024-01-19 20:24:14 (INFO) azure.core.pipeline.policies.http_logging_policy: Response status: 200
Response headers:
    'Transfer-Encoding': 'chunked'
    'Content-Type': 'application/json; odata.metadata=minimal; odata.streaming=true; charset=utf-8'
    'Content-Encoding': 'REDACTED'
    'Vary': 'REDACTED'
    'Server': 'Microsoft-IIS/10.0'
    'Strict-Transport-Security': 'REDACTED'
    'Preference-Applied': 'REDACTED'
    'OData-Version': 'REDACTED'
    'request-id': 'b399733a-b708-11ee-ae3d-002248c0058c'
    'elapsed-time': 'REDACTED'
    'Date': 'Fri, 19 Jan 2024 20:24:11 GMT'

I believe this is coming from azure-documents-search, from this line of code:

    search_client = SearchClient(
        endpoint=f"https://{os.environ['AZURE_SEARCH_SERVICE']}.search.windows.net",
        index_name=os.environ["AZURE_SEARCH_INDEX"],
        credential=azure_credential,
    )
    r = search_client.search("", top=1000)

We're also surprised by the number of REDACTED headers, but we wouldn't be worried if we just didn't see them at all.

Describe the solution you'd like

We think those headers should be at DEBUG level. Similar headers are shown at DEBUG level for other SDKs.

Describe alternatives you've considered

We've considered using print() instead of logging.info() so that we don't have to see these logs, but it's better practice to use info().

[kristapratico]

@pamelafox thanks for your feedback. What's logged here is controlled by the underlying azure-core library. I'll add a few core owners for their perspective: @xiangyan99 @kashifkhan @iscai-msft , but also wondering what would you want to see at the INFO level?

I'll leave this tagged as Search as well since it's possible we might want to unredact some of these headers/params, e.g. api-version.

[pamelafox]

@kristapratico Good question! I don't mind this output so much:

INFO:azure.identity.aio._credentials.environment:Incomplete environment configuration for EnvironmentCredential. These variables are set: AZURE_TENANT_ID
INFO:azure.identity.aio._credentials.managed_identity:ManagedIdentityCredential will use IMDS

Although I also think those would be fine at DEBUG level. It's good design question as to what should be an INFO level. Hm. I do know that both me and other developers were surprised to see the headers output, so I think that should be DEBUG level, but I don't have a solid heuristic yet for INFO vs DEBUG.

[kristapratico]

Got it, thanks for your perspective @pamelafox.

I know we've received other feedback regarding INFO logging being too verbose. Quick search brought up two more related issues: #29215 #33623

@johanste @annatisch @lmazuel what are your thoughts on this? At this point I'm not sure that we can drastically change what's included in INFO without impacting customers. Should we consider a custom logging level?