Mac time measurements

.github/workflows/main.yml

@@ -18,6 +18,9 @@ jobs:
           - elixir_version: '1.6.6'
             otp_version: '19.3'
         exclude:
+          # has shown weird behavior when it comes to dialyzer (aka only this one failing)
+          - elixir_version: '1.6.6'
+            otp_version: '21.3'
           - elixir_version: '1.6.6'
             otp_version: '22.3'
           - elixir_version: '1.10.3'
@@ -49,9 +52,10 @@ jobs:
       - name: Check if formatted
         if: ${{ contains(matrix.elixir_version, '1.10') }}
         run: mix format --check-formatted
+      - name: Actual Tests
+        run: MIX_ENV=test mix coveralls.github
       - name: Dialyzer
         run: mix dialyzer --halt-exit-status
-      - run: MIX_ENV=test mix coveralls.github
       - name: After script
         if: ${{ contains(matrix.elixir_version, '1.10') }}
         run: mix deps.get --only docs && MIX_ENV=docs mix inch.report

.tool-versions

@@ -1,2 +1,2 @@
 elixir 1.10.3-otp-22
-erlang 22.3
+erlang 22.3.4.24

lib/benchee/benchmark.ex

@@ -94,12 +94,12 @@ defmodule Benchee.Benchmark do
   """
   @spec collect(Suite.t(), module, module) :: Suite.t()
   def collect(
-        suite = %Suite{scenarios: scenarios, configuration: config},
+        suite = %Suite{scenarios: scenarios, configuration: config, system: system},
         printer \\ Printer,
         runner \\ Runner
       ) do
     printer.configuration_information(suite)
-    scenario_context = %ScenarioContext{config: config, printer: printer}
+    scenario_context = %ScenarioContext{config: config, printer: printer, system: system}
     scenarios = runner.run_scenarios(scenarios, scenario_context)
     %Suite{suite | scenarios: scenarios}
   end

lib/benchee/benchmark/repeated_measurement.ex

@@ -10,8 +10,8 @@ defmodule Benchee.Benchmark.RepeatedMeasurement do
   # Instead we repeat the function call n times until we measure at least ~10 (time unit) so
   # that the difference between measurements can at least be ~10%.
   #
-  # Today this is mostly only relevant on Windows as we have nanosecond precision on Linux and
-  # Mac OS and we've failed to produce a measurable function call that takes less than 10 nano
+  # Today this is mostly only relevant on Windows & Mac OS as we have nanosecond precision on
+  # Linux and we've failed to produce a measurable function call that takes less than 10 nano
   # seconds.
   #
   # That's also why this code lives in a separate module and not `Runner` - as it's rarely used
@@ -23,43 +23,92 @@ defmodule Benchee.Benchmark.RepeatedMeasurement do
 
   alias Benchee.Benchmark.{Collect, Hooks, Runner, ScenarioContext}
   alias Benchee.Scenario
+  alias Benchee.Utility.ErlangVersion
   alias Benchee.Utility.RepeatN
 
   @minimum_execution_time 10
   @times_multiplier 10
+  @nanosecond_resolution Benchee.Conversion.Duration.convert_value({1, :second}, :nanosecond)
+
   @spec determine_n_times(Scenario.t(), ScenarioContext.t(), boolean, module) ::
           {pos_integer, number}
   def determine_n_times(
         scenario,
-        scenario_context = %ScenarioContext{
-          num_iterations: num_iterations,
-          printer: printer
-        },
-        fast_warning,
-        collector \\ Collect.NativeTime
+        scenario_context = %ScenarioContext{system: system_info},
+        print_fast_warning,
+        clock_info \\ :erlang.system_info(:os_monotonic_time_source),
+        collector \\ Collect.Time
       ) do
+    resolution_adjustment = determine_resolution_adjustment(system_info, clock_info)
+
+    do_determine_n_times(
+      scenario,
+      scenario_context,
+      print_fast_warning,
+      resolution_adjustment,
+      collector
+    )
+  end
+
+  # See ERL-1067 aka which was fixed here
+  # https://erlang.org/download/otp_src_22.2.readme
+  @fixed_erlang_vesion "22.2.0"
+  # MacOS usually measures in micro seconds so that's the best default to return when not given
+  @old_macos_value 1_000
+
+  defp determine_resolution_adjustment(system_info, clock_info) do
+    if trust_clock?(system_info) do
+      # If the resolution is 1_000_000 that means microsecond, while 1_000_000_000 is nanosecond.
+      # we then need to adjust our measured time by that value. I.e. if we measured "5000" here we
+      # do not want to let it pass as it is essentially just "5" for our measurement purposes.
+      {:ok, resolution} = Access.fetch(clock_info, :resolution)
+
+      @nanosecond_resolution / resolution
+    else
+      @old_macos_value
+    end
+  end
+
+  # Can't really trust the macOS clock on OTP before mentioned version, see tickets linked above
+  defp trust_clock?(%{os: :macOS, erlang: erlang_version}) do
+    ErlangVersion.includes_fixes_from?(erlang_version, @fixed_erlang_vesion)
+  end
+
+  # If `suite.system` wasn't populated then we'll not mistrust it as well as all others
+  # (can happen if people call parts of benchee themselves without calling system first)
+  defp trust_clock?(_), do: true
+
+  defp do_determine_n_times(
+         scenario,
+         scenario_context = %ScenarioContext{
+           num_iterations: num_iterations,
+           printer: printer
+         },
+         print_fast_warning,
+         resolution_adjustment,
+         collector
+       ) do
     run_time = measure_iteration(scenario, scenario_context, collector)
+    resolution_adjusted_run_time = run_time / resolution_adjustment
 
-    if run_time >= @minimum_execution_time do
+    if resolution_adjusted_run_time >= @minimum_execution_time do
       {num_iterations, report_time(run_time, num_iterations)}
     else
-      if fast_warning, do: printer.fast_warning()
+      if print_fast_warning, do: printer.fast_warning()
 
       new_context = %ScenarioContext{
         scenario_context
         | num_iterations: num_iterations * @times_multiplier
       }
 
-      determine_n_times(scenario, new_context, false, collector)
+      do_determine_n_times(scenario, new_context, false, resolution_adjustment, collector)
     end
   end
 
   # we need to convert the time here since we measure native time to see when we have enough
   # repetitions but the first time is used in the actual samples
   defp report_time(measurement, num_iterations) do
-    measurement
-    |> :erlang.convert_time_unit(:native, :nanosecond)
-    |> adjust_for_iterations(num_iterations)
+    adjust_for_iterations(measurement, num_iterations)
   end
 
   defp adjust_for_iterations(measurement, 1), do: measurement

lib/benchee/benchmark/scenario_context.ex

@@ -6,6 +6,7 @@ defmodule Benchee.Benchmark.ScenarioContext do
   defstruct [
     :config,
     :printer,
+    :system,
     :current_time,
     :end_time,
     # before_scenario can alter the original input

lib/benchee/output/benchmark_printer.ex

@@ -99,8 +99,9 @@ defmodule Benchee.Output.BenchmarkPrinter do
   def fast_warning do
     IO.puts("""
     Warning: The function you are trying to benchmark is super fast, making measurements more unreliable!
-    This holds especially true for memory measurements.
-    See: https://github.com/PragTob/benchee/wiki/Benchee-Warnings#fast-execution-warning
+    This holds especially true for memory measurements or when running with hooks.
+
+    See: https://github.com/bencheeorg/benchee/wiki/Benchee-Warnings#fast-execution-warning
 
     You may disable this warning by passing print: [fast_warning: false] as configuration options.
     """)

lib/benchee/utility/erlang_version.ex

@@ -0,0 +1,124 @@
+defmodule Benchee.Utility.ErlangVersion do
+  @moduledoc false
+
+  # Internal module to deal with erlang version parsing oddity
+
+  @doc """
+  Was the given version before the reference version?
+
+  Used to check if a bugfix has already landed.
+
+  Applies some manual massaging, as erlang likes to report versios number not compatible with
+  SemVer. If we can't parse the version, to minimize false positives, we assume it's newer.
+
+  Only the `version_to_check` is treated loosely. `version_to_check` must be SemVer compatible,
+  as it is assumed to be provided by project maintainers.
+
+  ## Examples
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.0", "22.0.0")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.1", "22.0.0")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.0", "22.0.1")
+      false
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.4", "22.0.5")
+      false
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.4", "22.0.4")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.5", "22.0.4")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("21.999.9999", "22.0.0")
+      false
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("23.0.0", "22.0.0")
+      true
+
+      # weird longer version numbers work
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.0.0", "22.0.0")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0.0.14", "22.0.0")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("23.3.5.14", "22.0.0")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("21.3.5.14", "22.0.0")
+      false
+
+      # weird shorter version numbers work
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0", "22.0.0")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0", "22.0.1")
+      false
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.1", "22.0.0")
+      true
+
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("21.3", "22.0.0")
+      false
+
+      # rc version numbers work
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("22.0-rc3", "22.0.0")
+      false
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("23.0-rc0", "22.0.0")
+      true
+
+      # completely broken versions are assumed to be good to avoid false positives
+      # as this is not a main functionality but code to potentially work around an older erlang
+      # bug.
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("super erlang", "22.0.0")
+      true
+      iex> Benchee.Utility.ErlangVersion.includes_fixes_from?("", "22.0.0")
+      true
+  """
+  def includes_fixes_from?(version_to_check, reference_version) do
+    erlang_version = parse_erlang_version(version_to_check)
+
+    case erlang_version do
+      {:ok, version} -> Version.compare(version, reference_version) != :lt
+      # we do not know which version this is, so don't trust it?
+      _ -> true
+    end
+  end
+
+  # `Version` only supports full SemVer, Erlang loves version numbers like `22.3.4.24` or `22.0`
+  # which makes `Version` error out so we gotta manually alter them so that it's `22.3.4`
+  @last_version_segment ~r/\.\d+$/
+  defp parse_erlang_version(erlang_version) do
+    # dot count is a heuristic but it should work
+    dot_count =
+      erlang_version
+      |> String.graphemes()
+      |> Enum.count(&(&1 == "."))
+
+    version =
+      case dot_count do
+        3 -> Regex.replace(@last_version_segment, erlang_version, "")
+        1 -> deal_with_major_minor(erlang_version)
+        _ -> erlang_version
+      end
+
+    Version.parse(version)
+  end
+
+  # Only major/minor seem to get the rc treatment
+  # but if it is major/minor/patch `Version` handles it correctly.
+  # For the 4 digit versions we don't really care right now/normally does not happen.
+  defp deal_with_major_minor(erlang_version) do
+    # -rc and other weird versions contain -
+    if String.contains?(erlang_version, "-") do
+      String.replace(erlang_version, "-", ".0-")
+    else
+      "#{erlang_version}.0"
+    end
+  end
+end