playback.rb in right_develop-3.1.10

- old
+ new

@@ -87,11 +87,11 @@
       super
       throw(HALT_TRANSMIT, HALT_TRANSMIT)
     end
 
     RETRY_DELAY = 0.5
-    MAX_RETRIES = 100  # = 50 seconds; a socket usually times out in 60-120 seconds
+    MAX_RETRIES = 240  # = 120 seconds; a socket usually times out in 60-120 seconds
 
     # Overrides transmit to catch halt thrown by log_request.
     #
     # @param [URI[ uri of some kind
     # @param [Net::HTTP] req of some kind
@@ -174,11 +174,10 @@
       # response must exist in the current epoch (i.e. can only enter next epoch
       # after a valid response is found) or in a past epoch. the latter was
       # allowed due to multithreaded requests causing the epoch to advance
       # (in a non-throttled playback) before all requests for a past epoch have
       # been made. the current epoch is always preferred over past.
-      logger.debug("BEGIN playback state = #{state.inspect}") if logger.debug?
       file_path = nil
       past_epochs = state[:past_epochs] ||= []
       try_epochs = [state[:epoch]] + past_epochs
       first_tried_path = nil
       first_tried_epoch = nil
@@ -201,14 +200,23 @@
           response_hash[:http_status],
           response_hash[:headers],
           response_hash[:body])
         result = FakeNetHttpResponse.new(response_hash, response_metadata)
       else
-        msg = 'Unable to locate response file(s) in epoch range ' +
-              "[#{first_tried_epoch} - #{last_tried_epoch}]:\n  " +
-              first_tried_path.inspect
+        msg = <<EOF
+Unable to locate response file(s) in epoch range [#{first_tried_epoch} - #{last_tried_epoch}]:
+#{first_tried_path.inspect}
+request checksum_data = #{request_metadata.checksum_data.inspect}
+state = #{state.inspect}
+EOF
         raise PLAYBACK_ERROR, msg
       end
+
+      # defer any verbose debug logging (i.e. the current state) until after
+      # metadata has been successfully loaded because a retryable missing
+      # variable may occur a couple hundred times before the condition is
+      # satisfied, if ever.
+      logger.debug("BEGIN playback state = #{state.inspect}") if logger.debug?
       logger.debug("Played back response from #{file_path.inspect}.")
 
       # determine if epoch is done, which it is if every known request has been
       # responded to for the current epoch. there is a steady state at the end
       # of time when all responses are given but there is no next epoch.