From 8adf605894bd134190bde518321bf58fefb9b444 Mon Sep 17 00:00:00 2001
From: Daniel Schmidt <dcschmidt@berkeley.edu>
Date: Tue, 19 Dec 2023 18:03:39 -0800
Subject: [PATCH] Improve logging/logfile handling from the Watcher

---
 lib/gingr/watcher.rb | 42 +++++++++++++++++++++---------------------
 spec/watcher_spec.rb | 12 ++++++------
 2 files changed, 27 insertions(+), 27 deletions(-)

diff --git a/lib/gingr/watcher.rb b/lib/gingr/watcher.rb
index a7bd860..5255ad4 100644
--- a/lib/gingr/watcher.rb
+++ b/lib/gingr/watcher.rb
@@ -57,12 +57,10 @@ def listener
       @listener ||= begin
         Listen.to(ready_dir, only: WATCH_FILTER, force_polling: true) do |_, added, _|
           added.each do |zipfile|
-            logger.info("Processing zipfile: #{zipfile}")
-
             begin
               exec_gingr_all!(zipfile)
             rescue => e
-              logger.error("Error processing #{zipfile}, moving to #{failed_dir}: #{e.inspect}")
+              logger.debug("Continuing to watch despite error: #{e}")
             end
           end
         end
@@ -70,21 +68,26 @@ def listener
     end
 
     def exec_gingr_all!(zipfile)
-      begin
-        command = ['gingr', 'all', zipfile, *arguments]
-        logger.debug("Running command: #{command}")
+      command = ['gingr', 'all', zipfile, *arguments]
 
-        stdout, stderr, status = Open3.capture3(*command)
-        if !status.success?
-          raise SubprocessError, "Call to `gingr all` failed: #{status}"
-        end
+      logger.info("Processing zipfile: #{zipfile}")
+      logger.debug("Running command: #{command}")
+      logs, status = Open3.capture2e(*command)
 
-        logger.debug("Processed #{zipfile}, moving to #{processed_dir}")
-        FileUtils.mv(zipfile, processed_dir)
-      rescue => e
+      if !status.success?
+        logger.error("Error processing #{zipfile}, moving to #{processed_dir}")
+        logger.debug("Execute logs: #{logs}")
+
+        write_logs(logs, zipfile, failed_dir)
         FileUtils.mv(zipfile, failed_dir)
-        File.write(error_log_for(zipfile), collate_logs(stdout, stderr))
-        raise
+
+        raise SubprocessError, "Call to `gingr all` failed: #{status}"
+      else
+        logger.info("Processed #{zipfile}, moving to #{processed_dir}")
+        logger.debug("Execute logs: #{logs}")
+
+        write_logs(logs, zipfile, processed_dir)
+        FileUtils.mv(zipfile, processed_dir)
       end
     end
 
@@ -106,12 +109,9 @@ def dasherize(str)
       (str.length > 1 ? "--" : "-") + str.tr("_", "-")
     end
 
-    def collate_logs(stdout, stderr)
-      "#{stdout}\n#{stderr}\n"
-    end
-
-    def error_log_for(zipfile)
-      File.join(failed_dir, "#{File.basename(zipfile, '.*')}.log")
+    def write_logs(logs, zipfile, logdir)
+      logfile = File.join(logdir, "#{File.basename(zipfile, '.*')}.log")
+      File.write(logfile, logs)
     end
 
     def validate_directories!
diff --git a/spec/watcher_spec.rb b/spec/watcher_spec.rb
index 5dd6a0b..0e4027f 100644
--- a/spec/watcher_spec.rb
+++ b/spec/watcher_spec.rb
@@ -57,7 +57,7 @@ def success?
       end
 
       it 'passes arguments to `gingr all`' do
-        expect(Open3).to receive(:capture3).with(*%w(
+        expect(Open3).to receive(:capture2e).with(*%w(
           gingr all /opt/app/data/gingr/ready/vector.zip
             --geoserver-root /opt/app/data/geoserver
             --geoserver-secure-url http://admin:geoserver@geoserver-secure:8080/geoserver/rest/
@@ -65,7 +65,7 @@ def success?
             --solr-url http://solr:8983/solr/geodata-test
             --spatial-root /opt/app/data/spatial
             --update-reference-field true
-        )).and_return(['', '', MockStatus.successful])
+        )).and_return(['', MockStatus.successful])
 
         copy_zipfile_to_ready('vector.zip')
         watcher.exec_gingr_all!('/opt/app/data/gingr/ready/vector.zip')
@@ -73,7 +73,7 @@ def success?
     end
 
     it 'moves successfully processed files to the processed directory' do
-      expect(Open3).to receive(:capture3).and_return(['', '', MockStatus.successful])
+      expect(Open3).to receive(:capture2e).and_return(['', MockStatus.successful])
 
       copy_zipfile_to_ready('vector.zip')
       watcher.exec_gingr_all!('/opt/app/data/gingr/ready/vector.zip')
@@ -84,7 +84,7 @@ def success?
       watcher.start
 
       (1..4).each do |i|
-        exp = expect(Open3).to receive(:capture3).with(*%W(
+        exp = expect(Open3).to receive(:capture2e).with(*%W(
           gingr all /opt/app/data/gingr/ready/vector#{i}.zip
             --geoserver-root /opt/app/data/geoserver
             --geoserver-secure-url http://admin:geoserver@geoserver-secure:8080/geoserver/rest/
@@ -97,7 +97,7 @@ def success?
         if i.odd?
           exp.and_raise(Gingr::Watcher::SubprocessError)
         else
-          exp.and_return(['', '', MockStatus.successful])
+          exp.and_return(['', MockStatus.successful])
         end
 
         copy_zipfile_to_ready('vector.zip', "vector#{i}.zip")
@@ -110,7 +110,7 @@ def success?
     let(:options) { { unexpected_argument: true } }
 
     it 'moves failed files and the logs to the failed directory' do
-      expect(Open3).to receive(:capture3).and_return(['', 'Unknown switches', MockStatus.failed])
+      expect(Open3).to receive(:capture2e).and_return(['Unknown switches', MockStatus.failed])
       copy_zipfile_to_ready('vector.zip')
 
       expect { watcher.exec_gingr_all!('/opt/app/data/gingr/ready/vector.zip') }.to raise_error(Gingr::Watcher::SubprocessError)