Logging send/receive data at DEBUG level

[pohmelie]

This issue is result of aio-libs google group discussion. Since often developer have no server-side code/protocol/api, but trying to reverse client-side by comparing requests/responses, ability to «see what happend» is very important. For insecure connections there is wireshark, but most of services are secure nowadays.
Easiest way is to wrap transport, but I don't really know how this will affect performance.

[asvetlov]

I want just state it: logging should be performed in debug mode only. Perhaps it requires debug param in ClientSession constructor, that's fine.

Do you want to save request/response headers only or the whole bodies?
The last may be tricky: logging the whole content of downloaded file is very expensive, but saving the first 100 bytes maybe is now enough.
Suggestions?

[pohmelie]

Don't really know which case is better, but sometimes you need 101 bytes, and you'll be sad if some "bad library developer" will cut you at 100. I think there definetly should be some options/log levels restrictions for logging all bytes.

[asvetlov]

@pohmelie the decision is up to you.
I don't want to make a patch personally but rely on you.
It can be debug_info parameter with default value 100 but maybe you'll suggest better name.
debug_info=100 means 100 bytes, debug_info=0 or debug_info=None disables logging.
I really want to have the single param, blowing up leads to explosion.

[pohmelie]

@asvetlov
Is this what you mean?

if debug_info is not None:
    logging.debug(...)

Also, I read requests/urllib3 sources to see what is going on there. And they are just logging method, url, http version, response status code and response size. So, after that I think request/response content should not be logged, since you can log it on your own in user code.
Since this, should we still make condition for logging debug info? In case of excluding content there should be not so much things to log to(just lines before content?).
Regardless of choosen solution I need help to find place(s), where aiohttp actually converts "dictionaries" to bytes and sending data.

[asvetlov]

Ok, if we need boolean parameter than just debug=False is good name.
The explicit param is required, it allows to speed up execution in production mode a little bit.

Request sending is here: https://github.com/KeepSafe/aiohttp/blob/master/aiohttp/client_reqrep.py#L482
Response info is available here: https://github.com/KeepSafe/aiohttp/blob/master/aiohttp/client_reqrep.py#L668

Maybe pushing logging into redirection loop https://github.com/KeepSafe/aiohttp/blob/master/aiohttp/client.py#L182 is cleaner than modifying request/response classes.

Let's cope with regular http requests first and add websocket logging in another PR.

[pohmelie]

Maybe better solution is to use protocol.send_headers and protocol.HttpResponseParser? Cause this have all headers/cookies in native view. And there is no need to keep «http dicts» in mind.

[asvetlov]

Please no.
protocol is overridden by implementation details but I want to refactor it very deeply for sake of performance.
Also think about HTTP/2. Perhaps it will require different implementation.
Let's keep the proper abstraction level for request/response logging.

[txomon]

Guys, would it be possible to have some kind of logging. I am trying to understand how cookies and sessions get modified in my application and the docs speak about Logging but setting up client logging is totally useless at the moment.

Anything is better than something. If you are worried about performance go with the module variable way, but please, something!

[pohmelie]

@txomon, unfortunately I still have no time for this, sorry. As I realized this should be done very accurate: be in proper level of abstraction and don't decrease performance too much.

[txomon]

Just in case, debug level is not used in production, just during development, therefore the performance shouldn't be that concerning. Doing it the http.client is by far the most performing solution, although logging was also quite performing when not logging. About the abstraction level, the use case of client debugging is usually used when developing the library, so method, headers and body, and response status, headers and optionally body are the expected items. I think I am missing something because design wise it's just copying other libraries, isn't it?

…

On Wed, Feb 8, 2017, 15:07 pohmelie ***@***.***> wrote: @txomon <https://github.com/txomon>, unfortunately I still have no time for this, sorry. As I realized this should be done very accurate: be in proper level of abstraction and don't decrease performance too much. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#1087 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAN7mua7iQ5SWrJBytwp868uBeHyIzKbks5radoXgaJpZM4JkQY3> .

[mikenerone]

Just wanted to toss my vote in here, too. Situations come up for me regularly where some raw request logging would be very helpful.

[cecton]

What about receiving file objects for debugging? Like debug_in and debug_out. If the dev provides a valid file object opened in binary mode, every packet receive will be sent raw to debug_in and every packet sent will be sent to the other one.

With that, the implementation of the actual logging is done by the dev.

[asvetlov]

Superseded by #2313

[lock]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a [new issue] for related bugs.
If you feel like there's important points made in this discussion, please include those exceprts into that [new issue].
[new issue]: https://github.com/aio-libs/aiohttp/issues/new