diff --git a/Gemfile b/Gemfile index 773069fc9..1a7f410b3 100644 --- a/Gemfile +++ b/Gemfile @@ -8,6 +8,10 @@ source "https://rubygems.org" # Uncomment this to use development version of html formatter from github # gem "simplecov-html", github: "simplecov-ruby/simplecov-html" +# former std libs that have been ejected +gem "logger" +gem "ostruct" + gem "matrix" group :development do diff --git a/Gemfile.lock b/Gemfile.lock index 799664e48..9816229d3 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -83,6 +83,7 @@ GEM json (2.9.1) json (2.9.1-java) language_server-protocol (3.17.0.3) + logger (1.6.6) matrix (0.4.2) method_source (1.1.0) mini_mime (1.1.5) @@ -92,6 +93,7 @@ GEM nokogiri (1.18.1) mini_portile2 (~> 2.8.2) racc (~> 1.4) + ostruct (0.6.1) parallel (1.26.3) parser (3.3.6.0) ast (~> 2.4.1) @@ -180,8 +182,10 @@ DEPENDENCIES benchmark-ips capybara cucumber + logger matrix minitest + ostruct pry rackup rake @@ -192,4 +196,4 @@ DEPENDENCIES webrick BUNDLED WITH - 2.7.0.dev + 2.6.5 diff --git a/features/step_definitions/old_coverage_json_steps.rb b/features/step_definitions/old_coverage_json_steps.rb index 7f94f1434..57d18491e 100644 --- a/features/step_definitions/old_coverage_json_steps.rb +++ b/features/step_definitions/old_coverage_json_steps.rb @@ -15,7 +15,8 @@ in_current_directory do resultset_json = File.read(RESULTSET_JSON_PATH) resultset_hash = JSON.parse(resultset_json) - resultset_hash[COMMAND_NAME]["timestamp"] = Time.now.to_i + resultset_hash[COMMAND_NAME]["timestamp"] = SimpleCov::Timer.wall.truncate + resultset_hash[COMMAND_NAME]["started_at"] = SimpleCov::Timer.monotonic.truncate File.write(RESULTSET_JSON_PATH, JSON.pretty_generate(resultset_hash)) end end diff --git a/lib/simplecov.rb b/lib/simplecov.rb index 4250f46b4..26322559f 100644 --- a/lib/simplecov.rb +++ b/lib/simplecov.rb @@ -267,14 +267,21 @@ def result_exit_status(result) # def final_result_process? # checking for ENV["TEST_ENV_NUMBER"] to determine if the tests are being run in parallel - !defined?(ParallelTests) || !ENV["TEST_ENV_NUMBER"] || ParallelTests.last_process? + # Short circuit if not parallel + return true unless ENV["TEST_ENV_NUMBER"] + + make_parallel_tests_available + return true unless defined?(ParallelTests) + + ParallelTests.last_process? end # # @api private # def wait_for_other_processes - return unless defined?(ParallelTests) && final_result_process? + return unless final_result_process? + return unless defined?(ParallelTests) ParallelTests.wait_for_other_processes_to_finish end @@ -438,16 +445,22 @@ def make_parallel_tests_available end def probably_running_parallel_tests? + # As a result of the inherent difficulty of intelligently determining parallel testing, + # and for scenarios where the normal ENV variables may not get set, + # use an explicit trigger defined internally: SIMPLECOV_PARALLEL + return true if ENV.fetch("SIMPLECOV_PARALLEL", nil) + ENV.fetch("TEST_ENV_NUMBER", nil) && ENV.fetch("PARALLEL_TEST_GROUPS", nil) end end end -# requires are down here here for a load order reason I'm not sure what it is about +# requires are down here for a load order reason I'm not sure what it is about require "set" require "forwardable" require_relative "simplecov/configuration" SimpleCov.extend SimpleCov::Configuration +require_relative "simplecov/timer" require_relative "simplecov/coverage_statistics" require_relative "simplecov/exit_codes" require_relative "simplecov/profiles" diff --git a/lib/simplecov/combine.rb b/lib/simplecov/combine.rb index 93b27c9d9..26bd557ae 100644 --- a/lib/simplecov/combine.rb +++ b/lib/simplecov/combine.rb @@ -10,7 +10,7 @@ module Combine # Combine two coverage based on the given combiner_module. # # Combiners should always be called through this interface, - # as it takes care of short-circuiting of one of the coverages is nil. + # as it takes care of short-circuiting if one of the coverages is nil. # # @return [Hash] def combine(combiner_module, coverage_a, coverage_b) diff --git a/lib/simplecov/result.rb b/lib/simplecov/result.rb index 7741678c7..ca28314d2 100644 --- a/lib/simplecov/result.rb +++ b/lib/simplecov/result.rb @@ -15,8 +15,10 @@ class Result # Returns all files that are applicable to this result (sans filters!) as instances of SimpleCov::SourceFile. Aliased as :source_files attr_reader :files alias source_files files - # Explicitly set the Time this result has been created + # Explicitly set the Time (Wall) this result has been created attr_writer :created_at + # Explicitly set the Time (Monotonic) this result has been created for elapsed time calculations + attr_writer :started_at # Explicitly set the command name that was used for this coverage result. Defaults to SimpleCov.command_name attr_writer :command_name @@ -25,11 +27,12 @@ class Result # Initialize a new SimpleCov::Result from given Coverage.result (a Hash of filenames each containing an array of # coverage data) - def initialize(original_result, command_name: nil, created_at: nil) + def initialize(original_result, command_name: nil, created_at: nil, started_at: nil) result = original_result @original_result = result.freeze @command_name = command_name @created_at = created_at + @started_at = started_at @files = SimpleCov::FileList.new(result.map do |filename, coverage| SimpleCov::SourceFile.new(filename, JSON.parse(JSON.dump(coverage))) if File.file?(filename) end.compact.sort_by(&:filename)) @@ -51,9 +54,19 @@ def format! SimpleCov.formatter.new.format(self) end - # Defines when this result has been created. Defaults to Time.now + # Defines when this result has been created. Defaults to current wall clock time. + # Wall Clock (Realtime) is for knowing what time it is; it cannot be used for elapsed time calculations. + # Ref: https://blog.dnsimple.com/2018/03/elapsed-time-with-ruby-the-right-way/ + # See: #started_at def created_at - @created_at ||= Time.now + @created_at ||= Time.at(SimpleCov::Timer.wall.truncate) + end + + # Monotonic Clock is for calculating elapsed time accurately. + # Ref: https://blog.dnsimple.com/2018/03/elapsed-time-with-ruby-the-right-way/ + # See: #created_at + def started_at + @started_at ||= SimpleCov::Timer.monotonic.truncate end # The command name that launched this result. @@ -67,7 +80,8 @@ def to_hash { command_name => { "coverage" => coverage, - "timestamp" => created_at.to_i + "timestamp" => created_at.to_i, + "started_at" => started_at.to_i } } end @@ -75,7 +89,12 @@ def to_hash # Loads a SimpleCov::Result#to_hash dump def self.from_hash(hash) hash.map do |command_name, data| - new(data.fetch("coverage"), command_name: command_name, created_at: Time.at(data["timestamp"])) + new( + data.fetch("coverage"), + command_name: command_name, + created_at: Time.at(data["timestamp"]), + started_at: data["started_at"] + ) end end diff --git a/lib/simplecov/result_merger.rb b/lib/simplecov/result_merger.rb index a6b2e92ec..29b18edec 100644 --- a/lib/simplecov/result_merger.rb +++ b/lib/simplecov/result_merger.rb @@ -87,7 +87,17 @@ def within_merge_timeout?(data) end def time_since_result_creation(data) - Time.now - Time.at(data.fetch("timestamp")) + started_at = data.fetch("started_at", nil) + timer = + if started_at + # Use monotonic time + SimpleCov::Timer.new(started_at, Process::CLOCK_MONOTONIC) + else + # Fall back to using wall clock (support transparent upgrade from old result set data) + created_at = data.fetch("timestamp", nil) + SimpleCov::Timer.new(created_at, Process::CLOCK_REALTIME) + end + timer.elapsed_seconds end def create_result(command_names, coverage) @@ -102,7 +112,7 @@ def merge_coverage(*results) return results.first if results.size == 1 results.reduce do |(memo_command, memo_coverage), (command, coverage)| - # timestamp is dropped here, which is intentional (we merge it, it gets a new time stamp as of now) + # timestamp & started_at are dropped here, which is intentional (we merge it, it gets a new time stamp as of now) merged_coverage = Combine.combine(Combine::ResultsCombiner, memo_coverage, coverage) merged_command = memo_command + command diff --git a/lib/simplecov/timer.rb b/lib/simplecov/timer.rb new file mode 100644 index 000000000..cebf8b73d --- /dev/null +++ b/lib/simplecov/timer.rb @@ -0,0 +1,44 @@ +# frozen_string_literal: true + +# Use system uptime (monotonic time) to calculate accurate and reliable elapsed time. +# +# Question: +# Why not just do: +# elapsed_time = Time.now - other_time +# Answer: +# It is not accurate or reliable. +# https://blog.dnsimple.com/2018/03/elapsed-time-with-ruby-the-right-way/ +module SimpleCov + class Timer + # Monotonic clock: Process::CLOCK_MONOTONIC + # Wall clock: Process::CLOCK_REALTIME + attr_accessor :start_time, :clock + + class << self + def monotonic + read(Process::CLOCK_MONOTONIC) + end + + def wall + read(Process::CLOCK_REALTIME) + end + + # SimpleCov::Timer.read(Process::CLOCK_MONOTONIC) # => uptime in seconds (guaranteed directionally accurate) + # SimpleCov::Timer.read(Process::CLOCK_REALTIME) # => seconds since EPOCH (may not be directionally accurate) + def read(clock = Process::CLOCK_MONOTONIC) + Process.clock_gettime(clock) + end + end + + # Capture Time when instantiated + def initialize(start_time, clock = Process::CLOCK_MONOTONIC) + @start_time = start_time || self.class.read(clock) + @clock = clock + end + + # Get Elapsed Time in Seconds + def elapsed_seconds + (self.class.read(clock) - @start_time).truncate + end + end +end diff --git a/spec/result_merger_spec.rb b/spec/result_merger_spec.rb index 4d4c0e712..c701aeda1 100644 --- a/spec/result_merger_spec.rb +++ b/spec/result_merger_spec.rb @@ -175,7 +175,8 @@ data = { "some command name" => { "coverage" => content, - "timestamp" => Time.now.to_i + "timestamp" => SimpleCov::Timer.wall.truncate, + "started_at" => SimpleCov::Timer.monotonic.truncate } } File.open(file_path, "w+") do |f| @@ -286,7 +287,7 @@ def store_result(result, path:) end def outdated(result) - result.created_at = Time.now - 172_800 + result.started_at = SimpleCov::Timer.monotonic.truncate - 172_800 result end diff --git a/spec/result_spec.rb b/spec/result_spec.rb index ef3f37cf8..d80e99b7b 100644 --- a/spec/result_spec.rb +++ b/spec/result_spec.rb @@ -95,6 +95,10 @@ expect(dumped_result.created_at.to_i).to eq(subject.created_at.to_i) end + it "has the same started_at" do + expect(dumped_result.started_at.to_i).to eq(subject.started_at.to_i) + end + it "has the same command_name" do expect(dumped_result.command_name).to eq(subject.command_name) end @@ -212,17 +216,20 @@ source_fixture("sample.rb") => {"lines" => [nil, 1, 1, 1, nil, nil, 0, 0, nil, nil]} } end - let(:created_at) { Time.now.to_i } + let(:created_at) { SimpleCov::Timer.wall.truncate } + let(:started_at) { SimpleCov::Timer.monotonic.truncate } it "can consume multiple commands" do input = { "rspec" => { "coverage" => original_result, - "timestamp" => created_at + "timestamp" => created_at, + "started_at" => started_at }, "cucumber" => { "coverage" => other_result, - "timestamp" => created_at + "timestamp" => created_at, + "started_at" => started_at } } @@ -232,6 +239,7 @@ sorted = result.sort_by(&:command_name) expect(sorted.map(&:command_name)).to eq %w[cucumber rspec] expect(sorted.map(&:created_at).map(&:to_i)).to eq [created_at, created_at] + expect(sorted.map(&:started_at).map(&:to_i)).to eq [started_at, started_at] expect(sorted.map(&:original_result)).to eq [other_result, original_result] end end diff --git a/spec/simplecov_spec.rb b/spec/simplecov_spec.rb index 5e3937ca4..89b8fde87 100644 --- a/spec/simplecov_spec.rb +++ b/spec/simplecov_spec.rb @@ -215,7 +215,7 @@ end let(:collated) do - JSON.parse(File.read(resultset_path)).transform_values { |v| v.reject { |k| k == "timestamp" } } + JSON.parse(File.read(resultset_path)).transform_values { |v| v.reject { |k| k.start_with?("timestamp", "started_at") } } end context "when no files to be merged" do @@ -299,7 +299,9 @@ def create_mergeable_report(name, resultset, outdated: false) result = SimpleCov::Result.new(resultset) result.command_name = name - result.created_at = Time.now - 172_800 if outdated + result.created_at = SimpleCov::Timer.wall.truncate + result.started_at = SimpleCov::Timer.monotonic.truncate + result.started_at -= 172_800 if outdated SimpleCov::ResultMerger.store_result(result) FileUtils.mv resultset_path, "#{resultset_path}#{name}.final" end diff --git a/test_projects/rails/rspec_rails/Gemfile b/test_projects/rails/rspec_rails/Gemfile index 986f08a00..d5359a066 100644 --- a/test_projects/rails/rspec_rails/Gemfile +++ b/test_projects/rails/rspec_rails/Gemfile @@ -3,6 +3,9 @@ source "https://rubygems.org" # added gems +# former std libs that have been ejected +gem "logger" +gem "ostruct" gem "rspec-rails" gem "simplecov", path: "../../.." diff --git a/test_projects/rails/rspec_rails/config/boot.rb b/test_projects/rails/rspec_rails/config/boot.rb index d69bd27dc..b43a8ca5e 100644 --- a/test_projects/rails/rspec_rails/config/boot.rb +++ b/test_projects/rails/rspec_rails/config/boot.rb @@ -1,3 +1,10 @@ ENV['BUNDLE_GEMFILE'] ||= File.expand_path('../Gemfile', __dir__) require "bundler/setup" # Set up gems listed in the Gemfile. + +# Previously some gems masked a bug in Rails v6 and v7 where `logger` was not required, +# plugging the hole by requiring it themselves. +# Because this app is pinned to Rails v6.1, we must require logger manually. +# In order to not be reliant on other libraries to fix the bug in Rails for us, we do it too. +# See: https://stackoverflow.com/questions/79360526/uninitialized-constant-activesupportloggerthreadsafelevellogger-nameerror +require "logger"