diff --git a/big_tests/default.spec b/big_tests/default.spec index b88352f08d1..6df21abda9c 100644 --- a/big_tests/default.spec +++ b/big_tests/default.spec @@ -130,7 +130,11 @@ %% ct_mongoose_hook will: %% * ensure preset & mim_data_dir values are passed to ct Config %% * check server's purity after SUITE -{ct_hooks, [ct_groups_summary_hook, ct_tty_hook, ct_mongoose_hook, ct_progress_hook, +{ct_hooks, [ct_groups_summary_hook, ct_tty_hook, + ct_mongoose_hook, + {ct_mongoose_log_hook, [{host, mim2}, {print_init_and_done_for_testcases, false}]}, + {ct_mongoose_log_hook, [{host, mim3}, {print_init_and_done_for_testcases, false}]}, + ct_progress_hook, ct_markdown_errors_hook, ct_mongoose_log_hook]}. %% since test-runner.sh can be executed with the --one-node option, diff --git a/big_tests/dynamic_domains.spec b/big_tests/dynamic_domains.spec index 3662dcd9760..7ed9ad920b0 100644 --- a/big_tests/dynamic_domains.spec +++ b/big_tests/dynamic_domains.spec @@ -174,7 +174,10 @@ %% * ensure preset & mim_data_dir values are passed to ct Config %% * check server's purity after SUITE {ct_hooks, [ct_groups_summary_hook, ct_tty_hook, ct_mongoose_hook, ct_progress_hook, - ct_markdown_errors_hook, ct_mongoose_log_hook]}. + ct_markdown_errors_hook, + ct_mongoose_log_hook, + {ct_mongoose_log_hook, [{host, mim2}, {print_init_and_done_for_testcases, false}]}, + {ct_mongoose_log_hook, [{host, mim3}, {print_init_and_done_for_testcases, false}]}]}. %% since test-runner.sh can be executed with the --one-node option, %% log collection is enabled by default for host mim1 only. diff --git a/big_tests/mam.spec b/big_tests/mam.spec index 0183cb7862f..d521659b0ab 100644 --- a/big_tests/mam.spec +++ b/big_tests/mam.spec @@ -23,7 +23,10 @@ %% ct_mongoose_hook will: %% * ensure preset & mim_data_dir values are passed to ct Config %% * check server's purity after SUITE -{ct_hooks, [ct_groups_summary_hook, ct_tty_hook, ct_mongoose_hook, ct_progress_hook, +{ct_hooks, [ct_groups_summary_hook, ct_tty_hook, ct_mongoose_hook, + ct_progress_hook, + {ct_mongoose_log_hook, [{host, mim2}, {print_init_and_done_for_testcases, false}]}, + {ct_mongoose_log_hook, [{host, mim3}, {print_init_and_done_for_testcases, false}]}, ct_markdown_errors_hook, ct_mongoose_log_hook]}. %% since test-runner.sh can be executed with the --one-node option, diff --git a/big_tests/src/ct_mongoose_log_hook.erl b/big_tests/src/ct_mongoose_log_hook.erl index b6883189686..3717c7f6e76 100644 --- a/big_tests/src/ct_mongoose_log_hook.erl +++ b/big_tests/src/ct_mongoose_log_hook.erl @@ -33,7 +33,8 @@ -export([pre_init_per_testcase/3]). -export([post_end_per_testcase/4]). --record(state, { node_name, reader, writer, +-record(state, { print_init_and_done_for_testcases, + node_name, reader, writer, current_line_num, out_file, url_file, group, suite, log_flags = [] }). -include_lib("exml/include/exml.hrl"). @@ -48,30 +49,42 @@ id(Opts) -> init(_Id, Opts) -> Node = connect_mim_node(Opts), LogFlags = proplists:get_value(log, Opts, [suite]), - {ok, #state{ node_name=Node, log_flags=LogFlags }}. + PrintInitDone = proplists:get_value(print_init_and_done_for_testcases, Opts), + {ok, #state{ node_name=Node, log_flags=LogFlags, + print_init_and_done_for_testcases = PrintInitDone }}. %% @doc Called before init_per_suite is called. -pre_init_per_suite(Suite,Config,State) -> +pre_init_per_suite(_Suite, Config, State = #state{node_name = undefined}) -> + {Config, State}; +pre_init_per_suite(Suite, Config, State) -> maybe_print_log_on_mim_node(suite, starting, Suite, State), {Config, State#state{group=no_group, suite=Suite}}. %% @doc Called before end_per_suite. -post_end_per_suite(Suite,_Config,Return,State) -> +post_end_per_suite(_Suite, Config, Return, State = #state{node_name = undefined}) -> + {Config, State}; +post_end_per_suite(Suite, _Config, Return, State) -> maybe_print_log_on_mim_node(suite, finishing, Suite, State), {Return, State#state{suite=no_suite}}. %% @doc Called before each init_per_group. -pre_init_per_group(Group,Config,State) -> +pre_init_per_group(_Group, Config, State = #state{node_name = undefined}) -> + {Config, State}; +pre_init_per_group(Group, Config, State) -> maybe_print_log_on_mim_node(group, starting, Group, State), {Config, State#state{group=Group}}. %% @doc Called after each end_per_group. -post_end_per_group(Group,_Config,Return,State) -> +post_end_per_group(_Group, _Config, Return, State = #state{node_name = undefined}) -> + {Return, State}; +post_end_per_group(Group, _Config, Return, State) -> maybe_print_log_on_mim_node(group, finishing, Group, State), {Return, State#state{group=no_group}}. %% @doc Called before each test case. -pre_init_per_testcase(TC,Config,State=#state{}) -> +pre_init_per_testcase(_TC, Config, State = #state{node_name = undefined}) -> + {Config, State}; +pre_init_per_testcase(TC, Config, State=#state{}) -> maybe_print_log_on_mim_node(testcase, starting, TC, State), Dog = test_server:timetrap(test_server:seconds(10)), State3 = ensure_initialized(Config, State), @@ -80,7 +93,9 @@ pre_init_per_testcase(TC,Config,State=#state{}) -> {Config, State4}. %% @doc Called after each test case. -post_end_per_testcase(TC,_Config,Return,State) -> +post_end_per_testcase(_TC, _Config, Return, State = #state{node_name = undefined}) -> + {Return, State}; +post_end_per_testcase(TC, _Config, Return, State) -> Dog = test_server:timetrap(test_server:seconds(10)), State2 = post_insert_line_numbers_into_report(State, TC), test_server:timetrap_cancel(Dog), @@ -88,6 +103,8 @@ post_end_per_testcase(TC,_Config,Return,State) -> {Return, State2 }. %% @doc Called when the scope of the CTH is done +terminate(State = #state{node_name = undefined}) -> + State; terminate(State) -> insert_line_numbers_into_report(State). @@ -183,7 +200,7 @@ pre_insert_line_numbers_into_report(State=#state{node_name=Node, reader=Reader, Message = io_lib:format( "INIT suite=~p group=~p testcase=~p~n", [Suite, Group, TC]), - file:write(Writer, Message), + maybe_file_write(State, Writer, Message), State#state{current_line_num=CurrentLineNum2}. post_insert_line_numbers_into_report(State=#state{writer=undefined}, _TC) -> @@ -192,12 +209,17 @@ post_insert_line_numbers_into_report(State=#state{node_name=Node, reader=Reader, current_line_num=CurrentLineNum, url_file=UrlFile, group=Group, suite=Suite}, TC) -> CurrentLineNum2 = read_and_write_lines(Node, Reader, Writer, CurrentLineNum), - add_log_link_to_line(UrlFile, CurrentLineNum2, Node, " when finished"), + case CurrentLineNum of + CurrentLineNum2 -> + skip; %% Reduce noise in logs because nothing was logged + _ -> + add_log_link_to_line(UrlFile, CurrentLineNum2, Node, " when finished") + end, %% Write a message after the main part Message = io_lib:format( "DONE suite=~p group=~p testcase=~p~n", [Suite, Group, TC]), - file:write(Writer, Message), + maybe_file_write(State, Writer, Message), State#state{current_line_num=CurrentLineNum2}. insert_line_numbers_into_report(State=#state{node_name=Node, reader=Reader, writer=Writer, @@ -288,9 +310,13 @@ connect_mim_node(HookOpts) -> erlang:set_cookie(Node, Cookie), %% this log message lands at misc_io.log.html file ct:pal("connecting to the '~p' node (cookie: '~p')", [Node, Cookie]), - %% crash if cannot connect to the node - true = net_kernel:connect_node(Node), - Node. + case net_kernel:connect_node(Node) of + true -> + Node; + _ -> + %% Could happen if we test not with all nodes enabled. + undefined + end. maybe_print_log_on_mim_node(Type, Event, Name, #state{log_flags = LogFlags, node_name = Node}) -> ValidEvents = [starting, finishing], @@ -307,3 +333,8 @@ maybe_print_log_on_mim_node(Type, Event, Name, #state{log_flags = LogFlags, node _ -> ok end. + +maybe_file_write(State = #state{print_init_and_done_for_testcases = true}, Writer, Message) -> + file:write(Writer, Message); +maybe_file_write(_State, _Writer, _Message) -> + ok. diff --git a/big_tests/tests/mod_global_distrib_SUITE.erl b/big_tests/tests/mod_global_distrib_SUITE.erl index 4c9c6aefd50..7e5e8ec1a6b 100644 --- a/big_tests/tests/mod_global_distrib_SUITE.erl +++ b/big_tests/tests/mod_global_distrib_SUITE.erl @@ -1441,11 +1441,17 @@ print_sessions_debug_info(NodeName) -> %% ----------------------------------------------------------------------- %% Custom log levels for GD modules during the tests +%% Set it to true, if you need to debug GD on CI +detailed_logging() -> + false. + enable_logging() -> - mim_loglevel:enable_logging(test_hosts(), custom_loglevels()). + detailed_logging() andalso + mim_loglevel:enable_logging(test_hosts(), custom_loglevels()). disable_logging() -> - mim_loglevel:disable_logging(test_hosts(), custom_loglevels()). + detailed_logging() andalso + mim_loglevel:disable_logging(test_hosts(), custom_loglevels()). custom_loglevels() -> %% for "s2s connection to muc.localhost not found" debugging diff --git a/rel/files/app.config b/rel/files/app.config index fb91fcd3c1b..bcc98cd684f 100644 --- a/rel/files/app.config +++ b/rel/files/app.config @@ -42,7 +42,7 @@ file => "{{mongooseim_log_dir}}/mongooseim.log", type => wrap, max_no_files => 5, - max_no_bytes => 2097152, + max_no_bytes => 10485760, %% 10 Megabytes sync_mode_qlen => 2000, % If sync_mode_qlen is set to the same value as drop_mode_qlen, drop_mode_qlen => 2000, % synchronous mode is disabled. That is, the handler always runs flush_qlen => 5000, % in asynchronous mode, unless dropping or flushing is invoked. diff --git a/src/global_distrib/mod_global_distrib_connection.erl b/src/global_distrib/mod_global_distrib_connection.erl index ec7ad70f37b..1a8594d7cab 100644 --- a/src/global_distrib/mod_global_distrib_connection.erl +++ b/src/global_distrib/mod_global_distrib_connection.erl @@ -108,8 +108,14 @@ code_change(_OldVsn, State, _Extra) -> {ok, State}. terminate(Reason, State) -> - ?LOG_ERROR(#{what => gd_outgoing_socket_error, - reason => Reason, peer => State#state.peer, conn_id => State#state.conn_id}), + case Reason of + shutdown -> + ?LOG_INFO(#{what => gd_outgoing_socket_error, + reason => Reason, peer => State#state.peer, conn_id => State#state.conn_id}); + _ -> + ?LOG_ERROR(#{what => gd_outgoing_socket_error, + reason => Reason, peer => State#state.peer, conn_id => State#state.conn_id}) + end, mongoose_instrument:execute(?GLOBAL_DISTRIB_OUTGOING_CLOSED, #{}, #{count => 1, host => State#state.host}), catch mod_global_distrib_transport:close(State#state.socket), ignore. diff --git a/src/global_distrib/mod_global_distrib_receiver.erl b/src/global_distrib/mod_global_distrib_receiver.erl index 3cb4f89bfc5..00300d00e08 100644 --- a/src/global_distrib/mod_global_distrib_receiver.erl +++ b/src/global_distrib/mod_global_distrib_receiver.erl @@ -135,9 +135,16 @@ code_change(_Version, State, _Extra) -> {ok, State}. terminate(Reason, State) -> - ?LOG_WARNING(#{what => gd_incoming_socket_closed, - peer => State#state.peer, server => State#state.host, - reason => Reason, conn_id => State#state.conn_id}), + case Reason of + normal -> + ?LOG_INFO(#{what => gd_incoming_socket_closed, + peer => State#state.peer, server => State#state.host, + reason => Reason, conn_id => State#state.conn_id}); + _ -> + ?LOG_WARNING(#{what => gd_incoming_socket_closed, + peer => State#state.peer, server => State#state.host, + reason => Reason, conn_id => State#state.conn_id}) + end, mongoose_instrument:execute(?GLOBAL_DISTRIB_INCOMING_CLOSED, #{}, #{count => 1, host => State#state.host}), catch mod_global_distrib_transport:close(State#state.socket),