🐛 Disambiguate time usage

- `created_at` / `timestamp` is for wall clock time (for humans)
- `started_at` is for monotonic / elapsed time (for computers)

Author: pboling

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"] = SimpleCov::Timer.monotonic.truncate
+    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/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))
@@ -52,8 +55,18 @@ def format!
     end
 
     # Defines when this result has been created. Defaults to current truncated system monotonic uptime
+    # 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 ||= SimpleCov::Timer.monotonic.truncate
+      @created_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,8 +87,16 @@ def within_merge_timeout?(data)
       end
 
       def time_since_result_creation(data)
-        timestamp = data.fetch("timestamp")
-        timer = SimpleCov::Timer.new(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)
+            started_at = data.fetch("timestamp", nil)
+            SimpleCov::Timer.new(started_at, Process::CLOCK_REALTIME)
+          end
         timer.elapsed_seconds
       end
 
@@ -104,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

@@ -1,6 +1,6 @@
 # frozen_string_literal: true
 
-# Use system uptime to calculate accurate and reliable elapsed time.
+# Use system uptime (monotonic time) to calculate accurate and reliable elapsed time.
 #
 # Question:
 #   Why not just do:
@@ -10,22 +10,35 @@
 #     https://blog.dnsimple.com/2018/03/elapsed-time-with-ruby-the-right-way/
 module SimpleCov
   class Timer
-    attr_accessor :start_time
+    # Monotonic clock: Process::CLOCK_MONOTONIC
+    # Wall clock: Process::CLOCK_REALTIME
+    attr_accessor :start_time, :clock
 
     class << self
       def monotonic
-        Process.clock_gettime(Process::CLOCK_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)
-      @start_time = start_time || self.class.monotonic
+    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.monotonic - @start_time).truncate
+      (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" => SimpleCov::Timer.monotonic.truncate
+            "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 = SimpleCov::Timer.monotonic.truncate - 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) { SimpleCov::Timer.monotonic.truncate }
+      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 = SimpleCov::Timer.monotonic.truncate - 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