Repository navigation
Azure KeyVault Backend logging level #33255
Description
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
Activity
arjunanan6 commentedon Aug 9, 2023
The logging level appears to come from azure.core.pipeline.http_logging_policy.
This is the airflow config:
To make this more confusing:
arjunanan6 commentedon Aug 10, 2023
I believe I have an idea for this, please assign to me. :)
malthe commentedon Aug 10, 2023
Easiest is probably to set the logging level in your
$AIRFLOW_HOME/webserver_config.pyfile:arjunanan6 commentedon Aug 10, 2023
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 commentedon Aug 10, 2023
You probably don't care about any
INFOmessages fromazure.coreor below – better to get actual numbers out (i.e., telemetry instead of logging traces).But also, in Airflow,
$AIRFLOW_HOME/webserver_config.pyis configuration to a large extent. But perhaps Airflow should adopt some more sane defaults for its 3rd party dependencies.arjunanan6 commentedon Aug 11, 2023
@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 commentedon Aug 11, 2023
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 commentedon Aug 11, 2023
It could also be added to the
clientmethod, 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.
potiuk commentedon Aug 13, 2023
Yeah. I agree it's maybe not the best solution but better than leaving the defaults on. Indeed the policies are far to "chatty" on those, and since there is a way (A bit hidden) to change it, we can leave with it.
Better solution would be likely to add "azure" provider configuration (As of Airflow 2.7 we have the ability to add configuration in the providers) but for now same way as in WASB hook is probably good-enough.