search

Azure / msrest-for-python

The runtime library "msrest" for AutoRest generated Python clients.
MIT License
41 stars 64 forks source link

Response body for operations are never logged in msrest.http_logger #16

Closed mideeks closed 7 years ago

mideeks commented 7 years ago

Long running operations always send 'Transfer-Encoding: chunked' header and so the response bodies never get logged because of line 84 in http_logger.py. 

        elif result.headers.get("transfer-encoding") == 'chunked':
            _LOGGER.debug("Body contains chunked data.")
mideeks commented 7 years ago

Example log content. Note the last line says chunked even though in reality it is only a line or two of json.

2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Request URL: 'https://management.azure.com/subscriptions/00000000-0000-0000-0000-000000000000/providers/Microsoft.Compute/lo
cations/westeurope/operations/243e1cb4-2744-450a-b503-d2ec585b6219?api-version=2016-03-30'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Request method: 'GET'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Request headers:
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Accept': 'application/json'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Connection': 'keep-alive'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Accept-Encoding': 'gzip, deflate'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'User-Agent': 'python/3.5.2 (Darwin-15.6.0-x86_64-i386-64bit) requests/2.10.0 msrest/0.4.4 msrest_azure/0.4.6 computeman
agementclient/0.30.0rc6 Azure-SDK-For-Python'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'accept-language': 'en-US'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'x-ms-client-request-id': 'b9be95c6-f491-11e6-b29e-60f81da90d6a'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Content-Type': 'application/json; charset=utf-8'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Authorization': 'Bearer '
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Request body:
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: None
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Response status: 200
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Response headers:
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Cache-Control': 'no-cache'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Pragma': 'no-cache'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Transfer-Encoding': 'chunked'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Content-Type': 'application/json; charset=utf-8'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Content-Encoding': 'gzip'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Expires': '-1'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Vary': 'Accept-Encoding'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Strict-Transport-Security': 'max-age=31536000; includeSubDomains'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'x-ms-served-by': '6f32d27e-ec2d-4950-bfe9-556eec2b91e8_131285288494412108'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'x-ms-request-id': '4b46ef65-3f54-4178-a0aa-d46b2fd68152'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Server': 'Microsoft-HTTPAPI/2.0, Microsoft-HTTPAPI/2.0'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'x-ms-ratelimit-remaining-subscription-reads': '14854'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'x-ms-correlation-request-id': 'd1c86cae-237b-47b2-9e1c-6609cec9cd9d'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'x-ms-routing-request-id': 'WESTUS:20170216T214931Z:d1c86cae-237b-47b2-9e1c-6609cec9cd9d'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG:     'Date': 'Thu, 16 Feb 2017 21:49:31 GMT'
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Response content:
2017-02-16T13:49:31-0800 - msrest.http_logger (Thread-129) - DEBUG: Body contains chunked data.
lmazuel commented 7 years ago

Yes, I know about this. It has also as flaw to break debugging: if I use a breakpoint before msrest builds the final response, the debugger reads it itself and consume the stream. Then I get a "None has no read method" exception and my debug session is dead.

I'm not an expert in network, but I guess this has some performance interest? @annatisch? was this asked by the ARM team?