[ARVADOS] updated: f5258b8a0d48e6fb32cd42941be64a971402d429

[Git user]

Summary of changes:
 services/api/app/models/container.rb | 29 +++++++++++++++--------------
 services/api/app/models/job.rb       |  8 ++++----
 services/api/lib/log_reuse_info.rb   | 12 ++++++++----
 3 files changed, 27 insertions(+), 22 deletions(-)

       via  f5258b8a0d48e6fb32cd42941be64a971402d429 (commit)
      from  02d1074b356837f1a06a25ac3dc353ecf541b444 (commit)

Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.


commit f5258b8a0d48e6fb32cd42941be64a971402d429
Author: Tom Clegg <tom at curoverse.com>
Date:   Thu May 18 17:24:28 2017 -0400

    11590: Dry up log_reuse_info() calls.

diff --git a/services/api/app/models/container.rb b/services/api/app/models/container.rb
index 60911bd..47e213f 100644
--- a/services/api/app/models/container.rb
+++ b/services/api/app/models/container.rb
@@ -179,50 +179,51 @@ class Container < ArvadosModel
   def self.find_reusable(attrs)
     log_reuse_info { "starting with #{Container.all.count} container records in database" }
     candidates = Container.where_serialized(:command, attrs[:command])
-    log_reuse_info { "have #{candidates.count} candidates after filtering on command #{attrs[:command].inspect}" }
+    log_reuse_info(candidates) { "after filtering on command #{attrs[:command].inspect}" }
 
     candidates = candidates.where('cwd = ?', attrs[:cwd])
-    log_reuse_info { "have #{candidates.count} candidates after filtering on cwd #{attrs[:cwd].inspect}" }
+    log_reuse_info(candidates) { "after filtering on cwd #{attrs[:cwd].inspect}" }
 
     candidates = candidates.where_serialized(:environment, attrs[:environment])
-    log_reuse_info { "have #{candidates.count} candidates after filtering on environment #{attrs[:environment].inspect}" }
+    log_reuse_info(candidates) { "after filtering on environment #{attrs[:environment].inspect}" }
 
     candidates = candidates.where('output_path = ?', attrs[:output_path])
-    log_reuse_info { "have #{candidates.count} candidates after filtering on output_path #{attrs[:output_path].inspect}" }
+    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 { "have #{candidates.count} candidates after filtering on container_image #{image.inspect} (resolved from #{attrs[:container_image].inspect})" }
+    log_reuse_info(candidates) { "filtering on container_image #{image.inspect} (resolved from #{attrs[:container_image].inspect})" }
 
     candidates = candidates.where_serialized(:mounts, resolve_mounts(attrs[:mounts]))
-    log_reuse_info { "have #{candidates.count} candidates after filtering on mounts #{attrs[:mounts].inspect}" }
+    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 { "have #{candidates.count} candidates after filtering on runtime_constraints #{attrs[:runtime_constraints].inspect}" }
+    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..." }
 
-    # Check for Completed candidates whose output and log are both readable.
     select_readable_pdh = Collection.
       readable_by(current_user).
       select(:portable_data_hash).
       to_sql
 
     usable = candidates.where(state: Complete, exit_code: 0)
-    log_reuse_info { "have #{usable.count} with 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 { "have #{usable.count} with log readable by current user #{current_user.uuid}" }
+    log_reuse_info(usable) { "with readable log" }
 
     usable = usable.where("output IN (#{select_readable_pdh})")
-    log_reuse_info { "have #{usable.count} with output readable by current user #{current_user.uuid}" }
+    log_reuse_info(usable) { "with readable output" }
 
-    usable = usable.order('finished_at ASC').
-      limit(1).first
+    usable = usable.order('finished_at ASC').limit(1).first
     if usable
-      log_reuse_info { "done, reusing completed container #{usable.uuid}" }
+      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
diff --git a/services/api/app/models/job.rb b/services/api/app/models/job.rb
index 7536c3b..fa38ece 100644
--- a/services/api/app/models/job.rb
+++ b/services/api/app/models/job.rb
@@ -245,20 +245,20 @@ class Job < ArvadosModel
     candidates = candidates.where(
       'state = ? or (owner_uuid = ? and state in (?))',
       Job::Complete, current_user.uuid, [Job::Queued, Job::Running])
-    log_reuse_info { "have #{candidates.count} candidates after filtering on job state ((state=Complete) or (state=Queued/Running and (submitted by current user)))" }
+    log_reuse_info(candidates) { "after filtering on job state ((state=Complete) or (state=Queued/Running and (submitted by current user)))" }
 
     digest = Job.sorted_hash_digest(attrs[:script_parameters])
     candidates = candidates.where('script_parameters_digest = ?', digest)
-    log_reuse_info { "have #{candidates.count} candidates after filtering on script_parameters_digest #{digest}" }
+    log_reuse_info(candidates) { "after filtering on script_parameters_digest #{digest}" }
 
     candidates = candidates.where('nondeterministic is distinct from ?', true)
-    log_reuse_info { "have #{candidates.count} candidates after filtering on !nondeterministic" }
+    log_reuse_info(candidates) { "after filtering on !nondeterministic" }
 
     # prefer Running jobs over Queued
     candidates = candidates.order('state desc, created_at')
 
     candidates = apply_filters candidates, filters
-    log_reuse_info { "have #{candidates.count} candidates after filtering on repo, script, and custom filters #{filters.inspect}" }
+    log_reuse_info(candidates) { "after filtering on repo, script, and custom filters #{filters.inspect}" }
 
     chosen = nil
     incomplete_job = nil
diff --git a/services/api/lib/log_reuse_info.rb b/services/api/lib/log_reuse_info.rb
index 1bf050a..b325a65 100644
--- a/services/api/lib/log_reuse_info.rb
+++ b/services/api/lib/log_reuse_info.rb
@@ -2,11 +2,15 @@ module LogReuseInfo
   # log_reuse_info logs whatever the given block returns, if
   # log_reuse_decisions is enabled. It accepts a block instead of a
   # string because in some cases constructing the strings involves
-  # doing database queries, and we want to skip those queries when
-  # logging is disabled.
-  def log_reuse_info
+  # doing expensive things like database queries, and we want to skip
+  # those when logging is disabled.
+  def log_reuse_info(candidates=nil)
     if Rails.configuration.log_reuse_decisions
-      Rails.logger.info("find_reusable: " + yield)
+      msg = yield
+      if !candidates.nil?
+        msg = "have #{candidates.count} candidates " + msg
+      end
+      Rails.logger.info("find_reusable: " + msg)
     end
   end
 end

-----------------------------------------------------------------------


hooks/post-receive
--