Merge pull request #458 from dccunha/adds_query_to_curl_formatter

Logs 'base_uri' and query at Logger::CurlFormatter

lib/httparty/logger/curl_formatter.rb

@@ -2,46 +2,89 @@ module HTTParty
   module Logger
     class CurlFormatter #:nodoc:
       TAG_NAME = HTTParty.name
-      OUT = ">"
-      IN = "<"
+      OUT      = '>'.freeze
+      IN       = '<'.freeze
 
-      attr_accessor :level, :logger, :current_time
+      attr_accessor :level, :logger
 
       def initialize(logger, level)
-        @logger = logger
-        @level  = level.to_sym
+        @logger   = logger
+        @level    = level.to_sym
+        @messages = []
       end
 
       def format(request, response)
-        messages        = []
-        time            = Time.now.strftime("%Y-%m-%d %H:%M:%S %z")
-        http_method     = request.http_method.name.split("::").last.upcase
-        path            = request.path.to_s
+        @request  = request
+        @response = response
 
-        messages << print(time, OUT, "#{http_method} #{path}")
+        log_request
+        log_response
 
-        if request.options[:headers] && request.options[:headers].size > 0
-          request.options[:headers].each do |k, v|
-            messages << print(time, OUT, "#{k}: #{v}")
-          end
-        end
-
-        messages << print(time, OUT, request.raw_body)
-        messages << print(time, OUT, "")
-        messages << print(time, IN, "HTTP/#{response.http_version} #{response.code}")
-
-        headers = response.respond_to?(:headers) ? response.headers : response
-        response.each_header do |response_header|
-          messages << print(time, IN, "#{response_header.capitalize}: #{headers[response_header]}")
-        end
-
-        messages << print(time, IN, "\n#{response.body}")
-
-        @logger.send @level, messages.join("\n")
+        logger.send level, messages.join("\n")
       end
 
-      def print(time, direction, line)
-        "[#{TAG_NAME}] [#{time}] #{direction} #{line}"
+      private
+
+      attr_reader :request, :response
+      attr_accessor :messages
+
+      def log_request
+        log_url
+        log_headers
+        log_query
+        log OUT, request.raw_body if request.raw_body
+        log OUT
+      end
+
+      def log_response
+        log IN, "HTTP/#{response.http_version} #{response.code}"
+        log_response_headers
+        log IN, "\n#{response.body}"
+        log IN
+      end
+
+      def log_url
+        http_method = request.http_method.name.split("::").last.upcase
+        uri = if request.options[:base_uri]
+                request.options[:base_uri] + request.path.path
+              else
+                request.path.to_s
+              end
+
+        log OUT, "#{http_method} #{uri}"
+      end
+
+      def log_headers
+        return unless request.options[:headers] && request.options[:headers].size > 0
+
+        log OUT, 'Headers: '
+        log_hash request.options[:headers]
+      end
+
+      def log_query
+        return unless request.options[:query]
+
+        log OUT, 'Query: '
+        log_hash request.options[:query]
+      end
+
+      def log_response_headers
+        headers = response.respond_to?(:headers) ? response.headers : response
+        response.each_header do |response_header|
+          log IN, "#{response_header.capitalize}: #{headers[response_header]}"
+        end
+      end
+
+      def log_hash(hash)
+        hash.each { |k, v| log(OUT, "#{k}: #{v}") }
+      end
+
+      def log(direction, line = '')
+        messages << "[#{TAG_NAME}] [#{time}] #{direction} #{line}"
+      end
+
+      def time
+        @time ||= Time.now.strftime("%Y-%m-%d %H:%M:%S %z")
       end
     end
   end

spec/httparty/logger/curl_formatter_spec.rb

@@ -2,6 +2,107 @@ require File.expand_path(File.join(File.dirname(__FILE__), '..', '..', 'spec_hel
 
 RSpec.describe HTTParty::Logger::CurlFormatter do
   describe "#format" do
+    let(:logger)          { double('Logger') }
+    let(:response_object) { Net::HTTPOK.new('1.1', 200, 'OK') }
+    let(:parsed_response) { lambda { {"foo" => "bar"} } }
+
+    let(:response) do
+      HTTParty::Response.new(request, response_object, parsed_response)
+    end
+
+    let(:request) do
+      HTTParty::Request.new(Net::HTTP::Get, 'http://foo.bar.com/')
+    end
+
+    subject { described_class.new(logger, :info) }
+
+    before do
+      allow(logger).to receive(:info)
+      allow(request).to receive(:raw_body).and_return('content')
+      allow(response_object).to receive_messages(body: "{foo:'bar'}")
+      response_object['header-key'] = 'header-value'
+
+      subject.format request, response
+    end
+
+    context 'when request is logged' do
+      context "and request's option 'base_uri' is not present" do
+        it 'logs url' do
+          expect(logger).to have_received(:info).with(/\[HTTParty\] \[\d{4}-\d\d-\d\d \d\d:\d\d:\d\d\ [+-]\d{4}\] > GET http:\/\/foo.bar.com/)
+        end
+      end
+
+      context "and request's option 'base_uri' is present" do
+        let(:request) do
+          HTTParty::Request.new(Net::HTTP::Get, '/path', base_uri: 'http://foo.bar.com')
+        end
+
+        it 'logs url' do
+          expect(logger).to have_received(:info).with(/\[HTTParty\] \[\d{4}-\d\d-\d\d \d\d:\d\d:\d\d\ [+-]\d{4}\] > GET http:\/\/foo.bar.com\/path/)
+        end
+      end
+
+      context 'and headers are not present' do
+        it 'not log Headers' do
+          expect(logger).not_to have_received(:info).with(/Headers/)
+        end
+      end
+
+      context 'and headers are present' do
+        let(:request) do
+          HTTParty::Request.new(Net::HTTP::Get, '/path', base_uri: 'http://foo.bar.com', headers: { key: 'value' })
+        end
+
+        it 'logs Headers' do
+          expect(logger).to have_received(:info).with(/Headers/)
+        end
+
+        it 'logs headers keys' do
+          expect(logger).to have_received(:info).with(/key: value/)
+        end
+      end
+
+      context 'and query is not present' do
+        it 'not logs Query' do
+          expect(logger).not_to have_received(:info).with(/Query/)
+        end
+      end
+
+      context 'and query is present' do
+        let(:request) do
+          HTTParty::Request.new(Net::HTTP::Get, '/path', query: { key: 'value' })
+        end
+
+        it 'logs Query' do
+          expect(logger).to have_received(:info).with(/Query/)
+        end
+
+        it 'logs query params' do
+          expect(logger).to have_received(:info).with(/key: value/)
+        end
+      end
+
+      context 'when request raw_body is present' do
+        it 'not logs request body' do
+          expect(logger).to have_received(:info).with(/content/)
+        end
+      end
+    end
+
+    context 'when response is logged' do
+      it 'logs http version and response code' do
+        expect(logger).to have_received(:info).with(/HTTP\/1.1 200/)
+      end
+
+      it 'logs headers' do
+        expect(logger).to have_received(:info).with(/Header-key: header-value/)
+      end
+
+      it 'logs body' do
+        expect(logger).to have_received(:info).with(/{foo:'bar'}/)
+      end
+    end
+
     it "formats a response in a style that resembles a -v curl" do
       logger_double = double
       expect(logger_double).to receive(:info).with(