resolve archivesspace#2821

backend/app/lib/background_job_queue.rb

@@ -29,12 +29,14 @@ def get_next_job
     # This shouldn't really happen, but his replaces the concept of a stale job
     # used in an earlier implementation that was problematic because it could end up
     # calling the #run method on a job more than once.
+    unwatched_job_id = nil
     begin
       Job.running_jobs_untouched_since(Time.now - JOB_TIMEOUT_SECONDS).each do |job|
+        unwatched_job_id = job.id
         job.finish!(:canceled)
       end
     rescue Sequel::NoExistingObject
-      Log.debug("Another thread cancelled unwatched job #{job.id}, nothing to do on #{Thread.current[:name]}")
+      Log.debug("Another thread canceled unwatched job #{unwatched_job_id}, nothing to do on #{Thread.current[:name]}")
     rescue => e
       Log.error("Error trying to cancel unwatched jobs on #{Thread.current[:name]}: #{e.class} #{$!} #{$@}")
     end

backend/spec/model_job_spec.rb

@@ -209,16 +209,14 @@ class PermissionJobRunner < JobRunner
 
   describe "BackgroundJobQueue" do
 
-    let(:q) {
-      q = BackgroundJobQueue.new
+    let(:queue) {
+      queue = BackgroundJobQueue.new
     }
 
-
     before(:each) do
       @job = nil
     end
 
-
     after(:each) do
       as_test_user("admin") do
         RequestContext.open(:repo_id => $repo_id) do
@@ -230,7 +228,6 @@ class PermissionJobRunner < JobRunner
       end
     end
 
-
     it "can find the next queued job and start it", :skip_db_open do
       json = JSONModel(:job).from_hash({
                                        :job => {'jsonmodel_type' => 'nugatory_job'},
@@ -250,14 +247,13 @@ class PermissionJobRunner < JobRunner
       job_id = @job.id
       expect(@job.status).to eq('queued')
 
-      q.run_pending_job
+      queue.run_pending_job
 
       sleep(0.5)
 
       expect(Job.any_repo[job_id].status).to eq('completed')
     end
 
-
     it "can stop a canceled job and finish it", :skip_db_open do
       NugatoryJobRunner.run_till_canceled!
 
@@ -284,7 +280,7 @@ class PermissionJobRunner < JobRunner
         @job.cancel!
       end
 
-      q.run_pending_job
+      queue.run_pending_job
 
       cancel_thread.join
 
@@ -294,5 +290,39 @@ class PermissionJobRunner < JobRunner
       expect(job.time_finished).not_to be_nil
       expect(job.time_finished).to be < Time.now
     end
+
+  it "quietly logs and swallows error when a stale job doesn't exist", :skip_db_open do
+      allow(Log).to receive(:debug)
+      NugatoryJobRunner.run_till_canceled!
+
+      json = JSONModel(:job).from_hash({:job => {'jsonmodel_type' => 'nugatory_job'}})
+
+      as_test_user("admin") do
+        RequestContext.open do
+          RequestContext.put(:repo_id, $repo_id)
+          RequestContext.put(:current_username, "admin")
+          user = create(:user, :username => "jobber")
+
+          @job = Job.create_from_json(json,
+                                      :repo_id => $repo_id,
+                                      :user => user)
+        end
+      end
+
+      allow(Job).to receive(:running_jobs_untouched_since).and_return [@job]
+
+
+      as_test_user("admin") do
+        RequestContext.open do
+          RequestContext.put(:repo_id, $repo_id)
+          RequestContext.put(:current_username, "admin")
+          Job.any_repo[@job.id].delete
+        end
+      end
+
+      queue = BackgroundJobQueue.new
+      expect { queue.run_pending_job }.not_to raise_error
+      expect(Log).to have_received(:debug).with(/^Another thread canceled unwatched/)
+    end
   end
 end