CAPI logs should for request complete should include the response time

Convert time taken to ms. Fix Robocop errors.

Author: nookala

lib/cloud_controller/logs/request_logs.rb

@@ -28,10 +28,11 @@ def start_request(request_id, env)
 
       def complete_request(request_id, status, env, time_taken)
         return if @incomplete_requests.delete(request_id).nil?
+
         request = ActionDispatch::Request.new(env)
-        @logger.info("Completed #{status} vcap-request-id: #{request_id}", 
+        @logger.info("Completed #{status} vcap-request-id: #{request_id}",
                      { status_code: status,
-                       time_taken: time_taken,
+                       time_taken_in_ms: time_taken,
                        request_method: request.request_method,
                        request_fullpath: request.filtered_path })
       end

middleware/request_logs.rb

@@ -12,8 +12,8 @@ def call(env)
         start_time = Time.now
 
         status, headers, body = @app.call(env)
-
-        time_taken = Time.now - start_time
+        # convert to milliseconds
+        time_taken = (Time.now - start_time) * 1000
         @request_logs.complete_request(request_id, status, env, time_taken)
 
         [status, headers, body]

spec/unit/lib/cloud_controller/logs/request_logs_spec.rb

@@ -47,7 +47,13 @@ module VCAP::CloudController::Logs
 
           it 'logs the completion of the request' do
             request_logs.complete_request(request_id, status, env, time_taken)
-            expect(logger).to have_received(:info).with(/Completed 200 vcap-request-id: ID/, { time_taken: 30, request_method: "request_method", request_fullpath: "filtered_path", status_code: 200 })
+           expect(logger).to have_received(:info).with(
+            /\ACompleted 200 vcap-request-id: ID/,
+            time_taken_in_ms: 30,
+            request_method: 'request_method',
+            request_fullpath: 'filtered_path',
+            status_code: 200
+           )
           end
         end