diff --git a/.travis.yml b/.travis.yml index 21d94137..c7cd7c1f 100644 --- a/.travis.yml +++ b/.travis.yml @@ -10,7 +10,7 @@ env: rvm: - 2.0.0 - 2.1 - - 2.2 + - 2.2.5 - 2.3.0 - 2.3.1 - jruby-9.1.0.0 diff --git a/lib/http.rb b/lib/http.rb index 4e17d2ea..a51722a3 100644 --- a/lib/http.rb +++ b/lib/http.rb @@ -5,6 +5,7 @@ require "http/timeout/null" require "http/timeout/per_operation" require "http/timeout/global" +require "http/logger" require "http/chainable" require "http/client" require "http/connection" diff --git a/lib/http/chainable.rb b/lib/http/chainable.rb index f7fbd5d3..1324b070 100644 --- a/lib/http/chainable.rb +++ b/lib/http/chainable.rb @@ -162,6 +162,13 @@ def via(*proxy) end alias through via + # Set a logger. + # @param [Object] logger + # @option [Hash] options + def log(logger, options = {}) + branch(default_options.with_logger(:logger => logger, :options => options)) + end + # Make client follow redirects. # @param opts # @return [HTTP::Client] diff --git a/lib/http/client.rb b/lib/http/client.rb index 93c19bce..d1e24a0f 100644 --- a/lib/http/client.rb +++ b/lib/http/client.rb @@ -42,6 +42,8 @@ def request(verb, uri, opts = {}) ) res = perform(req, opts) + opts.logger.log(req, res) if opts.logger + return res unless opts.follow Redirector.new(opts.follow).perform(req, res) do |request| diff --git a/lib/http/logger.rb b/lib/http/logger.rb new file mode 100644 index 00000000..a4e8cdf0 --- /dev/null +++ b/lib/http/logger.rb @@ -0,0 +1,36 @@ +# frozen_string_literal: true +module HTTP + class Logger + attr_reader :logger, :print_options + + # @param [#info] logger + # @param [Hash] options + def initialize(logger, options = {}) + @logger = logger + + with = options.fetch(:with, []) + @print_options = { + :skip_headers => !with.include?(:headers), + :skip_body => !with.include?(:body), + :separator => "\n" + } + end + + # Logs HTTP request and response. + # + # @param [HTTP::Request] request + # @param [HTTP::Response] response + def log(request, response) + return unless logger + + log_info(request) + log_info(response) + end + + private + + def log_info(http) + logger.info(http.pretty_print(print_options)) + end + end +end diff --git a/lib/http/options.rb b/lib/http/options.rb index a69834c3..bdb7116b 100644 --- a/lib/http/options.rb +++ b/lib/http/options.rb @@ -50,7 +50,8 @@ def initialize(options = {}) :keep_alive_timeout => 5, :headers => {}, :cookies => {}, - :encoding => nil + :encoding => nil, + :logger => nil } opts_w_defaults = defaults.merge(options) @@ -73,6 +74,12 @@ def initialize(options = {}) self.encoding = Encoding.find(encoding) end + def_option :logger do |logger_hash| + logger = logger_hash[:logger] + options = logger_hash[:options] || {} + self.logger = HTTP::Logger.new(logger, options) + end + %w( proxy params form json body follow response socket_class nodelay ssl_socket_class ssl_context ssl diff --git a/lib/http/pretty_printer.rb b/lib/http/pretty_printer.rb new file mode 100644 index 00000000..80a4372c --- /dev/null +++ b/lib/http/pretty_printer.rb @@ -0,0 +1,51 @@ +# frozen_string_literal: true +module HTTP + # Printer for {HTTP::Request} and {HTTP::Response}. + # Expects `headline` method to be implemented. + # + # @example Usage + # + # class MyHttpRequest + # include HTTP::PrettyPrinter + # + # def headline + # "MyHttpRequest headline" + # end + # end + module PrettyPrinter + # Returns human-readable representation including headers. + # + # @return [String] + def inspect + pretty_print(:skip_headers => false) + end + + # Returns a printable representation of headers. + # @option [Hash] options + # @param [Boolean] skip_headers + # @param [Boolean] skip_body + # @param [String] separator + # @return [String] + def pretty_print(skip_headers: true, skip_body: true, separator: "\n") + StringIO.open do |io| + io << headline + append_headers(io, separator) unless skip_headers + io << "#{separator}#{body}" unless skip_body || skip_headers + io.string + end + end + + private + + def append_headers(io, separator) + headers.group_by { |header| header[0] }.each do |name, values| + value = values.map(&:last).join("; ") + io << "#{separator}#{name}: #{value}" + end + end + + def headline + raise NotImplementedError, "'headline' method must be implemented by classes/modules that include HTTP::PrettyPrinter module" + end + end +end diff --git a/lib/http/request.rb b/lib/http/request.rb index 61414789..3cc419e9 100644 --- a/lib/http/request.rb +++ b/lib/http/request.rb @@ -5,6 +5,7 @@ require "http/errors" require "http/headers" +require "http/pretty_printer" require "http/request/writer" require "http/version" require "http/uri" @@ -14,6 +15,7 @@ class Request extend Forwardable include HTTP::Headers::Mixin + include HTTP::PrettyPrinter # The method given was not understood class UnsupportedMethodError < RequestError; end diff --git a/lib/http/response.rb b/lib/http/response.rb index f49b7fc8..382132f8 100644 --- a/lib/http/response.rb +++ b/lib/http/response.rb @@ -4,6 +4,7 @@ require "http/headers" require "http/content_type" require "http/mime_type" +require "http/pretty_printer" require "http/response/status" require "http/uri" require "http/cookie_jar" @@ -14,6 +15,7 @@ class Response extend Forwardable include HTTP::Headers::Mixin + include HTTP::PrettyPrinter # @return [Status] attr_reader :status @@ -119,9 +121,10 @@ def parse(as = nil) MimeType[as || mime_type].decode to_s end - # Inspect a response - def inspect - "#<#{self.class}/#{@version} #{code} #{reason} #{headers.to_h.inspect}>" + private + + def headline + "HTTP/#{@version} #{status}" end end end diff --git a/spec/lib/http/logger_spec.rb b/spec/lib/http/logger_spec.rb new file mode 100644 index 00000000..f2316136 --- /dev/null +++ b/spec/lib/http/logger_spec.rb @@ -0,0 +1,104 @@ +RSpec.describe HTTP::Logger do + describe ".new" do + let(:logger) { double("logger") } + + context "logger" do + subject do + described_class.new(logger).logger + end + + it { is_expected.to eql logger } + end + + context "print options" do + context "with default options" do + subject do + described_class.new(logger).print_options + end + + let(:expected_print_options) do + { + :skip_headers => true, + :skip_body => true, + :separator => "\n" + } + end + + it { is_expected.to eq expected_print_options } + end + + context "with headers" do + subject do + described_class.new(logger, :with => [:headers]).print_options + end + + let(:expected_print_options) do + { + :skip_headers => false, + :skip_body => true, + :separator => "\n" + } + end + + it { is_expected.to eq expected_print_options } + end + + context "with body" do + subject do + described_class.new(logger, :with => [:body]).print_options + end + + let(:expected_print_options) do + { + :skip_headers => true, + :skip_body => false, + :separator => "\n" + } + end + + it { is_expected.to eq expected_print_options } + end + + context "with headers and body" do + subject do + described_class.new(logger, :with => [:headers, :body]).print_options + end + + let(:expected_print_options) do + { + :skip_headers => false, + :skip_body => false, + :separator => "\n" + } + end + + it { is_expected.to eq expected_print_options } + end + end + end + + describe "#log" do + let(:request) { double("request") } + let(:response) { double("response") } + let(:logger) { double("logger") } + subject { described_class.new(logger) } + + before do + allow(logger).to receive(:info) + allow(request).to receive(:pretty_print).with(subject.print_options).and_return("request print") + allow(response).to receive(:pretty_print).with(subject.print_options).and_return("response print") + end + + it "logs request" do + expect(logger).to receive(:info).with("request print") + + subject.log(request, response) + end + + it "logs response" do + expect(logger).to receive(:info).with("response print") + + subject.log(request, response) + end + end +end diff --git a/spec/lib/http/options/merge_spec.rb b/spec/lib/http/options/merge_spec.rb index bc55c55e..4c4285f4 100644 --- a/spec/lib/http/options/merge_spec.rb +++ b/spec/lib/http/options/merge_spec.rb @@ -60,7 +60,8 @@ :ssl_socket_class => described_class.default_ssl_socket_class, :ssl_context => nil, :cookies => {}, - :encoding => nil + :encoding => nil, + :logger => nil ) end end diff --git a/spec/lib/http/pretty_printer_spec.rb b/spec/lib/http/pretty_printer_spec.rb new file mode 100644 index 00000000..11329612 --- /dev/null +++ b/spec/lib/http/pretty_printer_spec.rb @@ -0,0 +1,64 @@ +# frozen_string_literal: true +RSpec.describe HTTP::PrettyPrinter do + class FakeRe + include HTTP::Headers::Mixin + include HTTP::PrettyPrinter + + attr_accessor :body + + def initialize + @headers = HTTP::Headers.new + end + + private + + def headline + "FakeRe headline" + end + end + + let(:fake) do + fake = FakeRe.new + fake.headers.set :my_header, "My value" + fake.headers.set :set_cookie, %w(hoo=ray woo=hoo) + fake.body = "Work my body over" + fake + end + + describe "#inspect" do + subject { fake.inspect } + it { is_expected.to eq "FakeRe headline\nMy-Header: My value\nSet-Cookie: hoo=ray; woo=hoo" } + end + + describe "#pretty_print" do + context "using default options" do + subject { fake.pretty_print } + + it { is_expected.to eq "FakeRe headline" } + end + + context "with headers" do + subject { fake.pretty_print(:skip_headers => false) } + + it { is_expected.to eq "FakeRe headline\nMy-Header: My value\nSet-Cookie: hoo=ray; woo=hoo" } + end + + context "with headers and body" do + subject { fake.pretty_print(:skip_headers => false, :skip_body => false) } + + it { is_expected.to eq "FakeRe headline\nMy-Header: My value\nSet-Cookie: hoo=ray; woo=hoo\nWork my body over" } + end + + context "with body, but without headers" do + subject { fake.pretty_print(:skip_body => false) } + + it { is_expected.to eq "FakeRe headline" } + end + + context "supplying a separator" do + subject { fake.pretty_print(:skip_headers => false, :skip_body => false, :separator => " | ") } + + it { is_expected.to eq "FakeRe headline | My-Header: My value | Set-Cookie: hoo=ray; woo=hoo | Work my body over" } + end + end +end diff --git a/spec/lib/http/response_spec.rb b/spec/lib/http/response_spec.rb index 2842ba4b..c9195b12 100644 --- a/spec/lib/http/response_spec.rb +++ b/spec/lib/http/response_spec.rb @@ -114,8 +114,7 @@ let(:body) { double :to_s => "foobar" } it "returns human-friendly response representation" do - expect(response.inspect). - to eq '#"text/plain"}>' + expect(response.inspect).to eq "HTTP/1.1 200 OK\nContent-Type: text/plain" end end diff --git a/spec/lib/http_spec.rb b/spec/lib/http_spec.rb index 5765c1d7..b63c0371 100644 --- a/spec/lib/http_spec.rb +++ b/spec/lib/http_spec.rb @@ -410,4 +410,45 @@ def setsockopt(*args) expect(socket_spy_class.setsockopt_calls).to eq([[Socket::IPPROTO_TCP, Socket::TCP_NODELAY, 1]]) end end + + describe ".log" do + context "when logger is supplied" do + let(:logger) { double("logger") } + subject { HTTP.log(logger) } + + after do + HTTP.default_options = {} + end + + it "sets HTTP logger" do + expect(subject.default_options.logger).to be_an_instance_of(HTTP::Logger) + end + + it "sets given logger in HTTP logger" do + http_logger = subject.default_options.logger + expect(http_logger.logger).to eql logger + end + + context "with options" do + let(:options) do + {:with => [:headers, :body]} + end + subject { HTTP.log(logger, options) } + + it "sets given options in HTTP logger" do + http_logger = subject.default_options.logger + expect(http_logger.print_options).to include(:skip_headers => false) + expect(http_logger.print_options).to include(:skip_body => false) + end + end + end + + context "when logger is not supplied" do + subject { HTTP } + + it "logger is nil" do + expect(subject.default_options.logger).to be_nil + end + end + end end