X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/fbc576b76977938cf7b742f9770ab90559136dc8..f15c51d123da2db1deeeb0e76685cf17eb56e039:/services/api/app/models/container.rb

diff --git a/services/api/app/models/container.rb b/services/api/app/models/container.rb
index 92ccb7c397..83765fb1dc 100644
--- a/services/api/app/models/container.rb
+++ b/services/api/app/models/container.rb
@@ -1,3 +1,8 @@
+# Copyright (C) The Arvados Authors. All rights reserved.
+#
+# SPDX-License-Identifier: AGPL-3.0
+
+require 'log_reuse_info'
 require 'whitelist_update'
 require 'safe_json'
 
@@ -8,6 +13,7 @@ class Container < ArvadosModel
   include WhitelistUpdate
   extend CurrentApiClient
   extend DbCurrentTime
+  extend LogReuseInfo
 
   serialize :environment, Hash
   serialize :mounts, Hash
@@ -175,41 +181,76 @@ class Container < ArvadosModel
   end
 
   def self.find_reusable(attrs)
-    candidates = Container.
-      where_serialized(:command, attrs[:command]).
-      where('cwd = ?', attrs[:cwd]).
-      where_serialized(:environment, attrs[:environment]).
-      where('output_path = ?', attrs[:output_path]).
-      where('container_image = ?', resolve_container_image(attrs[:container_image])).
-      where_serialized(:mounts, resolve_mounts(attrs[:mounts])).
-      where_serialized(:runtime_constraints, resolve_runtime_constraints(attrs[:runtime_constraints]))
-
-    # Check for Completed candidates whose output and log are both readable.
+    log_reuse_info { "starting with #{Container.all.count} container records in database" }
+    candidates = Container.where_serialized(:command, attrs[:command])
+    log_reuse_info(candidates) { "after filtering on command #{attrs[:command].inspect}" }
+
+    candidates = candidates.where('cwd = ?', attrs[:cwd])
+    log_reuse_info(candidates) { "after filtering on cwd #{attrs[:cwd].inspect}" }
+
+    candidates = candidates.where_serialized(:environment, attrs[:environment])
+    log_reuse_info(candidates) { "after filtering on environment #{attrs[:environment].inspect}" }
+
+    candidates = candidates.where('output_path = ?', attrs[:output_path])
+    log_reuse_info(candidates) { "after filtering on output_path #{attrs[:output_path].inspect}" }
+
+    image = resolve_container_image(attrs[:container_image])
+    candidates = candidates.where('container_image = ?', image)
+    log_reuse_info(candidates) { "after filtering on container_image #{image.inspect} (resolved from #{attrs[:container_image].inspect})" }
+
+    candidates = candidates.where_serialized(:mounts, resolve_mounts(attrs[:mounts]))
+    log_reuse_info(candidates) { "after filtering on mounts #{attrs[:mounts].inspect}" }
+
+    candidates = candidates.where_serialized(:runtime_constraints, resolve_runtime_constraints(attrs[:runtime_constraints]))
+    log_reuse_info(candidates) { "after filtering on runtime_constraints #{attrs[:runtime_constraints].inspect}" }
+
+    log_reuse_info { "checking for state=Complete with readable output and log..." }
+
     select_readable_pdh = Collection.
       readable_by(current_user).
       select(:portable_data_hash).
       to_sql
-    usable = candidates.
-      where(state: Complete).
-      where(exit_code: 0).
-      where("log IN (#{select_readable_pdh})").
-      where("output IN (#{select_readable_pdh})").
-      order('finished_at ASC').
-      limit(1).
-      first
-    return usable if usable
+
+    usable = candidates.where(state: Complete, exit_code: 0)
+    log_reuse_info(usable) { "with state=Complete, exit_code=0" }
+
+    usable = usable.where("log IN (#{select_readable_pdh})")
+    log_reuse_info(usable) { "with readable log" }
+
+    usable = usable.where("output IN (#{select_readable_pdh})")
+    log_reuse_info(usable) { "with readable output" }
+
+    usable = usable.order('finished_at ASC').limit(1).first
+    if usable
+      log_reuse_info { "done, reusing container #{usable.uuid} with state=Complete" }
+      return usable
+    end
 
     # Check for Running candidates and return the most likely to finish sooner.
+    log_reuse_info { "checking for state=Running..." }
     running = candidates.where(state: Running).
-      order('progress desc, started_at asc').limit(1).first
-    return running if not running.nil?
+              order('progress desc, started_at asc').
+              limit(1).first
+    if running
+      log_reuse_info { "done, reusing container #{running.uuid} with state=Running" }
+      return running
+    else
+      log_reuse_info { "have no containers in Running state" }
+    end
 
     # Check for Locked or Queued ones and return the most likely to start first.
-    locked_or_queued = candidates.where("state IN (?)", [Locked, Queued]).
-      order('state asc, priority desc, created_at asc').limit(1).first
-    return locked_or_queued if not locked_or_queued.nil?
+    locked_or_queued = candidates.
+                       where("state IN (?)", [Locked, Queued]).
+                       order('state asc, priority desc, created_at asc').
+                       limit(1).first
+    if locked_or_queued
+      log_reuse_info { "done, reusing container #{locked_or_queued.uuid} with state=#{locked_or_queued.state}" }
+      return locked_or_queued
+    else
+      log_reuse_info { "have no containers in Locked or Queued state" }
+    end
 
-    # No suitable candidate found.
+    log_reuse_info { "done, no reusable container found" }
     nil
   end
 
@@ -226,13 +267,15 @@ class Container < ArvadosModel
     # (because it's cheaper that way) and once after getting the lock
     # (because state might have changed while acquiring the lock).
     check_lock_fail
-    begin
-      reload(lock: 'FOR UPDATE NOWAIT')
-    rescue
-      raise LockFailedError.new("cannot lock: other transaction in progress")
+    transaction do
+      begin
+        reload(lock: 'FOR UPDATE NOWAIT')
+      rescue
+        raise LockFailedError.new("cannot lock: other transaction in progress")
+      end
+      check_lock_fail
+      update_attributes!(state: Locked)
     end
-    check_lock_fail
-    update_attributes!(state: Locked)
   end
 
   def check_unlock_fail
@@ -246,23 +289,21 @@ class Container < ArvadosModel
   def unlock
     # Check invalid state transitions twice (see lock)
     check_unlock_fail
-    reload(lock: 'FOR UPDATE')
-    check_unlock_fail
-    update_attributes!(state: Queued)
+    transaction do
+      reload(lock: 'FOR UPDATE')
+      check_unlock_fail
+      update_attributes!(state: Queued)
+    end
   end
 
   def self.readable_by(*users_list)
-    if users_list.select { |u| u.is_admin }.any?
-      return self
+    # Load optional keyword arguments, if they exist.
+    if users_list.last.is_a? Hash
+      kwargs = users_list.pop
+    else
+      kwargs = {}
     end
-    user_uuids = users_list.map { |u| u.uuid }
-    uuid_list = user_uuids + users_list.flat_map { |u| u.groups_i_can(:read) }
-    uuid_list.uniq!
-    permitted = "(SELECT head_uuid FROM links WHERE link_class='permission' AND tail_uuid IN (:uuids))"
-    joins(:container_requests).
-      where("container_requests.uuid IN #{permitted} OR "+
-            "container_requests.owner_uuid IN (:uuids)",
-            uuids: uuid_list)
+    Container.where(ContainerRequest.readable_by(*users_list).where("containers.uuid = container_requests.container_uuid").exists)
   end
 
   def final?
@@ -344,7 +385,7 @@ class Container < ArvadosModel
       when Running
         permitted.push :finished_at, :output, :log
       when Queued, Locked
-        permitted.push :finished_at
+        permitted.push :finished_at, :log
       end
 
     else