From a238e070e3f498b0fdb4112fd8467ef70a681e11 Mon Sep 17 00:00:00 2001 From: Dan Gudmundsson Date: Wed, 25 May 2016 11:44:36 +0200 Subject: Add test debug information and fix timing issues --- lib/mnesia/test/mnesia_atomicity_test.erl | 18 +++++++--- lib/mnesia/test/mnesia_consistency_test.erl | 54 ++++++++++++++++++++--------- lib/mnesia/test/mnesia_evil_backup.erl | 2 +- lib/mnesia/test/mnesia_recovery_test.erl | 11 +++++- lib/mnesia/test/mt.erl | 2 ++ 5 files changed, 65 insertions(+), 22 deletions(-) diff --git a/lib/mnesia/test/mnesia_atomicity_test.erl b/lib/mnesia/test/mnesia_atomicity_test.erl index 612c4ad368..cc32ba3826 100644 --- a/lib/mnesia/test/mnesia_atomicity_test.erl +++ b/lib/mnesia/test/mnesia_atomicity_test.erl @@ -700,11 +700,19 @@ start_restart_check(RestartOp, ReplicaNeed, Config) -> %% mnesia shall be killed at that node, where A is reading %% the information from - kill_where_to_read(TabName, N1, [N2, N3]), + Read = kill_where_to_read(TabName, N1, [N2, N3]), %% wait some time to let mnesia go down and spread those news around %% fun A shall be able to finish its job before being restarted - wait(500), + Wait = fun(Loop) -> + wait(300), + sys:get_status(mnesia_monitor), + case lists:member(Read, mnesia_lib:val({current, db_nodes})) of + true -> Loop(Loop); + false -> ok + end + end, + Wait(Wait), A ! go_ahead, %% the sticky write doesnt work on remote nodes !!! @@ -772,10 +780,12 @@ kill_where_to_read(TabName, N1, Nodes) -> Read = rpc:call(N1,mnesia,table_info, [TabName, where_to_read]), case lists:member(Read, Nodes) of true -> - mnesia_test_lib:kill_mnesia([Read]); + mnesia_test_lib:kill_mnesia([Read]), + Read; false -> ?error("Fault while killing Mnesia: ~p~n", [Read]), - mnesia_test_lib:kill_mnesia(Nodes) + mnesia_test_lib:kill_mnesia(Nodes), + Read end. sync_tid_release() -> diff --git a/lib/mnesia/test/mnesia_consistency_test.erl b/lib/mnesia/test/mnesia_consistency_test.erl index 9cc84de87b..2fe1bd34e6 100644 --- a/lib/mnesia/test/mnesia_consistency_test.erl +++ b/lib/mnesia/test/mnesia_consistency_test.erl @@ -665,10 +665,10 @@ consistency_after_restore(ReplicaType, Op, Config) -> [lists:foreach(fun(E) -> ok = mnesia:dirty_write({Tab, E, 2}) end, NList) || Tab <- Tabs], - Pids1 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carA, Op]), ok} || _ <- lists:seq(1, 5)], - Pids2 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carB, Op]), ok} || _ <- lists:seq(1, 5)], - Pids3 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carC, Op]), ok} || _ <- lists:seq(1, 5)], - Pids4 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carD, Op]), ok} || _ <- lists:seq(1, 5)], + Pids1 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carA, Op]), carA} || _ <- lists:seq(1, 5)], + Pids2 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carB, Op]), carB} || _ <- lists:seq(1, 5)], + Pids3 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carC, Op]), carC} || _ <- lists:seq(1, 5)], + Pids4 = [{'EXIT', spawn_link(?MODULE, change_tab, [self(), carD, Op]), carD} || _ <- lists:seq(1, 5)], AllPids = Pids1 ++ Pids2 ++ Pids3 ++ Pids4, @@ -678,19 +678,38 @@ consistency_after_restore(ReplicaType, Op, Config) -> Else -> Else end end, - + timer:sleep(timer:seconds(Delay)), %% Let changers grab locks ?verbose("Doing restore~n", []), ?match(Tabs, Restore(File, [{default_op, Op}])), - timer:sleep(timer:seconds(Delay)), %% Let em die + Collect = fun(Msg, Acc) -> + receive Msg -> Acc + after 10000 -> [Msg|Acc] + end + end, - ?match_multi_receive(AllPids), + Failed1 = lists:foldl(Collect, [], AllPids), + Failed = lists:foldl(Collect, [], Failed1), + + case Failed of + [] -> ok; + _ -> + ?match([], Failed), + io:format("TIME: ~p sec~n", [erlang:system_time(seconds) band 16#FF]), + Dbg = fun({_, Pid, Tab}) -> + io:format("Tab ~p: ~p~n",[Tab, process_info(Pid, current_stacktrace)]), + [io:format(" ~p~n", [Rec]) || Rec <- mnesia:dirty_match_object({Tab, '_', '_'})] + end, + [Dbg(Msg) || Msg <- Failed], + io:format(" Held: ~p~n", [mnesia_locker:get_held_locks()]), + io:format("Queue: ~p~n", [mnesia_locker:get_lock_queue()]) + end, - case ?match(ok, restore_verify_tabs(Tabs)) of - {success, ok} -> + case ?match(ok, restore_verify_tabs(Tabs)) of + {success, ok} -> file:delete(File); - _ -> + _ -> {T, M, S} = time(), File2 = ?flat_format("consistency_error~w~w~w.BUP", [T, M, S]), file:rename(File, File2) @@ -700,17 +719,20 @@ consistency_after_restore(ReplicaType, Op, Config) -> change_tab(Father, Tab, Test) -> Key = rand:uniform(20), Update = fun() -> + Time = erlang:system_time(seconds) band 16#FF, + case put(time, Time) of + Time -> ok; + _ -> io:format("~p ~p ~p sec~n", [self(), Tab, Time]) + end, case mnesia:read({Tab, Key}) of - [{Tab, Key, 1}] -> - quit; - [{Tab, Key, _N}] -> - mnesia:write({Tab, Key, 3}) + [{Tab, Key, 1}] -> quit; + [{Tab, Key, _N}] -> mnesia:write({Tab, Key, 3}) end end, case mnesia:transaction(Update) of {atomic, quit} -> - exit(ok); - {aborted, {no_exists, Tab}} when Test == recreate_tables ->%% I'll allow this + exit(Tab); + {aborted, {no_exists, Tab}} when Test == recreate_tables -> %% I'll allow this change_tab(Father, Tab, Test); {atomic, ok} -> change_tab(Father, Tab, Test) diff --git a/lib/mnesia/test/mnesia_evil_backup.erl b/lib/mnesia/test/mnesia_evil_backup.erl index b71348f144..e745ec9b04 100644 --- a/lib/mnesia/test/mnesia_evil_backup.erl +++ b/lib/mnesia/test/mnesia_evil_backup.erl @@ -325,7 +325,7 @@ restore(Config, Op) -> end, ?match(ok, file:delete(File1)), ?match(ok, file:delete(File2)), - ?match([], Check() -- Before), + ?match([], Check() -- (Before ++ [{ok, latest_log}, {ok, previous_log}])), ?verify_mnesia(Nodes, []). diff --git a/lib/mnesia/test/mnesia_recovery_test.erl b/lib/mnesia/test/mnesia_recovery_test.erl index 2388b595d0..130b87346f 100644 --- a/lib/mnesia/test/mnesia_recovery_test.erl +++ b/lib/mnesia/test/mnesia_recovery_test.erl @@ -504,12 +504,21 @@ with_checkpoint(Config, Type) when is_list(Config) -> ?match(ok, mnesia:deactivate_checkpoint(sune)), ?match([], check_chkp(Nodes)), + Wait = fun(Loop) -> + timer:sleep(300), + sys:get_status(mnesia_monitor), + case lists:member(Kill, mnesia_lib:val({current, db_nodes})) of + true -> Loop(Loop); + false -> ok + end + end, + case Kill of Node1 -> ignore; Node2 -> mnesia_test_lib:kill_mnesia([Kill]), - timer:sleep(500), %% Just to help debugging + Wait(Wait), ?match({ok, sune, _}, mnesia:activate_checkpoint([{name, sune}, {max, mnesia:system_info(tables)}, {ram_overrides_dump, true}])), diff --git a/lib/mnesia/test/mt.erl b/lib/mnesia/test/mt.erl index 793fb125e6..5a981bf539 100644 --- a/lib/mnesia/test/mt.erl +++ b/lib/mnesia/test/mt.erl @@ -80,6 +80,8 @@ resolve(Suite0) when is_atom(Suite0) -> {Suite, Case} -> {Suite, is_group(Suite,Case)} end; +resolve({Suite0, {group, Case}}) -> + resolve({Suite0, Case}); resolve({Suite0, Case}) when is_atom(Suite0), is_atom(Case) -> case alias(Suite0) of Suite when is_atom(Suite) -> -- cgit v1.2.3