Add report logging (#4483)

Add new report logging mechanism to log a map of key/value pairs
---------

Co-authored-by: ILYA Khlopotov <iilyak@apache.org>

19 files changed, 251 insertions, 29 deletions

diff --git a/src/couch_log/include/couch_log.hrl b/src/couch_log/include/couch_log.hrl
index fa544a88b..eabc9a7e3 100644
--- a/src/couch_log/include/couch_log.hrl
+++ b/src/couch_log/include/couch_log.hrl
@@ -15,7 +15,8 @@
     pid,
     msg,
     msg_id,
-    time_stamp
+    time_stamp,
+    type
 }).
 
 
diff --git a/src/couch_log/priv/stats_descriptions.cfg b/src/couch_log/priv/stats_descriptions.cfg
index 31e41614b..c1cea1628 100644
--- a/src/couch_log/priv/stats_descriptions.cfg
+++ b/src/couch_log/priv/stats_descriptions.cfg
@@ -46,3 +46,11 @@
     {type, counter},
     {desc, <<"number of logged warning messages">>}
 ]}.
+{[couch_log, level, report], [
+    {type, counter},
+    {desc, <<"number of logged report messages">>}
+]}.
+{[couch_log, level, report_error], [
+    {type, counter},
+    {desc, <<"number of failed report messages">>}
+]}.
diff --git a/src/couch_log/src/couch_log.erl b/src/couch_log/src/couch_log.erl
index b8a1ca4bd..595143962 100644
--- a/src/couch_log/src/couch_log.erl
+++ b/src/couch_log/src/couch_log.erl
@@ -21,7 +21,7 @@
     critical/2,
     alert/2,
     emergency/2,
-
+    report/2,
     set_level/1
 ]).
 
@@ -49,6 +49,18 @@ alert(Fmt, Args) -> log(alert, Fmt, Args).
 -spec emergency(string(), list()) -> ok.
 emergency(Fmt, Args) -> log(emergency, Fmt, Args).
 
+-spec report(string(), map()) -> true | false.
+report(ReportId, Meta) when is_map(Meta) ->
+    couch_stats:increment_counter([couch_log, level, report]),
+    case couch_log_formatter:format_report(self(), ReportId, Meta) of
+        {error, emsgtoolong} ->
+            couch_stats:increment_counter([couch_log, level, report_error]),
+            false;
+        {ok, Entry} ->
+            ok = couch_log_server:log(Entry),
+            true
+    end.
+
 -spec set_level(atom() | string() | integer()) -> true.
 set_level(Level) ->
     config:set("log", "level", couch_log_util:level_to_string(Level)).
diff --git a/src/couch_log/src/couch_log_config.erl b/src/couch_log/src/couch_log_config.erl
index 925973178..c3fd8fe85 100644
--- a/src/couch_log/src/couch_log_config.erl
+++ b/src/couch_log/src/couch_log_config.erl
@@ -43,6 +43,7 @@ entries() ->
     [
         {level, "level", "info"},
         {level_int, "level", "info"},
+        {report_level, "report_level", "info"},
         {max_message_size, "max_message_size", "16000"},
         {strip_last_msg, "strip_last_msg", "true"},
         {filter_fields, "filter_fields", "[pid, registered_name, error_info, messages]"}
@@ -87,6 +88,8 @@ forms() ->
 
 transform(level, LevelStr) ->
     couch_log_util:level_to_atom(LevelStr);
+transform(report_level, LevelStr) ->
+    couch_log_util:level_to_atom(LevelStr);
 transform(level_int, LevelStr) ->
     Level = couch_log_util:level_to_atom(LevelStr),
     couch_log_util:level_to_integer(Level);
diff --git a/src/couch_log/src/couch_log_config_dyn.erl b/src/couch_log/src/couch_log_config_dyn.erl
index ff781d3a0..1b1b3bd8e 100644
--- a/src/couch_log/src/couch_log_config_dyn.erl
+++ b/src/couch_log/src/couch_log_config_dyn.erl
@@ -22,6 +22,7 @@
 ]).
 
 get(level) -> info;
+get(report_level) -> info;
 get(level_int) -> 2;
 get(max_message_size) -> 16000;
 get(strip_last_msg) -> true;
diff --git a/src/couch_log/src/couch_log_formatter.erl b/src/couch_log/src/couch_log_formatter.erl
index 2ce0fba6d..91b64ad7d 100644
--- a/src/couch_log/src/couch_log_formatter.erl
+++ b/src/couch_log/src/couch_log_formatter.erl
@@ -21,6 +21,8 @@
     format/3,
     format/1,
 
+    format_report/3,
+
     format_reason/1,
     format_mfa/1,
     format_trace/1,
@@ -31,6 +33,30 @@
 
 -define(DEFAULT_TRUNCATION, 1024).
 
+-define(REPORT_LEVEL, report).
+
+format_report(Pid, Type, Meta) ->
+    MaxMsgSize = couch_log_config:get(max_message_size),
+    Msg =
+        case format_meta(Meta) of
+            "" -> "";
+            Msg0 -> ["[", Msg0, "]"]
+        end,
+    case iolist_size(Msg) > MaxMsgSize of
+        true ->
+            {error, emsgtoolong};
+        false ->
+            Entry = #log_entry{
+                level = couch_log_util:level_to_atom(?REPORT_LEVEL),
+                pid = Pid,
+                msg = Msg,
+                msg_id = couch_log_util:get_msg_id(),
+                time_stamp = couch_log_util:iso8601_timestamp(),
+                type = Type
+            },
+            {ok, Entry}
+    end.
+
 format(Level, Pid, Fmt, Args) ->
     #log_entry{
         level = couch_log_util:level_to_atom(Level),
@@ -436,3 +462,40 @@ get_value(Key, List, Default) ->
 
 supervisor_name({local, Name}) -> Name;
 supervisor_name(Name) -> Name.
+
+format_meta(Meta) ->
+    %% https://www.rfc-editor.org/rfc/rfc5424.html#section-6.3
+    %% iut="3" eventSource="Application" eventID="1011"
+    string:join(
+        maps:fold(
+            fun(K, V, Acc) ->
+                [to_str(K, V) | Acc]
+            end,
+            [],
+            Meta
+        ),
+        " "
+    ).
+
+%% passing complex terms as meta value is a mistake so we are going
+%% to eat it, because we cannot bubble up errors from logger
+%% Therefore following are not supported
+%% - lists
+%% - tuples
+%% - maps
+%% However we are not going to try to distinguish lists from string
+%% Atoms would be printed as strings
+to_str(K, _) when not (is_list(K) or is_atom(K)) ->
+    "";
+to_str(K, Term) when is_list(Term) ->
+    io_lib:format("~s=\"~s\"", [K, Term]);
+to_str(_K, Term) when is_tuple(Term) ->
+    "";
+to_str(_K, Term) when is_map(Term) ->
+    "";
+to_str(K, Term) when is_number(Term) ->
+    io_lib:format("~s=~p", [K, Term]);
+to_str(K, Term) when is_binary(Term) ->
+    io_lib:format("~s=\"~s\"", [K, Term]);
+to_str(K, Term) ->
+    io_lib:format("~s=\"~p\"", [K, Term]).
diff --git a/src/couch_log/src/couch_log_sup.erl b/src/couch_log/src/couch_log_sup.erl
index 0167192d8..a7c581ebd 100644
--- a/src/couch_log/src/couch_log_sup.erl
+++ b/src/couch_log/src/couch_log_sup.erl
@@ -59,6 +59,8 @@ handle_config_change("log", Key, _, _, S) ->
     case Key of
         "level" ->
             couch_log_config:reconfigure();
+        "report_level" ->
+            couch_log_config:reconfigure();
         "max_message_size" ->
             couch_log_config:reconfigure();
         "strip_last_msg" ->
diff --git a/src/couch_log/src/couch_log_util.erl b/src/couch_log/src/couch_log_util.erl
index 8be11e12d..68aaa85ce 100644
--- a/src/couch_log/src/couch_log_util.erl
+++ b/src/couch_log/src/couch_log_util.erl
@@ -21,7 +21,9 @@
     level_to_atom/1,
     level_to_string/1,
 
-    string_p/1
+    string_p/1,
+
+    maybe_format_type/1
 ]).
 
 -include("couch_log.hrl").
@@ -29,6 +31,8 @@
 -spec should_log(#log_entry{} | atom()) -> boolean().
 should_log(#log_entry{level = Level}) ->
     should_log(Level);
+should_log(report) ->
+    should_log(couch_log_config:get(report_level));
 should_log(Level) ->
     level_to_integer(Level) >= couch_log_config:get(level_int).
 
@@ -145,3 +149,10 @@ string_p1([]) ->
     true;
 string_p1(_) ->
     false.
+
+maybe_format_type(#log_entry{type = undefined} = Entry) ->
+    Entry;
+maybe_format_type(#log_entry{type = Type, msg = ["[" | Msg]} = Entry) ->
+    Entry#log_entry{msg = ["[", Type, " " | Msg]};
+maybe_format_type(#log_entry{} = Entry) ->
+    Entry.
diff --git a/src/couch_log/src/couch_log_writer_file.erl b/src/couch_log/src/couch_log_writer_file.erl
index 7341f08dc..68250d8ee 100644
--- a/src/couch_log/src/couch_log_writer_file.erl
+++ b/src/couch_log/src/couch_log_writer_file.erl
@@ -77,7 +77,7 @@ write(Entry, St) ->
         msg = Msg,
         msg_id = MsgId,
         time_stamp = TimeStamp
-    } = Entry,
+    } = couch_log_util:maybe_format_type(Entry),
     Fmt = "[~s] ~s ~s ~p ~s ",
     Args = [
         couch_log_util:level_to_string(Level),
diff --git a/src/couch_log/src/couch_log_writer_stderr.erl b/src/couch_log/src/couch_log_writer_stderr.erl
index 01e350971..5c2c761fa 100644
--- a/src/couch_log/src/couch_log_writer_stderr.erl
+++ b/src/couch_log/src/couch_log_writer_stderr.erl
@@ -27,14 +27,14 @@ init() ->
 terminate(_, _St) ->
     ok.
 
-write(Entry, St) ->
+write(#log_entry{type = Type} = Entry, St) ->
     #log_entry{
         level = Level,
         pid = Pid,
         msg = Msg,
         msg_id = MsgId,
         time_stamp = TimeStamp
-    } = Entry,
+    } = couch_log_util:maybe_format_type(Entry),
     Fmt = "[~s] ~s ~s ~p ~s ",
     Args = [
         couch_log_util:level_to_string(Level),
diff --git a/src/couch_log/src/couch_log_writer_syslog.erl b/src/couch_log/src/couch_log_writer_syslog.erl
index b95cf018c..76357bf3e 100644
--- a/src/couch_log/src/couch_log_writer_syslog.erl
+++ b/src/couch_log/src/couch_log_writer_syslog.erl
@@ -28,7 +28,9 @@
     hostname,
     os_pid,
     appid,
-    facility
+    facility,
+    report_level,
+    enterprise_number
 }).
 
 -define(SYSLOG_VERSION, 1).
@@ -55,7 +57,7 @@ init() ->
                         undefined
                 end
         end,
-
+    Level = list_to_atom(config:get("log", "report_level", "info")),
     {ok, #st{
         socket = Socket,
         host = Host,
@@ -63,20 +65,36 @@ init() ->
         hostname = net_adm:localhost(),
         os_pid = os:getpid(),
         appid = config:get("log", "syslog_appid", "couchdb"),
-        facility = get_facility(config:get("log", "syslog_facility", "local2"))
+        facility = get_facility(config:get("log", "syslog_facility", "local2")),
+        report_level = Level,
+        enterprise_number = config:get("log", "syslog_enterprise_number")
     }}.
 
 terminate(_Reason, St) ->
     gen_udp:close(St#st.socket).
 
-write(Entry, St) ->
+write(#log_entry{level = report} = Entry, #st{enterprise_number = undefined} = St) ->
+    do_write(Entry#log_entry{level = St#st.report_level}, St);
+write(#log_entry{level = report, type = Type} = Entry0, #st{report_level = Level} = St) ->
+    % append @${enterprise_number} to the type to conform with
+    % https://www.rfc-editor.org/rfc/rfc5424.html#page-15
+    TypeSDID = lists:flatten(io_lib:format("~s-DB@~s", [Type, St#st.enterprise_number])),
+    Entry = Entry0#log_entry{
+        type = TypeSDID,
+        level = Level
+    },
+    do_write(Entry, St);
+write(#log_entry{} = Entry, #st{} = St) ->
+    do_write(Entry, St).
+
+do_write(Entry, St) ->
     #log_entry{
         level = Level,
         pid = Pid,
         msg = Msg,
         msg_id = MsgId,
         time_stamp = TimeStamp
-    } = Entry,
+    } = couch_log_util:maybe_format_type(Entry),
     Fmt = "<~B>~B ~s ~s ~s ~p ~s - ",
     Args = [
         St#st.facility bor get_level(Level),
diff --git a/src/couch_log/test/eunit/couch_log_config_test.erl b/src/couch_log/test/eunit/couch_log_config_test.erl
index df7cdf977..3cf56b003 100644
--- a/src/couch_log/test/eunit/couch_log_config_test.erl
+++ b/src/couch_log/test/eunit/couch_log_config_test.erl
@@ -20,6 +20,7 @@
 couch_log_config_test_() ->
     {setup, fun couch_log_test_util:start/0, fun couch_log_test_util:stop/1, [
         ?T(check_level),
+        ?T(check_report_level),
         ?T(check_max_message_size),
         ?T(check_bad_level),
         ?T(check_bad_max_message_size),
@@ -29,6 +30,23 @@ couch_log_config_test_() ->
         ?T(check_bad_filter_fields)
     ]}.
 
+check_report_level() ->
+    % Default report_level is info
+    ?assertEqual(info, couch_log_config:get(report_level)),
+    couch_log_test_util:with_config_listener(fun() ->
+        config:set("log", "report_level", "emerg"),
+        couch_log_test_util:wait_for_config(),
+        ?assertEqual(emergency, couch_log_config:get(report_level)),
+
+        config:set("log", "report_level", "debug"),
+        couch_log_test_util:wait_for_config(),
+        ?assertEqual(debug, couch_log_config:get(report_level)),
+
+        config:delete("log", "report_level"),
+        couch_log_test_util:wait_for_config(),
+        ?assertEqual(info, couch_log_config:get(report_level))
+    end).
+
 check_level() ->
     % Default level is info
     ?assertEqual(info, couch_log_config:get(level)),
diff --git a/src/couch_log/test/eunit/couch_log_formatter_test.erl b/src/couch_log/test/eunit/couch_log_formatter_test.erl
index a4de74990..29d5497f6 100644
--- a/src/couch_log/test/eunit/couch_log_formatter_test.erl
+++ b/src/couch_log/test/eunit/couch_log_formatter_test.erl
@@ -25,6 +25,24 @@ truncate_test() ->
     Entry = couch_log_formatter:format(info, self(), Msg),
     ?assert(length(Entry#log_entry.msg) =< 16000).
 
+format_report_etoolong_test() ->
+    Payload = lists:flatten(lists:duplicate(1048576, "a")),
+    Resp = couch_log_formatter:format_report(self(), report123, #{
+        msg => Payload
+    }),
+    ?assertEqual({error, emsgtoolong}, Resp).
+
+format_report_test() ->
+    {ok, Entry} = couch_log_formatter:format_report(self(), report123, #{
+        foo => 123,
+        bar => "barStr",
+        baz => baz
+    }),
+    % NOTE: this currently hardcodes the ordering of the keys, however, map
+    % key order is not guaranteed and this may break.
+    Formatted = "[foo=123 baz=\"baz\" bar=\"barStr\"]",
+    ?assertEqual(Formatted, lists:flatten(Entry#log_entry.msg)).
+
 format_reason_test() ->
     MsgFmt = "This is a reason: ~r",
     Reason = {foo, [{x, k, 3}, {c, d, 2}]},
diff --git a/src/couch_log/test/eunit/couch_log_writer_ets.erl b/src/couch_log/test/eunit/couch_log_writer_ets.erl
index 7ddb9f39e..385aa9676 100644
--- a/src/couch_log/test/eunit/couch_log_writer_ets.erl
+++ b/src/couch_log/test/eunit/couch_log_writer_ets.erl
@@ -30,9 +30,10 @@ terminate(_, _St) ->
     ok.
 
 write(Entry0, St) ->
-    Entry = Entry0#log_entry{
-        msg = lists:flatten(Entry0#log_entry.msg),
-        time_stamp = lists:flatten(Entry0#log_entry.time_stamp)
+    Entry1 = couch_log_util:maybe_format_type(Entry0),
+    Entry = Entry1#log_entry{
+        msg = lists:flatten(Entry1#log_entry.msg),
+        time_stamp = lists:flatten(Entry1#log_entry.time_stamp)
     },
     Ignored = application:get_env(couch_log, ignored_pids, []),
     case lists:member(Entry#log_entry.pid, Ignored) of
diff --git a/src/couch_log/test/eunit/couch_log_writer_syslog_test.erl b/src/couch_log/test/eunit/couch_log_writer_syslog_test.erl
index 5a3f89520..19d2826ec 100644
--- a/src/couch_log/test/eunit/couch_log_writer_syslog_test.erl
+++ b/src/couch_log/test/eunit/couch_log_writer_syslog_test.erl
@@ -31,6 +31,12 @@ couch_log_writer_syslog_test_() ->
                 [{gen_udp, [unstick]}],
                 fun check_udp_send/0
             )
+        end,
+        fun() ->
+            couch_log_test_util:with_meck(
+                [{gen_udp, [unstick]}],
+                fun check_format/0
+            )
         end
     ]}.
 
@@ -81,6 +87,40 @@ check_udp_send() ->
     ?assert(meck:called(gen_udp, close, 1)),
     ?assert(meck:validate(gen_udp)).
 
+check_format() ->
+    meck:expect(gen_udp, open, 1, {ok, socket}),
+    meck:expect(gen_udp, send, 4, ok),
+    meck:expect(gen_udp, close, fun(socket) -> ok end),
+    config:set("log", "syslog_host", "localhost"),
+    config:set("log", "syslog_enterprise_number", "12345"),
+    try
+        Entry = #log_entry{
+            level = report,
+            pid = list_to_pid("<0.1.0>"),
+            msg = ["[", "foo=1", "]"],
+            msg_id = "msg_id",
+            time_stamp = "time_stamp",
+            type = report123
+        },
+        {ok, St} = ?WRITER:init(),
+        {ok, NewSt} = ?WRITER:write(Entry, St),
+        ok = ?WRITER:terminate(stop, NewSt)
+    after
+        config:delete("log", "syslog_host")
+    end,
+
+    ?assert(meck:called(gen_udp, open, 1)),
+    Packet = lists:flatten(meck:capture(first, gen_udp, send, '_', 4)),
+    [SeverityAndVsn, TS, _Host, AppId, Pid, MsgId, _ | Rest] = string:split(Packet, " ", all),
+    ?assertEqual("<150>1", SeverityAndVsn),
+    ?assertEqual("time_stamp", TS),
+    ?assertEqual("couchdb", AppId),
+    ?assertEqual("msg_id", MsgId),
+    ?assert(is_pid(catch list_to_pid(Pid))),
+    ?assertEqual("[report123-DB@12345 foo=1]\n", string:join(Rest, " ")),
+    ?assert(meck:called(gen_udp, close, 1)),
+    ?assert(meck:validate(gen_udp)).
+
 facility_test() ->
     Names = [
         "kern",
diff --git a/src/mango/src/mango_cursor_nouveau.erl b/src/mango/src/mango_cursor_nouveau.erl
index 8a6525cca..7cdad20cd 100644
--- a/src/mango/src/mango_cursor_nouveau.erl
+++ b/src/mango/src/mango_cursor_nouveau.erl
@@ -122,10 +122,10 @@ execute(Cursor, UserFun, UserAcc) ->
             JsonBM = nouveau_bookmark:pack(FinalBM),
             Arg = {add_key, bookmark, JsonBM},
             {_Go, FinalUserAcc} = UserFun(Arg, LastUserAcc),
-            FinalUserAcc0 = mango_execution_stats:maybe_add_stats(
+            {FinalUserAcc0, Stats1} = mango_execution_stats:maybe_add_stats(
                 Opts, UserFun, Stats0, FinalUserAcc
             ),
-            FinalUserAcc1 = mango_cursor:maybe_add_warning(UserFun, Cursor, Stats0, FinalUserAcc0),
+            FinalUserAcc1 = mango_cursor:maybe_add_warning(UserFun, Cursor, Stats1, FinalUserAcc0),
             {ok, FinalUserAcc1}
     end.
 
diff --git a/src/mango/src/mango_cursor_text.erl b/src/mango/src/mango_cursor_text.erl
index 959603316..7454aebfd 100644
--- a/src/mango/src/mango_cursor_text.erl
+++ b/src/mango/src/mango_cursor_text.erl
@@ -127,10 +127,12 @@ execute(Cursor, UserFun, UserAcc) ->
             JsonBM = dreyfus_bookmark:pack(FinalBM),
             Arg = {add_key, bookmark, JsonBM},
             {_Go, FinalUserAcc} = UserFun(Arg, LastUserAcc),
-            FinalUserAcc0 = mango_execution_stats:maybe_add_stats(
+            {FinalUserAcc0, Stats1} = mango_execution_stats:maybe_add_stats(
                 Opts, UserFun, Stats0, FinalUserAcc
             ),
-            FinalUserAcc1 = mango_cursor:maybe_add_warning(UserFun, Cursor, Stats0, FinalUserAcc0),
+            %% This needs Stats1 as log_end is called in maybe_add_stats
+            mango_execution_stats:log_stats(Stats1),
+            FinalUserAcc1 = mango_cursor:maybe_add_warning(UserFun, Cursor, Stats1, FinalUserAcc0),
             {ok, FinalUserAcc1}
     end.
 
diff --git a/src/mango/src/mango_cursor_view.erl b/src/mango/src/mango_cursor_view.erl
index eec8dc4fe..d5cffbc5c 100644
--- a/src/mango/src/mango_cursor_view.erl
+++ b/src/mango/src/mango_cursor_view.erl
@@ -229,11 +229,13 @@ execute(#cursor{db = Db, index = Idx, execution_stats = Stats} = Cursor0, UserFu
                     Arg = {add_key, bookmark, NewBookmark},
                     {_Go, FinalUserAcc} = UserFun(Arg, LastCursor#cursor.user_acc),
                     Stats0 = LastCursor#cursor.execution_stats,
-                    FinalUserAcc0 = mango_execution_stats:maybe_add_stats(
+                    {FinalUserAcc0, Stats1} = mango_execution_stats:maybe_add_stats(
                         Opts, UserFun, Stats0, FinalUserAcc
                     ),
+                    %% This needs Stats1 as log_end is called in maybe_add_stats
+                    mango_execution_stats:log_stats(Stats1),
                     FinalUserAcc1 = mango_cursor:maybe_add_warning(
-                        UserFun, Cursor, Stats0, FinalUserAcc0
+                        UserFun, Cursor, Stats1, FinalUserAcc0
                     ),
                     {ok, FinalUserAcc1};
                 {error, Reason} ->
diff --git a/src/mango/src/mango_execution_stats.erl b/src/mango/src/mango_execution_stats.erl
index 0db3edf5f..66104e89e 100644
--- a/src/mango/src/mango_execution_stats.erl
+++ b/src/mango/src/mango_execution_stats.erl
@@ -14,6 +14,7 @@
 
 -export([
     to_json/1,
+    to_map/1,
     incr_keys_examined/1,
     incr_docs_examined/1,
     incr_docs_examined/2,
@@ -21,6 +22,7 @@
     incr_results_returned/1,
     log_start/1,
     log_end/1,
+    log_stats/1,
     maybe_add_stats/4
 ]).
 
@@ -35,6 +37,15 @@ to_json(Stats) ->
         {execution_time_ms, Stats#execution_stats.executionTimeMs}
     ]}.
 
+to_map(Stats) ->
+    #{
+        total_keys_examined => Stats#execution_stats.totalKeysExamined,
+        total_docs_examined => Stats#execution_stats.totalDocsExamined,
+        total_quorum_docs_examined => Stats#execution_stats.totalQuorumDocsExamined,
+        results_returned => Stats#execution_stats.resultsReturned,
+        execution_time_ms => Stats#execution_stats.executionTimeMs
+    }.
+
 incr_keys_examined(Stats) ->
     Stats#execution_stats{
         totalKeysExamined = Stats#execution_stats.totalKeysExamined + 1
@@ -74,13 +85,24 @@ log_end(Stats) ->
 maybe_add_stats(Opts, UserFun, Stats0, UserAcc) ->
     Stats1 = log_end(Stats0),
     couch_stats:update_histogram([mango, query_time], Stats1#execution_stats.executionTimeMs),
+    %% TODO: add rows read when we collect the stats
+    %% TODO: add docs vs quorum docs
+    chttpd_stats:incr_reads(Stats1#execution_stats.totalDocsExamined),
+
+    FinalAcc =
+        case couch_util:get_value(execution_stats, Opts) of
+            true ->
+                JSONValue = to_json(Stats1),
+                Arg = {add_key, execution_stats, JSONValue},
+                {_Go, FinalUserAcc} = UserFun(Arg, UserAcc),
+                FinalUserAcc;
+            _ ->
+                UserAcc
+        end,
+    {FinalAcc, Stats1}.
 
-    case couch_util:get_value(execution_stats, Opts) of
-        true ->
-            JSONValue = to_json(Stats1),
-            Arg = {add_key, execution_stats, JSONValue},
-            {_Go, FinalUserAcc} = UserFun(Arg, UserAcc),
-            FinalUserAcc;
-        _ ->
-            UserAcc
-    end.
+log_stats(Stats) ->
+    MStats0 = to_map(Stats),
+    Nonce = list_to_binary(couch_log_util:get_msg_id()),
+    MStats1 = MStats0#{nonce => Nonce},
+    couch_log:report("mango-stats", MStats1).