Merge pull request #11506 from SergeTupchiy/EMQX-10274-do-not-download-empty-trace-log

fix(emqx_trace): don't download empty trace log file

apps/emqx/src/emqx_trace/emqx_trace.erl

@@ -160,7 +160,7 @@ create(Trace) ->
             end;
         false ->
             {error,
-                "The number of traces created has reache the maximum"
+                "The number of traces created has reached the maximum"
                 " please delete the useless ones first"}
     end.
 
@@ -371,10 +371,16 @@ start_trace(Trace) ->
 
 stop_trace(Finished, Started) ->
     lists:foreach(
-        fun(#{name := Name, type := Type, filter := Filter}) ->
+        fun(#{name := Name, id := HandlerID, dst := FilePath, type := Type, filter := Filter}) ->
             case lists:member(Name, Finished) of
                 true ->
-                    ?TRACE("API", "trace_stopping", #{Type => Filter}),
+                    _ = maybe_sync_logfile(HandlerID),
+                    case file:read_file_info(FilePath) of
+                        {ok, #file_info{size = Size}} when Size > 0 ->
+                            ?TRACE("API", "trace_stopping", #{Type => Filter});
+                        _ ->
+                            ok
+                    end,
                     emqx_trace_handler:uninstall(Type, Name);
                 false ->
                     ok
@@ -383,6 +389,19 @@ stop_trace(Finished, Started) ->
         Started
     ).
 
+maybe_sync_logfile(HandlerID) ->
+    case logger:get_handler_config(HandlerID) of
+        {ok, #{module := Mod}} ->
+            case erlang:function_exported(Mod, filesync, 1) of
+                true ->
+                    Mod:filesync(HandlerID);
+                false ->
+                    ok
+            end;
+        _ ->
+            ok
+    end.
+
 clean_stale_trace_files() ->
     TraceDir = trace_dir(),
     case file:list_dir(TraceDir) of

apps/emqx/test/emqx_trace_SUITE.erl

@@ -24,6 +24,7 @@
 -include_lib("emqx/include/emqx.hrl").
 -include_lib("emqx/include/emqx_trace.hrl").
 -include_lib("snabbkaffe/include/snabbkaffe.hrl").
+-include_lib("kernel/include/file.hrl").
 
 %%--------------------------------------------------------------------
 %% Setups
@@ -52,6 +53,7 @@ init_per_testcase(_, Config) ->
     Config.
 
 end_per_testcase(_) ->
+    snabbkaffe:stop(),
     ok.
 
 t_base_create_delete(_Config) ->
@@ -454,6 +456,36 @@ t_migrate_trace(_Config) ->
     ),
     ok.
 
+%% If no relevant event occurred, the log file size must be exactly 0 after stopping the trace.
+t_empty_trace_log_file(_Config) ->
+    ?check_trace(
+        begin
+            Now = erlang:system_time(second),
+            Name = <<"empty_trace_log">>,
+            Trace = [
+                {<<"name">>, Name},
+                {<<"type">>, clientid},
+                {<<"clientid">>, <<"test_trace_no_clientid_1">>},
+                {<<"start_at">>, Now},
+                {<<"end_at">>, Now + 100}
+            ],
+            ?wait_async_action(
+                ?assertMatch({ok, _}, emqx_trace:create(Trace)),
+                #{?snk_kind := update_trace_done}
+            ),
+            ok = emqx_trace_handler_SUITE:filesync(Name, clientid),
+            {ok, Filename} = emqx_trace:get_trace_filename(Name),
+            ?assertMatch({ok, #{size := 0}}, emqx_trace:trace_file_detail(Filename)),
+            ?wait_async_action(
+                ?assertEqual(ok, emqx_trace:update(Name, false)),
+                #{?snk_kind := update_trace_done}
+            ),
+            ?assertMatch({ok, #{size := 0}}, emqx_trace:trace_file_detail(Filename)),
+            ?assertEqual(ok, emqx_trace:delete(Name))
+        end,
+        []
+    ).
+
 build_new_trace_data() ->
     Now = erlang:system_time(second),
     {ok, _} = emqx_trace:create([

apps/emqx_management/src/emqx_mgmt_api_trace.erl

@@ -22,6 +22,7 @@
 -include_lib("emqx/include/logger.hrl").
 -include_lib("snabbkaffe/include/snabbkaffe.hrl").
 -include_lib("hocon/include/hoconsc.hrl").
+-include_lib("emqx_utils/include/emqx_utils_api.hrl").
 
 -export([
     api_spec/0,
@@ -51,8 +52,7 @@
 -define(MAX_SINT32, 2147483647).
 
 -define(TO_BIN(_B_), iolist_to_binary(_B_)).
--define(NOT_FOUND(N), {404, #{code => 'NOT_FOUND', message => ?TO_BIN([N, " NOT FOUND"])}}).
+-define(NOT_FOUND_WITH_MSG(N), ?NOT_FOUND(?TO_BIN([N, " NOT FOUND"]))).
--define(SERVICE_UNAVAILABLE(C, M), {503, #{code => C, message => ?TO_BIN(M)}}).
 -define(TAGS, [<<"Trace">>]).
 
 namespace() -> "trace".
@@ -476,13 +476,13 @@ format_trace(Trace0) ->
 delete_trace(delete, #{bindings := #{name := Name}}) ->
     case emqx_trace:delete(Name) of
         ok -> {204};
-        {error, not_found} -> ?NOT_FOUND(Name)
+        {error, not_found} -> ?NOT_FOUND_WITH_MSG(Name)
     end.
 
 update_trace(put, #{bindings := #{name := Name}}) ->
     case emqx_trace:update(Name, false) of
         ok -> {200, #{enable => false, name => Name}};
-        {error, not_found} -> ?NOT_FOUND(Name)
+        {error, not_found} -> ?NOT_FOUND_WITH_MSG(Name)
     end.
 
 %% if HTTP request headers include accept-encoding: gzip and file size > 300 bytes.
@@ -493,64 +493,85 @@ download_trace_log(get, #{bindings := #{name := Name}, query_string := Query}) -
             case parse_node(Query, undefined) of
                 {ok, Node} ->
                     TraceFiles = collect_trace_file(Node, TraceLog),
-                    %% We generate a session ID so that we name files
+                    maybe_download_trace_log(Name, TraceLog, TraceFiles);
-                    %% with unique names. Then we won't cause
-                    %% overwrites for concurrent requests.
-                    SessionId = emqx_utils:gen_id(),
-                    ZipDir = filename:join([emqx_trace:zip_dir(), SessionId]),
-                    ok = file:make_dir(ZipDir),
-                    %% Write files to ZipDir and create an in-memory zip file
-                    Zips = group_trace_file(ZipDir, TraceLog, TraceFiles),
-                    ZipName = binary_to_list(Name) ++ ".zip",
-                    Binary =
-                        try
-                            {ok, {ZipName, Bin}} = zip:zip(ZipName, Zips, [memory, {cwd, ZipDir}]),
-                            Bin
-                        after
-                            %% emqx_trace:delete_files_after_send(ZipFileName, Zips),
-                            %% TODO use file replace file_binary.(delete file after send is not ready now).
-                            ok = file:del_dir_r(ZipDir)
-                        end,
-                    ?tp(trace_api_download_trace_log, #{
-                        files => Zips,
-                        name => Name,
-                        session_id => SessionId,
-                        zip_dir => ZipDir,
-                        zip_name => ZipName
-                    }),
-                    Headers = #{
-                        <<"content-type">> => <<"application/x-zip">>,
-                        <<"content-disposition">> => iolist_to_binary(
-                            "attachment; filename=" ++ ZipName
-                        )
-                    },
-                    {200, Headers, {file_binary, ZipName, Binary}};
                 {error, not_found} ->
-                    ?NOT_FOUND(<<"Node">>)
+                    ?NOT_FOUND_WITH_MSG(<<"Node">>)
             end;
         {error, not_found} ->
-            ?NOT_FOUND(Name)
+            ?NOT_FOUND_WITH_MSG(Name)
     end.
 
+maybe_download_trace_log(Name, TraceLog, TraceFiles) ->
+    case group_trace_files(TraceLog, TraceFiles) of
+        #{nonempty := Files} ->
+            do_download_trace_log(Name, TraceLog, Files);
+        #{error := Reasons} ->
+            ?INTERNAL_ERROR(Reasons);
+        #{empty := _} ->
+            ?NOT_FOUND(<<"Trace is empty">>)
+    end.
+
+do_download_trace_log(Name, TraceLog, TraceFiles) ->
+    %% We generate a session ID so that we name files
+    %% with unique names. Then we won't cause
+    %% overwrites for concurrent requests.
+    SessionId = emqx_utils:gen_id(),
+    ZipDir = filename:join([emqx_trace:zip_dir(), SessionId]),
+    ok = file:make_dir(ZipDir),
+    %% Write files to ZipDir and create an in-memory zip file
+    Zips = group_trace_file(ZipDir, TraceLog, TraceFiles),
+    ZipName = binary_to_list(Name) ++ ".zip",
+    Binary =
+        try
+            {ok, {ZipName, Bin}} = zip:zip(ZipName, Zips, [memory, {cwd, ZipDir}]),
+            Bin
+        after
+            %% emqx_trace:delete_files_after_send(ZipFileName, Zips),
+            %% TODO use file replace file_binary.(delete file after send is not ready now).
+            ok = file:del_dir_r(ZipDir)
+        end,
+    ?tp(trace_api_download_trace_log, #{
+        files => Zips,
+        name => Name,
+        session_id => SessionId,
+        zip_dir => ZipDir,
+        zip_name => ZipName
+    }),
+    Headers = #{
+        <<"content-type">> => <<"application/x-zip">>,
+        <<"content-disposition">> => iolist_to_binary(
+            "attachment; filename=" ++ ZipName
+        )
+    },
+    {200, Headers, {file_binary, ZipName, Binary}}.
+
+group_trace_files(TraceLog, TraceFiles) ->
+    maps:groups_from_list(
+        fun
+            ({ok, _Node, <<>>}) ->
+                empty;
+            ({ok, _Node, _Bin}) ->
+                nonempty;
+            ({error, Node, Reason}) ->
+                ?SLOG(error, #{
+                    msg => "download_trace_log_error",
+                    node => Node,
+                    log => TraceLog,
+                    reason => Reason
+                }),
+                error
+        end,
+        TraceFiles
+    ).
+
 group_trace_file(ZipDir, TraceLog, TraceFiles) ->
     lists:foldl(
-        fun(Res, Acc) ->
+        fun({ok, Node, Bin}, Acc) ->
-            case Res of
+            FileName = Node ++ "-" ++ TraceLog,
-                {ok, Node, Bin} ->
+            ZipName = filename:join([ZipDir, FileName]),
-                    FileName = Node ++ "-" ++ TraceLog,
+            case file:write_file(ZipName, Bin) of
-                    ZipName = filename:join([ZipDir, FileName]),
+                ok -> [FileName | Acc];
-                    case file:write_file(ZipName, Bin) of
+                _ -> Acc
-                        ok -> [FileName | Acc];
-                        _ -> Acc
-                    end;
-                {error, Node, Reason} ->
-                    ?SLOG(error, #{
-                        msg => "download_trace_log_error",
-                        node => Node,
-                        log => TraceLog,
-                        reason => Reason
-                    }),
-                    Acc
             end
         end,
         [],
@@ -578,7 +599,7 @@ log_file_detail(get, #{bindings := #{name := Name}}) ->
             TraceFiles = collect_trace_file_detail(TraceLog),
             {200, group_trace_file_detail(TraceFiles)};
         {error, not_found} ->
-            ?NOT_FOUND(Name)
+            ?NOT_FOUND_WITH_MSG(Name)
     end.
 
 group_trace_file_detail(TraceLogDetail) ->
@@ -609,7 +630,7 @@ stream_log_file(get, #{bindings := #{name := Name}, query_string := Query}) ->
                     Meta = #{<<"position">> => Position, <<"bytes">> => Bytes},
                     {200, #{meta => Meta, items => <<"">>}};
                 {error, not_found} ->
-                    ?NOT_FOUND(Name);
+                    ?NOT_FOUND_WITH_MSG(Name);
                 {error, enomem} ->
                     ?SLOG(warning, #{
                         code => not_enough_mem,
@@ -617,12 +638,12 @@ stream_log_file(get, #{bindings := #{name := Name}, query_string := Query}) ->
                         bytes => Bytes,
                         name => Name
                     }),
-                    ?SERVICE_UNAVAILABLE('SERVICE_UNAVAILABLE', <<"Requested chunk size too big">>);
+                    ?SERVICE_UNAVAILABLE(<<"Requested chunk size too big">>);
                 {badrpc, nodedown} ->
-                    ?NOT_FOUND(<<"Node">>)
+                    ?NOT_FOUND_WITH_MSG(<<"Node">>)
             end;
         {error, not_found} ->
-            ?NOT_FOUND(<<"Node">>)
+            ?NOT_FOUND_WITH_MSG(<<"Node">>)
     end.
 
 -spec get_trace_size() -> #{{node(), file:name_all()} => non_neg_integer()}.

apps/emqx_management/test/emqx_mgmt_api_trace_SUITE.erl

@@ -369,6 +369,28 @@ t_trace_files_are_deleted_after_download(_Config) ->
     ),
     ok.
 
+t_download_empty_trace(_Config) ->
+    ClientId = <<"client-test-empty-trace-download">>,
+    Now = erlang:system_time(second),
+    Name = <<"test_client_id_empty_trace">>,
+    load(),
+    create_trace(Name, ClientId, Now),
+    ok = emqx_trace_handler_SUITE:filesync(Name, clientid),
+    ?check_trace(
+        begin
+            ?wait_async_action(
+                ?assertMatch(
+                    {ok, _}, request_api(put, api_path(<<"trace/", Name/binary, "/stop">>), #{})
+                ),
+                #{?snk_kind := update_trace_done}
+            )
+        end,
+        []
+    ),
+    {error, {{_, 404, _}, _Headers, Body}} =
+        request_api(get, api_path(<<"trace/", Name/binary, "/download">>), [], #{return_all => true}),
+    ?assertMatch(#{<<"message">> := <<"Trace is empty">>}, emqx_utils_json:decode(Body)).
+
 to_rfc3339(Second) ->
     list_to_binary(calendar:system_time_to_rfc3339(Second)).
 
@@ -376,8 +398,11 @@ request_api(Method, Url) ->
     request_api(Method, Url, []).
 
 request_api(Method, Url, Body) ->
-    Opts = #{httpc_req_opts => [{body_format, binary}]},
+    request_api(Method, Url, Body, #{}).
-    emqx_mgmt_api_test_util:request_api(Method, Url, [], [], Body, Opts).
+
+request_api(Method, Url, Body, Opts) ->
+    Opts1 = Opts#{httpc_req_opts => [{body_format, binary}]},
+    emqx_mgmt_api_test_util:request_api(Method, Url, [], [], Body, Opts1).
 
 api_path(Path) ->
     emqx_mgmt_api_test_util:api_path([Path]).

changes/ce/fix-11506.en.md

@@ -0,0 +1,4 @@
+Don't download a trace log file if it is empty.
+
+After this fix, GET `/api/v5/trace/clientempty/download` returns 404 `{"code":"NOT_FOUND","message":"Trace is empty"}`
+If no events matching the trace condition occurred.