6 include ApplicationHelper
10 EXIT_RETRY_UNLOCKED = 93
11 RETRY_UNLOCKED_LIMIT = 3
15 self.utc.strftime "%Y-%m-%d_%H:%M:%S"
20 @crunch_job_bin = (ENV['CRUNCH_JOB_BIN'] || `which arv-crunch-job`.strip)
21 if @crunch_job_bin.empty?
22 raise "No CRUNCH_JOB_BIN env var, and crunch-job not in path."
25 @docker_bin = ENV['CRUNCH_JOB_DOCKER_BIN']
26 @docker_run_args = ENV['CRUNCH_JOB_DOCKER_RUN_ARGS']
27 @cgroup_root = ENV['CRUNCH_CGROUP_ROOT']
29 @arvados_internal = Rails.configuration.git_internal_dir
30 if not File.exist? @arvados_internal
31 $stderr.puts `mkdir -p #{@arvados_internal.shellescape} && git init --bare #{@arvados_internal.shellescape}`
32 raise "No internal git repository available" unless ($? == 0)
35 @repo_root = Rails.configuration.git_repositories_dir
36 @arvados_repo_path = Repository.where(name: "arvados").first.server_path
42 @pipe_auth_tokens = {}
45 @todo_job_retries = {}
46 @job_retry_counts = Hash.new(0)
51 return act_as_system_user
56 @todo = @todo_job_retries.values + Job.queue.select(&:repository)
58 if @runoptions[:pipelines]
59 @todo_pipelines = PipelineInstance.queue
63 def each_slurm_line(cmd, outfmt, max_fields=nil)
64 max_fields ||= outfmt.split(":").size
65 max_fields += 1 # To accommodate the node field we add
66 @@slurm_version ||= Gem::Version.new(`sinfo --version`.match(/\b[\d\.]+\b/)[0])
67 if Gem::Version.new('2.3') <= @@slurm_version
68 `#{cmd} --noheader -o '%n:#{outfmt}'`.each_line do |line|
69 yield line.chomp.split(":", max_fields)
72 # Expand rows with hostname ranges (like "foo[1-3,5,9-12]:idle")
73 # into multiple rows with one hostname each.
74 `#{cmd} --noheader -o '%N:#{outfmt}'`.each_line do |line|
75 tokens = line.chomp.split(":", max_fields)
76 if (re = tokens[0].match(/^(.*?)\[([-,\d]+)\]$/))
78 re[2].split(",").each do |range|
79 range = range.split("-").collect(&:to_i)
80 (range[0]..range[-1]).each do |n|
81 yield [re[1] + n.to_s] + tokens
93 each_slurm_line("sinfo", "%t") do |hostname, state|
94 # Treat nodes in idle* state as down, because the * means that slurm
95 # hasn't been able to communicate with it recently.
96 state.sub!(/^idle\*/, "down")
97 state.sub!(/\W+$/, "")
98 state = "down" unless %w(idle alloc down).include?(state)
99 slurm_nodes[hostname] = {state: state, job: nil}
101 each_slurm_line("squeue", "%j") do |hostname, job_uuid|
102 slurm_nodes[hostname][:job] = job_uuid if slurm_nodes[hostname]
107 def update_node_status
108 return unless Server::Application.config.crunch_job_wrapper.to_s.match(/^slurm/)
109 slurm_status.each_pair do |hostname, slurmdata|
110 next if @node_state[hostname] == slurmdata
112 node = Node.where('hostname=?', hostname).order(:last_ping_at).last
114 $stderr.puts "dispatch: update #{hostname} state to #{slurmdata}"
115 node.info["slurm_state"] = slurmdata[:state]
116 node.job_uuid = slurmdata[:job]
118 @node_state[hostname] = slurmdata
120 $stderr.puts "dispatch: failed to update #{node.uuid}: #{node.errors.messages}"
122 elsif slurmdata[:state] != 'down'
123 $stderr.puts "dispatch: SLURM reports '#{hostname}' is not down, but no node has that name"
126 $stderr.puts "dispatch: error updating #{hostname} node status: #{error}"
131 def positive_int(raw_value, default=nil)
132 value = begin raw_value.to_i rescue 0 end
140 NODE_CONSTRAINT_MAP = {
141 # Map Job runtime_constraints keys to the corresponding Node info key.
142 'min_ram_mb_per_node' => 'total_ram_mb',
143 'min_scratch_mb_per_node' => 'total_scratch_mb',
144 'min_cores_per_node' => 'total_cpu_cores',
147 def nodes_available_for_job_now(job)
148 # Find Nodes that satisfy a Job's runtime constraints (by building
149 # a list of Procs and using them to test each Node). If there
150 # enough to run the Job, return an array of their names.
151 # Otherwise, return nil.
152 need_procs = NODE_CONSTRAINT_MAP.each_pair.map do |job_key, node_key|
154 positive_int(node.properties[node_key], 0) >=
155 positive_int(job.runtime_constraints[job_key], 0)
158 min_node_count = positive_int(job.runtime_constraints['min_nodes'], 1)
160 Node.all.select do |node|
161 node.info['slurm_state'] == 'idle'
162 end.sort_by do |node|
163 # Prefer nodes with no price, then cheap nodes, then expensive nodes
164 node.properties['cloud_node']['price'].to_f rescue 0
166 if need_procs.select { |need_proc| not need_proc.call(node) }.any?
167 # At least one runtime constraint is not satisfied by this node
171 if usable_nodes.count >= min_node_count
172 return usable_nodes.map { |n| n.hostname }
178 def nodes_available_for_job(job)
179 # Check if there are enough idle nodes with the Job's minimum
180 # hardware requirements to run it. If so, return an array of
181 # their names. If not, up to once per hour, signal start_jobs to
182 # hold off launching Jobs. This delay is meant to give the Node
183 # Manager an opportunity to make new resources available for new
186 # The exact timing parameters here might need to be adjusted for
187 # the best balance between helping the longest-waiting Jobs run,
188 # and making efficient use of immediately available resources.
189 # These are all just first efforts until we have more data to work
191 nodelist = nodes_available_for_job_now(job)
192 if nodelist.nil? and not did_recently(:wait_for_available_nodes, 3600)
193 $stderr.puts "dispatch: waiting for nodes for #{job.uuid}"
194 @node_wait_deadline = Time.now + 5.minutes
199 def fail_job job, message, skip_lock: false
200 $stderr.puts "dispatch: #{job.uuid}: #{message}"
202 Log.new(object_uuid: job.uuid,
203 event_type: 'dispatch',
204 owner_uuid: job.owner_uuid,
206 properties: {"text" => message}).save!
208 $stderr.puts "dispatch: log.create failed"
211 if not skip_lock and not have_job_lock?(job)
213 job.lock @authorizations[job.uuid].user.uuid
214 rescue ArvadosModel::AlreadyLockedError
215 $stderr.puts "dispatch: tried to mark job #{job.uuid} as failed but it was already locked by someone else"
222 $stderr.puts "dispatch: save failed setting job #{job.uuid} to failed"
226 def stdout_s(cmd_a, opts={})
227 IO.popen(cmd_a, "r", opts) do |pipe|
228 return pipe.read.chomp
233 ["git", "--git-dir=#{@arvados_internal}"] + cmd_a
236 def get_authorization(job)
237 if @authorizations[job.uuid] and
238 @authorizations[job.uuid].user.uuid != job.modified_by_user_uuid
239 # We already made a token for this job, but we need a new one
240 # because modified_by_user_uuid has changed (the job will run
241 # as a different user).
242 @authorizations[job.uuid].update_attributes expires_at: Time.now
243 @authorizations[job.uuid] = nil
245 if not @authorizations[job.uuid]
246 auth = ApiClientAuthorization.
247 new(user: User.where('uuid=?', job.modified_by_user_uuid).first,
250 $stderr.puts "dispatch: auth.save failed for #{job.uuid}"
252 @authorizations[job.uuid] = auth
255 @authorizations[job.uuid]
258 def internal_repo_has_commit? sha1
259 if (not @fetched_commits[sha1] and
260 sha1 == stdout_s(git_cmd("rev-list", "-n1", sha1), err: "/dev/null") and
262 @fetched_commits[sha1] = true
264 return @fetched_commits[sha1]
267 def get_commit src_repo, sha1
268 return true if internal_repo_has_commit? sha1
270 # commit does not exist in internal repository, so import the
271 # source repository using git fetch-pack
272 cmd = git_cmd("fetch-pack", "--no-progress", "--all", src_repo)
273 $stderr.puts "dispatch: #{cmd}"
274 $stderr.puts(stdout_s(cmd))
275 @fetched_commits[sha1] = ($? == 0)
278 def tag_commit(commit_hash, tag_name)
279 # @git_tags[T]==V if we know commit V has been tagged T in the
280 # arvados_internal repository.
281 if not @git_tags[tag_name]
282 cmd = git_cmd("tag", tag_name, commit_hash)
283 $stderr.puts "dispatch: #{cmd}"
284 $stderr.puts(stdout_s(cmd, err: "/dev/null"))
286 # git tag failed. This may be because the tag already exists, so check for that.
287 tag_rev = stdout_s(git_cmd("rev-list", "-n1", tag_name))
289 # We got a revision back
290 if tag_rev != commit_hash
291 # Uh oh, the tag doesn't point to the revision we were expecting.
292 # Someone has been monkeying with the job record and/or git.
293 fail_job job, "Existing tag #{tag_name} points to commit #{tag_rev} but expected commit #{commit_hash}"
296 # we're okay (fall through to setting @git_tags below)
298 # git rev-list failed for some reason.
299 fail_job job, "'git tag' for #{tag_name} failed but did not find any existing tag using 'git rev-list'"
303 # 'git tag' was successful, or there is an existing tag that points to the same revision.
304 @git_tags[tag_name] = commit_hash
305 elsif @git_tags[tag_name] != commit_hash
306 fail_job job, "Existing tag #{tag_name} points to commit #{@git_tags[tag_name]} but this job uses commit #{commit_hash}"
314 next if @running[job.uuid]
317 case Server::Application.config.crunch_job_wrapper
320 # Don't run more than one at a time.
324 when :slurm_immediate
325 nodelist = nodes_available_for_job(job)
327 if Time.now < @node_wait_deadline
333 cmd_args = ["salloc",
338 "--job-name=#{job.uuid}",
339 "--nodelist=#{nodelist.join(',')}"]
341 raise "Unknown crunch_job_wrapper: #{Server::Application.config.crunch_job_wrapper}"
344 cmd_args = sudo_preface + cmd_args
346 next unless get_authorization job
348 ready = internal_repo_has_commit? job.script_version
351 # Import the commit from the specified repository into the
352 # internal repository. This should have been done already when
353 # the job was created/updated; this code is obsolete except to
354 # avoid deployment races. Failing the job would be a
355 # reasonable thing to do at this point.
356 repo = Repository.where(name: job.repository).first
357 if repo.nil? or repo.server_path.nil?
358 fail_job job, "Repository #{job.repository} not found under #{@repo_root}"
361 ready &&= get_commit repo.server_path, job.script_version
362 ready &&= tag_commit job.script_version, job.uuid
365 # This should be unnecessary, because API server does it during
366 # job create/update, but it's still not a bad idea to verify the
367 # tag is correct before starting the job:
368 ready &&= tag_commit job.script_version, job.uuid
370 # The arvados_sdk_version doesn't support use of arbitrary
371 # remote URLs, so the requested version isn't necessarily copied
372 # into the internal repository yet.
373 if job.arvados_sdk_version
374 ready &&= get_commit @arvados_repo_path, job.arvados_sdk_version
375 ready &&= tag_commit job.arvados_sdk_version, "#{job.uuid}-arvados-sdk"
379 fail_job job, "commit not present in internal repository"
383 cmd_args += [@crunch_job_bin,
384 '--job-api-token', @authorizations[job.uuid].api_token,
386 '--git-dir', @arvados_internal]
389 cmd_args += ['--cgroup-root', @cgroup_root]
393 cmd_args += ['--docker-bin', @docker_bin]
397 cmd_args += ['--docker-run-args', @docker_run_args]
400 if have_job_lock?(job)
401 cmd_args << "--force-unlock"
404 $stderr.puts "dispatch: #{cmd_args.join ' '}"
407 i, o, e, t = Open3.popen3(*cmd_args)
409 $stderr.puts "dispatch: popen3: #{$!}"
414 $stderr.puts "dispatch: job #{job.uuid}"
415 start_banner = "dispatch: child #{t.pid} start #{LogTime.now}"
416 $stderr.puts start_banner
418 @running[job.uuid] = {
424 buf: {stderr: '', stdout: ''},
427 job_auth: @authorizations[job.uuid],
428 stderr_buf_to_flush: '',
429 stderr_flushed_at: Time.new(0),
432 log_throttle_is_open: true,
433 log_throttle_reset_time: Time.now + Rails.configuration.crunch_log_throttle_period,
434 log_throttle_bytes_so_far: 0,
435 log_throttle_lines_so_far: 0,
436 log_throttle_bytes_skipped: 0,
437 log_throttle_partial_line_last_at: Time.new(0),
438 log_throttle_first_partial_line: true,
441 @todo_job_retries.delete(job.uuid)
446 # Test for hard cap on total output and for log throttling. Returns whether
447 # the log line should go to output or not. Modifies "line" in place to
448 # replace it with an error if a logging limit is tripped.
449 def rate_limit running_job, line
452 if running_job[:log_throttle_is_open]
455 matches = line.match(/^\S+ \S+ \d+ \d+ stderr (.*)/)
456 if matches and matches[1] and matches[1].start_with?('[...]') and matches[1].end_with?('[...]')
458 if Time.now > running_job[:log_throttle_partial_line_last_at] + Rails.configuration.crunch_log_partial_line_throttle_period
459 running_job[:log_throttle_partial_line_last_at] = Time.now
466 running_job[:log_throttle_lines_so_far] += 1
467 running_job[:log_throttle_bytes_so_far] += linesize
468 running_job[:bytes_logged] += linesize
471 if (running_job[:bytes_logged] >
472 Rails.configuration.crunch_limit_log_bytes_per_job)
473 message = "Exceeded log limit #{Rails.configuration.crunch_limit_log_bytes_per_job} bytes (crunch_limit_log_bytes_per_job). Log will be truncated."
474 running_job[:log_throttle_reset_time] = Time.now + 100.years
475 running_job[:log_throttle_is_open] = false
477 elsif (running_job[:log_throttle_bytes_so_far] >
478 Rails.configuration.crunch_log_throttle_bytes)
479 remaining_time = running_job[:log_throttle_reset_time] - Time.now
480 message = "Exceeded rate #{Rails.configuration.crunch_log_throttle_bytes} bytes per #{Rails.configuration.crunch_log_throttle_period} seconds (crunch_log_throttle_bytes). Logging will be silenced for the next #{remaining_time.round} seconds."
481 running_job[:log_throttle_is_open] = false
483 elsif (running_job[:log_throttle_lines_so_far] >
484 Rails.configuration.crunch_log_throttle_lines)
485 remaining_time = running_job[:log_throttle_reset_time] - Time.now
486 message = "Exceeded rate #{Rails.configuration.crunch_log_throttle_lines} lines per #{Rails.configuration.crunch_log_throttle_period} seconds (crunch_log_throttle_lines), logging will be silenced for the next #{remaining_time.round} seconds."
487 running_job[:log_throttle_is_open] = false
489 elsif partial_line and running_job[:log_throttle_first_partial_line]
490 running_job[:log_throttle_first_partial_line] = false
491 message = "Rate-limiting partial segments of long lines to one every #{Rails.configuration.crunch_log_partial_line_throttle_period} seconds."
495 if not running_job[:log_throttle_is_open]
496 # Don't log anything if any limit has been exceeded. Just count lossage.
497 running_job[:log_throttle_bytes_skipped] += linesize
501 # Yes, write to logs, but use our "rate exceeded" message
502 # instead of the log message that exceeded the limit.
503 message += " A complete log is still being written to Keep, and will be available when the job finishes.\n"
509 running_job[:log_throttle_is_open]
514 @running.each do |job_uuid, j|
516 if now > j[:log_throttle_reset_time]
517 # It has been more than throttle_period seconds since the last
518 # checkpoint so reset the throttle
519 if j[:log_throttle_bytes_skipped] > 0
520 message = "#{job_uuid} ! Skipped #{j[:log_throttle_bytes_skipped]} bytes of log"
522 j[:stderr_buf_to_flush] << "#{LogTime.now} #{message}\n"
525 j[:log_throttle_reset_time] = now + Rails.configuration.crunch_log_throttle_period
526 j[:log_throttle_bytes_so_far] = 0
527 j[:log_throttle_lines_so_far] = 0
528 j[:log_throttle_bytes_skipped] = 0
529 j[:log_throttle_is_open] = true
530 j[:log_throttle_partial_line_last_at] = Time.new(0)
531 j[:log_throttle_first_partial_line] = true
534 j[:buf].each do |stream, streambuf|
535 # Read some data from the child stream
538 # It's important to use a big enough buffer here. When we're
539 # being flooded with logs, we must read and discard many
540 # bytes at once. Otherwise, we can easily peg a CPU with
541 # time-checking and other loop overhead. (Quick tests show a
542 # 1MiB buffer working 2.5x as fast as a 64 KiB buffer.)
544 # So don't reduce this buffer size!
545 buf = j[stream].read_nonblock(2**20)
546 rescue Errno::EAGAIN, EOFError
549 # Short circuit the counting code if we're just going to throw
550 # away the data anyway.
551 if not j[:log_throttle_is_open]
552 j[:log_throttle_bytes_skipped] += streambuf.size + buf.size
559 # Append to incomplete line from previous read, if any
563 streambuf.each_line do |line|
564 if not line.end_with? $/
565 if line.size > Rails.configuration.crunch_log_throttle_bytes
566 # Without a limit here, we'll use 2x an arbitrary amount
567 # of memory, and waste a lot of time copying strings
568 # around, all without providing any feedback to anyone
569 # about what's going on _or_ hitting any of our throttle
572 # Here we leave "line" alone, knowing it will never be
573 # sent anywhere: rate_limit() will reach
574 # crunch_log_throttle_bytes immediately. However, we'll
575 # leave [...] in bufend: if the trailing end of the long
576 # line does end up getting sent anywhere, it will have
577 # some indication that it is incomplete.
580 # If line length is sane, we'll wait for the rest of the
581 # line to appear in the next read_pipes() call.
586 # rate_limit returns true or false as to whether to actually log
587 # the line or not. It also modifies "line" in place to replace
588 # it with an error if a logging limit is tripped.
589 if rate_limit j, line
590 $stderr.print "#{job_uuid} ! " unless line.index(job_uuid)
592 pub_msg = "#{LogTime.now} #{line.strip}\n"
593 j[:stderr_buf_to_flush] << pub_msg
597 # Leave the trailing incomplete line (if any) in streambuf for
599 streambuf.replace bufend
601 # Flush buffered logs to the logs table, if appropriate. We have
602 # to do this even if we didn't collect any new logs this time:
603 # otherwise, buffered data older than seconds_between_events
604 # won't get flushed until new data arrives.
610 return if 0 == @running.size
616 pid_done = waitpid(-1, Process::WNOHANG | Process::WUNTRACED)
618 j_done = @running.values.
619 select { |j| j[:wait_thr].pid == pid_done }.
622 rescue SystemCallError
623 # I have @running processes but system reports I have no
624 # children. This is likely to happen repeatedly if it happens at
625 # all; I will log this no more than once per child process I
627 if 0 < @running.select { |uuid,j| j[:warned_waitpid_error].nil? }.size
628 children = @running.values.collect { |j| j[:wait_thr].pid }.join ' '
629 $stderr.puts "dispatch: IPC bug: waitpid() error (#{$!}), but I have children #{children}"
631 @running.each do |uuid,j| j[:warned_waitpid_error] = true end
634 @running.each do |uuid, j|
635 if j[:wait_thr].status == false
636 pid_done = j[:wait_thr].pid
644 job_done = j_done[:job]
646 # Ensure every last drop of stdout and stderr is consumed.
648 # Reset flush timestamp to make sure log gets written.
649 j_done[:stderr_flushed_at] = Time.new(0)
650 # Write any remaining logs.
653 j_done[:buf].each do |stream, streambuf|
655 $stderr.puts streambuf + "\n"
659 # Wait the thread (returns a Process::Status)
660 exit_status = j_done[:wait_thr].value.exitstatus
661 exit_tempfail = exit_status == EXIT_TEMPFAIL
663 $stderr.puts "dispatch: child #{pid_done} exit #{exit_status}"
664 $stderr.puts "dispatch: job #{job_done.uuid} end"
666 jobrecord = Job.find_by_uuid(job_done.uuid)
668 if exit_status == EXIT_RETRY_UNLOCKED or (exit_tempfail and @job_retry_counts.include? jobrecord.uuid)
669 # Only this crunch-dispatch process can retry the job:
670 # it's already locked, and there's no way to put it back in the
671 # Queued state. Put it in our internal todo list unless the job
672 # has failed this way excessively.
673 @job_retry_counts[jobrecord.uuid] += 1
674 exit_tempfail = @job_retry_counts[jobrecord.uuid] <= RETRY_UNLOCKED_LIMIT
676 @todo_job_retries[jobrecord.uuid] = jobrecord
678 $stderr.puts("dispatch: job #{jobrecord.uuid} exceeded node failure retry limit -- giving up")
683 @job_retry_counts.delete(jobrecord.uuid)
684 if jobrecord.state == "Running"
685 # Apparently there was an unhandled error. That could potentially
686 # include "all allocated nodes failed" when we don't to retry
687 # because the job has already been retried RETRY_UNLOCKED_LIMIT
688 # times. Fail the job.
689 jobrecord.state = "Failed"
690 if not jobrecord.save
691 $stderr.puts "dispatch: jobrecord.save failed"
695 # If the job failed to run due to an infrastructure
696 # issue with crunch-job or slurm, we want the job to stay in the
697 # queue. If crunch-job exited after losing a race to another
698 # crunch-job process, it exits 75 and we should leave the job
699 # record alone so the winner of the race can do its thing.
700 # If crunch-job exited after all of its allocated nodes failed,
701 # it exits 93, and we want to retry it later (see the
702 # EXIT_RETRY_UNLOCKED `if` block).
704 # There is still an unhandled race condition: If our crunch-job
705 # process is about to lose a race with another crunch-job
706 # process, but crashes before getting to its "exit 75" (for
707 # example, "cannot fork" or "cannot reach API server") then we
708 # will assume incorrectly that it's our process's fault
709 # jobrecord.started_at is non-nil, and mark the job as failed
710 # even though the winner of the race is probably still doing
714 # Invalidate the per-job auth token, unless the job is still queued and we
715 # might want to try it again.
716 if jobrecord.state != "Queued" and !@todo_job_retries.include?(jobrecord.uuid)
717 j_done[:job_auth].update_attributes expires_at: Time.now
720 @running.delete job_done.uuid
724 expire_tokens = @pipe_auth_tokens.dup
725 @todo_pipelines.each do |p|
726 pipe_auth = (@pipe_auth_tokens[p.uuid] ||= ApiClientAuthorization.
727 create(user: User.where('uuid=?', p.modified_by_user_uuid).first,
729 puts `export ARVADOS_API_TOKEN=#{pipe_auth.api_token} && arv-run-pipeline-instance --run-pipeline-here --no-wait --instance #{p.uuid}`
730 expire_tokens.delete p.uuid
733 expire_tokens.each do |k, v|
734 v.update_attributes expires_at: Time.now
735 @pipe_auth_tokens.delete k
741 (argv.any? ? argv : ['--jobs', '--pipelines']).each do |arg|
744 @runoptions[:jobs] = true
746 @runoptions[:pipelines] = true
748 abort "Unrecognized command line option '#{arg}'"
751 if not (@runoptions[:jobs] or @runoptions[:pipelines])
752 abort "Nothing to do. Please specify at least one of: --jobs, --pipelines."
759 # We want files written by crunch-dispatch to be writable by other
760 # processes with the same GID, see bug #7228
763 # This is how crunch-job child procs know where the "refresh"
765 ENV["CRUNCH_REFRESH_TRIGGER"] = Rails.configuration.crunch_refresh_trigger
767 # If salloc can't allocate resources immediately, make it use our
768 # temporary failure exit code. This ensures crunch-dispatch won't
769 # mark a job failed because of an issue with node allocation.
770 # This often happens when another dispatcher wins the race to
772 ENV["SLURM_EXIT_IMMEDIATE"] = CrunchDispatch::EXIT_TEMPFAIL.to_s
774 if ENV["CRUNCH_DISPATCH_LOCKFILE"]
775 lockfilename = ENV.delete "CRUNCH_DISPATCH_LOCKFILE"
776 lockfile = File.open(lockfilename, File::RDWR|File::CREAT, 0644)
777 unless lockfile.flock File::LOCK_EX|File::LOCK_NB
778 abort "Lock unavailable on #{lockfilename} - exit"
783 %w{TERM INT}.each do |sig|
786 $stderr.puts "Received #{signame} signal"
787 @signal[:term] = true
792 User.first.group_permissions
793 $stderr.puts "dispatch: ready"
794 while !@signal[:term] or @running.size > 0
797 @running.each do |uuid, j|
798 if !j[:started] and j[:sent_int] < 2
800 Process.kill 'INT', j[:wait_thr].pid
802 # No such pid = race condition + desired result is
809 refresh_todo unless did_recently(:refresh_todo, 1.0)
810 update_node_status unless did_recently(:update_node_status, 1.0)
811 unless @todo.empty? or did_recently(:start_jobs, 1.0) or @signal[:term]
814 unless (@todo_pipelines.empty? and @pipe_auth_tokens.empty?) or did_recently(:update_pipelines, 5.0)
819 select(@running.values.collect { |j| [j[:stdout], j[:stderr]] }.flatten,
822 # If there are jobs we wanted to retry, we have to mark them as failed now.
823 # Other dispatchers can't pick them up because we hold their lock.
824 @todo_job_retries.each_key do |job_uuid|
825 job = Job.find_by_uuid(job_uuid)
826 if job.state == "Running"
827 fail_job(job, "crunch-dispatch was stopped during job's tempfail retry loop")
832 def fail_jobs before: nil
833 act_as_system_user do
835 if before == 'reboot'
837 open('/proc/stat').map(&:split).each do |stat, t|
843 raise "Could not find btime in /proc/stat"
845 threshold = Time.at(boottime.to_i)
847 threshold = Time.parse(before, Time.now)
849 threshold = db_current_time
851 Rails.logger.info "fail_jobs: threshold is #{threshold}"
853 if Rails.configuration.crunch_job_wrapper == :slurm_immediate
854 # [["slurm_job_id", "slurm_job_name"], ...]
855 squeue = File.popen(['squeue', '-h', '-o', '%i %j']).readlines.map do |line|
856 line.strip.split(' ', 2)
862 Job.where('state = ? and started_at < ?', Job::Running, threshold).
864 Rails.logger.debug "fail_jobs: #{job.uuid} started #{job.started_at}"
865 squeue.each do |slurm_id, slurm_name|
866 if slurm_name == job.uuid
867 Rails.logger.info "fail_jobs: scancel #{slurm_id} for #{job.uuid}"
871 fail_job(job, "cleaned up stale job: started before #{threshold}",
879 def have_job_lock?(job)
880 # Return true if the given job is locked by this crunch-dispatch, normally
881 # because we've run crunch-job for it.
882 @todo_job_retries.include?(job.uuid)
885 def did_recently(thing, min_interval)
886 if !@did_recently[thing] or @did_recently[thing] < Time.now - min_interval
887 @did_recently[thing] = Time.now
894 # send message to log table. we want these records to be transient
895 def write_log running_job
896 return if running_job[:stderr_buf_to_flush] == ''
898 # Send out to log event if buffer size exceeds the bytes per event or if
899 # it has been at least crunch_log_seconds_between_events seconds since
901 if running_job[:stderr_buf_to_flush].size > Rails.configuration.crunch_log_bytes_per_event or
902 (Time.now - running_job[:stderr_flushed_at]) >= Rails.configuration.crunch_log_seconds_between_events
904 log = Log.new(object_uuid: running_job[:job].uuid,
905 event_type: 'stderr',
906 owner_uuid: running_job[:job].owner_uuid,
907 properties: {"text" => running_job[:stderr_buf_to_flush]})
909 running_job[:events_logged] += 1
911 $stderr.puts "Failed to write logs"
912 $stderr.puts exception.backtrace
914 running_job[:stderr_buf_to_flush] = ''
915 running_job[:stderr_flushed_at] = Time.now
920 cmd = sudo_preface + ['scancel', slurm_id]
921 puts File.popen(cmd).read
923 Rails.logger.error "scancel #{slurm_id.shellescape}: $?"
928 return [] if not Server::Application.config.crunch_job_user
930 Server::Application.config.crunch_job_user,
931 "LD_LIBRARY_PATH=#{ENV['LD_LIBRARY_PATH']}",
932 "PATH=#{ENV['PATH']}",
933 "PERLLIB=#{ENV['PERLLIB']}",
934 "PYTHONPATH=#{ENV['PYTHONPATH']}",
935 "RUBYLIB=#{ENV['RUBYLIB']}",
936 "GEM_PATH=#{ENV['GEM_PATH']}"]