tachometer + tests

config/config.exs

@@ -28,3 +28,5 @@ use Mix.Config
 # here (which is why it is important to import them last).
 #
 #     import_config "#{Mix.env}.exs"
+
+config :tachometer, poll_interval: 1000

lib/tachometer.ex

@@ -1,2 +1,54 @@
 defmodule Tachometer do
+  require Logger
+
+  def start(_type, args) do
+    poll_interval = args[:poll_interval] ||  Application.get_env(:tachometer, :poll_interval)
+    if poll_interval do
+      start(poll_interval)
+    else
+      start
+    end
+  end
+
+  def start(poll_interval \\ 1000) do
+    Logger.info  "Starting Tachometer with poll interval: #{inspect poll_interval}"
+    Tachometer.Supervisor.start_link(poll_interval)
+  end
+
+  def stop do
+    Tachometer.Supervisor.stop
+  end
+
+  def start_link do
+    {:ok, _pid} = Agent.start_link fn -> 0 end, name: __MODULE__
+  end
+
+  def safe_read(fallback \\ 0.50) do
+    try do
+      read
+    catch
+      _,_  ->
+        Logger.warn "#{inspect __MODULE__ }.safe_read used fallback value of #{fallback}"
+        fallback
+    end
+  end
+
+  def read do
+    Agent.get __MODULE__, fn(state)-> state end
+  end
+
+  def safe_set_poll_interval(interval) do
+    try do
+      set_poll_interval(interval)
+    catch
+      _,_ ->
+        Logger.warn "#{inspect __MODULE__ }.safe_set_poll_interval failed"
+    end
+    :ok
+  end
+
+  def set_poll_interval(interval) do
+    Tachometer.SchedulerPoller.set_poll_interval(interval)
+  end
+
 end

lib/tachometer/scheduler_poller.ex

@@ -0,0 +1,62 @@
+defmodule Tachometer.SchedulerPoller do
+  require Logger
+
+  def start_link(poll_interval) do
+    :erlang.system_flag(:scheduler_wall_time, true)
+    initial_reading = :erlang.statistics(:scheduler_wall_time)
+    pid = spawn_link(__MODULE__, :poll, [poll_interval, initial_reading])
+    unregister()
+    true = Process.register(pid, __MODULE__)
+    {:ok, pid}
+  end
+
+  defp unregister do
+    if Process.whereis(__MODULE__), do: Process.unregister(__MODULE__)
+  end
+
+  def stop do
+    unregister
+    :erlang.system_flag(:scheduler_wall_time, false)
+  end
+
+  def poll(interval, first) do
+    receive do
+      {:set_poll_interval, new_interval} ->
+        interval = new_interval
+      message ->
+        Logger.warn "received unexpected message #{inspect message}"
+    after
+      interval -> :ok
+    end
+    last = :erlang.statistics(:scheduler_wall_time)
+    __scheduler_usage(first, last) |> update_tachometer
+    poll(interval, last)
+  end
+
+  def set_poll_interval(interval) do
+    send __MODULE__, {:set_poll_interval, interval}
+    :ok
+  end
+
+  def __scheduler_usage(first, last) do
+    # TODO: consider making this asynchronous so that it gets
+    #       factored into the statistics in the next loop
+    {last_active,  last_total}  = reduce_sample(last)
+    {first_active, first_total} = reduce_sample(first)
+    (last_active - first_active)/(last_total - first_total)
+  end
+
+  defp update_tachometer(usage) do
+    Agent.cast Tachometer, fn(_old_usage)-> usage end
+  end
+
+  defp reduce_sample(sample) do
+    sample |>
+    Enum.reduce({0,0},
+      fn({_scheduler, active_time, total_time}, {total_active, total_total}) ->
+        {active_time + total_active, total_time + total_total}
+      end
+    )
+  end
+
+end

lib/tachometer/supervisor.ex

@@ -0,0 +1,17 @@
+defmodule Tachometer.Supervisor do
+  import Supervisor.Spec
+
+  def start_link(poll_interval) do
+    children = [
+      worker(Tachometer, []),
+      worker(Tachometer.SchedulerPoller, [poll_interval])
+    ]
+
+    Supervisor.start_link(children, strategy: :rest_for_one, name: __MODULE__)
+  end
+
+  def stop do
+    Supervisor.stop(__MODULE__, :normal)
+  end
+
+end

mix.exs

@@ -7,14 +7,20 @@ defmodule Tachometer.Mixfile do
      elixir: "~> 1.2",
      build_embedded: Mix.env == :prod,
      start_permanent: Mix.env == :prod,
+     package: package,
+     description: description,
      deps: deps]
   end
 
   # Configuration for the OTP application
   #
   # Type "mix help compile.app" for more information
   def application do
-    [applications: [:logger]]
+    [applications: [:logger],
+     mod: {Tachometer, []},
+     registered: [Tachometer,
+                  Tachometer.SchedulerPoller,
+                  Tachometer.Supervisor]]
   end
 
   # Dependencies can be Hex packages:
@@ -29,4 +35,18 @@ defmodule Tachometer.Mixfile do
   defp deps do
     []
   end
+
+  defp description do
+    """
+    Scheduler instrumentation for BEAM in Elixir
+    """
+  end
+
+  defp package do
+    [# These are the default files included in the package
+     maintainers: ["Paul Hierommnimon"],
+     licenses: ["GNU GPLv3"],
+     links: %{"GitHub" => "https://github.com/pavlos/tachometer",
+              "Docs" => "https://github.com/pavlos/tachometer"}]
+    end
 end

test/tachometer_test.exs

@@ -1,8 +1,108 @@
 defmodule TachometerTest do
-  use ExUnit.Case
-  doctest Tachometer
+  use ExUnit.Case, async: false
+  alias Tachometer
 
-  test "the truth" do
-    assert 1 + 1 == 2
+  @poll_interval 50
+  @wait_interval (@poll_interval * 3)
+
+  setup_all do
+    {:ok, _pid} = Tachometer.start @poll_interval
+    {:ok, []}
+  end
+
+  test "doing nothing gives a reading close to 0" do
+    wait
+    reading = Tachometer.read
+    reading |> assert_in_delta(0, 0.02)
+  end
+
+  test "peg one scheduler" do
+    spawn_link fn-> fib_calc(100) end
+    wait
+    reading = Tachometer.read
+    expected_reading = 1/(:erlang.system_info(:schedulers))
+    reading |> assert_in_delta(expected_reading, 0.02)
+  end
+
+  test "peg several schedulers" do
+    total_schedulers = :erlang.system_info :schedulers
+
+    for n <- 1..total_schedulers do
+      pids = for _ <- 1..n, do: spawn fn-> fib_calc(100) end
+      try do
+        wait
+        expected_reading = n/(:erlang.system_info(:schedulers))
+        reading = Tachometer.read
+        reading |> assert_in_delta(expected_reading, 0.02)
+      after
+        pids |> Enum.map(fn(p)-> p |> Process.exit(:kill) end)
+      end
+    end
+  end
+
+  test "waiting on network IO gives low reading" do
+    wait
+    test_listen
+    wait
+    reading = Tachometer.read
+    reading |> assert_in_delta(0, 0.01)
+  end
+
+  test "update polling interval from long to short happens instantly" do
+    on_exit fn -> Tachometer.set_poll_interval @poll_interval  end
+
+    Tachometer.set_poll_interval :infinity
+
+    wait
+    reading0 = Tachometer.read
+    wait
+    reading1 = Tachometer.read
+    wait
+    wait
+    reading2 = Tachometer.read
+
+    assert reading0 == reading1
+    assert reading1 == reading2
+
+    Tachometer.set_poll_interval @poll_interval
+    wait
+    reading3 = Tachometer.read
+    refute reading0 == reading3
+  end
+
+  test "computes scheduler usage correctly" do
+    first = [{4, 1000, 5000}, {2, 1500, 5000}, {7, 5000, 5000}, # = 7500/15000
+             {5, 2000, 5000}, {6, 3000, 5000}, {3, 5000, 5000}, # = 10000/15000
+             {8, 0, 5000}, {1, 4000, 5000}]                     # = 4000/10000
+    # = 21500/40000
+
+    last = [{5, 4000, 10000}, {3, 9000, 10000}, {4, 6000, 10000}, # = 19000/30000
+            {7, 10000, 10000}, {2, 1500, 10000}, {6, 4500, 10000},# = 16000/30000
+            {1, 4500, 10000}, {8, 2000, 10000}]                   # = 6500/20000
+    #= 41500/80000
+
+    actual = Tachometer.SchedulerPoller.__scheduler_usage first, last
+    expected = 20000/40000
+    assert actual == expected
   end
+
+  defp wait do
+    :timer.sleep @wait_interval
+  end
+
+  defp test_listen do
+    (9500..9999) |>
+    Enum.map(fn(port)->
+      spawn_link fn ->
+        {:ok, listenSocket} = :gen_tcp.listen(port, [{:active, true}, :binary])
+        {:ok, _acceptSocket} = :gen_tcp.accept(listenSocket)
+      end
+    end)
+  end
+
+  # super inefficient, on purpose
+  defp fib_calc(0), do: 0
+  defp fib_calc(1), do: 1
+  defp fib_calc(n), do: fib_calc(n-1) + fib_calc(n-2)
+
 end

test/test_helper.exs

@@ -1 +1,7 @@
 ExUnit.start()
+
+try do
+  Tachometer.stop
+catch
+  :exit, :noproc -> IO.puts "caught noproc"
+end