From d2d02bad8c068c818057ac92e8aaa861195ef1aa Mon Sep 17 00:00:00 2001
From: "John R. Daily" <git@epep.us>
Date: Tue, 28 Apr 2015 11:11:41 -0400
Subject: [PATCH] Fix the async threshold test to eliminate a race

It now tests something slightly different,
but should be sufficient to validate the
behavior is correct.
---
 src/lager_backend_throttle.erl | 26 ++++++++++++++++++++++++++
 test/lager_test_backend.erl    | 23 +++++++++++++++++++----
 2 files changed, 45 insertions(+), 4 deletions(-)

diff --git a/src/lager_backend_throttle.erl b/src/lager_backend_throttle.erl
index 8b6f3ec..73ac113 100644
--- a/src/lager_backend_throttle.erl
+++ b/src/lager_backend_throttle.erl
@@ -29,6 +29,17 @@
 -export([init/1, handle_call/2, handle_event/2, handle_info/2, terminate/2,
         code_change/3]).
 
+%%
+%% Allow test code to verify that we're doing the needful.
+-ifdef(TEST).
+-define(ETS_TABLE, async_threshold_test).
+-define(TOGGLE_SYNC(), test_increment(sync_toggled)).
+-define(TOGGLE_ASYNC(), test_increment(async_toggled)).
+-else.
+-define(TOGGLE_SYNC(), true).
+-define(TOGGLE_ASYNC(), true).
+-endif.
+
 -record(state, {
         hwm :: non_neg_integer(),
         window_min :: non_neg_integer(),
@@ -52,10 +63,12 @@ handle_event({log, _Message},State) ->
     case {Len > State#state.hwm, Len < State#state.window_min, State#state.async} of
         {true, _, true} ->
             %% need to flip to sync mode
+            ?TOGGLE_SYNC(),
             lager_config:set(async, false),
             {ok, State#state{async=false}};
         {_, true, false} ->
             %% need to flip to async mode
+            ?TOGGLE_ASYNC(),
             lager_config:set(async, true),
             {ok, State#state{async=true}};
         _ ->
@@ -76,3 +89,16 @@ terminate(_Reason, _State) ->
 code_change(_OldVsn, State, _Extra) ->
     {ok, State}.
 
+-ifdef(TEST).
+test_get(Key) ->
+    get_default(ets:lookup(?ETS_TABLE, Key)).
+
+test_increment(Key) ->
+    ets:insert(?ETS_TABLE,
+               {Key, test_get(Key) + 1}).
+
+get_default([]) ->
+    0;
+get_default([{_Key, Value}]) ->
+    Value.
+-endif.
diff --git a/test/lager_test_backend.erl b/test/lager_test_backend.erl
index 7ef27ec..662abcc 100644
--- a/test/lager_test_backend.erl
+++ b/test/lager_test_backend.erl
@@ -1233,6 +1233,9 @@ async_threshold_test_() ->
     {foreach,
         fun() ->
                 error_logger:tty(false),
+                ets:new(async_threshold_test, [set, named_table, public]),
+                ets:insert_new(async_threshold_test, {sync_toggled, 0}),
+                ets:insert_new(async_threshold_test, {async_toggled, 0}),
                 application:load(lager),
                 application:set_env(lager, error_logger_redirect, false),
                 application:set_env(lager, async_threshold, 2),
@@ -1244,6 +1247,7 @@ async_threshold_test_() ->
                 application:unset_env(lager, async_threshold),
                 application:stop(lager),
                 application:stop(goldrush),
+                ets:delete(async_threshold_test),
                 error_logger:tty(true)
         end,
         [
@@ -1258,11 +1262,22 @@ async_threshold_test_() ->
                         %% serialize on mailbox
                         _ = gen_event:which_handlers(lager_event),
                         timer:sleep(500),
-                        %% there should be a ton of outstanding messages now, so async is false
-                        ?assertEqual(false, lager_config:get(async)),
-                        %% wait for all the workers to return, meaning that all the messages have been logged (since we're in sync mode)
+
+                        %% By now the flood of messages will have
+                        %% forced the backend throttle to turn off
+                        %% async mode, but it's possible all
+                        %% outstanding requests have been processed,
+                        %% so checking the current status (sync or
+                        %% async) is an exercise in race control.
+
+                        %% Instead, we'll see whether the backend
+                        %% throttle has toggled into sync mode at any
+                        %% point in the past
+                        ?assertMatch([{sync_toggled, N}] when N > 0,
+                                                              ets:lookup(async_threshold_test, sync_toggled)),
+                        %% wait for all the workers to return, meaning that all the messages have been logged (since we're definitely in sync mode at the end of the run)
                         collect_workers(Workers),
-                        %% serialize ont  the mailbox again
+                        %% serialize on the mailbox again
                         _ = gen_event:which_handlers(lager_event),
                         %% just in case...
                         timer:sleep(1000),