CHEF-5198: a better fix

- reverts previous fix to CHEF-5198
- applies stream handler middleware in (proper) reverse order
- adds debugging around middleware application
- moves dumping of response header debugging to before applying
  response/streaming middleware

3 files changed, 23 insertions, 13 deletions

diff --git a/lib/chef/http.rb b/lib/chef/http.rb
index 42b5decd6b..e73e8e5549 100644
--- a/lib/chef/http.rb
+++ b/lib/chef/http.rb
@@ -50,7 +50,10 @@ class Chef
       end
 
       def handle_chunk(next_chunk)
-        @stream_handlers.inject(next_chunk) do |chunk, handler|
+        # stream handlers handle responses so must be applied in reverse order
+        # (same as #apply_stream_complete_middleware or #apply_response_midddleware)
+        @stream_handlers.reverse.inject(next_chunk) do |chunk, handler|
+          Chef::Log.debug("Chef::HTTP::StreamHandler calling #{handler.class}#handle_chunk")
           handler.handle_chunk(chunk)
         end
       end
@@ -210,18 +213,21 @@ class Chef
 
     def apply_request_middleware(method, url, headers, data)
       middlewares.inject([method, url, headers, data]) do |req_data, middleware|
+        Chef::Log.debug("Chef::HTTP calling #{middleware.class}#handle_request")
         middleware.handle_request(*req_data)
       end
     end
 
     def apply_response_middleware(response, rest_request, return_value)
       middlewares.reverse.inject([response, rest_request, return_value]) do |res_data, middleware|
+        Chef::Log.debug("Chef::HTTP calling #{middleware.class}#handle_response")
         middleware.handle_response(*res_data)
       end
     end
 
     def apply_stream_complete_middleware(response, rest_request, return_value)
       middlewares.reverse.inject([response, rest_request, return_value]) do |res_data, middleware|
+        Chef::Log.debug("Chef::HTTP calling #{middleware.class}#handle_stream_complete")
         middleware.handle_stream_complete(*res_data)
       end
     end
@@ -253,14 +259,6 @@ class Chef
         end
         @last_response = response
 
-        Chef::Log.debug("---- HTTP Status and Header Data: ----")
-        Chef::Log.debug("HTTP #{response.http_version} #{response.code} #{response.msg}")
-
-        response.each do |header, value|
-          Chef::Log.debug("#{header}: #{value}")
-        end
-        Chef::Log.debug("---- End HTTP Status/Header Data ----")
-
         if response.kind_of?(Net::HTTPSuccess)
           [response, request, return_value]
         elsif response.kind_of?(Net::HTTPNotModified) # Must be tested before Net::HTTPRedirection because it's subclass.
diff --git a/lib/chef/http/basic_client.rb b/lib/chef/http/basic_client.rb
index 05ac662b7c..e800112dbe 100644
--- a/lib/chef/http/basic_client.rb
+++ b/lib/chef/http/basic_client.rb
@@ -61,7 +61,16 @@ class Chef
         base_headers.each do |name, value|
           Chef::Log.debug("#{name}: #{value}")
         end
+        Chef::Log.debug("---- End HTTP Request Header Data ----")
         http_client.request(http_request) do |response|
+          Chef::Log.debug("---- HTTP Status and Header Data: ----")
+          Chef::Log.debug("HTTP #{response.http_version} #{response.code} #{response.msg}")
+
+          response.each do |header, value|
+            Chef::Log.debug("#{header}: #{value}")
+          end
+          Chef::Log.debug("---- End HTTP Status/Header Data ----")
+
           yield response if block_given?
           # http_client.request may not have the return signature we want, so
           # force the issue:
diff --git a/lib/chef/http/simple.rb b/lib/chef/http/simple.rb
index 40ac864224..d675a17ee8 100644
--- a/lib/chef/http/simple.rb
+++ b/lib/chef/http/simple.rb
@@ -7,12 +7,15 @@ class Chef
   class HTTP
 
     class Simple < HTTP
-      # When we 'use' middleware the first middleware is applied last on requests and
-      # first on responses (confusingly).  So validatecontentlength must come before
-      # decompressor in order to be applied before decmopressing the response.
-      use ValidateContentLength
+
       use Decompressor
       use CookieManager
+
+      # ValidateContentLength should come after Decompressor
+      # because the order of middlewares is reversed when handling
+      # responses.
+      use ValidateContentLength
+
     end
   end
 end