Logging request payload\data\body with httplog is broken in 3.0.0

[igorigorigorigor]

Httplog(https://github.com/trusche/httplog) logs kind of memory pointer instead of the payload\data\body itself.
D, [2017-10-17T18:42:06.013390 #53965] DEBUG -- : [httplog] Sending: POST https://address.domain/api_method
D, [2017-10-17T18:42:06.013533 #53965] DEBUG -- : [httplog] Data: #<HTTP::Request::Body:0x007f93735632c8>

Here is my code for this
payload = { :param_1 => param_1.to_s, :param_2 => param_2.to_s, :param_3 => param_3.to_s}.to_json
HTTP.headers("id" => ID, :"User-Agent" => user_agent).post(url), :body => payload)

[janko]

The change introduced in #412 is responsible for this behaviour. Previously HTTP::Request#body returned the object that was assigned as :body, but now it returns an instance of HTTP::Request::Body. I'll try to come up with a PR for httplog.

[janko]

@igorigorigorigor This PR should bring necessary changes to HTTP.rb for me to then be able to send a PR to httplog – #438.

[tycooon]

The solution is not ideal, because you can't simply do source.to_s: some source types (like form data) require being rewinded after that, otherwise the request hangs forever.
See trusche/httplog#56.

[janko]

@tycooon I was actually thinking of that the httplog gem would just do source.inspect, so the logs would look like this:

HTTP.post("http://example.com", body: "body")
# [httplog] Data: "body"

HTTP.post("http://example.com", json: { key: "value" })
# [httplog] Data: "{\"key\":\"value\"}"

HTTP.post("https://example.com", body: Enumerator.new { |y| ... })
# [httplog] Data: #<Enumerator: ...>

HTTP.post("https://example.com", body: File.open("/path/to/file"))
# [httplog] Data: #<File:/path/to/file>

HTTP.post("https://example.com", form: {file: HTTP::FormData::File.new("/path/to/file")})
# [httplog] Data: #<HTTP::FormData::Multipart:0x007fedd70d1728 @boundary="---------------------65612a9a946c41388f3563b91ad41f03fb85a9587e", @glue="-----------------------65612a9a946c41388f3563b91ad41f03fb85a9587e\r\n", @tail="-----------------------65612a9a946c41388f3563b91ad41f03fb85a9587e--\r\n", @io=#<HTTP::FormData::CompositeIO:0x007fedd70d1048 @index=0, @buffer="", @ios=[#<StringIO:0x007fedd70d0f80>, #<HTTP::FormData::Multipart::Param:0x007fedd70d1610 @name="file", @part=#<HTTP::FormData::File:0x007fedd70d18b8 @io=#<File:/path/to/file>, @content_type="application/octet-stream", @filename="Gemfile">, @io=#<HTTP::FormData::CompositeIO:0x007fedd70d12a0 @index=0, @buffer="", @ios=[#<StringIO:0x007fedd70d1228>, #<HTTP::FormData::File:0x007fedd70d18b8 @io=#<File:/path/to/file>, @content_type="application/octet-stream", @filename="file">, #<StringIO:0x007fedd70d1200>]>>, #<StringIO:0x007fedd70d0f58>]>>

For me this would be how I would like httplog to log my requests; if I'm passing for request body anything other than a string, then the request body will probably be large and I would like to avoid logging it, because it could cause my logs to grow in size. What do you think about that?

[tycooon]

@janko-m this doesn't work well with FormData:

> HTTP.build_request(:post, "http://a.com", form: { a: 1 }).body.source.inspect
=> "#<HTTP::FormData::Urlencoded:0x00007fd1d5986530 @io=#<StringIO:0x00007fd1d59860a8>>"

[janko]

@tycooon Yeah, URL-encoded request bodies really should be shown as strings, and not as Ruby objects.

It seems that you've already solved everything in trusche/httplog#56. Yes, the HTTP::FormData bodies need to be rewinded after calling #to_s, I don't remember why I didn't make it happen automatically. Heck, I just went ahead and opened a PR for that – httprb/form_data#21 😃

[janko]

@tycooon Is httplog now working properly? Can this issue be closed?

[tycooon]

Yep, we fixed it here trusche/httplog#56.

[janko]

Awesome, thank you!