diff --git a/apps/emqx_plugin_libs/src/emqx_trace/emqx_trace_api.erl b/apps/emqx_plugin_libs/src/emqx_trace/emqx_trace_api.erl index 7d982c00d..8e052ca66 100644 --- a/apps/emqx_plugin_libs/src/emqx_trace/emqx_trace_api.erl +++ b/apps/emqx_plugin_libs/src/emqx_trace/emqx_trace_api.erl @@ -107,8 +107,10 @@ group_trace_file(ZipDir, TraceLog, TraceFiles) -> case Res of {ok, Node, Bin} -> ZipName = ZipDir ++ Node ++ "-" ++ TraceLog, - ok = file:write_file(ZipName, Bin), - [Node ++ "-" ++ TraceLog | Acc]; + case file:write_file(ZipName, Bin) of + ok -> [Node ++ "-" ++ TraceLog | Acc]; + _ -> Acc + end; {error, Node, Reason} -> ?LOG(error, "download trace log error:~p", [{Node, TraceLog, Reason}]), Acc diff --git a/apps/emqx_plugin_libs/test/emqx_trace_SUITE.erl b/apps/emqx_plugin_libs/test/emqx_trace_SUITE.erl index c08211e02..94ab71270 100644 --- a/apps/emqx_plugin_libs/test/emqx_trace_SUITE.erl +++ b/apps/emqx_plugin_libs/test/emqx_trace_SUITE.erl @@ -229,21 +229,22 @@ t_client_event(_Config) -> Name = <<"test_client_id_event">>, ok = emqx_trace:create([{<<"name">>, Name}, {<<"type">>, <<"clientid">>}, {<<"clientid">>, ClientId}, {<<"start_at">>, Start}]), - ct:sleep(200), + ok = emqx_trace_handler_SUITE:filesync(Name, clientid), {ok, Client} = emqtt:start_link([{clean_start, true}, {clientid, ClientId}]), {ok, _} = emqtt:connect(Client), emqtt:ping(Client), ok = emqtt:publish(Client, <<"/test">>, #{}, <<"1">>, [{qos, 0}]), ok = emqtt:publish(Client, <<"/test">>, #{}, <<"2">>, [{qos, 0}]), - ct:sleep(200), + ok = emqx_trace_handler_SUITE:filesync(Name, clientid), ok = emqx_trace:create([{<<"name">>, <<"test_topic">>}, {<<"type">>, <<"topic">>}, {<<"topic">>, <<"/test">>}, {<<"start_at">>, Start}]), - ct:sleep(200), + ok = emqx_trace_handler_SUITE:filesync(<<"test_topic">>, topic), {ok, Bin} = file:read_file(emqx_trace:log_file(Name, Now)), ok = emqtt:publish(Client, <<"/test">>, #{}, <<"3">>, [{qos, 0}]), ok = emqtt:publish(Client, <<"/test">>, #{}, <<"4">>, [{qos, 0}]), ok = emqtt:disconnect(Client), - ct:sleep(200), + ok = emqx_trace_handler_SUITE:filesync(Name, clientid), + ok = emqx_trace_handler_SUITE:filesync(<<"test_topic">>, topic), {ok, Bin2} = file:read_file(emqx_trace:log_file(Name, Now)), {ok, Bin3} = file:read_file(emqx_trace:log_file(<<"test_topic">>, Now)), ct:pal("Bin ~p Bin2 ~p Bin3 ~p", [byte_size(Bin), byte_size(Bin2), byte_size(Bin3)]), @@ -293,7 +294,7 @@ t_download_log(_Config) -> {ok, Client} = emqtt:start_link([{clean_start, true}, {clientid, ClientId}]), {ok, _} = emqtt:connect(Client), [begin _ = emqtt:ping(Client) end ||_ <- lists:seq(1, 5)], - ct:sleep(100), + ok = emqx_trace_handler_SUITE:filesync(Name, clientid), {ok, ZipFile} = emqx_trace_api:download_zip_log(#{name => Name}, []), ?assert(filelib:file_size(ZipFile) > 0), ok = emqtt:disconnect(Client), diff --git a/test/emqx_trace_handler_SUITE.erl b/test/emqx_trace_handler_SUITE.erl index e314c7994..b42b1a591 100644 --- a/test/emqx_trace_handler_SUITE.erl +++ b/test/emqx_trace_handler_SUITE.erl @@ -62,7 +62,9 @@ t_trace_clientid(_Config) -> emqx_trace_handler:install(clientid, <<"client4">>, bad_level, "tmp/client4.log"), {error, {handler_not_added, {file_error, ".", eisdir}}} = emqx_trace_handler:install(clientid, <<"client5">>, debug, "."), - ct:sleep(100), + ok = filesync(<<"client">>, clientid), + ok = filesync(<<"client2">>, clientid), + ok = filesync(<<"client3">>, clientid), %% Verify the tracing file exits ?assert(filelib:is_regular("tmp/client.log")), @@ -83,7 +85,9 @@ t_trace_clientid(_Config) -> emqtt:connect(T), emqtt:publish(T, <<"a/b/c">>, <<"hi">>), emqtt:ping(T), - ct:sleep(200), + ok = filesync(<<"client">>, clientid), + ok = filesync(<<"client2">>, clientid), + ok = filesync(<<"client3">>, clientid), %% Verify messages are logged to "tmp/client.log" but not "tmp/client2.log". {ok, Bin} = file:read_file("tmp/client.log"), @@ -109,7 +113,8 @@ t_trace_topic(_Config) -> emqx_logger:set_log_level(debug), ok = emqx_trace_handler:install(topic, <<"x/#">>, all, "tmp/topic_trace_x.log"), ok = emqx_trace_handler:install(topic, <<"y/#">>, all, "tmp/topic_trace_y.log"), - ct:sleep(100), + ok = filesync(<<"x/#">>, topic), + ok = filesync(<<"y/#">>, topic), %% Verify the tracing file exits ?assert(filelib:is_regular("tmp/topic_trace_x.log")), @@ -128,7 +133,8 @@ t_trace_topic(_Config) -> emqtt:publish(T, <<"x/y/z">>, <<"hi2">>), emqtt:subscribe(T, <<"x/y/z">>), emqtt:unsubscribe(T, <<"x/y/z">>), - ct:sleep(200), + ok = filesync(<<"x/#">>, topic), + ok = filesync(<<"y/#">>, topic), {ok, Bin} = file:read_file("tmp/topic_trace_x.log"), ?assertNotEqual(nomatch, binary:match(Bin, [<<"hi1">>])), @@ -152,7 +158,8 @@ t_trace_ip_address(_Config) -> %% Start tracing ok = emqx_trace_handler:install(ip_address, "127.0.0.1", all, "tmp/ip_trace_x.log"), ok = emqx_trace_handler:install(ip_address, "192.168.1.1", all, "tmp/ip_trace_y.log"), - ct:sleep(100), + ok = filesync(<<"127.0.0.1">>, ip_address), + ok = filesync(<<"192.168.1.1">>, ip_address), %% Verify the tracing file exits ?assert(filelib:is_regular("tmp/ip_trace_x.log")), @@ -173,7 +180,8 @@ t_trace_ip_address(_Config) -> emqtt:publish(T, <<"x/y/z">>, <<"hi2">>), emqtt:subscribe(T, <<"x/y/z">>), emqtt:unsubscribe(T, <<"x/y/z">>), - ct:sleep(200), + ok = filesync(<<"127.0.0.1">>, ip_address), + ok = filesync(<<"192.168.1.1">>, ip_address), {ok, Bin} = file:read_file("tmp/ip_trace_x.log"), ?assertNotEqual(nomatch, binary:match(Bin, [<<"hi1">>])), @@ -189,3 +197,20 @@ t_trace_ip_address(_Config) -> {error, _Reason} = emqx_trace_handler:uninstall(ip_address, <<"127.0.0.2">>), emqtt:disconnect(T), ?assertEqual([], emqx_trace_handler:running()). + + +filesync(Name, Type) -> + filesync(Name, Type, 3). + +%% sometime the handler process is not started yet. +filesync(_Name, _Type, 0) -> ok; +filesync(Name, Type, Retry) -> + try + Handler = binary_to_atom(<<"trace_", + (atom_to_binary(Type))/binary, "_", Name/binary>>), + ok = logger_disk_log_h:filesync(Handler) + catch E:R -> + ct:pal("Filesync error:~p ~p~n", [{Name, Type, Retry}, {E, R}]), + ct:sleep(100), + filesync(Name, Type, Retry - 1) + end.