services/api/script/crunch-dispatch.rb

   1 #!/usr/bin/env ruby
   2
   3 include Process
   4
   5 $warned = {}
   6 $signal = {}
   7 %w{TERM INT}.each do |sig|
   8   signame = sig
   9   Signal.trap(sig) do
  10     $stderr.puts "Received #{signame} signal"
  11     $signal[:term] = true
  12   end
  13 end
  14
  15 if ENV["CRUNCH_DISPATCH_LOCKFILE"]
  16   lockfilename = ENV.delete "CRUNCH_DISPATCH_LOCKFILE"
  17   lockfile = File.open(lockfilename, File::RDWR|File::CREAT, 0644)
  18   unless lockfile.flock File::LOCK_EX|File::LOCK_NB
  19     abort "Lock unavailable on #{lockfilename} - exit"
  20   end
  21 end
  22
  23 ENV["RAILS_ENV"] = ARGV[0] || ENV["RAILS_ENV"] || "development"
  24
  25 require File.dirname(__FILE__) + '/../config/boot'
  26 require File.dirname(__FILE__) + '/../config/environment'
  27 require 'open3'
  28
  29 LOG_BUFFER_SIZE = 4096
  30
  31 class Dispatcher
  32   include ApplicationHelper
  33
  34   def sysuser
  35     return act_as_system_user
  36   end
  37
  38   def refresh_todo
  39     @todo = Job.queue.select do |j| j.repository end
  40     @todo_pipelines = PipelineInstance.queue
  41   end
  42
  43   def sinfo
  44     @@slurm_version ||= Gem::Version.new(`sinfo --version`.match(/\b[\d\.]+\b/)[0])
  45     if Gem::Version.new('2.3') <= @@slurm_version
  46       `sinfo --noheader -o '%n:%t'`.strip
  47     else
  48       # Expand rows with hostname ranges (like "foo[1-3,5,9-12]:idle")
  49       # into multiple rows with one hostname each.
  50       `sinfo --noheader -o '%N:%t'`.split("\n").collect do |line|
  51         tokens = line.split ":"
  52         if (re = tokens[0].match /^(.*?)\[([-,\d]+)\]$/)
  53           re[2].split(",").collect do |range|
  54             range = range.split("-").collect(&:to_i)
  55             (range[0]..range[-1]).collect do |n|
  56               [re[1] + n.to_s, tokens[1..-1]].join ":"
  57             end
  58           end
  59         else
  60           tokens.join ":"
  61         end
  62       end.flatten.join "\n"
  63     end
  64   end
  65
  66   def update_node_status
  67     if Server::Application.config.crunch_job_wrapper.to_s.match /^slurm/
  68       @nodes_in_state = {idle: 0, alloc: 0, down: 0}
  69       @node_state ||= {}
  70       node_seen = {}
  71       begin
  72         sinfo.split("\n").
  73           each do |line|
  74           re = line.match /(\S+?):+(idle|alloc|down)/
  75           next if !re
  76
  77           # sinfo tells us about a node N times if it is shared by N partitions
  78           next if node_seen[re[1]]
  79           node_seen[re[1]] = true
  80
  81           # count nodes in each state
  82           @nodes_in_state[re[2].to_sym] += 1
  83
  84           # update our database (and cache) when a node's state changes
  85           if @node_state[re[1]] != re[2]
  86             @node_state[re[1]] = re[2]
  87             node = Node.where('hostname=?', re[1]).first
  88             if node
  89               $stderr.puts "dispatch: update #{re[1]} state to #{re[2]}"
  90               node.info[:slurm_state] = re[2]
  91               node.save
  92             elsif re[2] != 'down'
  93               $stderr.puts "dispatch: sinfo reports '#{re[1]}' is not down, but no node has that name"
  94             end
  95           end
  96         end
  97       rescue
  98       end
  99     end
 100   end
 101
 102   def start_jobs
 103     @todo.each do |job|
 104
 105       min_nodes = 1
 106       begin
 107         if job.runtime_constraints['min_nodes']
 108           min_nodes = begin job.runtime_constraints['min_nodes'].to_i rescue 1 end
 109         end
 110       end
 111
 112       begin
 113         next if @nodes_in_state[:idle] < min_nodes
 114       rescue
 115       end
 116
 117       next if @running[job.uuid]
 118       next if !take(job)
 119
 120       cmd_args = nil
 121       case Server::Application.config.crunch_job_wrapper
 122       when :none
 123         cmd_args = []
 124       when :slurm_immediate
 125         cmd_args = ["salloc",
 126                     "--chdir=/",
 127                     "--immediate",
 128                     "--exclusive",
 129                     "--no-kill",
 130                     "--job-name=#{job.uuid}",
 131                     "--nodes=#{min_nodes}"]
 132       else
 133         raise "Unknown crunch_job_wrapper: #{Server::Application.config.crunch_job_wrapper}"
 134       end
 135
 136       if Server::Application.config.crunch_job_user
 137         cmd_args.unshift("sudo", "-E", "-u",
 138                          Server::Application.config.crunch_job_user,
 139                          "PATH=#{ENV['PATH']}",
 140                          "PERLLIB=#{ENV['PERLLIB']}",
 141                          "PYTHONPATH=#{ENV['PYTHONPATH']}",
 142                          "RUBYLIB=#{ENV['RUBYLIB']}",
 143                          "GEM_PATH=#{ENV['GEM_PATH']}")
 144       end
 145
 146       job_auth = ApiClientAuthorization.
 147         new(user: User.where('uuid=?', job.modified_by_user_uuid).first,
 148             api_client_id: 0)
 149       job_auth.save
 150
 151       crunch_job_bin = (ENV['CRUNCH_JOB_BIN'] || `which arv-crunch-job`.strip)
 152       if crunch_job_bin == ''
 153         raise "No CRUNCH_JOB_BIN env var, and crunch-job not in path."
 154       end
 155
 156       require 'shellwords'
 157
 158       arvados_internal = Rails.configuration.git_internal_dir
 159       if not File.exists? arvados_internal
 160         $stderr.puts `mkdir -p #{arvados_internal.shellescape} && cd #{arvados_internal.shellescape} && git init --bare`
 161       end
 162
 163       src_repo = File.join(Rails.configuration.git_repositories_dir, job.repository + '.git')
 164       src_repo = File.join(Rails.configuration.git_repositories_dir, job.repository, '.git') unless File.exists? src_repo
 165
 166       unless src_repo
 167         $stderr.puts "dispatch: #{File.join Rails.configuration.git_repositories_dir, job.repository} doesn't exist"
 168         sleep 1
 169         untake(job)
 170         next
 171       end
 172
 173       $stderr.puts `cd #{arvados_internal.shellescape} && git fetch --no-tags #{src_repo.shellescape} && git tag #{job.uuid.shellescape} #{job.script_version.shellescape}`
 174
 175       cmd_args << crunch_job_bin
 176       cmd_args << '--job-api-token'
 177       cmd_args << job_auth.api_token
 178       cmd_args << '--job'
 179       cmd_args << job.uuid
 180       cmd_args << '--git-dir'
 181       cmd_args << arvados_internal
 182
 183       $stderr.puts "dispatch: #{cmd_args.join ' '}"
 184
 185       begin
 186         i, o, e, t = Open3.popen3(*cmd_args)
 187       rescue
 188         $stderr.puts "dispatch: popen3: #{$!}"
 189         sleep 1
 190         untake(job)
 191         next
 192       end
 193
 194       $stderr.puts "dispatch: job #{job.uuid}"
 195       start_banner = "dispatch: child #{t.pid} start #{Time.now.ctime.to_s}"
 196       $stderr.puts start_banner
 197
 198       @running[job.uuid] = {
 199         stdin: i,
 200         stdout: o,
 201         stderr: e,
 202         wait_thr: t,
 203         job: job,
 204         stderr_buf: '',
 205         started: false,
 206         sent_int: 0,
 207         job_auth: job_auth,
 208         stderr_buf_to_flush: '',
 209         stderr_flushed_at: 0
 210       }
 211       i.close
 212     end
 213   end
 214
 215   def take(job)
 216     # no-op -- let crunch-job take care of locking.
 217     true
 218   end
 219
 220   def untake(job)
 221     # no-op -- let crunch-job take care of locking.
 222     true
 223   end
 224
 225   def read_pipes
 226     @running.each do |job_uuid, j|
 227       job = j[:job]
 228
 229       # Throw away child stdout
 230       begin
 231         j[:stdout].read_nonblock(2**20)
 232       rescue Errno::EAGAIN, EOFError
 233       end
 234
 235       # Read whatever is available from child stderr
 236       stderr_buf = false
 237       begin
 238         stderr_buf = j[:stderr].read_nonblock(2**20)
 239       rescue Errno::EAGAIN, EOFError
 240       end
 241
 242       if stderr_buf
 243         j[:stderr_buf] << stderr_buf
 244         if j[:stderr_buf].index "\n"
 245           lines = j[:stderr_buf].lines("\n").to_a
 246           if j[:stderr_buf][-1] == "\n"
 247             j[:stderr_buf] = ''
 248           else
 249             j[:stderr_buf] = lines.pop
 250           end
 251           lines.each do |line|
 252             $stderr.print "#{job_uuid} ! " unless line.index(job_uuid)
 253             $stderr.puts line
 254             pub_msg = "#{Time.now.ctime.to_s} #{line.strip} \n"
 255             j[:stderr_buf_to_flush] << pub_msg
 256           end
 257
 258           if (LOG_BUFFER_SIZE < j[:stderr_buf_to_flush].size) || ((j[:stderr_flushed_at]+1) < Time.now.to_i)
 259             write_log j
 260           end
 261         end
 262       end
 263     end
 264   end
 265
 266   def reap_children
 267     return if 0 == @running.size
 268     pid_done = nil
 269     j_done = nil
 270
 271     if false
 272       begin
 273         pid_done = waitpid(-1, Process::WNOHANG | Process::WUNTRACED)
 274         if pid_done
 275           j_done = @running.values.
 276             select { |j| j[:wait_thr].pid == pid_done }.
 277             first
 278         end
 279       rescue SystemCallError
 280         # I have @running processes but system reports I have no
 281         # children. This is likely to happen repeatedly if it happens at
 282         # all; I will log this no more than once per child process I
 283         # start.
 284         if 0 < @running.select { |uuid,j| j[:warned_waitpid_error].nil? }.size
 285           children = @running.values.collect { |j| j[:wait_thr].pid }.join ' '
 286           $stderr.puts "dispatch: IPC bug: waitpid() error (#{$!}), but I have children #{children}"
 287         end
 288         @running.each do |uuid,j| j[:warned_waitpid_error] = true end
 289       end
 290     else
 291       @running.each do |uuid, j|
 292         if j[:wait_thr].status == false
 293           pid_done = j[:wait_thr].pid
 294           j_done = j
 295         end
 296       end
 297     end
 298
 299     return if !pid_done
 300
 301     job_done = j_done[:job]
 302     $stderr.puts "dispatch: child #{pid_done} exit"
 303     $stderr.puts "dispatch: job #{job_done.uuid} end"
 304
 305     # Ensure every last drop of stdout and stderr is consumed
 306     read_pipes
 307     write_log j_done # write any remaining logs
 308
 309     if j_done[:stderr_buf] and j_done[:stderr_buf] != ''
 310       $stderr.puts j_done[:stderr_buf] + "\n"
 311     end
 312
 313     # Wait the thread
 314     j_done[:wait_thr].value
 315
 316     jobrecord = Job.find_by_uuid(job_done.uuid)
 317     if jobrecord.started_at
 318       # Clean up state fields in case crunch-job exited without
 319       # putting the job in a suitable "finished" state.
 320       jobrecord.running = false
 321       jobrecord.finished_at ||= Time.now
 322       if jobrecord.success.nil?
 323         jobrecord.success = false
 324       end
 325       jobrecord.save!
 326     else
 327       # Don't fail the job if crunch-job didn't even get as far as
 328       # starting it. If the job failed to run due to an infrastructure
 329       # issue with crunch-job or slurm, we want the job to stay in the
 330       # queue.
 331     end
 332
 333     # Invalidate the per-job auth token
 334     j_done[:job_auth].update_attributes expires_at: Time.now
 335
 336     @running.delete job_done.uuid
 337   end
 338
 339   def update_pipelines
 340     expire_tokens = @pipe_auth_tokens.dup
 341     @todo_pipelines.each do |p|
 342       pipe_auth = (@pipe_auth_tokens[p.uuid] ||= ApiClientAuthorization.
 343                    create(user: User.where('uuid=?', p.modified_by_user_uuid).first,
 344                           api_client_id: 0))
 345       puts `export ARVADOS_API_TOKEN=#{pipe_auth.api_token} && arv-run-pipeline-instance --run-here --no-wait --instance #{p.uuid}`
 346       expire_tokens.delete p.uuid
 347     end
 348
 349     expire_tokens.each do |k, v|
 350       v.update_attributes expires_at: Time.now
 351       @pipe_auth_tokens.delete k
 352     end
 353   end
 354
 355   def run
 356     act_as_system_user
 357     @running ||= {}
 358     @pipe_auth_tokens ||= { }
 359     $stderr.puts "dispatch: ready"
 360     while !$signal[:term] or @running.size > 0
 361       read_pipes
 362       if $signal[:term]
 363         @running.each do |uuid, j|
 364           if !j[:started] and j[:sent_int] < 2
 365             begin
 366               Process.kill 'INT', j[:wait_thr].pid
 367             rescue Errno::ESRCH
 368               # No such pid = race condition + desired result is
 369               # already achieved
 370             end
 371             j[:sent_int] += 1
 372           end
 373         end
 374       else
 375         refresh_todo unless did_recently(:refresh_todo, 1.0)
 376         update_node_status
 377         unless @todo.empty? or did_recently(:start_jobs, 1.0) or $signal[:term]
 378           start_jobs
 379         end
 380         unless (@todo_pipelines.empty? and @pipe_auth_tokens.empty?) or did_recently(:update_pipelines, 5.0)
 381           update_pipelines
 382         end
 383       end
 384       reap_children
 385       select(@running.values.collect { |j| [j[:stdout], j[:stderr]] }.flatten,
 386              [], [], 1)
 387     end
 388   end
 389
 390   protected
 391
 392   def did_recently(thing, min_interval)
 393     @did_recently ||= {}
 394     if !@did_recently[thing] or @did_recently[thing] < Time.now - min_interval
 395       @did_recently[thing] = Time.now
 396       false
 397     else
 398       true
 399     end
 400   end
 401
 402   # send message to log table. we want these records to be transient
 403   def write_log running_job
 404     begin
 405       if (running_job && running_job[:stderr_buf_to_flush] != '')
 406         log = Log.new(object_uuid: running_job[:job].uuid,
 407                       event_type: 'stderr',
 408                       owner_uuid: running_job[:job].owner_uuid,
 409                       properties: {"text" => running_job[:stderr_buf_to_flush]})
 410         log.save!
 411         running_job[:stderr_buf_to_flush] = ''
 412         running_job[:stderr_flushed_at] = Time.now.to_i
 413       end
 414     rescue
 415       running_job[:stderr_buf] = "Failed to write logs \n"
 416       running_job[:stderr_buf_to_flush] = ''
 417       running_job[:stderr_flushed_at] = Time.now.to_i
 418     end
 419   end
 420
 421 end
 422
 423 # This is how crunch-job child procs know where the "refresh" trigger file is
 424 ENV["CRUNCH_REFRESH_TRIGGER"] = Rails.configuration.crunch_refresh_trigger
 425
 426 Dispatcher.new.run