Fix: always use monotonic clock to measure time

Mostly fixes spec, benchmark and some compiler timings.

src/benchmark.cr

@@ -117,9 +117,9 @@ module Benchmark
 
   # Returns the time used to execute the given block.
   def measure(label = "") : BM::Tms
-    t0, r0 = Process.times, Time.now
+    t0, r0 = Process.times, Time.monotonic
     yield
-    t1, r1 = Process.times, Time.now
+    t1, r1 = Process.times, Time.monotonic
     BM::Tms.new(t1.utime - t0.utime,
       t1.stime - t0.stime,
       t1.cutime - t0.cutime,
@@ -134,8 +134,6 @@ module Benchmark
   # Benchmark.realtime { "a" * 100_000 } # => 00:00:00.0005840
   # ```
   def realtime : Time::Span
-    r0 = Time.now
-    yield
-    Time.now - r0
+    Time.measure { yield }
   end
 end

src/benchmark/ips.cr

@@ -60,18 +60,17 @@ module Benchmark
         @items.each do |item|
           GC.collect
 
-          before = Time.now
-          target = Time.now + @warmup_time
           count = 0
+          elapsed = Time.measure do
+            target = Time.monotonic + @warmup_time
 
-          while Time.now < target
-            item.call
-            count += 1
+            while Time.monotonic < target
+              item.call
+              count += 1
+            end
           end
 
-          after = Time.now
-
-          item.set_cycles(after - before, count)
+          item.set_cycles(elapsed, count)
         end
       end
 
@@ -80,20 +79,14 @@ module Benchmark
           GC.collect
 
           measurements = [] of Time::Span
-          target = Time.now + @calculation_time
+          target = Time.monotonic + @calculation_time
 
           loop do
-            before = Time.now
-            item.call_for_100ms
-            after = Time.now
-
-            measurements << after - before
-
-            break if Time.now >= target
+            elapsed = Time.measure { item.call_for_100ms }
+            measurements << elapsed
+            break if Time.monotonic >= target
           end
 
-          final_time = Time.now
-
           ips = measurements.map { |m| item.cycles.to_f / m.total_seconds }
           item.calculate_stats(ips)
 

src/compiler/crystal/command.cr

@@ -208,13 +208,14 @@ class Crystal::Command
     time? = @time && !@progress_tracker.stats?
     status, elapsed_time = @progress_tracker.stage("Execute") do
       begin
-        start_time = Time.now
-        Process.run(output_filename, args: run_args, input: Process::Redirect::Inherit, output: Process::Redirect::Inherit, error: Process::Redirect::Inherit) do |process|
-          # Ignore the signal so we don't exit the running process
-          # (the running process can still handle this signal)
-          Signal::INT.ignore # do
+        elapsed = Time.measure do
+          Process.run(output_filename, args: run_args, input: Process::Redirect::Inherit, output: Process::Redirect::Inherit, error: Process::Redirect::Inherit) do |process|
+            # Ignore the signal so we don't exit the running process
+            # (the running process can still handle this signal)
+            Signal::INT.ignore # do
+          end
         end
-        {$?, Time.now - start_time}
+        {$?, elapsed}
       ensure
         File.delete(output_filename) rescue nil
 

src/compiler/crystal/macros/macros.cr

@@ -104,7 +104,7 @@ class Crystal::Program
   end
 
   def macro_compile(filename)
-    time = Time.now
+    time = Time.monotonic
 
     source = File.read(filename)
 
@@ -127,7 +127,7 @@ class Crystal::Program
     File.utime(now, now, program_dir)
 
     if can_reuse_previous_compilation?(filename, executable_path, recorded_requires_path, requires_path)
-      elapsed_time = Time.now - time
+      elapsed_time = Time.monotonic - time
       return CompiledMacroRun.new(executable_path, elapsed_time, true)
     end
 
@@ -166,7 +166,7 @@ class Crystal::Program
       requires_with_timestamps.to_json(file)
     end
 
-    elapsed_time = Time.now - time
+    elapsed_time = Time.monotonic - time
     CompiledMacroRun.new(executable_path, elapsed_time, false)
   end
 

src/compiler/crystal/progress_tracker.cr

@@ -18,9 +18,9 @@ module Crystal
       print_stats
       print_progress
 
-      start_time = Time.now
+      time_start = Time.monotonic
       retval = yield
-      time_taken = Time.now - start_time
+      time_taken = Time.monotonic - time_start
 
       print_stats(time_taken)
       print_progress

src/crystal/main.cr

@@ -32,9 +32,10 @@ module Crystal
   # ```
   # fun main(argc : Int32, argv : UInt8**) : Int32
   #   Crystal.main do
-  #     time = Time.now
-  #     Crystal.main_user_code(argc, argv)
-  #     puts "Time to execute program: #{Time.now - time}"
+  #     elapsed = Time.measure do
+  #       Crystal.main_user_code(argc, argv)
+  #     end
+  #     puts "Time to execute program: #{elapsed}"
   #   end
   # end
   # ```

src/http/server/handlers/log_handler.cr

@@ -8,9 +8,7 @@ class HTTP::LogHandler
   end
 
   def call(context)
-    time = Time.now
-    call_next(context)
-    elapsed = Time.now - time
+    elapsed = Time.measure { call_next(context) }
     elapsed_text = elapsed_text(elapsed)
 
     @io.puts "#{context.request.method} #{context.request.resource} - #{context.response.status_code} (#{elapsed_text})"

src/spec/dsl.cr

@@ -166,9 +166,9 @@ module Spec
 
   # :nodoc:
   def self.run
-    start_time = Time.now
+    start_time = Time.monotonic
     at_exit do
-      elapsed_time = Time.now - start_time
+      elapsed_time = Time.monotonic - start_time
       Spec::RootContext.print_results(elapsed_time)
       exit 1 unless Spec::RootContext.succeeded
     end

src/spec/methods.cr

@@ -12,16 +12,16 @@ module Spec::Methods
 
     Spec.formatters.each(&.before_example(description))
 
-    start = Time.now
+    start = Time.monotonic
     begin
       Spec.run_before_each_hooks
       block.call
-      Spec::RootContext.report(:success, description, file, line, Time.now - start)
+      Spec::RootContext.report(:success, description, file, line, Time.monotonic - start)
     rescue ex : Spec::AssertionFailed
-      Spec::RootContext.report(:fail, description, file, line, Time.now - start, ex)
+      Spec::RootContext.report(:fail, description, file, line, Time.monotonic - start, ex)
       Spec.abort! if Spec.fail_fast?
     rescue ex
-      Spec::RootContext.report(:error, description, file, line, Time.now - start, ex)
+      Spec::RootContext.report(:error, description, file, line, Time.monotonic - start, ex)
       Spec.abort! if Spec.fail_fast?
     ensure
       Spec.run_after_each_hooks