Fix problems with logger in JSON format

This commit addresses PR comments and fixes a problem with the JSON log

lib/pushmi_pullyu/cli.rb

@@ -199,9 +199,8 @@ def rotate_logs
   def run_preservation_cycle
     begin
       entity = queue.wait_next_item
-      # We add + 1 to the get_entity_ingestion_attempt because humans like to start counting from 1
       PushmiPullyu::Logging.log_preservation_attempt(entity,
-                                                     queue.get_entity_ingestion_attempt(entity) + 1)
+                                                     queue.get_entity_ingestion_attempt(entity))
       return unless entity && entity[:type].present? && entity[:uuid].present?
     rescue StandardError => e
       log_exception(e)
@@ -224,10 +223,9 @@ def run_preservation_cycle
       log_exception(e)
       begin
         queue.add_entity_in_timeframe(entity)
-        # We add + 1 to the get_entity_ingestion_attempt because humans like to start counting from 1
-        PushmiPullyu::Logging.log_preservation_fail_and_retry(entity, queue.get_entity_ingestion_attempt(entity) + 1, e)
+        PushmiPullyu::Logging.log_preservation_fail_and_retry(entity, queue.get_entity_ingestion_attempt(entity), e)
       rescue PushmiPullyu::PreservationQueue::MaxDepositAttemptsReached => e
-        PushmiPullyu::Logging.log_preservation_failure(entity, queue.get_entity_ingestion_attempt(entity) + 1, e)
+        PushmiPullyu::Logging.log_preservation_failure(entity, queue.get_entity_ingestion_attempt(entity), e)
         log_exception(e)
       end
 

lib/pushmi_pullyu/logging.rb

@@ -86,6 +86,8 @@ def log_preservation_success(entity, deposited_file, aip_directory)
     end
 
     def log_preservation_fail_and_retry(entity, try_attempt, exception)
+      # We add + 1 to try_attempt because humans like to start counting from 1
+      try_attempt += 1
       message = "#{entity[:type]} failed to be deposited and will try again.\n" \
                 "Here are the details of this preservation event:\n" \
                 "\t#{entity[:type]} uuid: #{entity[:uuid]}" \
@@ -106,10 +108,12 @@ def log_preservation_fail_and_retry(entity, try_attempt, exception)
     end
 
     def log_preservation_failure(entity, try_attempt, exception)
+      # We add + 1 to try_attempt because humans like to start counting from 1
+      try_attempt += 1
       message = "#{entity[:type]} failed to be deposited.\n" \
                 "Here are the details of this preservation event:\n" \
                 "\t#{entity[:type]} uuid: #{entity[:uuid]}" \
-                "\tRetry attempt: #{try_attempt}\n"
+                "\tTry attempt: #{try_attempt}\n"
 
       message_information = {
         event_type: :failure,
@@ -124,10 +128,12 @@ def log_preservation_failure(entity, try_attempt, exception)
     end
 
     def log_preservation_attempt(entity, try_attempt)
+      # We add + 1 to try_attempt because humans like to start counting from 1
+      try_attempt += 1
       message = "#{entity[:type]} will attempt to be deposited.\n" \
                 "Here are the details of this preservation event:\n" \
                 "\t#{entity[:type]} uuid: #{entity[:uuid]}" \
-                "\tRetry attempt: #{try_attempt}\n"
+                "\tTry attempt: #{try_attempt}\n"
 
       message_information = {
         event_type: :attempt,

spec/pushmi_pullyu/logging_spec.rb

@@ -183,7 +183,7 @@ class LoggerTest
       expect(File.exist?("#{tmp_log_dir}/preservation_events.log")).to be(true)
       log_data = File.read("#{tmp_log_dir}/preservation_events.log")
       expect(log_data).to include("#{entity[:type]} will attempt to be deposited.")
-      expect(log_data).to include("#{entity[:type]} uuid: #{entity[:uuid]}	Retry attempt: 1")
+      expect(log_data).to include("#{entity[:type]} uuid: #{entity[:uuid]}	Try attempt: 2")
 
       # Check JSON log
       expect(File.exist?("#{tmp_log_dir}/preservation_events.json")).to be(true)
@@ -194,7 +194,7 @@ class LoggerTest
         'event_type' => 'attempt',
         'entity_type' => 'items',
         'entity_uuid' => 'e2ec88e3-3266-4e95-8575-8b04fac2a679',
-        'try_attempt' => 1,
+        'try_attempt' => 2,
         'event_time' => Time.now.to_s
       )
     end
@@ -232,7 +232,7 @@ class LoggerTest
       log_data = File.read("#{tmp_log_dir}/preservation_events.log")
       expect(log_data).to include("#{entity[:type]} failed to be deposited and will try again.")
       expect(log_data).to include(
-        "#{entity[:type]} uuid: #{entity[:uuid]}	Readding to preservation queue with try attempt: 2"
+        "#{entity[:type]} uuid: #{entity[:uuid]}	Readding to preservation queue with try attempt: 3"
       )
 
       # Check JSON log
@@ -244,7 +244,7 @@ class LoggerTest
         'event_type' => 'fail_and_retry',
         'entity_type' => 'items',
         'entity_uuid' => 'e2ec88e3-3266-4e95-8575-8b04fac2a679',
-        'try_attempt' => 2,
+        'try_attempt' => 3,
         'error_message' => 'PushmiPullyu::AIP::Downloader::JupiterDownloadError',
         'event_time' => Time.now.to_s
       )
@@ -280,7 +280,7 @@ class LoggerTest
       expect(File.exist?("#{tmp_log_dir}/preservation_events.log")).to be(true)
       log_data = File.read("#{tmp_log_dir}/preservation_events.log")
       expect(log_data).to include("#{entity[:type]} failed to be deposited.")
-      expect(log_data).to include("#{entity[:type]} uuid: #{entity[:uuid]}	Retry attempt: 15")
+      expect(log_data).to include("#{entity[:type]} uuid: #{entity[:uuid]}	Try attempt: 16")
 
       # Check JSON log
       expect(File.exist?("#{tmp_log_dir}/preservation_events.json")).to be(true)
@@ -290,7 +290,7 @@ class LoggerTest
         'event_type' => 'failure',
         'entity_type' => 'items',
         'entity_uuid' => 'e2ec88e3-3266-4e95-8575-8b04fac2a679',
-        'try_attempt' => 15,
+        'try_attempt' => 16,
         'error_message' => 'PushmiPullyu::PreservationQueue::MaxDepositAttemptsReached',
         'event_time' => Time.now.to_s
       )