Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Smarter hibernate #103

Closed
wants to merge 9 commits into from
Closed
Show file tree
Hide file tree
Changes from 7 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
22 changes: 21 additions & 1 deletion integration_test/cases/backoff_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,19 @@ defmodule BackoffTest do
alias TestAgent, as: A

test "backoff after failed initial connection attempt" do
agent = spawn_agent_backoff_after_failed()
opts = [agent: agent, parent: self(), backoff_min: 10]
execute_test_backoff_after_failed(agent, opts)
end

@tag :idle_hibernate_backoff
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should not require this tag, all pools should support this.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually lets keep this for now, ignore the above comment.

test "backoff after failed initial connection attempt with idle_hibernate" do
agent = spawn_agent_backoff_after_failed()
opts = [agent: agent, parent: self(), backoff_min: 10, idle_hibernate: true]
execute_test_backoff_after_failed(agent, opts, true)
end

defp spawn_agent_backoff_after_failed() do
err = RuntimeError.exception("oops")
stack = [
fn(opts) ->
Expand All @@ -16,12 +29,19 @@ defmodule BackoffTest do
{:ok, :state}
end]
{:ok, agent} = A.start_link(stack)
agent
end

opts = [agent: agent, parent: self(), backoff_min: 10]
defp execute_test_backoff_after_failed(agent, opts, test_hibernate? \\ false) do
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If theres enough logic to share a function we could try to simplify the test when hibenating and not share function. We might have overlapping tests.

{:ok, _} = P.start_link(opts)
assert_receive {:error, conn}
assert_receive {:hi, ^conn}

if test_hibernate? do
assert {:current_function, {:erlang, :hibernate, 3}} ==
Process.info(conn, :current_function)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This may have a race condition as we can't guarantee the process has hibernated because of the async nature of processes. However we can leave this until its observed.

end

assert [
connect: [opts2],
connect: [opts2]] = A.record(agent)
Expand Down
23 changes: 22 additions & 1 deletion integration_test/cases/idle_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,19 @@ defmodule TestIdle do

@tag :idle_timeout
test "ping after idle timeout" do
agent = spawn_agent()
opts = [agent: agent, parent: self(), idle_timeout: 50]
execute_test_case(agent, opts)
end

@tag :idle_hibernate
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should support this for all pools that can do idle_timeout, I left a comment on how to achieve this previously.

Copy link
Member

@fishcakez fishcakez Nov 21, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually lets keep this for now, ignore the above comment.

test "ping after idle timeout using hibernate" do
agent = spawn_agent()
opts = [agent: agent, parent: self(), idle_timeout: 50, idle_hibernate: true]
execute_test_case(agent, opts, true)
end

defp spawn_agent() do
parent = self()
stack = [
fn(opts) ->
Expand All @@ -27,12 +40,19 @@ defmodule TestIdle do
:timer.sleep(:infinity)
end]
{:ok, agent} = A.start_link(stack)
agent
end

opts = [agent: agent, parent: self(), idle_timeout: 50]
defp execute_test_case(agent, opts, test_hibernate? \\ false) do
{:ok, pool} = P.start_link(opts)
assert_receive {:hi, conn}
if test_hibernate? do
assert {:current_function, {:erlang, :hibernate, 3}} ==
Process.info(conn, :current_function)
end
assert_receive {:pong, ^conn}
assert_receive {:pong, ^conn}

send(conn, {:continue, self()})
P.run(pool, fn(_) -> :ok end)
assert_receive {:pong, ^conn}
Expand All @@ -43,4 +63,5 @@ defmodule TestIdle do
ping: [:state],
ping: [:state]] = A.record(agent)
end

end
2 changes: 1 addition & 1 deletion integration_test/ownership/test_helper.exs
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
ExUnit.start([capture_log: true, assert_receive_timeout: 500,
exclude: [:idle_timeout, :pool_overflow, :dequeue_disconnected,
:queue_timeout_raise]])
:queue_timeout_raise, :idle_hibernate]])

Code.require_file "../../test/test_support.exs", __DIR__

Expand Down
3 changes: 2 additions & 1 deletion integration_test/sojourn/test_helper.exs
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,8 @@ case :erlang.system_info(:otp_release) do
ExUnit.start([exclude: [:test]])
_ ->
ExUnit.start([capture_log: :true, assert_receive_timeout: 500,
exclude: [:enqueue_disconnected, :queue_timeout_exit]])
exclude: [:enqueue_disconnected, :queue_timeout_exit,
:idle_hibernate_backoff, :idle_hibernate]])

{:ok, _} = TestPool.ensure_all_started()
end
46 changes: 38 additions & 8 deletions lib/db_connection/connection.ex
Original file line number Diff line number Diff line change
Expand Up @@ -18,9 +18,10 @@ defmodule DBConnection.Connection do
require Logger
alias DBConnection.Backoff

@pool_timeout 5_000
@timeout 15_000
@idle_timeout 1_000
@pool_timeout 5_000
@timeout 15_000
@idle_timeout 1_000
@idle_hibernate false

## DBConnection.Pool API

Expand Down Expand Up @@ -108,12 +109,14 @@ defmodule DBConnection.Connection do

s = %{mod: mod, opts: opts, state: nil, client: :closed, broker: broker,
regulator: regulator, lock: nil, queue: queue, timer: nil,
hibernate_timer: nil,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please use idle_timer as the timer is for idle and not hibernating, but hibernate is a possible side effect of going idle.

backoff: Backoff.new(opts),
after_connect: Keyword.get(opts, :after_connect),
after_connect_timeout: Keyword.get(opts, :after_connect_timeout,
@timeout), idle: idle,
idle_timeout: Keyword.get(opts, :idle_timeout, @idle_timeout),
idle_time: 0, after_timeout: after_timeout}
idle_time: 0, after_timeout: after_timeout,
idle_hibernate: Keyword.get(opts, :idle_hibernate, @idle_hibernate)}
if mode == :connection and Keyword.get(opts, :sync_connect, false) do
connect(:init, s)
else
Expand All @@ -130,7 +133,7 @@ defmodule DBConnection.Connection do
def connect(_, s) do
%{mod: mod, opts: opts, backoff: backoff, after_connect: after_connect,
idle: idle, idle_timeout: idle_timeout, regulator: regulator,
lock: lock} = s
lock: lock, idle_hibernate: idle_hibernate} = s
case apply(mod, :connect, [opts]) do
{:ok, state} when after_connect != nil ->
ref = make_ref()
Expand All @@ -153,7 +156,7 @@ defmodule DBConnection.Connection do
end)
done_lock(regulator, lock)
{timeout, backoff} = Backoff.backoff(backoff)
{:backoff, timeout, %{s | lock: nil, backoff: backoff}}
maybe_hibernate(idle_hibernate, {:backoff, timeout, %{s | lock: nil, backoff: backoff}})
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should test this part with the other backoff handling

end
end

Expand Down Expand Up @@ -353,6 +356,11 @@ defmodule DBConnection.Connection do
end
end

def handle_info({:timeout, timer, :trigger_hibernate},
%{idle_hibernate: idle_hibernate} = s) when is_reference(timer) do
maybe_hibernate(idle_hibernate, {:noreply, %{s | hibernate_timer: nil}})
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

end

def handle_info(:timeout, %{client: nil, broker: nil} = s) do
%{mod: mod, state: state} = s
case apply(mod, :ping, [state]) do
Expand All @@ -377,6 +385,9 @@ defmodule DBConnection.Connection do
def handle_info(msg, %{client: {_, :connect}} = s) do
do_handle_info(msg, s)
end
def handle_info(:timeout, %{idle_hibernate: idle_hibernate} = s) do
maybe_hibernate(idle_hibernate, {:noreply, %{s | hibernate_timer: nil}})
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should never reach this handle_info/2 clause. I think we can delete this clause.

end
def handle_info(msg, %{mod: mod} = s) do
Logger.info(fn() ->
[inspect(mod), ?\s, ?(, inspect(self()), ") missed message: " |
Expand Down Expand Up @@ -563,10 +574,23 @@ defmodule DBConnection.Connection do
end
end

defp handle_timeout(%{client: nil, idle_timeout: idle_timeout,
idle_hibernate: true,
hibernate_timer: hibernate_timer} = s) do
cancel_timer(hibernate_timer)
hibernate_timer = Process.send_after(self(), :timeout, idle_timeout)
# hibernate_timer = start_timer(self(), idle_timeout, :trigger_hibernate)
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NEED HELP !

The test will failed if I use start_timer, but it works well if I use Process.send_after/3.

The error information:


  1) test ping after idle timeout using hibernate (TestIdle)
     integration_test/cases/idle_test.exs:15
     No message matching {:pong, ^conn} after 500ms.
     The following variables were pinned:
       conn = #PID<0.561.0>
     The process mailbox is empty.
     code: execute_test_case(agent, opts, true)
     stacktrace:
       integration_test/cases/idle_test.exs:53: TestIdle.execute_test_case/3
       integration_test/cases/idle_test.exs:18: (test)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When the timer arrives we need to call the logic that is currently done by handle_info(:timeout, ...) because the timer is replacing that timeout. The reason it fails is because we don't call apply(mod, :ping, [state]) anymore.

maybe_hibernate(true, {:noreply, %{s | hibernate_timer: hibernate_timer}})
end
defp handle_timeout(%{client: nil, idle_timeout: idle_timeout} = s) do
{:noreply, s, idle_timeout}
end
defp handle_timeout(s), do: {:noreply, s}
defp handle_timeout(%{idle_hibernate: idle_hibernate} = s) do
maybe_hibernate(idle_hibernate, {:noreply, s})
end

defp maybe_hibernate(true, res), do: Tuple.append(res, :hibernate)
defp maybe_hibernate(_, res), do: res

defp demonitor({_, mon}) when is_reference(mon) do
Process.demonitor(mon, [:flush])
Expand All @@ -581,11 +605,15 @@ defmodule DBConnection.Connection do
defp start_timer(pid, timeout) do
:erlang.start_timer(timeout, self(), {__MODULE__, pid, timeout})
end
defp start_timer(_, :infinity, _), do: nil
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Lets reuse the existing timer function by calling start_timer(:idle, timeout) so the message carries some information!

defp start_timer(pid, timeout, msg) do
:erlang.start_timer(timeout, pid, msg)
end

defp cancel_timer(nil), do: :ok
defp cancel_timer(timer) do
case :erlang.cancel_timer(timer) do
false -> flush_timer(timer)
false -> :erlang.read_timer(timer) and flush_timer(timer)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

read_timer will always be false here so wont flush, we don't need this part.

_ -> :ok
end
end
Expand All @@ -594,6 +622,8 @@ defmodule DBConnection.Connection do
receive do
{:timeout, ^timer, {__MODULE__, _, _}} ->
:ok
{:timeout, ^timer, :trigger_hibernate} ->
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We won't need this clause see above!

:ok
after
0 ->
raise ArgumentError, "timer #{inspect(timer)} does not exist"
Expand Down