Monotonic time

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

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

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

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"

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)

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,15 +80,21 @@ def to_hash
       {
         command_name => {
           "coverage" => coverage,
-          "timestamp" => created_at.to_i
+          "timestamp" => created_at.to_i,
+          "started_at" => started_at.to_i
         }
       }
     end
 
     # 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
 

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
 

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

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
 

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

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

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: "../../.."

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"