services/api/script/crunch-dispatch.rb

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