From 19aa0c6fc0dbb670831c8cb6df54f715804258ad Mon Sep 17 00:00:00 2001
From: Xiang Yan <xiangyan@microsoft.com>
Date: Mon, 16 Aug 2021 15:28:36 -0700
Subject: [PATCH 1/7] integrate logs

---
 .../core/pipeline/policies/_universal.py      | 216 +++++++++++++-----
 .../test_http_logging_policy_async.py         | 148 ++++++------
 .../tests/test_http_logging_policy.py         | 148 ++++++------
 3 files changed, 321 insertions(+), 191 deletions(-)

diff --git a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
index 1e8d712bc12d..19c141460b48 100644
--- a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
+++ b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
@@ -246,6 +246,8 @@ def on_request(self, request):
 
 
 class NetworkTraceLoggingPolicy(SansIOHTTPPolicy):
+    MULTI_RECORD_LOG = "AZURE_MULTI_RECORD_LOG"
+
     """The logging policy in the pipeline is used to output HTTP network trace to the configured logger.
 
     This accepts both global configuration, and per-request level with "enable_http_logger"
@@ -280,27 +282,55 @@ def on_request(self, request):
                 return
 
             try:
-                _LOGGER.debug("Request URL: %r", http_request.url)
-                _LOGGER.debug("Request method: %r", http_request.method)
-                _LOGGER.debug("Request headers:")
-                for header, value in http_request.headers.items():
-                    _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")
-                    return
-                try:
-                    if isinstance(http_request.body, types.AsyncGeneratorType):
+                multi_record = os.environ.get(NetworkTraceLoggingPolicy.MULTI_RECORD_LOG, False)
+                if multi_record:
+                    _LOGGER.debug("Request URL: %r", http_request.url)
+                    _LOGGER.debug("Request method: %r", http_request.method)
+                    _LOGGER.debug("Request headers:")
+                    for header, value in http_request.headers.items():
+                        _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")
                         return
-                except AttributeError:
-                    pass
-                if http_request.body:
-                    _LOGGER.debug(str(http_request.body))
-                    return
-                _LOGGER.debug("This request has no body")
+                    try:
+                        if isinstance(http_request.body, types.AsyncGeneratorType):
+                            _LOGGER.debug("File upload")
+                            return
+                    except AttributeError:
+                        pass
+                    if http_request.body:
+                        _LOGGER.debug(str(http_request.body))
+                        return
+                    _LOGGER.debug("This request has no body")
+                else:
+                    log_string = "Request URL: '{}'".format(http_request.url)
+                    log_string = "/nRequest method: '{}'".format(http_request.method)
+                    log_string += "/nRequest headers:"
+                    for header, value in http_request.headers.items():
+                        log_string += "/n    '{}': '{}'".format(header, value)
+                    log_string += "/nRequest body:"
+
+                    # We don't want to log the binary data of a file upload.
+                    if isinstance(http_request.body, types.GeneratorType):
+                        log_string += "/nFile upload"
+                        _LOGGER.debug(log_string)
+                        return
+                    try:
+                        if isinstance(http_request.body, types.AsyncGeneratorType):
+                            log_string += "/nFile upload"
+                            _LOGGER.debug(log_string)
+                            return
+                    except AttributeError:
+                        pass
+                    if http_request.body:
+                        log_string += "/n{}}d".format(str(http_request.body))
+                        _LOGGER.debug(log_string)
+                        return
+                    log_string += "/nThis request has no body"
+                    _LOGGER.debug(log_string)
             except Exception as err:  # pylint: disable=broad-except
                 _LOGGER.debug("Failed to log request: %r", err)
 
@@ -320,28 +350,54 @@ def on_response(self, request, response):
                 if not _LOGGER.isEnabledFor(logging.DEBUG):
                     return
 
-                _LOGGER.debug("Response status: %r", http_response.status_code)
-                _LOGGER.debug("Response headers:")
-                for res_header, value in http_response.headers.items():
-                    _LOGGER.debug("    %r: %r", res_header, value)
-
-                # We don't want to log binary data if the response is a file.
-                _LOGGER.debug("Response content:")
-                pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE)
-                header = http_response.headers.get('content-disposition')
-
-                if header and pattern.match(header):
-                    filename = header.partition('=')[2]
-                    _LOGGER.debug("File attachments: %s", filename)
-                elif http_response.headers.get("content-type", "").endswith("octet-stream"):
-                    _LOGGER.debug("Body contains binary data.")
-                elif http_response.headers.get("content-type", "").startswith("image"):
-                    _LOGGER.debug("Body contains image data.")
+                multi_record = os.environ.get(NetworkTraceLoggingPolicy.MULTI_RECORD_LOG, False)
+                if multi_record:
+                    _LOGGER.debug("Response status: %r", http_response.status_code)
+                    _LOGGER.debug("Response headers:")
+                    for res_header, value in http_response.headers.items():
+                        _LOGGER.debug("    %r: %r", res_header, value)
+
+                    # We don't want to log binary data if the response is a file.
+                    _LOGGER.debug("Response content:")
+                    pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE)
+                    header = http_response.headers.get('content-disposition')
+
+                    if header and pattern.match(header):
+                        filename = header.partition('=')[2]
+                        _LOGGER.debug("File attachments: %s", filename)
+                    elif http_response.headers.get("content-type", "").endswith("octet-stream"):
+                        _LOGGER.debug("Body contains binary data.")
+                    elif http_response.headers.get("content-type", "").startswith("image"):
+                        _LOGGER.debug("Body contains image data.")
+                    else:
+                        if response.context.options.get('stream', False):
+                            _LOGGER.debug("Body is streamable")
+                        else:
+                            _LOGGER.debug(http_response.text())
                 else:
-                    if response.context.options.get('stream', False):
-                        _LOGGER.debug("Body is streamable")
+                    log_string = "Response status: '{}'".format(http_response.status_code)
+                    log_string += "/nResponse headers:"
+                    for res_header, value in http_response.headers.items():
+                        log_string += "/n    '{}': '{}'".format(res_header, value)
+
+                    # We don't want to log binary data if the response is a file.
+                    log_string += "/nResponse content:"
+                    pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE)
+                    header = http_response.headers.get('content-disposition')
+
+                    if header and pattern.match(header):
+                        filename = header.partition('=')[2]
+                        log_string += "/nFile attachments: {}".format(filename)
+                    elif http_response.headers.get("content-type", "").endswith("octet-stream"):
+                        log_string += "/nBody contains binary data."
+                    elif http_response.headers.get("content-type", "").startswith("image"):
+                        log_string += "/nBody contains image data."
                     else:
-                        _LOGGER.debug(http_response.text())
+                        if response.context.options.get('stream', False):
+                            log_string += "/nBody is streamable."
+                        else:
+                            log_string += "/n{}}".format(http_response.text())
+                    _LOGGER.debug(log_string)
         except Exception as err:  # pylint: disable=broad-except
             _LOGGER.debug("Failed to log response: %s", repr(err))
 
@@ -376,6 +432,7 @@ class HttpLoggingPolicy(SansIOHTTPPolicy):
         "User-Agent",
     ])
     REDACTED_PLACEHOLDER = "REDACTED"
+    MULTI_RECORD_LOG = "AZURE_MULTI_RECORD_LOG"
 
     def __init__(self, logger=None, **kwargs):  # pylint: disable=unused-argument
         self.logger = logger or logging.getLogger(
@@ -420,26 +477,54 @@ def on_request(self, request):
             parsed_url[4] = "&".join(["=".join(part) for part in filtered_qp])
             redacted_url = urllib.parse.urlunparse(parsed_url)
 
-            logger.info("Request URL: %r", redacted_url)
-            logger.info("Request method: %r", http_request.method)
-            logger.info("Request headers:")
-            for header, value in http_request.headers.items():
-                value = self._redact_header(header, value)
-                logger.info("    %r: %r", header, value)
-            if isinstance(http_request.body, types.GeneratorType):
-                logger.info("File upload")
-                return
-            try:
-                if isinstance(http_request.body, types.AsyncGeneratorType):
+            multi_record = os.environ.get(HttpLoggingPolicy.MULTI_RECORD_LOG, False)
+            if multi_record:
+                logger.info("Request URL: %r", redacted_url)
+                logger.info("Request method: %r", http_request.method)
+                logger.info("Request headers:")
+                for header, value in http_request.headers.items():
+                    value = self._redact_header(header, value)
+                    logger.info("    %r: %r", header, value)
+                if isinstance(http_request.body, types.GeneratorType):
                     logger.info("File upload")
                     return
-            except AttributeError:
-                pass
-            if http_request.body:
-                logger.info("A body is sent with the request")
+                try:
+                    if isinstance(http_request.body, types.AsyncGeneratorType):
+                        logger.info("File upload")
+                        return
+                except AttributeError:
+                    pass
+                if http_request.body:
+                    logger.info("A body is sent with the request")
+                    return
+                logger.info("No body was attached to the request")
                 return
-            logger.info("No body was attached to the request")
-            return
+            else:
+                log_string = "Request URL: '{}'".format(redacted_url)
+                log_string += "/nRequest method: '{}'".format(http_request.method)
+                log_string += "/nRequest headers:"
+                for header, value in http_request.headers.items():
+                    value = self._redact_header(header, value)
+                    log_string += "/n    '{}': '{}'".format(header, value)
+                if isinstance(http_request.body, types.GeneratorType):
+                    log_string += "/nFile upload"
+                    logger.info(log_string)
+                    return
+                try:
+                    if isinstance(http_request.body, types.AsyncGeneratorType):
+                        log_string += "/nFile upload"
+                        logger.info(log_string)
+                        return
+                except AttributeError:
+                    pass
+                if http_request.body:
+                    log_string += "/nA body is sent with the request"
+                    logger.info(log_string)
+                    return
+                log_string += "/nNo body was attached to the request"
+                logger.info(log_string)
+                return
+
         except Exception as err:  # pylint: disable=broad-except
             logger.warning("Failed to log request: %s", repr(err))
 
@@ -453,14 +538,23 @@ def on_response(self, request, response):
             if not logger.isEnabledFor(logging.INFO):
                 return
 
-            logger.info("Response status: %r", http_response.status_code)
-            logger.info("Response headers:")
-            for res_header, value in http_response.headers.items():
-                value = self._redact_header(res_header, value)
-                logger.info("    %r: %r", res_header, value)
+            multi_record = os.environ.get(HttpLoggingPolicy.MULTI_RECORD_LOG, False)
+            if multi_record:
+                logger.info("Response status: %r", http_response.status_code)
+                logger.info("Response headers:")
+                for res_header, value in http_response.headers.items():
+                    value = self._redact_header(res_header, value)
+                    logger.info("    %r: %r", res_header, value)
+            else:
+                log_string = "Response status: {}".format(http_response.status_code)
+                log_string += "/nResponse headers:"
+                for res_header, value in http_response.headers.items():
+                    value = self._redact_header(res_header, value)
+                    log_string += "/n    '{}': '{}'".format(res_header, value)
         except Exception as err:  # pylint: disable=broad-except
             logger.warning("Failed to log response: %s", repr(err))
 
+        logger.info(log_string)
 
 class ContentDecodePolicy(SansIOHTTPPolicy):
     """Policy for decoding unstreamed response content.
diff --git a/sdk/core/azure-core/tests/async_tests/test_http_logging_policy_async.py b/sdk/core/azure-core/tests/async_tests/test_http_logging_policy_async.py
index 13ed07d67af6..d0868898fc02 100644
--- a/sdk/core/azure-core/tests/async_tests/test_http_logging_policy_async.py
+++ b/sdk/core/azure-core/tests/async_tests/test_http_logging_policy_async.py
@@ -53,13 +53,15 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'No body was attached to the request'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -74,19 +76,23 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 12
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
-    assert mock_handler.messages[6].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[7].message == "Request method: 'GET'"
-    assert mock_handler.messages[8].message == 'Request headers:'
-    assert mock_handler.messages[9].message == 'No body was attached to the request'
-    assert mock_handler.messages[10].message == 'Response status: 202'
-    assert mock_handler.messages[11].message == 'Response headers:'
+    assert len(mock_handler.messages) == 4
+    messages_request1 = mock_handler.messages[0].message.split("/n")
+    messages_response1 = mock_handler.messages[1].message.split("/n")
+    messages_request2 = mock_handler.messages[2].message.split("/n")
+    messages_response2 = mock_handler.messages[3].message.split("/n")
+    assert messages_request1[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request1[1] == "Request method: 'GET'"
+    assert messages_request1[2] == 'Request headers:'
+    assert messages_request1[3] == 'No body was attached to the request'
+    assert messages_response1[0] == 'Response status: 202'
+    assert messages_response1[1] == 'Response headers:'
+    assert messages_request2[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request2[1] == "Request method: 'GET'"
+    assert messages_request2[2] == 'Request headers:'
+    assert messages_request2[3] == 'No body was attached to the request'
+    assert messages_response2[0] == 'Response status: 202'
+    assert messages_response2[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -109,25 +115,27 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 10
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/?country=france&city=REDACTED'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == "Request headers:"
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/?country=france&city=REDACTED'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == "Request headers:"
     # Dict not ordered in Python, exact logging order doesn't matter
     assert set([
-        mock_handler.messages[3].message,
-        mock_handler.messages[4].message
+        messages_request[3],
+        messages_request[4]
     ]) == set([
         "    'Accept': 'Caramel'",
         "    'Hate': 'REDACTED'"
     ])
-    assert mock_handler.messages[5].message == 'No body was attached to the request'
-    assert mock_handler.messages[6].message == "Response status: 202"
-    assert mock_handler.messages[7].message == "Response headers:"
+    assert messages_request[5] == 'No body was attached to the request'
+    assert messages_response[0] == "Response status: 202"
+    assert messages_response[1] == "Response headers:"
     # Dict not ordered in Python, exact logging order doesn't matter
     assert set([
-        mock_handler.messages[8].message,
-        mock_handler.messages[9].message
+        messages_response[2],
+        messages_response[3]
     ]) == set([
         "    'Content-Type': 'Caramel'",
         "    'HateToo': 'REDACTED'"
@@ -168,13 +176,15 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'No body was attached to the request'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -191,19 +201,23 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 12
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
-    assert mock_handler.messages[6].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[7].message == "Request method: 'GET'"
-    assert mock_handler.messages[8].message == 'Request headers:'
-    assert mock_handler.messages[9].message == 'No body was attached to the request'
-    assert mock_handler.messages[10].message == 'Response status: 202'
-    assert mock_handler.messages[11].message == 'Response headers:'
+    assert len(mock_handler.messages) == 4
+    messages_request1 = mock_handler.messages[0].message.split("/n")
+    messages_response1 = mock_handler.messages[1].message.split("/n")
+    messages_request2 = mock_handler.messages[2].message.split("/n")
+    messages_response2 = mock_handler.messages[3].message.split("/n")
+    assert messages_request1[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request1[1] == "Request method: 'GET'"
+    assert messages_request1[2] == 'Request headers:'
+    assert messages_request1[3] == 'No body was attached to the request'
+    assert messages_response1[0] == 'Response status: 202'
+    assert messages_response1[1] == 'Response headers:'
+    assert messages_request2[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request2[1] == "Request method: 'GET'"
+    assert messages_request2[2] == 'Request headers:'
+    assert messages_request2[3] == 'No body was attached to the request'
+    assert messages_response2[0] == 'Response status: 202'
+    assert messages_response2[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -237,13 +251,15 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'A body is sent with the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'A body is sent with the request'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -280,12 +296,14 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'File upload'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'File upload'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()
diff --git a/sdk/core/azure-core/tests/test_http_logging_policy.py b/sdk/core/azure-core/tests/test_http_logging_policy.py
index bd427bdc3e79..a73b34cb8086 100644
--- a/sdk/core/azure-core/tests/test_http_logging_policy.py
+++ b/sdk/core/azure-core/tests/test_http_logging_policy.py
@@ -54,13 +54,15 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'No body was attached to the request'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -75,19 +77,23 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 12
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
-    assert mock_handler.messages[6].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[7].message == "Request method: 'GET'"
-    assert mock_handler.messages[8].message == 'Request headers:'
-    assert mock_handler.messages[9].message == 'No body was attached to the request'
-    assert mock_handler.messages[10].message == 'Response status: 202'
-    assert mock_handler.messages[11].message == 'Response headers:'
+    assert len(mock_handler.messages) == 4
+    messages_request1 = mock_handler.messages[0].message.split("/n")
+    messages_response1 = mock_handler.messages[1].message.split("/n")
+    messages_request2 = mock_handler.messages[2].message.split("/n")
+    messages_response2 = mock_handler.messages[3].message.split("/n")
+    assert messages_request1[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request1[1] == "Request method: 'GET'"
+    assert messages_request1[2] == 'Request headers:'
+    assert messages_request1[3] == 'No body was attached to the request'
+    assert messages_response1[0] == 'Response status: 202'
+    assert messages_response1[1] == 'Response headers:'
+    assert messages_request2[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request2[1] == "Request method: 'GET'"
+    assert messages_request2[2] == 'Request headers:'
+    assert messages_request2[3] == 'No body was attached to the request'
+    assert messages_response2[0] == 'Response status: 202'
+    assert messages_response2[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -110,25 +116,27 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 10
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/?country=france&city=REDACTED'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == "Request headers:"
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/?country=france&city=REDACTED'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == "Request headers:"
     # Dict not ordered in Python, exact logging order doesn't matter
     assert set([
-        mock_handler.messages[3].message,
-        mock_handler.messages[4].message
+        messages_request[3],
+        messages_request[4]
     ]) == set([
         "    'Accept': 'Caramel'",
         "    'Hate': 'REDACTED'"
     ])
-    assert mock_handler.messages[5].message == 'No body was attached to the request'
-    assert mock_handler.messages[6].message == "Response status: 202"
-    assert mock_handler.messages[7].message == "Response headers:"
+    assert messages_request[5] == 'No body was attached to the request'
+    assert messages_response[0] == "Response status: 202"
+    assert messages_response[1] == "Response headers:"
     # Dict not ordered in Python, exact logging order doesn't matter
     assert set([
-        mock_handler.messages[8].message,
-        mock_handler.messages[9].message
+        messages_response[2],
+        messages_response[3]
     ]) == set([
         "    'Content-Type': 'Caramel'",
         "    'HateToo': 'REDACTED'"
@@ -169,13 +177,15 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'No body was attached to the request'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -192,19 +202,23 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 12
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'No body was attached to the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
-    assert mock_handler.messages[6].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[7].message == "Request method: 'GET'"
-    assert mock_handler.messages[8].message == 'Request headers:'
-    assert mock_handler.messages[9].message == 'No body was attached to the request'
-    assert mock_handler.messages[10].message == 'Response status: 202'
-    assert mock_handler.messages[11].message == 'Response headers:'
+    assert len(mock_handler.messages) == 4
+    messages_request1 = mock_handler.messages[0].message.split("/n")
+    messages_response1 = mock_handler.messages[1].message.split("/n")
+    messages_request2 = mock_handler.messages[2].message.split("/n")
+    messages_response2 = mock_handler.messages[3].message.split("/n")
+    assert messages_request1[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request1[1] == "Request method: 'GET'"
+    assert messages_request1[2] == 'Request headers:'
+    assert messages_request1[3] == 'No body was attached to the request'
+    assert messages_response1[0] == 'Response status: 202'
+    assert messages_response1[1] == 'Response headers:'
+    assert messages_request2[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request2[1] == "Request method: 'GET'"
+    assert messages_request2[2] == 'Request headers:'
+    assert messages_request2[3] == 'No body was attached to the request'
+    assert messages_response2[0] == 'Response status: 202'
+    assert messages_response2[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -238,13 +252,15 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'A body is sent with the request'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'A body is sent with the request'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()
 
@@ -280,12 +296,14 @@ def emit(self, record):
     policy.on_response(request, response)
 
     assert all(m.levelname == 'INFO' for m in mock_handler.messages)
-    assert len(mock_handler.messages) == 6
-    assert mock_handler.messages[0].message == "Request URL: 'http://127.0.0.1/'"
-    assert mock_handler.messages[1].message == "Request method: 'GET'"
-    assert mock_handler.messages[2].message == 'Request headers:'
-    assert mock_handler.messages[3].message == 'File upload'
-    assert mock_handler.messages[4].message == 'Response status: 202'
-    assert mock_handler.messages[5].message == 'Response headers:'
+    assert len(mock_handler.messages) == 2
+    messages_request = mock_handler.messages[0].message.split("/n")
+    messages_response = mock_handler.messages[1].message.split("/n")
+    assert messages_request[0] == "Request URL: 'http://127.0.0.1/'"
+    assert messages_request[1] == "Request method: 'GET'"
+    assert messages_request[2] == 'Request headers:'
+    assert messages_request[3] == 'File upload'
+    assert messages_response[0] == 'Response status: 202'
+    assert messages_response[1] == 'Response headers:'
 
     mock_handler.reset()

From 481c05d4543ed006f098712475047e2cbf239295 Mon Sep 17 00:00:00 2001
From: Xiang Yan <xiangyan@microsoft.com>
Date: Mon, 16 Aug 2021 16:38:40 -0700
Subject: [PATCH 2/7] update

---
 .../core/pipeline/policies/_universal.py      | 139 +++++++++---------
 1 file changed, 68 insertions(+), 71 deletions(-)

diff --git a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
index 19c141460b48..5b5efbf4f4b8 100644
--- a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
+++ b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
@@ -305,32 +305,32 @@ def on_request(self, request):
                         _LOGGER.debug(str(http_request.body))
                         return
                     _LOGGER.debug("This request has no body")
-                else:
-                    log_string = "Request URL: '{}'".format(http_request.url)
-                    log_string = "/nRequest method: '{}'".format(http_request.method)
-                    log_string += "/nRequest headers:"
-                    for header, value in http_request.headers.items():
-                        log_string += "/n    '{}': '{}'".format(header, value)
-                    log_string += "/nRequest body:"
+                    return
+                log_string = "Request URL: '{}'".format(http_request.url)
+                log_string = "/nRequest method: '{}'".format(http_request.method)
+                log_string += "/nRequest headers:"
+                for header, value in http_request.headers.items():
+                    log_string += "/n    '{}': '{}'".format(header, value)
+                log_string += "/nRequest body:"
 
-                    # We don't want to log the binary data of a file upload.
-                    if isinstance(http_request.body, types.GeneratorType):
+                # We don't want to log the binary data of a file upload.
+                if isinstance(http_request.body, types.GeneratorType):
+                    log_string += "/nFile upload"
+                    _LOGGER.debug(log_string)
+                    return
+                try:
+                    if isinstance(http_request.body, types.AsyncGeneratorType):
                         log_string += "/nFile upload"
                         _LOGGER.debug(log_string)
                         return
-                    try:
-                        if isinstance(http_request.body, types.AsyncGeneratorType):
-                            log_string += "/nFile upload"
-                            _LOGGER.debug(log_string)
-                            return
-                    except AttributeError:
-                        pass
-                    if http_request.body:
-                        log_string += "/n{}}d".format(str(http_request.body))
-                        _LOGGER.debug(log_string)
-                        return
-                    log_string += "/nThis request has no body"
+                except AttributeError:
+                    pass
+                if http_request.body:
+                    log_string += "/n{}".format(str(http_request.body))
                     _LOGGER.debug(log_string)
+                    return
+                log_string += "/nThis request has no body"
+                _LOGGER.debug(log_string)
             except Exception as err:  # pylint: disable=broad-except
                 _LOGGER.debug("Failed to log request: %r", err)
 
@@ -374,30 +374,30 @@ def on_response(self, request, response):
                             _LOGGER.debug("Body is streamable")
                         else:
                             _LOGGER.debug(http_response.text())
-                else:
-                    log_string = "Response status: '{}'".format(http_response.status_code)
-                    log_string += "/nResponse headers:"
-                    for res_header, value in http_response.headers.items():
-                        log_string += "/n    '{}': '{}'".format(res_header, value)
-
-                    # We don't want to log binary data if the response is a file.
-                    log_string += "/nResponse content:"
-                    pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE)
-                    header = http_response.headers.get('content-disposition')
+                    return
+                log_string = "Response status: '{}'".format(http_response.status_code)
+                log_string += "/nResponse headers:"
+                for res_header, value in http_response.headers.items():
+                    log_string += "/n    '{}': '{}'".format(res_header, value)
 
-                    if header and pattern.match(header):
-                        filename = header.partition('=')[2]
-                        log_string += "/nFile attachments: {}".format(filename)
-                    elif http_response.headers.get("content-type", "").endswith("octet-stream"):
-                        log_string += "/nBody contains binary data."
-                    elif http_response.headers.get("content-type", "").startswith("image"):
-                        log_string += "/nBody contains image data."
+                # We don't want to log binary data if the response is a file.
+                log_string += "/nResponse content:"
+                pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE)
+                header = http_response.headers.get('content-disposition')
+
+                if header and pattern.match(header):
+                    filename = header.partition('=')[2]
+                    log_string += "/nFile attachments: {}".format(filename)
+                elif http_response.headers.get("content-type", "").endswith("octet-stream"):
+                    log_string += "/nBody contains binary data."
+                elif http_response.headers.get("content-type", "").startswith("image"):
+                    log_string += "/nBody contains image data."
+                else:
+                    if response.context.options.get('stream', False):
+                        log_string += "/nBody is streamable."
                     else:
-                        if response.context.options.get('stream', False):
-                            log_string += "/nBody is streamable."
-                        else:
-                            log_string += "/n{}}".format(http_response.text())
-                    _LOGGER.debug(log_string)
+                        log_string += "/n{}".format(http_response.text())
+                _LOGGER.debug(log_string)
         except Exception as err:  # pylint: disable=broad-except
             _LOGGER.debug("Failed to log response: %s", repr(err))
 
@@ -499,31 +499,29 @@ def on_request(self, request):
                     return
                 logger.info("No body was attached to the request")
                 return
-            else:
-                log_string = "Request URL: '{}'".format(redacted_url)
-                log_string += "/nRequest method: '{}'".format(http_request.method)
-                log_string += "/nRequest headers:"
-                for header, value in http_request.headers.items():
-                    value = self._redact_header(header, value)
-                    log_string += "/n    '{}': '{}'".format(header, value)
-                if isinstance(http_request.body, types.GeneratorType):
+            log_string = "Request URL: '{}'".format(redacted_url)
+            log_string += "/nRequest method: '{}'".format(http_request.method)
+            log_string += "/nRequest headers:"
+            for header, value in http_request.headers.items():
+                value = self._redact_header(header, value)
+                log_string += "/n    '{}': '{}'".format(header, value)
+            if isinstance(http_request.body, types.GeneratorType):
+                log_string += "/nFile upload"
+                logger.info(log_string)
+                return
+            try:
+                if isinstance(http_request.body, types.AsyncGeneratorType):
                     log_string += "/nFile upload"
                     logger.info(log_string)
                     return
-                try:
-                    if isinstance(http_request.body, types.AsyncGeneratorType):
-                        log_string += "/nFile upload"
-                        logger.info(log_string)
-                        return
-                except AttributeError:
-                    pass
-                if http_request.body:
-                    log_string += "/nA body is sent with the request"
-                    logger.info(log_string)
-                    return
-                log_string += "/nNo body was attached to the request"
+            except AttributeError:
+                pass
+            if http_request.body:
+                log_string += "/nA body is sent with the request"
                 logger.info(log_string)
                 return
+            log_string += "/nNo body was attached to the request"
+            logger.info(log_string)
 
         except Exception as err:  # pylint: disable=broad-except
             logger.warning("Failed to log request: %s", repr(err))
@@ -545,17 +543,16 @@ def on_response(self, request, response):
                 for res_header, value in http_response.headers.items():
                     value = self._redact_header(res_header, value)
                     logger.info("    %r: %r", res_header, value)
-            else:
-                log_string = "Response status: {}".format(http_response.status_code)
-                log_string += "/nResponse headers:"
-                for res_header, value in http_response.headers.items():
-                    value = self._redact_header(res_header, value)
-                    log_string += "/n    '{}': '{}'".format(res_header, value)
+                return
+            log_string = "Response status: {}".format(http_response.status_code)
+            log_string += "/nResponse headers:"
+            for res_header, value in http_response.headers.items():
+                value = self._redact_header(res_header, value)
+                log_string += "/n    '{}': '{}'".format(res_header, value)
+            logger.info(log_string)
         except Exception as err:  # pylint: disable=broad-except
             logger.warning("Failed to log response: %s", repr(err))
 
-        logger.info(log_string)
-
 class ContentDecodePolicy(SansIOHTTPPolicy):
     """Policy for decoding unstreamed response content.
 

From ead8edab84545910486d0f9e7a82e636ae301cf2 Mon Sep 17 00:00:00 2001
From: Xiang Yan <xiangyan@microsoft.com>
Date: Mon, 16 Aug 2021 17:27:14 -0700
Subject: [PATCH 3/7] update

---
 .../azure-core/azure/core/pipeline/policies/_universal.py     | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
index 5b5efbf4f4b8..1425533f5641 100644
--- a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
+++ b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
@@ -266,7 +266,7 @@ class NetworkTraceLoggingPolicy(SansIOHTTPPolicy):
     def __init__(self, logging_enable=False, **kwargs): # pylint: disable=unused-argument
         self.enable_http_logger = logging_enable
 
-    def on_request(self, request):
+    def on_request(self, request):  # pylint: disable=too-many-return-statements
         # type: (PipelineRequest) -> None
         """Logs HTTP request to the DEBUG logger.
 
@@ -453,7 +453,7 @@ def _redact_header(self, key, value):
         ]
         return value if key.lower() in lower_case_allowed_header_names else HttpLoggingPolicy.REDACTED_PLACEHOLDER
 
-    def on_request(self, request):
+    def on_request(self, request):  # pylint: disable=too-many-return-statements
         # type: (PipelineRequest) -> None
         """Logs HTTP method, url and headers.
         :param request: The PipelineRequest object.

From 4e22d706ab9d1717ab03d7e94ddaa6b40dbe3365 Mon Sep 17 00:00:00 2001
From: Xiang Yan <xiangyan@microsoft.com>
Date: Tue, 17 Aug 2021 09:00:19 -0700
Subject: [PATCH 4/7] update

---
 .../tests/test_certificates_client.py         | 30 +++++++++-------
 .../tests/test_certificates_client_async.py   | 30 +++++++++-------
 .../tests/test_key_client.py                  | 34 +++++++++++--------
 .../tests/test_keys_async.py                  | 34 +++++++++++--------
 .../tests/test_secrets_async.py               | 30 +++++++++-------
 .../tests/test_secrets_client.py              | 30 +++++++++-------
 6 files changed, 106 insertions(+), 82 deletions(-)

diff --git a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py
index c6d342232467..a471833f7988 100644
--- a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py
+++ b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py
@@ -593,13 +593,15 @@ def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    if body["provider"] == "Test":
-                        return
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        if body["provider"] == "Test":
+                            return
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
         assert False, "Expected request body wasn't logged"
 
@@ -617,12 +619,14 @@ def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    assert body["provider"] != "Test", "Client request body was logged"
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        assert body["provider"] != "Test", "Client request body was logged"
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
     @only_2016_10_01()
     @client_setup
diff --git a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py
index 9f9c3b6036dd..1df080127f3e 100644
--- a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py
+++ b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py
@@ -602,13 +602,15 @@ async def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    if body["provider"] == "Test":
-                        return
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        if body["provider"] == "Test":
+                            return
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
         assert False, "Expected request body wasn't logged"
 
@@ -626,12 +628,14 @@ async def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    assert body["provider"] != "Test", "Client request body was logged"
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        assert body["provider"] != "Test", "Client request body was logged"
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
     @all_api_versions()
     @client_setup
diff --git a/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py b/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py
index 384f3e23db77..6493c6f5c491 100644
--- a/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py
+++ b/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py
@@ -389,14 +389,16 @@ def test_logging_enabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    expected_kty = "RSA-HSM" if is_hsm else "RSA"
-                    if body["kty"] == expected_kty:
-                        return
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        expected_kty = "RSA-HSM" if is_hsm else "RSA"
+                        if body["kty"] == expected_kty:
+                            return
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
         assert False, "Expected request body wasn't logged"
 
@@ -414,13 +416,15 @@ def test_logging_disabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    expected_kty = "RSA-HSM" if is_hsm else "RSA"
-                    assert body["kty"] != expected_kty, "Client request body was logged"
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        expected_kty = "RSA-HSM" if is_hsm else "RSA"
+                        assert body["kty"] != expected_kty, "Client request body was logged"
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
     @only_hsm_7_3_preview()
     @client_setup
diff --git a/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py b/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py
index cecba8d3cf97..8c3c460292c6 100644
--- a/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py
+++ b/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py
@@ -419,14 +419,16 @@ async def test_logging_enabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    expected_kty = "RSA-HSM" if is_hsm else "RSA"
-                    if body["kty"] == expected_kty:
-                        return
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        expected_kty = "RSA-HSM" if is_hsm else "RSA"
+                        if body["kty"] == expected_kty:
+                            return
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
         assert False, "Expected request body wasn't logged"
 
@@ -444,13 +446,15 @@ async def test_logging_disabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    expected_kty = "RSA-HSM" if is_hsm else "RSA"
-                    assert body["kty"] != expected_kty, "Client request body was logged"
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        expected_kty = "RSA-HSM" if is_hsm else "RSA"
+                        assert body["kty"] != expected_kty, "Client request body was logged"
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
     @only_hsm_7_3_preview()
     @client_setup
diff --git a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py
index b8c6ff8edb49..180fa63690f4 100644
--- a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py
+++ b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py
@@ -291,13 +291,15 @@ async def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    if body["value"] == "secret-value":
-                        return
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        if body["value"] == "secret-value":
+                            return
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
         assert False, "Expected request body wasn't logged"
 
@@ -315,12 +317,14 @@ async def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    assert body["value"] != "secret-value", "Client request body was logged"
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        assert body["value"] != "secret-value", "Client request body was logged"
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
 
 def test_service_headers_allowed_in_logs():
diff --git a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py
index 82aa6a6ed230..d0240ba86d11 100644
--- a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py
+++ b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py
@@ -297,13 +297,15 @@ def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    if body["value"] == "secret-value":
-                        return
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        if body["value"] == "secret-value":
+                            return
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
         assert False, "Expected request body wasn't logged"
 
@@ -321,12 +323,14 @@ def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                try:
-                    body = json.loads(message.message)
-                    assert body["value"] != "secret-value", "Client request body was logged"
-                except (ValueError, KeyError):
-                    # this means the message is not JSON or has no kty property
-                    pass
+                messages_request = message.split("/n")
+                for m in messages_request:
+                    try:
+                        body = json.loads(m)
+                        assert body["value"] != "secret-value", "Client request body was logged"
+                    except (ValueError, KeyError):
+                        # this means the message is not JSON or has no kty property
+                        pass
 
 
 def test_service_headers_allowed_in_logs():

From 8592e6d5f6df129a7bb243393a9d771d92f5ded4 Mon Sep 17 00:00:00 2001
From: Xiang Yan <xiangyan@microsoft.com>
Date: Tue, 17 Aug 2021 09:50:22 -0700
Subject: [PATCH 5/7] update

---
 .../tests/test_certificates_client.py                         | 4 ++--
 .../tests/test_certificates_client_async.py                   | 4 ++--
 sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py     | 4 ++--
 sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py     | 4 ++--
 .../azure-keyvault-secrets/tests/test_secrets_async.py        | 4 ++--
 .../azure-keyvault-secrets/tests/test_secrets_client.py       | 4 ++--
 6 files changed, 12 insertions(+), 12 deletions(-)

diff --git a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py
index a471833f7988..6a5126df5ca2 100644
--- a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py
+++ b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client.py
@@ -593,7 +593,7 @@ def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
@@ -619,7 +619,7 @@ def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
diff --git a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py
index 1df080127f3e..beb97d41b629 100644
--- a/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py
+++ b/sdk/keyvault/azure-keyvault-certificates/tests/test_certificates_client_async.py
@@ -602,7 +602,7 @@ async def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
@@ -628,7 +628,7 @@ async def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
diff --git a/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py b/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py
index 6493c6f5c491..1609ededad21 100644
--- a/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py
+++ b/sdk/keyvault/azure-keyvault-keys/tests/test_key_client.py
@@ -389,7 +389,7 @@ def test_logging_enabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
@@ -416,7 +416,7 @@ def test_logging_disabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
diff --git a/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py b/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py
index 8c3c460292c6..17a2604bd223 100644
--- a/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py
+++ b/sdk/keyvault/azure-keyvault-keys/tests/test_keys_async.py
@@ -419,7 +419,7 @@ async def test_logging_enabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
@@ -446,7 +446,7 @@ async def test_logging_disabled(self, client, is_hsm, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
diff --git a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py
index 180fa63690f4..ccd5828f3f84 100644
--- a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py
+++ b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_async.py
@@ -291,7 +291,7 @@ async def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
@@ -317,7 +317,7 @@ async def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
diff --git a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py
index d0240ba86d11..893ac113e5cd 100644
--- a/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py
+++ b/sdk/keyvault/azure-keyvault-secrets/tests/test_secrets_client.py
@@ -297,7 +297,7 @@ def test_logging_enabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)
@@ -323,7 +323,7 @@ def test_logging_disabled(self, client, **kwargs):
 
         for message in mock_handler.messages:
             if message.levelname == "DEBUG" and message.funcName == "on_request":
-                messages_request = message.split("/n")
+                messages_request = message.message.split("/n")
                 for m in messages_request:
                     try:
                         body = json.loads(m)

From a0517ae425e6d2a168a4f40e40671364676cfa09 Mon Sep 17 00:00:00 2001
From: Xiang Yan <xiangsjtu@gmail.com>
Date: Fri, 27 Aug 2021 14:50:15 -0700
Subject: [PATCH 6/7] Update _universal.py

---
 sdk/core/azure-core/azure/core/pipeline/policies/_universal.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
index 1425533f5641..aeab6a433b60 100644
--- a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
+++ b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
@@ -307,7 +307,7 @@ def on_request(self, request):  # pylint: disable=too-many-return-statements
                     _LOGGER.debug("This request has no body")
                     return
                 log_string = "Request URL: '{}'".format(http_request.url)
-                log_string = "/nRequest method: '{}'".format(http_request.method)
+                log_string += "/nRequest method: '{}'".format(http_request.method)
                 log_string += "/nRequest headers:"
                 for header, value in http_request.headers.items():
                     log_string += "/n    '{}': '{}'".format(header, value)

From 24fef037caea6f83256d5f6d8c0cf8f2d64a7100 Mon Sep 17 00:00:00 2001
From: Xiang Yan <xiangyan@microsoft.com>
Date: Fri, 27 Aug 2021 15:18:56 -0700
Subject: [PATCH 7/7] update

---
 .../core/pipeline/policies/_universal.py      | 52 +------------------
 1 file changed, 1 insertion(+), 51 deletions(-)

diff --git a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
index aeab6a433b60..8f18d04883bb 100644
--- a/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
+++ b/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
@@ -246,7 +246,6 @@ def on_request(self, request):
 
 
 class NetworkTraceLoggingPolicy(SansIOHTTPPolicy):
-    MULTI_RECORD_LOG = "AZURE_MULTI_RECORD_LOG"
 
     """The logging policy in the pipeline is used to output HTTP network trace to the configured logger.
 
@@ -282,30 +281,6 @@ def on_request(self, request):  # pylint: disable=too-many-return-statements
                 return
 
             try:
-                multi_record = os.environ.get(NetworkTraceLoggingPolicy.MULTI_RECORD_LOG, False)
-                if multi_record:
-                    _LOGGER.debug("Request URL: %r", http_request.url)
-                    _LOGGER.debug("Request method: %r", http_request.method)
-                    _LOGGER.debug("Request headers:")
-                    for header, value in http_request.headers.items():
-                        _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")
-                        return
-                    try:
-                        if isinstance(http_request.body, types.AsyncGeneratorType):
-                            _LOGGER.debug("File upload")
-                            return
-                    except AttributeError:
-                        pass
-                    if http_request.body:
-                        _LOGGER.debug(str(http_request.body))
-                        return
-                    _LOGGER.debug("This request has no body")
-                    return
                 log_string = "Request URL: '{}'".format(http_request.url)
                 log_string += "/nRequest method: '{}'".format(http_request.method)
                 log_string += "/nRequest headers:"
@@ -350,31 +325,6 @@ def on_response(self, request, response):
                 if not _LOGGER.isEnabledFor(logging.DEBUG):
                     return
 
-                multi_record = os.environ.get(NetworkTraceLoggingPolicy.MULTI_RECORD_LOG, False)
-                if multi_record:
-                    _LOGGER.debug("Response status: %r", http_response.status_code)
-                    _LOGGER.debug("Response headers:")
-                    for res_header, value in http_response.headers.items():
-                        _LOGGER.debug("    %r: %r", res_header, value)
-
-                    # We don't want to log binary data if the response is a file.
-                    _LOGGER.debug("Response content:")
-                    pattern = re.compile(r'attachment; ?filename=["\w.]+', re.IGNORECASE)
-                    header = http_response.headers.get('content-disposition')
-
-                    if header and pattern.match(header):
-                        filename = header.partition('=')[2]
-                        _LOGGER.debug("File attachments: %s", filename)
-                    elif http_response.headers.get("content-type", "").endswith("octet-stream"):
-                        _LOGGER.debug("Body contains binary data.")
-                    elif http_response.headers.get("content-type", "").startswith("image"):
-                        _LOGGER.debug("Body contains image data.")
-                    else:
-                        if response.context.options.get('stream', False):
-                            _LOGGER.debug("Body is streamable")
-                        else:
-                            _LOGGER.debug(http_response.text())
-                    return
                 log_string = "Response status: '{}'".format(http_response.status_code)
                 log_string += "/nResponse headers:"
                 for res_header, value in http_response.headers.items():
@@ -432,7 +382,7 @@ class HttpLoggingPolicy(SansIOHTTPPolicy):
         "User-Agent",
     ])
     REDACTED_PLACEHOLDER = "REDACTED"
-    MULTI_RECORD_LOG = "AZURE_MULTI_RECORD_LOG"
+    MULTI_RECORD_LOG = "AZURE_SDK_LOGGING_MULTIRECORD"
 
     def __init__(self, logger=None, **kwargs):  # pylint: disable=unused-argument
         self.logger = logger or logging.getLogger(