Merge pull request #146 from murny/log-file-details

Add file details to preservation logs on successful upload

lib/pushmi_pullyu/aip.rb

@@ -12,7 +12,7 @@ def create(noid)
     PushmiPullyu::AIP::Downloader.new(noid, aip_directory).run
     PushmiPullyu::AIP::Creator.new(noid, aip_directory, aip_filename).run
 
-    yield aip_filename
+    yield aip_filename, aip_directory
 
     FileUtils.rm_rf(aip_filename) if File.exist?(aip_filename)
     FileUtils.rm_rf(aip_directory) if File.exist?(aip_directory)

lib/pushmi_pullyu/cli.rb

@@ -174,11 +174,11 @@ def run_preservation_cycle
     Rollbar.scoped(noid: item) do
       begin
         # Download AIP from Fedora, bag and tar AIP directory and cleanup after block code
-        PushmiPullyu::AIP.create(item) do |aip_filename|
+        PushmiPullyu::AIP.create(item) do |aip_filename, aip_directory|
           # Push tarred AIP to swift API
           deposited_file = swift.deposit_file(aip_filename, options[:swift][:container])
           # Log successful preservation event to the log files
-          PushmiPullyu::Logging.log_preservation_event(deposited_file)
+          PushmiPullyu::Logging.log_preservation_event(deposited_file, aip_directory)
         end
       # rubocop:disable Lint/RescueException
       rescue Exception => e

lib/pushmi_pullyu/logging.rb

@@ -13,58 +13,96 @@ def call(_severity, _timestamp, _program_name, msg)
 
   end
 
-  def self.initialize_logger(log_target = STDOUT)
-    @logger = Logger.new(log_target)
-    @logger.level = Logger::INFO
-    @logger
+  def logger
+    PushmiPullyu::Logging.logger
   end
 
-  def self.logger
-    @logger ||= initialize_logger
-  end
+  class << self
 
-  def self.log_aip_activity(aip_directory, message)
-    log_file = "#{aip_directory}/data/logs/aipcreation.log"
-    aip_logger = Logger.new(log_file)
-    aip_logger.level = logger.level
+    attr_writer :logger
 
-    # Log to both the application log, and the log file that gets archived in the AIP
-    logger.info(message)
-    aip_logger.info(message)
+    def initialize_logger(log_target = STDOUT)
+      @logger = Logger.new(log_target)
+      @logger.level = Logger::INFO
+      @logger
+    end
 
-    aip_logger.close
-  end
+    def logger
+      @logger ||= initialize_logger
+    end
 
-  def self.log_preservation_event(deposited_file)
-    preservation_logger = Logger.new("#{PushmiPullyu.options[:logdir]}/preservation_events.log")
+    def log_aip_activity(aip_directory, message)
+      log_file = "#{aip_directory}/data/logs/aipcreation.log"
+      aip_logger = Logger.new(log_file)
+      aip_logger.level = logger.level
 
-    message = "#{deposited_file.name} was successfully deposited into Swift Storage! \n"\
-    "Here are the details of this preservation event: \n"\
-    "\t NOID: '#{deposited_file.name}' \n"\
-    "\t Timestamp of Completion: '#{deposited_file.last_modified}' \n"\
-    "\t AIP Checksum: '#{deposited_file.etag}' \n"\
-    "\t Metadata: #{deposited_file.metadata} \n"
+      # Log to both the application log, and the log file that gets archived in the AIP
+      logger.info(message)
+      aip_logger.info(message)
 
-    # Log to both the application log, and the preservation log file
-    logger.info(message)
-    preservation_logger.info(message)
+      aip_logger.close
+    end
 
-    preservation_logger.close
-  end
+    def log_preservation_event(deposited_file, aip_directory)
+      preservation_logger = Logger.new("#{PushmiPullyu.options[:logdir]}/preservation_events.log")
 
-  def self.logger=(log)
-    @logger = log
-  end
+      message = "#{deposited_file.name} was successfully deposited into Swift Storage!\n"\
+      "Here are the details of this preservation event:\n"\
+      "\tNOID: '#{deposited_file.name}'\n"\
+      "\tTimestamp of Completion: '#{deposited_file.last_modified}'\n"\
+      "\tAIP Checksum: '#{deposited_file.etag}'\n"\
+      "\tMetadata: #{deposited_file.metadata}\n"\
+
+      file_details = file_log_details(aip_directory)
+
+      if file_details.present?
+        message << "\tFile Details:\n"
+        file_details.each do |file_detail|
+          message << %(\t\t{"fileset_uuid": "#{file_detail[:fileset_name]}",
+\t\t"details": {
+\t\t\t"file_name": "#{file_detail[:file_name]}",
+\t\t\t"file_type": "#{file_detail[:file_extension]}",
+\t\t\t"file_size": #{file_detail[:file_size]}
+\t\t}}\n)
+        end
+      end
 
-  def self.reopen
-    if @logger
-      @logger.reopen
-    else
-      @logger = initialize_logger
+      # Log to both the application log, and the preservation log file
+      logger.info(message)
+      preservation_logger.info(message)
+
+      preservation_logger.close
+    end
+
+    def reopen
+      if @logger
+        @logger.reopen
+      else
+        @logger = initialize_logger
+      end
+    end
+
+    private
+
+    def file_log_details(aip_directory)
+      file_details = []
+      data_files_location = "#{aip_directory}/data/objects/files"
+
+      if Dir.exist?(data_files_location)
+        Dir.glob("#{data_files_location}/*") do |folder|
+          Dir.glob("#{folder}/*") do |file|
+            file_details << {
+              fileset_name: File.dirname(file).split('/')[-1],
+              file_name: File.basename(file),
+              file_size: File.size(file),
+              file_extension: File.extname(file).strip.downcase[1..-1]
+            }
+          end
+        end
+      end
+
+      file_details
     end
-  end
 
-  def logger
-    PushmiPullyu::Logging.logger
   end
 end

spec/integration/acceptance_spec.rb

@@ -62,14 +62,55 @@
         expect(deposited_file.metadata['promise']).to eql 'bronze'
 
         # Log successful preservation event to the log files
-        PushmiPullyu::Logging.log_preservation_event(deposited_file)
+        PushmiPullyu::Logging.log_preservation_event(deposited_file, aip_folder)
       end
     end
 
     expect(File.exist?("#{log_folder}/preservation_events.log")).to eq(true)
-    expect(
-      File.read("#{log_folder}/preservation_events.log")
-    ).to include("#{noid} was successfully deposited into Swift Storage!")
+
+    log_details = <<~HEREDOC
+      #{noid} was successfully deposited into Swift Storage!
+      Here are the details of this preservation event:
+      \tNOID: '#{noid}'
+      \tTimestamp of Completion: 'Wed, 07 Jun 2017 20:55:45 GMT'
+      \tAIP Checksum: '2752dc32b7a56b42aee3dd4d235a24a2'
+      \tMetadata: {"project-id"=>"#{noid}", "aip-version"=>"1.0", "promise"=>"bronze", "project"=>"ERA"}
+      \tFile Details:
+    HEREDOC
+
+    file_details_one = <<~HEREDOC
+      \t\t{"fileset_uuid": "01bb1b09-974d-478b-8826-2c606a447606",
+      \t\t"details": {
+      \t\t\t"file_name": "theses.jpg",
+      \t\t\t"file_type": "jpg",
+      \t\t\t"file_size": 53678
+      \t\t}}
+    HEREDOC
+
+    file_details_two = <<~HEREDOC
+      \t\t{"fileset_uuid": "837977d6-de61-49ea-a912-a65af5c9005e",
+      \t\t"details": {
+      \t\t\t"file_name": "image-sample.jpeg",
+      \t\t\t"file_type": "jpeg",
+      \t\t\t"file_size": 12401
+      \t\t}}
+    HEREDOC
+
+    file_details_three = <<~HEREDOC
+      \t\t{"fileset_uuid": "856444b6-8dd5-4dfa-857d-435e354a2ead",
+      \t\t"details": {
+      \t\t\t"file_name": "era-logo.png",
+      \t\t\t"file_type": "png",
+      \t\t\t"file_size": 5612
+      \t\t}}
+    HEREDOC
+
+    log_file = File.read("#{log_folder}/preservation_events.log")
+
+    expect(log_file).to include(log_details)
+    expect(log_file).to include(file_details_one)
+    expect(log_file).to include(file_details_two)
+    expect(log_file).to include(file_details_three)
 
     # aip file and folder should have been cleaned up
     expect(File.exist?(aip_folder)).to eq(false)

spec/pushmi_pullyu/logging_spec.rb

@@ -82,6 +82,7 @@ class LoggerTest
 
   describe '.log_preservation_event' do
     let(:tmp_log_dir) { 'tmp/logs' }
+    let(:tmp_aip_dir) { 'tmp/test_aip_dir' }
 
     it 'logs preservation event to both preservation log and application log' do
       FileUtils.mkdir_p(tmp_log_dir)
@@ -99,7 +100,7 @@ class LoggerTest
                     'project' => 'ERA' }
       )
 
-      PushmiPullyu::Logging.log_preservation_event(deposited_file)
+      PushmiPullyu::Logging.log_preservation_event(deposited_file, tmp_aip_dir)
 
       expect(File.exist?("#{tmp_log_dir}/preservation_events.log")).to eq(true)
       expect(PushmiPullyu::Logging.logger).to have_received(:info).with(an_instance_of(String)).once