diff --git a/sdk/storage/azure-storage-blob/README.md b/sdk/storage/azure-storage-blob/README.md index 992a1493984c..a788684d12d2 100644 --- a/sdk/storage/azure-storage-blob/README.md +++ b/sdk/storage/azure-storage-blob/README.md @@ -345,6 +345,8 @@ Other optional configuration keyword arguments that can be specified on the clie * __user_agent__ (str): Appends the custom value to the user-agent header to be sent with the request. * __logging_enable__ (bool): Enables logging at the DEBUG level. Defaults to False. Can also be passed in at the client level to enable it for all requests. +* __logging_body__ (bool): Enables logging the request and response body. Defaults to False. Can also be passed in at +the client level to enable it for all requests. * __headers__ (dict): Pass in custom headers as key, value pairs. E.g. `headers={'CustomValue': value}` ## Troubleshooting diff --git a/sdk/storage/azure-storage-blob/azure/storage/blob/_shared/policies.py b/sdk/storage/azure-storage-blob/azure/storage/blob/_shared/policies.py index 00068a7ba112..c6c6bb9aa5cc 100644 --- a/sdk/storage/azure-storage-blob/azure/storage/blob/_shared/policies.py +++ b/sdk/storage/azure-storage-blob/azure/storage/blob/_shared/policies.py @@ -12,7 +12,6 @@ from io import SEEK_SET, UnsupportedOperation import logging import uuid -import types from typing import Any, TYPE_CHECKING from wsgiref.handlers import format_date_time try: @@ -183,11 +182,15 @@ class StorageLoggingPolicy(NetworkTraceLoggingPolicy): This accepts both global configuration, and per-request level with "enable_http_logger" """ + def __init__(self, logging_enable=False, **kwargs): + self.logging_body = kwargs.pop("logging_body", False) + super(StorageLoggingPolicy, self).__init__(logging_enable=logging_enable, **kwargs) def on_request(self, request): # type: (PipelineRequest, Any) -> None http_request = request.http_request options = request.context.options + self.logging_body = self.logging_body or options.pop("logging_body", False) if options.pop("logging_enable", self.enable_http_logger): request.context["logging_enable"] = True if not _LOGGER.isEnabledFor(logging.DEBUG): @@ -216,11 +219,11 @@ def on_request(self, request): _LOGGER.debug(" %r: %r", header, value) _LOGGER.debug("Request body:") - # We don't want to log the binary data of a file upload. - if isinstance(http_request.body, types.GeneratorType): - _LOGGER.debug("File upload") - else: + if self.logging_body: _LOGGER.debug(str(http_request.body)) + else: + # We don't want to log the binary data of a file upload. + _LOGGER.debug("Hidden body, please use logging_body to show body") except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log request: %r", err) @@ -240,19 +243,24 @@ def on_response(self, request, response): _LOGGER.debug("Response content:") pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE) header = response.http_response.headers.get('content-disposition') + resp_content_type = response.http_response.headers.get("content-type", "") if header and pattern.match(header): filename = header.partition('=')[2] _LOGGER.debug("File attachments: %s", filename) - elif response.http_response.headers.get("content-type", "").endswith("octet-stream"): + elif resp_content_type.endswith("octet-stream"): _LOGGER.debug("Body contains binary data.") - elif response.http_response.headers.get("content-type", "").startswith("image"): + elif resp_content_type.startswith("image"): _LOGGER.debug("Body contains image data.") - else: - if response.context.options.get('stream', False): + + if self.logging_body and resp_content_type.startswith("text"): + _LOGGER.debug(response.http_response.text()) + elif self.logging_body: + try: + _LOGGER.debug(response.http_response.body()) + except ValueError: _LOGGER.debug("Body is streamable") - else: - _LOGGER.debug(response.http_response.text()) + except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log response: %s", repr(err)) diff --git a/sdk/storage/azure-storage-blob/tests/recordings/test_logging.test_logging_request_and_response_body.yaml b/sdk/storage/azure-storage-blob/tests/recordings/test_logging.test_logging_request_and_response_body.yaml new file mode 100644 index 000000000000..a7a7f2afe918 --- /dev/null +++ b/sdk/storage/azure-storage-blob/tests/recordings/test_logging.test_logging_request_and_response_body.yaml @@ -0,0 +1,253 @@ +interactions: +- request: + body: null + headers: + Accept: + - application/xml + Accept-Encoding: + - gzip, deflate + Connection: + - keep-alive + Content-Length: + - '0' + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-date: + - Thu, 22 Jul 2021 00:58:15 GMT + x-ms-version: + - '2020-08-04' + method: PUT + uri: https://storagename.blob.core.windows.net/utcontainer21d61510?restype=container + response: + body: + string: "\uFEFFContainerAlreadyExistsThe + specified container already exists.\nRequestId:e1cc4389-801e-00bf-1f94-7e6451000000\nTime:2021-07-22T00:58:15.9669124Z" + headers: + content-length: + - '230' + content-type: + - application/xml + date: + - Thu, 22 Jul 2021 00:58:15 GMT + server: + - Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + x-ms-error-code: + - ContainerAlreadyExists + x-ms-version: + - '2020-08-04' + status: + code: 409 + message: The specified container already exists. +- request: + body: aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa + headers: + Accept: + - application/xml + Accept-Encoding: + - gzip, deflate + Connection: + - keep-alive + Content-Length: + - '4096' + Content-Type: + - application/octet-stream + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-blob-type: + - BlockBlob + x-ms-date: + - Thu, 22 Jul 2021 00:58:16 GMT + x-ms-version: + - '2020-08-04' + method: PUT + uri: https://storagename.blob.core.windows.net/utcontainer21d61510/srcblob21d61510 + response: + body: + string: '' + headers: + content-length: + - '0' + content-md5: + - IaGZxT9CKjgOILFi+26+nA== + date: + - Thu, 22 Jul 2021 00:58:15 GMT + etag: + - '"0x8D94CABC9EBBC01"' + last-modified: + - Thu, 22 Jul 2021 00:58:16 GMT + server: + - Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + x-ms-content-crc64: + - Ep3PX5ZZvPI= + x-ms-request-server-encrypted: + - 'true' + x-ms-version: + - '2020-08-04' + status: + code: 201 + message: Created +- request: + body: testloggingbody + headers: + Accept: + - application/xml + Accept-Encoding: + - gzip, deflate + Connection: + - keep-alive + Content-Length: + - '15' + Content-Type: + - application/octet-stream + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-blob-type: + - BlockBlob + x-ms-date: + - Thu, 22 Jul 2021 00:58:16 GMT + x-ms-version: + - '2020-08-04' + method: PUT + uri: https://storagename.blob.core.windows.net/utcontainer21d61510/testloggingblob21d61510 + response: + body: + string: '' + headers: + content-length: + - '0' + content-md5: + - kiWDMg2eTMJ7rcIxBGHjdQ== + date: + - Thu, 22 Jul 2021 00:58:15 GMT + etag: + - '"0x8D94CABC9FF6EAB"' + last-modified: + - Thu, 22 Jul 2021 00:58:16 GMT + server: + - Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + x-ms-content-crc64: + - V9QvlmP+jQ4= + x-ms-request-server-encrypted: + - 'true' + x-ms-version: + - '2020-08-04' + status: + code: 201 + message: Created +- request: + body: null + headers: + Accept: + - application/xml + Accept-Encoding: + - gzip, deflate + Connection: + - keep-alive + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-date: + - Thu, 22 Jul 2021 00:58:16 GMT + x-ms-range: + - bytes=0-33554431 + x-ms-version: + - '2020-08-04' + method: GET + uri: https://storagename.blob.core.windows.net/utcontainer21d61510/testloggingblob21d61510 + response: + body: + string: testloggingbody + headers: + accept-ranges: + - bytes + content-length: + - '15' + content-range: + - bytes 0-14/15 + content-type: + - application/octet-stream + date: + - Thu, 22 Jul 2021 00:58:15 GMT + etag: + - '"0x8D94CABC9FF6EAB"' + last-modified: + - Thu, 22 Jul 2021 00:58:16 GMT + server: + - Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + vary: + - Origin + x-ms-blob-content-md5: + - kiWDMg2eTMJ7rcIxBGHjdQ== + x-ms-blob-type: + - BlockBlob + x-ms-creation-time: + - Thu, 22 Jul 2021 00:18:58 GMT + x-ms-lease-state: + - available + x-ms-lease-status: + - unlocked + x-ms-server-encrypted: + - 'true' + x-ms-version: + - '2020-08-04' + status: + code: 206 + message: Partial Content +- request: + body: null + headers: + Accept: + - application/xml + Accept-Encoding: + - gzip, deflate + Connection: + - keep-alive + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-date: + - Thu, 22 Jul 2021 00:58:16 GMT + x-ms-range: + - bytes=0-33554431 + x-ms-version: + - '2020-08-04' + method: GET + uri: https://storagename.blob.core.windows.net/utcontainer21d61510/testloggingblob21d61510 + response: + body: + string: testloggingbody + headers: + accept-ranges: + - bytes + content-length: + - '15' + content-range: + - bytes 0-14/15 + content-type: + - application/octet-stream + date: + - Thu, 22 Jul 2021 00:58:15 GMT + etag: + - '"0x8D94CABC9FF6EAB"' + last-modified: + - Thu, 22 Jul 2021 00:58:16 GMT + server: + - Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + vary: + - Origin + x-ms-blob-content-md5: + - kiWDMg2eTMJ7rcIxBGHjdQ== + x-ms-blob-type: + - BlockBlob + x-ms-creation-time: + - Thu, 22 Jul 2021 00:18:58 GMT + x-ms-lease-state: + - available + x-ms-lease-status: + - unlocked + x-ms-server-encrypted: + - 'true' + x-ms-version: + - '2020-08-04' + status: + code: 206 + message: Partial Content +version: 1 diff --git a/sdk/storage/azure-storage-blob/tests/recordings/test_logging_async.test_logging_request_and_response_body.yaml b/sdk/storage/azure-storage-blob/tests/recordings/test_logging_async.test_logging_request_and_response_body.yaml new file mode 100644 index 000000000000..71ab0b488355 --- /dev/null +++ b/sdk/storage/azure-storage-blob/tests/recordings/test_logging_async.test_logging_request_and_response_body.yaml @@ -0,0 +1,141 @@ +interactions: +- request: + body: null + headers: + Accept: + - application/xml + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-date: + - Thu, 22 Jul 2021 00:58:07 GMT + x-ms-version: + - '2020-08-04' + method: PUT + uri: https://storagename.blob.core.windows.net/utcontainera9a0178d?restype=container + response: + body: + string: "\uFEFFContainerAlreadyExistsThe + specified container already exists.\nRequestId:841a715d-701e-00bb-2394-7ee956000000\nTime:2021-07-22T00:58:07.4850376Z" + headers: + content-length: '230' + content-type: application/xml + date: Thu, 22 Jul 2021 00:58:06 GMT + server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + x-ms-error-code: ContainerAlreadyExists + x-ms-version: '2020-08-04' + status: + code: 409 + message: The specified container already exists. + url: https://emilydevtest.blob.core.windows.net/utcontainera9a0178d?restype=container +- request: + body: testloggingbody + headers: + Accept: + - application/xml + Content-Length: + - '15' + Content-Type: + - application/octet-stream + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-blob-type: + - BlockBlob + x-ms-date: + - Thu, 22 Jul 2021 00:58:07 GMT + x-ms-version: + - '2020-08-04' + method: PUT + uri: https://storagename.blob.core.windows.net/utcontainera9a0178d/testloggingbloba9a0178d + response: + body: + string: '' + headers: + content-length: '0' + content-md5: kiWDMg2eTMJ7rcIxBGHjdQ== + date: Thu, 22 Jul 2021 00:58:06 GMT + etag: '"0x8D94CABC4D57331"' + last-modified: Thu, 22 Jul 2021 00:58:07 GMT + server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + x-ms-content-crc64: V9QvlmP+jQ4= + x-ms-request-server-encrypted: 'true' + x-ms-version: '2020-08-04' + status: + code: 201 + message: Created + url: https://emilydevtest.blob.core.windows.net/utcontainera9a0178d/testloggingbloba9a0178d +- request: + body: null + headers: + Accept: + - application/xml + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-date: + - Thu, 22 Jul 2021 00:58:07 GMT + x-ms-range: + - bytes=0-33554431 + x-ms-version: + - '2020-08-04' + method: GET + uri: https://storagename.blob.core.windows.net/utcontainera9a0178d/testloggingbloba9a0178d + response: + body: + string: testloggingbody + headers: + accept-ranges: bytes + content-length: '15' + content-range: bytes 0-14/15 + content-type: application/octet-stream + date: Thu, 22 Jul 2021 00:58:06 GMT + etag: '"0x8D94CABC4D57331"' + last-modified: Thu, 22 Jul 2021 00:58:07 GMT + server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + vary: Origin + x-ms-blob-content-md5: kiWDMg2eTMJ7rcIxBGHjdQ== + x-ms-blob-type: BlockBlob + x-ms-creation-time: Thu, 22 Jul 2021 00:34:21 GMT + x-ms-lease-state: available + x-ms-lease-status: unlocked + x-ms-server-encrypted: 'true' + x-ms-version: '2020-08-04' + status: + code: 206 + message: Partial Content + url: https://emilydevtest.blob.core.windows.net/utcontainera9a0178d/testloggingbloba9a0178d +- request: + body: testloggingbody + headers: + Accept: + - application/xml + Content-Length: + - '15' + Content-Type: + - application/octet-stream + User-Agent: + - azsdk-python-storage-blob/12.9.0b1 Python/3.7.3 (Windows-10-10.0.19041-SP0) + x-ms-blob-type: + - BlockBlob + x-ms-date: + - Thu, 22 Jul 2021 00:58:07 GMT + x-ms-version: + - '2020-08-04' + method: PUT + uri: https://storagename.blob.core.windows.net/utcontainera9a0178d/testloggingbloba9a0178d + response: + body: + string: '' + headers: + content-length: '0' + content-md5: kiWDMg2eTMJ7rcIxBGHjdQ== + date: Thu, 22 Jul 2021 00:58:06 GMT + etag: '"0x8D94CABC4DC2B2A"' + last-modified: Thu, 22 Jul 2021 00:58:07 GMT + server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0 + x-ms-content-crc64: V9QvlmP+jQ4= + x-ms-request-server-encrypted: 'true' + x-ms-version: '2020-08-04' + status: + code: 201 + message: Created + url: https://emilydevtest.blob.core.windows.net/utcontainera9a0178d/testloggingbloba9a0178d +version: 1 diff --git a/sdk/storage/azure-storage-blob/tests/test_logging.py b/sdk/storage/azure-storage-blob/tests/test_logging.py index a53cf01dc497..08c18bdb7ad5 100644 --- a/sdk/storage/azure-storage-blob/tests/test_logging.py +++ b/sdk/storage/azure-storage-blob/tests/test_logging.py @@ -42,8 +42,11 @@ def _setup(self, bsc): source_blob = bsc.get_blob_client(self.container_name, self.source_blob_name) if self.is_live: - bsc.create_container(self.container_name) - source_blob.upload_blob(self.source_blob_data) + try: + bsc.create_container(self.container_name) + except: + pass + source_blob.upload_blob(self.source_blob_data, overwrite=True) # generate a SAS so that it is accessible with a URL sas_token = generate_blob_sas( @@ -57,6 +60,28 @@ def _setup(self, bsc): ) sas_source = BlobClient.from_blob_url(source_blob.url, credential=sas_token) self.source_blob_url = sas_source.url + + @BlobPreparer() + def test_logging_request_and_response_body(self, storage_account_name, storage_account_key): + # Arrange + bsc = BlobServiceClient(self.account_url(storage_account_name, "blob"), storage_account_key, logging_enable=True) + self._setup(bsc) + container = bsc.get_container_client(self.container_name) + request_body = 'testloggingbody' + blob_name = self.get_resource_name("testloggingblob") + blob_client = container.get_blob_client(blob_name) + blob_client.upload_blob(request_body, overwrite=True) + # Act + with LogCaptured(self) as log_captured: + blob_client.download_blob() + log_as_str = log_captured.getvalue() + self.assertFalse(request_body in log_as_str) + + with LogCaptured(self) as log_captured: + blob_client.download_blob(logging_body=True) + log_as_str = log_captured.getvalue() + self.assertTrue(request_body in log_as_str) + self.assertEqual(log_as_str.count(request_body), 1) @BlobPreparer() def test_authorization_is_scrubbed_off(self, storage_account_name, storage_account_key): diff --git a/sdk/storage/azure-storage-blob/tests/test_logging_async.py b/sdk/storage/azure-storage-blob/tests/test_logging_async.py index a5b705cbf13e..2e58e0fb7ab6 100644 --- a/sdk/storage/azure-storage-blob/tests/test_logging_async.py +++ b/sdk/storage/azure-storage-blob/tests/test_logging_async.py @@ -85,7 +85,28 @@ async def _setup(self, bsc): pass @BlobPreparer() - @AsyncStorageTestCase.await_prepared_test + async def test_logging_request_and_response_body(self, storage_account_name, storage_account_key): + bsc = BlobServiceClient(self.account_url(storage_account_name, "blob"), storage_account_key, transport=AiohttpTestTransport(), logging_enable=True) + await self._setup(bsc) + # Arrange + container = bsc.get_container_client(self.container_name) + request_body = 'testloggingbody' + blob_name = self.get_resource_name("testloggingblob") + blob_client = container.get_blob_client(blob_name) + await blob_client.upload_blob(request_body, overwrite=True) + # Act + with LogCaptured(self) as log_captured: + await blob_client.download_blob() + log_as_str = log_captured.getvalue() + self.assertFalse(request_body in log_as_str) + + with LogCaptured(self) as log_captured: + await blob_client.upload_blob(request_body, overwrite=True, logging_body=True) + log_as_str = log_captured.getvalue() + self.assertTrue(request_body in log_as_str) + self.assertEqual(log_as_str.count(request_body), 1) + + @BlobPreparer() async def test_authorization_is_scrubbed_off(self, storage_account_name, storage_account_key): bsc = BlobServiceClient(self.account_url(storage_account_name, "blob"), storage_account_key, transport=AiohttpTestTransport()) await self._setup(bsc) diff --git a/sdk/storage/azure-storage-file-datalake/README.md b/sdk/storage/azure-storage-file-datalake/README.md index 7e8ead8ad8b4..f9a95d9ebb8f 100644 --- a/sdk/storage/azure-storage-file-datalake/README.md +++ b/sdk/storage/azure-storage-file-datalake/README.md @@ -159,6 +159,44 @@ for path in paths: print(path.name + '\n') ``` +## Optional Configuration + +Optional keyword arguments that can be passed in at the client and per-operation level. + +### Retry Policy configuration + +Use the following keyword arguments when instantiating a client to configure the retry policy: + +* __retry_total__ (int): Total number of retries to allow. Takes precedence over other counts. +Pass in `retry_total=0` if you do not want to retry on requests. Defaults to 10. +* __retry_connect__ (int): How many connection-related errors to retry on. Defaults to 3. +* __retry_read__ (int): How many times to retry on read errors. Defaults to 3. +* __retry_status__ (int): How many times to retry on bad status codes. Defaults to 3. +* __retry_to_secondary__ (bool): Whether the request should be retried to secondary, if able. +This should only be enabled of RA-GRS accounts are used and potentially stale data can be handled. +Defaults to `False`. + +### Other client / per-operation configuration + +Other optional configuration keyword arguments that can be specified on the client or per-operation. + +**Client keyword arguments:** + +* __connection_timeout__ (int): Optionally sets the connect and read timeout value, in seconds. +* __transport__ (Any): User-provided transport to send the HTTP request. + +**Per-operation keyword arguments:** + +* __raw_response_hook__ (callable): The given callback uses the response returned from the service. +* __raw_request_hook__ (callable): The given callback uses the request before being sent to service. +* __client_request_id__ (str): Optional user specified identification of the request. +* __user_agent__ (str): Appends the custom value to the user-agent header to be sent with the request. +* __logging_enable__ (bool): Enables logging at the DEBUG level. Defaults to False. Can also be passed in at +the client level to enable it for all requests. +* __logging_body__ (bool): Enables logging the request and response body. Defaults to False. Can also be passed in at +the client level to enable it for all requests. +* __headers__ (dict): Pass in custom headers as key, value pairs. E.g. `headers={'CustomValue': value}` + ## Troubleshooting ### General DataLake Storage clients raise exceptions defined in [Azure Core](https://github.com/Azure/azure-sdk-for-python/blob/main/sdk/core/azure-core/README.md). diff --git a/sdk/storage/azure-storage-file-datalake/azure/storage/filedatalake/_shared/policies.py b/sdk/storage/azure-storage-file-datalake/azure/storage/filedatalake/_shared/policies.py index 00068a7ba112..c6c6bb9aa5cc 100644 --- a/sdk/storage/azure-storage-file-datalake/azure/storage/filedatalake/_shared/policies.py +++ b/sdk/storage/azure-storage-file-datalake/azure/storage/filedatalake/_shared/policies.py @@ -12,7 +12,6 @@ from io import SEEK_SET, UnsupportedOperation import logging import uuid -import types from typing import Any, TYPE_CHECKING from wsgiref.handlers import format_date_time try: @@ -183,11 +182,15 @@ class StorageLoggingPolicy(NetworkTraceLoggingPolicy): This accepts both global configuration, and per-request level with "enable_http_logger" """ + def __init__(self, logging_enable=False, **kwargs): + self.logging_body = kwargs.pop("logging_body", False) + super(StorageLoggingPolicy, self).__init__(logging_enable=logging_enable, **kwargs) def on_request(self, request): # type: (PipelineRequest, Any) -> None http_request = request.http_request options = request.context.options + self.logging_body = self.logging_body or options.pop("logging_body", False) if options.pop("logging_enable", self.enable_http_logger): request.context["logging_enable"] = True if not _LOGGER.isEnabledFor(logging.DEBUG): @@ -216,11 +219,11 @@ def on_request(self, request): _LOGGER.debug(" %r: %r", header, value) _LOGGER.debug("Request body:") - # We don't want to log the binary data of a file upload. - if isinstance(http_request.body, types.GeneratorType): - _LOGGER.debug("File upload") - else: + if self.logging_body: _LOGGER.debug(str(http_request.body)) + else: + # We don't want to log the binary data of a file upload. + _LOGGER.debug("Hidden body, please use logging_body to show body") except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log request: %r", err) @@ -240,19 +243,24 @@ def on_response(self, request, response): _LOGGER.debug("Response content:") pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE) header = response.http_response.headers.get('content-disposition') + resp_content_type = response.http_response.headers.get("content-type", "") if header and pattern.match(header): filename = header.partition('=')[2] _LOGGER.debug("File attachments: %s", filename) - elif response.http_response.headers.get("content-type", "").endswith("octet-stream"): + elif resp_content_type.endswith("octet-stream"): _LOGGER.debug("Body contains binary data.") - elif response.http_response.headers.get("content-type", "").startswith("image"): + elif resp_content_type.startswith("image"): _LOGGER.debug("Body contains image data.") - else: - if response.context.options.get('stream', False): + + if self.logging_body and resp_content_type.startswith("text"): + _LOGGER.debug(response.http_response.text()) + elif self.logging_body: + try: + _LOGGER.debug(response.http_response.body()) + except ValueError: _LOGGER.debug("Body is streamable") - else: - _LOGGER.debug(response.http_response.text()) + except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log response: %s", repr(err)) diff --git a/sdk/storage/azure-storage-file-share/README.md b/sdk/storage/azure-storage-file-share/README.md index 3d483fbdd42e..12e3d448fd4c 100644 --- a/sdk/storage/azure-storage-file-share/README.md +++ b/sdk/storage/azure-storage-file-share/README.md @@ -282,6 +282,8 @@ Other optional configuration keyword arguments that can be specified on the clie * __user_agent__ (str): Appends the custom value to the user-agent header to be sent with the request. * __logging_enable__ (bool): Enables logging at the DEBUG level. Defaults to False. Can also be passed in at the client level to enable it for all requests. +* __logging_body__ (bool): Enables logging the request and response body. Defaults to False. Can also be passed in at +the client level to enable it for all requests. * __headers__ (dict): Pass in custom headers as key, value pairs. E.g. `headers={'CustomValue': value}` diff --git a/sdk/storage/azure-storage-file-share/azure/storage/fileshare/_shared/policies.py b/sdk/storage/azure-storage-file-share/azure/storage/fileshare/_shared/policies.py index 00068a7ba112..c6c6bb9aa5cc 100644 --- a/sdk/storage/azure-storage-file-share/azure/storage/fileshare/_shared/policies.py +++ b/sdk/storage/azure-storage-file-share/azure/storage/fileshare/_shared/policies.py @@ -12,7 +12,6 @@ from io import SEEK_SET, UnsupportedOperation import logging import uuid -import types from typing import Any, TYPE_CHECKING from wsgiref.handlers import format_date_time try: @@ -183,11 +182,15 @@ class StorageLoggingPolicy(NetworkTraceLoggingPolicy): This accepts both global configuration, and per-request level with "enable_http_logger" """ + def __init__(self, logging_enable=False, **kwargs): + self.logging_body = kwargs.pop("logging_body", False) + super(StorageLoggingPolicy, self).__init__(logging_enable=logging_enable, **kwargs) def on_request(self, request): # type: (PipelineRequest, Any) -> None http_request = request.http_request options = request.context.options + self.logging_body = self.logging_body or options.pop("logging_body", False) if options.pop("logging_enable", self.enable_http_logger): request.context["logging_enable"] = True if not _LOGGER.isEnabledFor(logging.DEBUG): @@ -216,11 +219,11 @@ def on_request(self, request): _LOGGER.debug(" %r: %r", header, value) _LOGGER.debug("Request body:") - # We don't want to log the binary data of a file upload. - if isinstance(http_request.body, types.GeneratorType): - _LOGGER.debug("File upload") - else: + if self.logging_body: _LOGGER.debug(str(http_request.body)) + else: + # We don't want to log the binary data of a file upload. + _LOGGER.debug("Hidden body, please use logging_body to show body") except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log request: %r", err) @@ -240,19 +243,24 @@ def on_response(self, request, response): _LOGGER.debug("Response content:") pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE) header = response.http_response.headers.get('content-disposition') + resp_content_type = response.http_response.headers.get("content-type", "") if header and pattern.match(header): filename = header.partition('=')[2] _LOGGER.debug("File attachments: %s", filename) - elif response.http_response.headers.get("content-type", "").endswith("octet-stream"): + elif resp_content_type.endswith("octet-stream"): _LOGGER.debug("Body contains binary data.") - elif response.http_response.headers.get("content-type", "").startswith("image"): + elif resp_content_type.startswith("image"): _LOGGER.debug("Body contains image data.") - else: - if response.context.options.get('stream', False): + + if self.logging_body and resp_content_type.startswith("text"): + _LOGGER.debug(response.http_response.text()) + elif self.logging_body: + try: + _LOGGER.debug(response.http_response.body()) + except ValueError: _LOGGER.debug("Body is streamable") - else: - _LOGGER.debug(response.http_response.text()) + except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log response: %s", repr(err)) diff --git a/sdk/storage/azure-storage-queue/README.md b/sdk/storage/azure-storage-queue/README.md index 4a953ef4686c..c8c714c7beb0 100644 --- a/sdk/storage/azure-storage-queue/README.md +++ b/sdk/storage/azure-storage-queue/README.md @@ -298,6 +298,8 @@ Other optional configuration keyword arguments that can be specified on the clie * __user_agent__ (str): Appends the custom value to the user-agent header to be sent with the request. * __logging_enable__ (bool): Enables logging at the DEBUG level. Defaults to False. Can also be passed in at the client level to enable it for all requests. +* __logging_body__ (bool): Enables logging the request and response body. Defaults to False. Can also be passed in at +the client level to enable it for all requests. * __headers__ (dict): Pass in custom headers as key, value pairs. E.g. `headers={'CustomValue': value}` diff --git a/sdk/storage/azure-storage-queue/azure/storage/queue/_shared/policies.py b/sdk/storage/azure-storage-queue/azure/storage/queue/_shared/policies.py index 00068a7ba112..c6c6bb9aa5cc 100644 --- a/sdk/storage/azure-storage-queue/azure/storage/queue/_shared/policies.py +++ b/sdk/storage/azure-storage-queue/azure/storage/queue/_shared/policies.py @@ -12,7 +12,6 @@ from io import SEEK_SET, UnsupportedOperation import logging import uuid -import types from typing import Any, TYPE_CHECKING from wsgiref.handlers import format_date_time try: @@ -183,11 +182,15 @@ class StorageLoggingPolicy(NetworkTraceLoggingPolicy): This accepts both global configuration, and per-request level with "enable_http_logger" """ + def __init__(self, logging_enable=False, **kwargs): + self.logging_body = kwargs.pop("logging_body", False) + super(StorageLoggingPolicy, self).__init__(logging_enable=logging_enable, **kwargs) def on_request(self, request): # type: (PipelineRequest, Any) -> None http_request = request.http_request options = request.context.options + self.logging_body = self.logging_body or options.pop("logging_body", False) if options.pop("logging_enable", self.enable_http_logger): request.context["logging_enable"] = True if not _LOGGER.isEnabledFor(logging.DEBUG): @@ -216,11 +219,11 @@ def on_request(self, request): _LOGGER.debug(" %r: %r", header, value) _LOGGER.debug("Request body:") - # We don't want to log the binary data of a file upload. - if isinstance(http_request.body, types.GeneratorType): - _LOGGER.debug("File upload") - else: + if self.logging_body: _LOGGER.debug(str(http_request.body)) + else: + # We don't want to log the binary data of a file upload. + _LOGGER.debug("Hidden body, please use logging_body to show body") except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log request: %r", err) @@ -240,19 +243,24 @@ def on_response(self, request, response): _LOGGER.debug("Response content:") pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE) header = response.http_response.headers.get('content-disposition') + resp_content_type = response.http_response.headers.get("content-type", "") if header and pattern.match(header): filename = header.partition('=')[2] _LOGGER.debug("File attachments: %s", filename) - elif response.http_response.headers.get("content-type", "").endswith("octet-stream"): + elif resp_content_type.endswith("octet-stream"): _LOGGER.debug("Body contains binary data.") - elif response.http_response.headers.get("content-type", "").startswith("image"): + elif resp_content_type.startswith("image"): _LOGGER.debug("Body contains image data.") - else: - if response.context.options.get('stream', False): + + if self.logging_body and resp_content_type.startswith("text"): + _LOGGER.debug(response.http_response.text()) + elif self.logging_body: + try: + _LOGGER.debug(response.http_response.body()) + except ValueError: _LOGGER.debug("Body is streamable") - else: - _LOGGER.debug(response.http_response.text()) + except Exception as err: # pylint: disable=broad-except _LOGGER.debug("Failed to log response: %s", repr(err))