Add machi_verbose.hrl

This commit is contained in:
Scott Lystig Fritchie 2015-07-16 16:01:53 +09:00
parent 197687064b
commit 73ac220d75
3 changed files with 63 additions and 31 deletions

31
include/machi_verbose.hrl Normal file
View file

@ -0,0 +1,31 @@
%% -------------------------------------------------------------------
%%
%% Machi: a small village of replicated files
%%
%% Copyright (c) 2014-2015 Basho Technologies, Inc. All Rights Reserved.
%%
%% This file is provided to you under the Apache License,
%% Version 2.0 (the "License"); you may not use this file
%% except in compliance with the License. You may obtain
%% a copy of the License at
%%
%% http://www.apache.org/licenses/LICENSE-2.0
%%
%% Unless required by applicable law or agreed to in writing,
%% software distributed under the License is distributed on an
%% "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
%% KIND, either express or implied. See the License for the
%% specific language governing permissions and limitations
%% under the License.
%%
%% -------------------------------------------------------------------
-ifdef(PULSE).
-define(V(Fmt, Args), pulse:format(Fmt, Args)).
-else. % PULSE
-define(V(Fmt, Args), io:format(user, Fmt, Args)).
-endif. % PULSE
-define(D(X), ?V("~s ~p\n", [??X, X])).
-define(Dw(X), ?V("~s ~w\n", [??X, X])).

View file

@ -53,6 +53,7 @@
-include("machi_projection.hrl").
-include("machi_chain_manager.hrl").
-include("machi_verbose.hrl").
-record(ch_mgr, {
name :: pv1_server(),
@ -74,9 +75,6 @@
proxies_dict :: orddict:orddict()
}).
-define(D(X), io:format(user, "~s ~p\n", [??X, X])).
-define(Dw(X), io:format(user, "~s ~w\n", [??X, X])).
-define(FLU_PC, machi_proxy_flu1_client).
-define(TO, (2*1000)). % default timeout
@ -990,7 +988,7 @@ react_to_env_A30(Retries, P_latest, LatestUnanimousP, _ReadExtra,
[FLU || {FLU, {{{epk,_},_}, Cnt}} <- AllFlapCounts,
Cnt >= FlapLimit],
FlappingAll = (PossibleFlappers -- SeenFlappers) == [],
%% erlang:display({'YOYO',MyName,NewEpoch,FlappingAll}),
?V("~w,", [{'YOYO',MyName,NewEpoch,FlappingAll}]),
NewFlap = OldFlap#flap_i{flapping_me=true,
flapping_all=FlappingAll},
@ -1288,7 +1286,7 @@ react_to_env_B10(Retries, P_newprop, P_latest, LatestUnanimousP,
{flap_limit, FlapLimit}]}),
case proplists:get_value(private_write_verbose, S#ch_mgr.opts) of
true ->
io:format(user, "{FLAP: ~w flaps ~w}! ", [S#ch_mgr.name, P_newprop_flap_count]);
?V("{FLAP: ~w flaps ~w}! ", [S#ch_mgr.name, P_newprop_flap_count]);
_ ->
ok
end,
@ -1369,7 +1367,7 @@ react_to_env_C100(P_newprop, #projection_v1{author_server=Author_latest,
?REACT(c100),
Sane = projection_transition_is_sane(P_current, P_latest, MyName),
%% deadlock more frequent here???? if Sane == true -> ok; true -> io:format(user, "insane-~w-~w,", [MyName, P_newprop#projection_v1.epoch_number]) end, %%% DELME!!!
if Sane == true -> ok; true -> ?V("insane-~w-~w,", [MyName, P_newprop#projection_v1.epoch_number]) end, %%% DELME!!!
Flap_latest = if is_record(Flap_latest0, flap_i) ->
Flap_latest0;
true ->
@ -1401,7 +1399,7 @@ react_to_env_C100(P_newprop, #projection_v1{author_server=Author_latest,
Flap_latest#flap_i.flapping_me == true andalso
Flap_latest#flap_i.flapping_all == true ->
?REACT({c100, ?LINE}),
io:format(user, "\n\n1YOYO ~w breaking the cycle of ~p\n", [MyName, machi_projection:make_summary(P_latest)]),
?V("\n\n1YOYO ~w breaking the cycle of ~p\n", [MyName, machi_projection:make_summary(P_latest)]),
%% This is a fun case. We had just enough asymmetric partition
%% to cause the chain to fragment into two *incompatible* and
%% *overlapping membership* chains, but the chain fragmentation
@ -1437,7 +1435,7 @@ react_to_env_C100(P_newprop, #projection_v1{author_server=Author_latest,
Flap_latest#flap_i.flapping_me == true andalso
Flap_latest#flap_i.flapping_all == true ->
?REACT({c100, ?LINE}),
io:format(user, "\n\n2YOYO ~w breaking the cycle of ~p\n", [MyName, machi_projection:make_summary(P_latest)]),
?V("\n\n2YOYO ~w breaking the cycle of ~p\n", [MyName, machi_projection:make_summary(P_latest)]),
react_to_env_C103(P_latest, S);
{expected_author2,_ExpectedAuthor2}=_ExpectedErr ->
case get(perhaps_reset_loop) of
@ -1500,7 +1498,7 @@ react_to_env_C110(P_latest, #ch_mgr{name=MyName} = S) ->
%% timeout exception.
%% ok = ?FLU_PC:write_projection(MyNamePid, private, P_latest2, ?TO*30),
Goo = P_latest2#projection_v1.epoch_number,
%% io:format(user, "HEE110 ~w ~w ~w\n", [S#ch_mgr.name, self(), lists:reverse(get(react))]),
%% ?V("HEE110 ~w ~w ~w\n", [S#ch_mgr.name, self(), lists:reverse(get(react))]),
{ok,Goo} = {?FLU_PC:write_projection(MyNamePid, private, P_latest2, ?TO*30),Goo},
case proplists:get_value(private_write_verbose, S#ch_mgr.opts) of
@ -1513,7 +1511,7 @@ react_to_env_C110(P_latest, #ch_mgr{name=MyName} = S) ->
false ->
case proplists:get_value(private_write_verbose, S#ch_mgr.opts) of
true ->
io:format(user, "\n~2..0w:~2..0w:~2..0w.~3..0w ~p uses plain: ~w\n",
?V("\n~2..0w:~2..0w:~2..0w.~3..0w ~p uses plain: ~w\n",
[HH,MM,SS,MSec, S#ch_mgr.name,
machi_projection:make_summary(P_latest2x)]);
_ ->
@ -1524,7 +1522,7 @@ react_to_env_C110(P_latest, #ch_mgr{name=MyName} = S) ->
true ->
P_inner = inner_projection_or_self(P_latest2),
P_innerx = P_inner#projection_v1{dbg2=[]}, % limit verbose len.
io:format(user, "\n~2..0w:~2..0w:~2..0w.~3..0w ~p uses inner: ~w\n",
?V("\n~2..0w:~2..0w:~2..0w.~3..0w ~p uses inner: ~w\n",
[HH,MM,SS,MSec, S#ch_mgr.name,
machi_projection:make_summary(P_innerx)]);
_ ->
@ -1551,7 +1549,7 @@ react_to_env_C120(P_latest, FinalProps, #ch_mgr{proj_history=H}=S) ->
H2
end,
%% HH = [if is_atom(X) -> X; is_tuple(X) -> {element(1,X), element(2,X)} end || X <- get(react), is_atom(X) orelse size(X) == 3],
%% io:format(user, "HEE120 ~w ~w ~w\n", [S#ch_mgr.name, self(), lists:reverse(HH)]),
%% ?V("HEE120 ~w ~w ~w\n", [S#ch_mgr.name, self(), lists:reverse(HH)]),
?REACT({c120, [{latest, machi_projection:make_summary(P_latest)}]}),
{{now_using, FinalProps, P_latest#projection_v1.epoch_number},
@ -1565,7 +1563,7 @@ react_to_env_C200(Retries, P_latest, S) ->
%% Actually implement it? None of the above?
yo:tell_author_yo(P_latest#projection_v1.author_server)
catch _Type:_Err ->
%% io:format(user, "TODO: tell_author_yo is broken: ~p ~p\n",
%% ?V("TODO: tell_author_yo is broken: ~p ~p\n",
%% [_Type, _Err]),
ok
end,

View file

@ -27,6 +27,7 @@
-compile(export_all).
-include("machi_projection.hrl").
-include("machi_verbose.hrl").
-include_lib("eqc/include/eqc.hrl").
-include_lib("eqc/include/eqc_statem.hrl").
@ -169,8 +170,7 @@ all_list() ->
[P#p_srvr.name || {P, _Dir} <- all_list_extra()].
setup(Num, Seed) ->
?QC_FMT("\nsetup(~w", [Num]),
error_logger:tty(false),
?V("\nsetup(~w", [Num]),
All_list = lists:sublist(all_list(), Num),
All_listE = lists:sublist(all_list_extra(), Num),
%% shutdown_hard() has taken care of killing all relevant procs.
@ -178,12 +178,12 @@ setup(Num, Seed) ->
machi_flu1_test:clean_up_data_dir(Dir),
filelib:ensure_dir(Dir ++ "/not-used")
end || {_P, Dir} <- All_listE],
?QC_FMT(",z~w", [?LINE]),
?V(",z~w", [?LINE]),
%% Start partition simulator
{ok, PSimPid} = machi_partition_simulator:start_link(Seed, 0, 100),
_Partitions = machi_partition_simulator:get(All_list),
?QC_FMT(",z~w", [?LINE]),
?V(",z~w", [?LINE]),
%% Start FLUs and their associated procs
{ok, SupPid} = machi_flu_sup:start_link(),
@ -194,7 +194,7 @@ setup(Num, Seed) ->
end || {P, Dir} <- All_listE],
%% Set up the chain
Dict = orddict:from_list([{P#p_srvr.name, P} || {P, _Dir} <- All_listE]),
?QC_FMT(",z~w", [?LINE]),
?V(",z~w", [?LINE]),
[machi_chain_manager1:set_chain_members(get_chmgr(P), Dict) ||
{P, _Dir} <- All_listE],
%% Trigger some environment reactions for humming consensus: first
@ -203,17 +203,17 @@ setup(Num, Seed) ->
[begin
_QQa = machi_chain_manager1:test_react_to_env(get_chmgr(P))
end || {P, _Dir} <- All_listE, _I <- lists:seq(1,20), _Repeat <- [1,2]],
?QC_FMT(",z~w", [?LINE]),
?V(",z~w", [?LINE]),
[begin
_QQa = machi_chain_manager1:test_react_to_env(get_chmgr(P))
end || _I <- lists:seq(1,20), {P, _Dir} <- All_listE, _Repeat <- [1,2]],
?QC_FMT(",z~w", [?LINE]),
?V(",z~w", [?LINE]),
ProxiesDict = ?FLU_PC:start_proxies(Dict),
Res = {PSimPid, SupPid, ProxiesDict, All_listE},
put(manager_pids_hack, Res),
?QC_FMT("),", []),
?V("),", []),
Res.
change_partitions(OldThreshold, NoPartitionThreshold)
@ -245,28 +245,28 @@ private_stable_check() ->
{_PSimPid, _SupPid, ProxiesDict, All_listE} = get(manager_pids_hack),
Res = private_projections_are_stable_check(ProxiesDict, All_listE),
if not Res ->
io:format(user, "BUMMER: private stable check failed!\n", []);
?V("BUMMER: private stable check failed!\n", []);
true ->
ok
end,
Res.
do_ticks(Num, PidsMaybe, OldThreshold, NoPartitionThreshold) ->
io:format(user, "~p,~p,~p|", [Num, OldThreshold, NoPartitionThreshold]),
?V("~p,~p,~p|", [Num, OldThreshold, NoPartitionThreshold]),
{_PSimPid, _SupPid, ProxiesDict, All_listE} =
case PidsMaybe of
undefined -> get(manager_pids_hack);
_ -> PidsMaybe
end,
if is_atom(OldThreshold) ->
?QC_FMT("{e=~w},", [get_biggest_private_epoch_number(ProxiesDict)]),
?V("{e=~w},", [get_biggest_private_epoch_number(ProxiesDict)]),
machi_partition_simulator:no_partitions();
true ->
change_partitions(OldThreshold, NoPartitionThreshold)
end,
Res = exec_ticks(Num, All_listE),
if not is_integer(OldThreshold) ->
?QC_FMT("{e=~w},", [get_biggest_private_epoch_number(ProxiesDict)]);
?V("{e=~w},", [get_biggest_private_epoch_number(ProxiesDict)]);
true ->
ok
end,
@ -283,7 +283,7 @@ get_biggest_private_epoch_number(ProxiesDict) ->
dump_state() ->
try
?QC_FMT("dump_state(", []),
?V("dump_state(", []),
{_PSimPid, _SupPid, ProxiesDict, _AlE} = get(manager_pids_hack),
Report = ?MGRTEST:unanimous_report(ProxiesDict),
Namez = ProxiesDict,
@ -294,12 +294,12 @@ dump_state() ->
P#projection_v1.epoch_number /= 0]
end} || {Name, Proxy} <- ProxiesDict],
?QC_FMT(")", []),
?V(")", []),
Diag1 = Diag2 = "skip_diags",
{Report, PrivProjs, lists:flatten([Diag1, Diag2])}
catch XX:YY ->
?QC_FMT("OUCH: ~p ~p @ ~p\n", [XX, YY, erlang:get_stacktrace()]),
?QC_FMT("Exiting now to move to manual post-mortem....\n", []),
?V("OUCH: ~p ~p @ ~p\n", [XX, YY, erlang:get_stacktrace()]),
?V("Exiting now to move to manual post-mortem....\n", []),
erlang:halt(0),
false
end.
@ -329,6 +329,9 @@ prop_pulse(Style) when Style == new; Style == regression ->
Cmds1 ++
Stabilize2 ++
[{set,{var,99999999}, {call, ?MODULE, dump_state, []}}],
error_logger:tty(false),
pulse:verbose([format]),
{_H2, S2, Res} = pulse:run(
fun() ->
{_H, _S, _R} = run_commands(?MODULE, Cmds)
@ -368,7 +371,7 @@ prop_pulse(Style) when Style == new; Style == regression ->
ok = shutdown_hard(),
?WHENFAIL(
begin
?QC_FMT("PrivProjs = ~P\n", [PrivProjs, 50]),
%% ?QC_FMT("PrivProjs = ~P\n", [PrivProjs, 50]),
?QC_FMT("Report = ~p\n", [Report]),
?QC_FMT("Cmds = ~p\n", [Cmds]),
?QC_FMT("Res = ~p\n", [Res]),
@ -376,7 +379,7 @@ prop_pulse(Style) when Style == new; Style == regression ->
?QC_FMT("Sane = ~p\n", [Sane]),
?QC_FMT("AllDisjointDetail = ~p\n", [AllDisjointDetail]),
?QC_FMT("SingleChainNoRepair failure = ~p\n", [SingleChainNoRepairDetail])
%% ,erlang:halt(0)
,?QC_FMT("\n\nHalting now!!!!!!!!!!\n\n", []),timer:sleep(500),erlang:halt(1)
end,
conjunction([{res, Res == true orelse Res == ok},
{all_disjoint, AllDisjointP},