fix: replace ct:sleep/1 by filesync/2

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),
+                case file:write_file(ZipName, Bin) of
-                [Node ++ "-" ++ TraceLog | Acc];
+                    ok -> [Node ++ "-" ++ TraceLog | Acc];
+                    _ -> Acc
+                end;
             {error, Node, Reason} ->
                 ?LOG(error, "download trace log error:~p", [{Node, TraceLog, Reason}]),
                 Acc

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),

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.