diff --git a/lib/rspecq.rb b/lib/rspecq.rb index aaa4c86..1d75355 100644 --- a/lib/rspecq.rb +++ b/lib/rspecq.rb @@ -1,4 +1,5 @@ require "rspec/core" +require "sentry-raven" module RSpecQ # If a worker haven't executed an example for more than WORKER_LIVENESS_SEC diff --git a/lib/rspecq/worker.rb b/lib/rspecq/worker.rb index ce29792..822c8da 100644 --- a/lib/rspecq/worker.rb +++ b/lib/rspecq/worker.rb @@ -102,10 +102,11 @@ def try_publish_queue!(queue) timings = queue.timings if timings.empty? - # TODO: should be a warning reported somewhere (Sentry?) q_size = queue.publish(files_to_run.shuffle) - puts "WARNING: No timings found! Published queue in " \ - "random order (size=#{q_size})" + log_event( + "No timings found! Published queue in random order (size=#{q_size})", + "warning" + ) return end @@ -114,7 +115,12 @@ def try_publish_queue!(queue) end.map(&:first) & files_to_run if slow_files.any? - puts "Slow files (threshold=#{file_split_threshold}): #{slow_files}" + log_event( + "Slow files detected (threshold=#{file_split_threshold}): #{slow_files}", + "info", + slow_files: slow_files, + slow_files_count: slow_files.count, + ) end # prepare jobs to run @@ -127,7 +133,7 @@ def try_publish_queue!(queue) jobs = jobs.each_with_object({}) do |j, h| # heuristic: put untimed jobs in the middle of the queue - puts "New/untimed job: #{j}" if timings[j].nil? + log_event("New/untimed job: #{j}", "debug", job: j) if timings[j].nil? h[j] = timings[j] || default_timing end @@ -168,14 +174,22 @@ def files_to_example_ids(files) out = `#{cmd}` if !$?.success? - # TODO: emit warning to Sentry - puts "WARNING: Error splitting slow files; falling back to regular scheduling:" - - begin - pp JSON.parse(out) - rescue JSON::ParserError - puts out - end + puts out + puts $?.inspect + rspec_output = begin + JSON.parse(out) + rescue JSON::ParserError + out + end + + log_event( + "Failed to split slow files, falling back to regular scheduling", + "error", + rspec_output: rspec_output, + cmd_result: $?.inspect, + ) + + pp rspec_output puts return files @@ -192,5 +206,21 @@ def relative_path(job) def elapsed(since) Process.clock_gettime(Process::CLOCK_MONOTONIC) - since end + + def log_event(msg, level, additional={}) + puts msg + + Raven.capture_message(msg, level: level, extra: { + build: @build_id, + worker: @worker_id, + queue: queue.inspect, + files_or_dirs_to_run: @files_or_dirs_to_run, + populate_timings: populate_timings, + file_split_threshold: file_split_threshold, + heartbeat_updated_at: @heartbeat_updated_at, + object: self.inspect, + pid: Process.pid, + }.merge(additional)) + end end end diff --git a/rspecq.gemspec b/rspecq.gemspec index c4824a6..9a80bdc 100644 --- a/rspecq.gemspec +++ b/rspecq.gemspec @@ -19,6 +19,7 @@ Gem::Specification.new do |s| end s.add_dependency "redis" + s.add_dependency "sentry-raven" s.add_development_dependency "rake" s.add_development_dependency "pry-byebug"