Azure KeyVault Backend logging level

[arjunanan6]

Apache Airflow version

2.6.3

What happened

I've set up Azure keyvaults as a backend for fetching connections, and it works fine. However, there's just too much logging and it's causing issues for our users to read logs. For example:

[2023-08-09, 13:32:30 CEST] {_universal.py:513} INFO - Request URL: 'https://REDACTED.vault.azure.net/secrets/airflow-connections-ode-odbc-dev-dw/?api-version=REDACTED'
Request method: 'GET'
Request headers:
    'Accept': 'application/json'
    'x-ms-client-request-id': '6cdf2a74-36a8-11ee-8cac-6ac595ee5ea6'
    'User-Agent': 'azsdk-python-keyvault-secrets/4.7.0 Python/3.9.17 (Linux-5.4.0-1111-azure-x86_64-with-glibc2.31)'
No body was attached to the request
[2023-08-09, 13:32:30 CEST] {_universal.py:549} INFO - Response status: 401
Response headers:
    'Cache-Control': 'no-cache'
    'Pragma': 'no-cache'
    'Content-Length': '97'
    'Content-Type': 'application/json; charset=utf-8'
    'Expires': '-1'
    'WWW-Authenticate': 'Bearer authorization="https://login.microsoftonline.com/100b3c99-f3e2-4da0-9c8a-b9d345742c36", resource="https://vault.azure.net"'
    'x-ms-keyvault-region': 'REDACTED'
    'x-ms-client-request-id': '6cdf2a74-36a8-11ee-8cac-6ac595ee5ea6'
    'x-ms-request-id': '563d7428-9df4-4d6a-9766-19626395056f'
    'x-ms-keyvault-service-version': '1.9.908.1'
    'x-ms-keyvault-network-info': 'conn_type=Ipv4;addr=20.76.1.64;act_addr_fam=InterNetwork;'
    'X-Content-Type-Options': 'REDACTED'
    'Strict-Transport-Security': 'REDACTED'
    'Date': 'Wed, 09 Aug 2023 11:32:30 GMT'
[2023-08-09, 13:32:30 CEST] {_universal.py:513} INFO - Request URL: 'https://login.microsoftonline.com/100b3c99-f3e2-4da0-9c8a-b9d345742c36/v2.0/.well-known/openid-configuration'
Request method: 'GET'
Request headers:
    'User-Agent': 'azsdk-python-identity/1.13.0 Python/3.9.17 (Linux-5.4.0-1111-azure-x86_64-with-glibc2.31)'
No body was attached to the request
[2023-08-09, 13:32:30 CEST] {_universal.py:549} INFO - Response status: 200
Response headers:
    'Cache-Control': 'max-age=86400, private'
    'Content-Type': 'application/json; charset=utf-8'
    'Strict-Transport-Security': 'REDACTED'
    'X-Content-Type-Options': 'REDACTED'
    'Access-Control-Allow-Origin': 'REDACTED'
    'Access-Control-Allow-Methods': 'REDACTED'
    'P3P': 'REDACTED'
    'x-ms-request-id': '80869b0e-4cde-47f7-8721-3f430a8c3600'
    'x-ms-ests-server': 'REDACTED'
    'X-XSS-Protection': 'REDACTED'
    'Set-Cookie': 'REDACTED'
    'Date': 'Wed, 09 Aug 2023 11:32:30 GMT'
    'Content-Length': '1753'
[2023-08-09, 13:32:30 CEST] {_universal.py:513} INFO - Request URL: 'https://login.microsoftonline.com/common/discovery/instance?api-version=REDACTED&authorization_endpoint=REDACTED'
Request method: 'GET'
Request headers:
    'Accept': 'application/json'
    'User-Agent': 'azsdk-python-identity/1.13.0 Python/3.9.17 (Linux-5.4.0-1111-azure-x86_64-with-glibc2.31)'
No body was attached to the request
[2023-08-09, 13:32:30 CEST] {_universal.py:549} INFO - Response status: 200
Response headers:
    'Cache-Control': 'max-age=86400, private'
    'Content-Type': 'application/json; charset=utf-8'
    'Strict-Transport-Security': 'REDACTED'
    'X-Content-Type-Options': 'REDACTED'
    'Access-Control-Allow-Origin': 'REDACTED'
    'Access-Control-Allow-Methods': 'REDACTED'
    'P3P': 'REDACTED'
    'x-ms-request-id': '93b3dfad-72c7-4629-8625-d2b335363a00'
    'x-ms-ests-server': 'REDACTED'
    'X-XSS-Protection': 'REDACTED'
    'Set-Cookie': 'REDACTED'
    'Date': 'Wed, 09 Aug 2023 11:32:30 GMT'
    'Content-Length': '945'
[2023-08-09, 13:32:30 CEST] {_universal.py:510} INFO - Request URL: 'https://login.microsoftonline.com/100b3c99-f3e2-4da0-9c8a-b9d345742c36/oauth2/v2.0/token'
Request method: 'POST'
Request headers:
    'Accept': 'application/json'
    'x-client-sku': 'REDACTED'
    'x-client-ver': 'REDACTED'
    'x-client-os': 'REDACTED'
    'x-client-cpu': 'REDACTED'
    'x-ms-lib-capability': 'REDACTED'
    'client-request-id': 'REDACTED'
    'x-client-current-telemetry': 'REDACTED'
    'x-client-last-telemetry': 'REDACTED'
    'User-Agent': 'azsdk-python-identity/1.13.0 Python/3.9.17 (Linux-5.4.0-1111-azure-x86_64-with-glibc2.31)'
A body is sent with the request
[2023-08-09, 13:32:30 CEST] {_universal.py:549} INFO - Response status: 200
Response headers:
    'Cache-Control': 'no-store, no-cache'
    'Pragma': 'no-cache'
    'Content-Type': 'application/json; charset=utf-8'
    'Expires': '-1'
    'Strict-Transport-Security': 'REDACTED'
    'X-Content-Type-Options': 'REDACTED'
    'P3P': 'REDACTED'
    'client-request-id': 'REDACTED'
    'x-ms-request-id': '79cf595b-4f41-47c3-a370-f9321c533a00'
    'x-ms-ests-server': 'REDACTED'
    'x-ms-clitelem': 'REDACTED'
    'X-XSS-Protection': 'REDACTED'
    'Set-Cookie': 'REDACTED'
    'Date': 'Wed, 09 Aug 2023 11:32:30 GMT'
    'Content-Length': '1313'
[2023-08-09, 13:32:30 CEST] {chained.py:87} INFO - DefaultAzureCredential acquired a token from EnvironmentCredential
[2023-08-09, 13:32:30 CEST] {_universal.py:513} INFO - Request URL: 'https://REDACTED.vault.azure.net/secrets/airflow-connections-ode-odbc-dev-dw/?api-version=REDACTED'
Request method: 'GET'
Request headers:
    'Accept': 'application/json'
    'x-ms-client-request-id': '6cdf2a74-36a8-11ee-8cac-6ac595ee5ea6'
    'User-Agent': 'azsdk-python-keyvault-secrets/4.7.0 Python/3.9.17 (Linux-5.4.0-1111-azure-x86_64-with-glibc2.31)'
    'Authorization': 'REDACTED'
No body was attached to the request
[2023-08-09, 13:32:30 CEST] {_universal.py:549} INFO - Response status: 404
Response headers:
    'Cache-Control': 'no-cache'
    'Pragma': 'no-cache'
    'Content-Length': '332'
    'Content-Type': 'application/json; charset=utf-8'
    'Expires': '-1'
    'x-ms-keyvault-region': 'REDACTED'
    'x-ms-client-request-id': '6cdf2a74-36a8-11ee-8cac-6ac595ee5ea6'
    'x-ms-request-id': 'ac41c47c-30f0-46cf-9157-6e5dba031ffa'
    'x-ms-keyvault-service-version': '1.9.908.1'
    'x-ms-keyvault-network-info': 'conn_type=Ipv4;addr=20.76.1.64;act_addr_fam=InterNetwork;'
    'x-ms-keyvault-rbac-assignment-id': 'REDACTED'
    'x-ms-keyvault-rbac-cache': 'REDACTED'
    'X-Content-Type-Options': 'REDACTED'
    'Strict-Transport-Security': 'REDACTED'
    'Date': 'Wed, 09 Aug 2023 11:32:30 GMT'
[2023-08-09, 13:32:30 CEST] {base.py:73} INFO - Using connection ID 'ode-odbc-dev-dw' for task execution.
[2023-08-09, 13:32:30 CEST] {_universal.py:513} INFO - Request URL: 'https://REDACTED.vault.azure.net/secrets/airflow-connections-ode-odbc-dev-dw/?api-version=REDACTED'
Request method: 'GET'
Request headers:
    'Accept': 'application/json'
    'x-ms-client-request-id': '6d2b797e-36a8-11ee-8cac-6ac595ee5ea6'
    'User-Agent': 'azsdk-python-keyvault-secrets/4.7.0 Python/3.9.17 (Linux-5.4.0-1111-azure-x86_64-with-glibc2.31)'
    'Authorization': 'REDACTED'
No body was attached to the request
[2023-08-09, 13:32:30 CEST] {_universal.py:549} INFO - Response status: 404
Response headers:
    'Cache-Control': 'no-cache'
    'Pragma': 'no-cache'
    'Content-Length': '332'
    'Content-Type': 'application/json; charset=utf-8'
    'Expires': '-1'
    'x-ms-keyvault-region': 'REDACTED'
    'x-ms-client-request-id': '6d2b797e-36a8-11ee-8cac-6ac595ee5ea6'
    'x-ms-request-id': 'ac37f859-14cc-48e3-8a88-6214b96ef75e'
    'x-ms-keyvault-service-version': '1.9.908.1'
    'x-ms-keyvault-network-info': 'conn_type=Ipv4;addr=20.76.1.64;act_addr_fam=InterNetwork;'
    'x-ms-keyvault-rbac-assignment-id': 'REDACTED'
    'x-ms-keyvault-rbac-cache': 'REDACTED'
    'X-Content-Type-Options': 'REDACTED'
    'Strict-Transport-Security': 'REDACTED'
    'Date': 'Wed, 09 Aug 2023 11:32:30 GMT'
[2023-08-09, 13:32:31 CEST] {base.py:73} INFO - Using connection ID 'ode-odbc-dev-dw' for task execution.

Changing airflow logging_level to WARNING/ERROR is one way, but then the task logs don't have sufficient information. Is it possible to influence just the logging level on SecretClient?

What you think should happen instead

Ideally, it should be possible to set logging level specifically for the keyvault backend in the backend_kwargs:

backend_kwargs = {"connections_prefix": "airflow-connections", "variables_prefix": "airflow-variables", "vault_url": "https://example-akv-resource-name.vault.azure.net/", "logging_level": "WARNING"}

How to reproduce

Set up KV backend as described here.

Operating System

Debian GNU/Linux

Versions of Apache Airflow Providers

No response

Deployment

Official Apache Airflow Helm Chart

Deployment details

Deployed with Helm chart on AKS.

Anything else

No response

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Code of Conduct

• I agree to follow this project's Code of Conduct

[arjunanan6]

The logging level appears to come from azure.core.pipeline.http_logging_policy.

This is the airflow config:

airflow config get-value logging logging_level
INFO

To make this more confusing:

>>> logger = logging.getLogger("azure.core.pipeline.policies.http_logging_policy")
>>> logger
<Logger azure.core.pipeline.policies.http_logging_policy (WARNING)>

[arjunanan6]

I believe I have an idea for this, please assign to me. :)

[malthe]

Easiest is probably to set the logging level in your $AIRFLOW_HOME/webserver_config.py file:

logging.getLogger("azure.core").setLevel(logging.WARNING)

[arjunanan6]

Yeah that's exactly the easiest way to do it. I wonder if it should be configurable somehow - probably not necessary.
Otherwise, it's just for:
logging.getLogger('azure.core.pipeline.policies.http_logging_policy')

[malthe]

You probably don't care about any INFO messages from azure.core or below – better to get actual numbers out (i.e., telemetry instead of logging traces).

But also, in Airflow, $AIRFLOW_HOME/webserver_config.py is configuration to a large extent. But perhaps Airflow should adopt some more sane defaults for its 3rd party dependencies.

[arjunanan6]

@malthe It was not set the logging level for azure.core in webserver_config. It looks like a more drastic approach is required like in the PR. This was my first approach to solving this and I can see a very similar approach was used in WasbHook.

[malthe]

I suppose the webserver configuration only applies for the webserver pod ... presumably, you're seeing this from a worker pod. Then another approach is required, but you really shouldn't change a global configuration within the __init__ method of a class ...

That's an unexpected side-effect I think!

Perhaps a plugin such as AzureLoggingDefaults – ?

[arjunanan6]

It could also be added to the client method, that's no problem. I just went with the same approach that was used in the WasbHook, and I suppose in this case it really does not matter since it's applying a global config.

For a quick fix locally for me - absolutely, a plugin could do it. But I really am struggling to see the need for all this verbosity that comes by default for KV interactions. It's just excessive.