Skip to content

Commit

Permalink
integrate logs (Azure#20300)
Browse files Browse the repository at this point in the history
* integrate logs

* update

* update

* update

* update

* Update _universal.py

* update
  • Loading branch information
xiangyan99 authored Sep 23, 2021
1 parent cbdaf08 commit 424c3c7
Show file tree
Hide file tree
Showing 9 changed files with 346 additions and 245 deletions.
107 changes: 74 additions & 33 deletions sdk/core/azure-core/azure/core/pipeline/policies/_universal.py
Original file line number Diff line number Diff line change
Expand Up @@ -246,6 +246,7 @@ def on_request(self, request):


class NetworkTraceLoggingPolicy(SansIOHTTPPolicy):

"""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"
Expand All @@ -264,7 +265,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.
Expand All @@ -280,27 +281,31 @@ 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:")
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():
_LOGGER.debug(" %r: %r", header, value)
_LOGGER.debug("Request body:")
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):
_LOGGER.debug("File upload")
log_string += "/nFile upload"
_LOGGER.debug(log_string)
return
try:
if isinstance(http_request.body, types.AsyncGeneratorType):
_LOGGER.debug("File upload")
log_string += "/nFile upload"
_LOGGER.debug(log_string)
return
except AttributeError:
pass
if http_request.body:
_LOGGER.debug(str(http_request.body))
log_string += "/n{}".format(str(http_request.body))
_LOGGER.debug(log_string)
return
_LOGGER.debug("This request has no body")
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)

Expand All @@ -320,28 +325,29 @@ 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:")
log_string = "Response status: '{}'".format(http_response.status_code)
log_string += "/nResponse headers:"
for res_header, value in http_response.headers.items():
_LOGGER.debug(" %r: %r", res_header, value)
log_string += "/n '{}': '{}'".format(res_header, value)

# We don't want to log binary data if the response is a file.
_LOGGER.debug("Response content:")
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]
_LOGGER.debug("File attachments: %s", filename)
log_string += "/nFile attachments: {}".format(filename)
elif http_response.headers.get("content-type", "").endswith("octet-stream"):
_LOGGER.debug("Body contains binary data.")
log_string += "/nBody contains binary data."
elif http_response.headers.get("content-type", "").startswith("image"):
_LOGGER.debug("Body contains image data.")
log_string += "/nBody contains image data."
else:
if response.context.options.get('stream', False):
_LOGGER.debug("Body is streamable")
log_string += "/nBody is streamable."
else:
_LOGGER.debug(http_response.text())
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))

Expand Down Expand Up @@ -376,6 +382,7 @@ class HttpLoggingPolicy(SansIOHTTPPolicy):
"User-Agent",
])
REDACTED_PLACEHOLDER = "REDACTED"
MULTI_RECORD_LOG = "AZURE_SDK_LOGGING_MULTIRECORD"

def __init__(self, logger=None, **kwargs): # pylint: disable=unused-argument
self.logger = logger or logging.getLogger(
Expand All @@ -396,7 +403,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.
Expand All @@ -420,26 +427,52 @@ 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:")
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
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
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)
logger.info(" %r: %r", header, value)
log_string += "/n '{}': '{}'".format(header, value)
if isinstance(http_request.body, types.GeneratorType):
logger.info("File upload")
log_string += "/nFile upload"
logger.info(log_string)
return
try:
if isinstance(http_request.body, types.AsyncGeneratorType):
logger.info("File upload")
log_string += "/nFile upload"
logger.info(log_string)
return
except AttributeError:
pass
if http_request.body:
logger.info("A body is sent with the request")
log_string += "/nA body is sent with the request"
logger.info(log_string)
return
logger.info("No body was attached to the request")
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))

Expand All @@ -453,15 +486,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:")
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)
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)
logger.info(" %r: %r", 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))


class ContentDecodePolicy(SansIOHTTPPolicy):
"""Policy for decoding unstreamed response content.
Expand Down
Loading

0 comments on commit 424c3c7

Please sign in to comment.