From 199950e29c8faa990b9bcf04796df3ab6e7234df Mon Sep 17 00:00:00 2001 From: Mikhail Uvarov Date: Wed, 4 Dec 2024 14:42:07 +0100 Subject: [PATCH 1/4] Print mnesia:wait_for_tables progress --- src/mongoose_internal_databases.erl | 25 ++++++++++++++++++++++++- 1 file changed, 24 insertions(+), 1 deletion(-) diff --git a/src/mongoose_internal_databases.erl b/src/mongoose_internal_databases.erl index 7518de3be4d..8b2c55f25c3 100644 --- a/src/mongoose_internal_databases.erl +++ b/src/mongoose_internal_databases.erl @@ -10,6 +10,8 @@ -export([instrumentation/0]). -ignore_xref([instrumentation/0]). +-include("mongoose_logger.hrl"). + -type db() :: mnesia | cets. -spec init() -> ok. @@ -28,11 +30,32 @@ init(mnesia, #{}) -> ok end, application:start(mnesia, permanent), - mnesia:wait_for_tables(mnesia:system_info(local_tables), infinity), + wait_for_tables_loop(mnesia:system_info(local_tables), 10000, 0), mongoose_node_num_mnesia:init(); init(cets, #{}) -> ok. +%% Sometimes mnesia:wait_for_tables/2 could hang on startup. +%% This function logs which tables are not ready and their status. +wait_for_tables_loop(Tables, Interval, Total) -> + case mnesia:wait_for_tables(Tables, Interval) of + ok -> + ok; + {timeout, WaitingTables} -> + ?LOG_WARNING(#{what => mnesia_wait_for_tables_progress, + waiting_for_tables => WaitingTables, + waiting_time => Total + Interval}), + [log_detailed_table_info(Tab) || Tab <- WaitingTables], + wait_for_tables_loop(WaitingTables, Interval, Total + Interval); + {error, Reason} -> + error({mnesia_wait_for_tables_failed, Reason}) + end. + +log_detailed_table_info(Tab) -> + ?LOG_WARNING(#{what => log_detailed_table_info, + table => Tab, + details => mnesia:table_info(Tab, all)}). + -spec instrumentation() -> [mongoose_instrument:spec()]. instrumentation() -> lists:flatmap(fun instrumentation/1, maps:keys(mongoose_config:get_opt(internal_databases))). From 7ea781bd6cdae644ae2a360e269a0f558893eae4 Mon Sep 17 00:00:00 2001 From: Mikhail Uvarov Date: Wed, 11 Dec 2024 13:30:16 +0100 Subject: [PATCH 2/4] Skip inject_module for local nodes --- test/common/mongoose_helper.erl | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/test/common/mongoose_helper.erl b/test/common/mongoose_helper.erl index 0818bef3ca7..a644a4801cc 100644 --- a/test/common/mongoose_helper.erl +++ b/test/common/mongoose_helper.erl @@ -351,18 +351,20 @@ inject_module(Module) -> inject_module(Module, ReloadIfAlreadyLoaded) -> inject_module(mim(), Module, ReloadIfAlreadyLoaded). --spec inject_module(Node :: atom(), +-spec inject_module(Node :: distributed_helper:rpc_spec(), Module :: module(), ReloadIfAlreadyLoaded :: no_reload | reload) -> ok | already_loaded. -inject_module(Node, Module, no_reload) -> +inject_module(#{node := NodeAtom} = Node, Module, _) when NodeAtom =:= node() -> + already_loaded; +inject_module(#{} = Node, Module, no_reload) -> case successful_rpc(Node, code, is_loaded, [Module]) of false -> inject_module(Node, Module, reload); _ -> already_loaded end; -inject_module(Node, Module, reload) -> +inject_module(#{} = Node, Module, reload) -> {Mod, Bin, File} = code:get_object_code(Module), successful_rpc(Node, code, load_binary, [Mod, File, Bin]). From c6131e5a18e841e3a44096705455c83b1d2b0ace Mon Sep 17 00:00:00 2001 From: Mikhail Uvarov Date: Wed, 11 Dec 2024 13:31:39 +0100 Subject: [PATCH 3/4] Add test for mongoose_internal_databases:wait_for_mnesia --- src/mongoose_internal_databases.erl | 9 ++++-- test/mnesia_db_SUITE.erl | 47 +++++++++++++++++++++++++++++ 2 files changed, 53 insertions(+), 3 deletions(-) create mode 100644 test/mnesia_db_SUITE.erl diff --git a/src/mongoose_internal_databases.erl b/src/mongoose_internal_databases.erl index 8b2c55f25c3..813ac39d579 100644 --- a/src/mongoose_internal_databases.erl +++ b/src/mongoose_internal_databases.erl @@ -7,8 +7,8 @@ -export([probe/2]). %% For tests --export([instrumentation/0]). --ignore_xref([instrumentation/0]). +-export([instrumentation/0, wait_for_mnesia/0]). +-ignore_xref([instrumentation/0, wait_for_mnesia/0]). -include("mongoose_logger.hrl"). @@ -30,11 +30,14 @@ init(mnesia, #{}) -> ok end, application:start(mnesia, permanent), - wait_for_tables_loop(mnesia:system_info(local_tables), 10000, 0), + wait_for_mnesia(), mongoose_node_num_mnesia:init(); init(cets, #{}) -> ok. +wait_for_mnesia() -> + wait_for_tables_loop(mnesia:system_info(local_tables), 10000, 0). + %% Sometimes mnesia:wait_for_tables/2 could hang on startup. %% This function logs which tables are not ready and their status. wait_for_tables_loop(Tables, Interval, Total) -> diff --git a/test/mnesia_db_SUITE.erl b/test/mnesia_db_SUITE.erl new file mode 100644 index 00000000000..21d8f9a57f4 --- /dev/null +++ b/test/mnesia_db_SUITE.erl @@ -0,0 +1,47 @@ +-module(mnesia_db_SUITE). +-compile([export_all, nowarn_export_all]). + +-include_lib("exml/include/exml.hrl"). +-include_lib("eunit/include/eunit.hrl"). +-include("mongoose.hrl"). +-include("jlib.hrl"). + +local() -> + #{node => node()}. + +all() -> + [mnesia_wait_for_tables]. + +init_per_suite(Config) -> + Config. + +end_per_suite(Config) -> + ok. + +init_per_testcase(_, C) -> + mock_mnesia(), + logger_ct_backend:start(local()), + C. + +end_per_testcase(_, _) -> + meck:unload(), + logger_ct_backend:stop(local()). + +mock_mnesia() -> + meck:new(mnesia, []), + meck:expect(mnesia, system_info, fun(local_tables) -> [test_table_fast, test_table_slow] end), + meck:expect(mnesia, table_info, fun(_, _) -> [] end), + meck:expect(mnesia, wait_for_tables, fun(Tables, Interval) -> + case meck:num_calls(mnesia, wait_for_tables, '_') > 5 of + true -> ok; + false -> {timeout, Tables -- [test_table_fast]} + end + end), + ok. + +mnesia_wait_for_tables(_Config) -> + logger_ct_backend:capture(warning, local()), + mongoose_internal_databases:wait_for_mnesia(), + logger_ct_backend:stop_capture(local()), + FilterFun = fun(_, Msg) -> re:run(Msg, "what: mnesia_wait_for_tables_progress") /= nomatch end, + 6 = length(logger_ct_backend:recv(FilterFun)). From 01ec22e7388620926b164f4b8b18a7cee6eba052 Mon Sep 17 00:00:00 2001 From: Michael Uvarov Date: Thu, 12 Dec 2024 15:15:09 +0100 Subject: [PATCH 4/4] Apply suggestions from code review Co-authored-by: jacekwegr <110383193+jacekwegr@users.noreply.github.com> --- test/common/mongoose_helper.erl | 2 +- test/mnesia_db_SUITE.erl | 7 ++----- 2 files changed, 3 insertions(+), 6 deletions(-) diff --git a/test/common/mongoose_helper.erl b/test/common/mongoose_helper.erl index a644a4801cc..044704c8c3e 100644 --- a/test/common/mongoose_helper.erl +++ b/test/common/mongoose_helper.erl @@ -355,7 +355,7 @@ inject_module(Module, ReloadIfAlreadyLoaded) -> Module :: module(), ReloadIfAlreadyLoaded :: no_reload | reload) -> ok | already_loaded. -inject_module(#{node := NodeAtom} = Node, Module, _) when NodeAtom =:= node() -> +inject_module(#{node := NodeAtom} = _Node, _, _) when NodeAtom =:= node() -> already_loaded; inject_module(#{} = Node, Module, no_reload) -> case successful_rpc(Node, code, is_loaded, [Module]) of diff --git a/test/mnesia_db_SUITE.erl b/test/mnesia_db_SUITE.erl index 21d8f9a57f4..3b4e217ca85 100644 --- a/test/mnesia_db_SUITE.erl +++ b/test/mnesia_db_SUITE.erl @@ -1,10 +1,7 @@ -module(mnesia_db_SUITE). -compile([export_all, nowarn_export_all]). --include_lib("exml/include/exml.hrl"). -include_lib("eunit/include/eunit.hrl"). --include("mongoose.hrl"). --include("jlib.hrl"). local() -> #{node => node()}. @@ -15,7 +12,7 @@ all() -> init_per_suite(Config) -> Config. -end_per_suite(Config) -> +end_per_suite(_Config) -> ok. init_per_testcase(_, C) -> @@ -31,7 +28,7 @@ mock_mnesia() -> meck:new(mnesia, []), meck:expect(mnesia, system_info, fun(local_tables) -> [test_table_fast, test_table_slow] end), meck:expect(mnesia, table_info, fun(_, _) -> [] end), - meck:expect(mnesia, wait_for_tables, fun(Tables, Interval) -> + meck:expect(mnesia, wait_for_tables, fun(Tables, _Interval) -> case meck:num_calls(mnesia, wait_for_tables, '_') > 5 of true -> ok; false -> {timeout, Tables -- [test_table_fast]}