Log outgoing HTTP requests when using HTTPoison.Base

[davidstump]

Howdy! First, thanks for the client - really enjoy using it :)

Second, I have had a few requests to log outgoing HTTP requests for a variety of reasons on different applications. When using your own methods that call out to something like HTTPoison.get - no big deal. However, when you are using the method use HTTPoison.Base it becomes a bit harrier. You can use a few of the callbacks to log different parts of the requests, but this becomes a little cumbersome. Ideally, it would be nice to get a succinct log entry like:

[info] [http] GET http://github.com/foo/bar STATUS 200

Would you be open to either a new extendable function that logs the current request, or an option passed to Base something like: use HTTPoison.Base, log_requests: true (or whatever naming sounds better than that)?

Happy to work on a PR - but didn't know if there was any interest, opinions, etc first.

Cheers :)

[edgurgel]

You can probably achieve this by overriding request/5:

def request(method, url, request_headers, body, hn_options) do
  log_something(method, url, request_headers,body, hn_options)
   super(method, url, request_headers, body, hn_options)
end

[davidstump]

Haha! My current workaround is almost exactly that:

def request(method, url, headers, body, opts) do
  super(method, url, headers, body, opts)
  |> log_outgoing_http_request()
end

[davidstump]

I can keep using that approach as it works fine. Only real reason I brought it up was it feels a little awkward to shove a function in the middle of the request/response chain and hope it doesn't muck up the stack trace if anything goes wrong.

Let me know if you ever think it would be anything useful. Otherwise, thanks for the quick reply/help.

Thanks!

[edgurgel]

I actually think this can be super useful. Let's wait for some feedback and see if more people like the idea? Thanks for starting this issue 👍

[ddefrenne]

Logging a request would be really handy, especially when trying to debug.

[mmartinson]

This would be really useful. Thanks @davidstump

Couple suggestions for API:

1. I think it could be useful to provide a logger callback module in place of or in addition to a boolean that enables/disables logging. It would definitely fine to ship with a default logger that generates the example log message you give, but there are probably some good cases for add a custom logging callback module, for adding logger metadata for example, or logging structured data.

2. It could be useful to specify which log level is desired for the messages. Which could use an API like this to call the Logger with the messages.

That would leave the config API looking something like use HTTPoison.Base, logger: HTTPoison.Logger, log_level: :info

Happy to hear others' input and feedback.

[davidstump]

Thinking back about this - would it be easier/preferable for the lib to log the requests, or add another optional hook to handle/log responses allowing clients to log the data in whatever format, text, etc they want?

[mmartinson]

I could see a case for going either way. On one side, keeping the library small keeps it simpler to maintain. Alternatively, helpful logging seems to fit well with the pit of success philosophy that is embraced elsewhere in the ecosystem. I lean slightly towards the latter, since I think that it's solid to have logging in place around IO in particular and that logs coming from the library would be particularly helpful for people who would probably plan to get around to doing it, but don't before they are having an issue.

[ghost]

If you're running on top of hackney (I presume you are) there's a handy way to get detailed logging without polluting your code :

https://github.com/benoitc/hackney/blob/master/doc/hackney_trace.md

:hackney_trace.enable(10,'/tmp/output.txt')
:hackney_trace.disable()
:hackney_trace.enable(:max,'/tmp/output.txt')

I always forget this trick - maybe someone could PR it to the README or something.

[adamu]

Just adding to @bryanhuntesl's post above, you can have it trace to stdout with

:hackney_trace.enable(:max, :io)