Couch stats resource tracker v3 rebase main

rebar.config.script

@@ -127,6 +127,7 @@ SubDirs = [
     "src/couch_mrview",
     "src/couch_replicator",
     "src/couch_pse_tests",
+    "src/couch_srt",
     "src/couch_stats",
     "src/couch_peruser",
     "src/couch_tests",

rel/overlay/etc/default.ini

@@ -1150,3 +1150,94 @@ url = {{nouveau_url}}
 ;mem3_shards = true
 ;nouveau_index_manager = true
 ;dreyfus_index_manager = true
+
+; Couch Stats Resource Tracker (CSRT)
+[csrt]
+;enable = false
+;enable_init_p = false
+;enable_reporting = false
+;enable_rpc_reporting = false
+
+; Truncate reports to not include zero values for counter fields. This is a
+; simple way to save space and should be left enabled unless you need a fixed
+; output structure in the process lifecycle reports.
+;should_truncate_reports = true
+
+; Limit queries to a maxinum number of rows
+;query_limit = 100
+;query_cardinality_limit = 10000
+
+; CSRT Logger Matchers
+;
+; These matchers are filters to decide whether or not to generate a process
+; lifecyle report at the end of an HTTP request with a detailed report
+; quantifying the CouchDB resources used to fulfill that request. These filters
+; are design to make it easy to log a report for requests that utilize a lot
+; of CouchDB resources, take a long time, or use heavy filtering, without having
+; to enable report logging for _all_ requests. These reports can be enabled at
+; the RPC worker level too, but for view queries and other aggregate operations,
+; that can generate a report per shard interacted with to fullfill the request,
+; and can generate a lot of data. The logger matchers are a way to dynamically
+; control what is being logged on the fly, or to tailor fit the quantity of logs
+; generated to store usage information in a predictable manner.
+;
+; These reports can be used to find potential workloads
+; to refactor, but also to retroactively understand the workload that during a
+; particular window of time. The node level stats collected and reported can
+; inform you that, for example, a great deal of IO operations and database reads
+; are being performed, but they do not provide cardinality into the databases
+; and requests inducing te resource usage. This is where the process lifecycle
+; reports come in: after a request is completed, if it matched a filter, a
+; report is logged containing the final quantitative counts of resources usage
+; to fulfill that request as well as qualitative information like username,
+; dbname, nonce, and more. See CSRT.md for more details.
+;
+; There are a series of default logger matchers designed to filter for requests
+; that surpass a threshold on a particular dimension, for example, when enabled,
+; the ioq_calls default matcher filters true for requests that invoke more than
+; 10,000 IOQ calls. The default named matchers are enabled by name and boolean
+; in the `[csrt_logger.matchers_enabled]` section, and similarly, the Threshold
+; value for each of the default matchers is specified in the config section
+; `[csrt_logger.matchers_threshold]` by name and integer threshold quantity.
+;
+; The default loggers above operate against any HTTP requests flowing through
+; CouchDB, whereas the `[csrt_logger.dbnames_io]` provides a simple way to
+; specify database specific matchers, at the expense of the granularity
+; available in the default matchers. The "dbnames_io" logger matcher filters
+; for requests against a particular database that induce more than the specified
+; threshold of IO operations. This is a generic IO catchall matcher, not
+; specific to ioq_calls or docs_read, like the default matchers.
+;
+; CSRT dbname matchers
+; Given a dbname and a positive integer, this will enable an IO matcher
+; against the provided db for any requests that induce IO in quantities
+; greater than the provided threshold on any one of: ioq_calls, rows_read
+; docs_read, get_kp_node, get_kv_node, or changes_processed.
+[csrt_logger.dbnames_io]
+; For example:
+; foo = 100
+; _dbs = 123
+; _users = 234
+; foo/bar = 200
+
+; CSRT default matchers - enablement configuration
+; The default CSRT loggers can be individually enabled below
+[csrt_logger.matchers_enabled]
+;all_coordinators = false
+;all_rpc_workers = false
+;docs_read = false
+;rows_read = false
+;docs_written = false
+;long_reqs = false
+;changes_processed = false
+;ioq_calls = false
+
+; CSRT default matchers - threshold configuration
+; This specifies the integer Threshold for the various builtin matchers
+[csrt_logger.matchers_threshold]
+;docs_read = 1000
+;rows_read = 1000
+;docs_written = 500
+;long_reqs = 60000
+;changes_processed = 1000
+;ioq_calls = 10000

rel/reltool.config

@@ -38,6 +38,7 @@
         couch_log,
         couch_mrview,
         couch_replicator,
+        couch_srt,
         couch_stats,
         couch_event,
         couch_peruser,
@@ -103,6 +104,7 @@
     {app, couch_log, [{incl_cond, include}]},
     {app, couch_mrview, [{incl_cond, include}]},
     {app, couch_replicator, [{incl_cond, include}]},
+    {app, couch_srt, [{incl_cond, include}]},
     {app, couch_stats, [{incl_cond, include}]},
     {app, couch_event, [{incl_cond, include}]},
     {app, couch_peruser, [{incl_cond, include}]},

src/chttpd/src/chttpd.erl

@@ -339,6 +339,10 @@ handle_request_int(MochiReq) ->
     % Save client socket so that it can be monitored for disconnects
     chttpd_util:mochiweb_client_req_set(MochiReq),
 
+    %% This is probably better in before_request, but having Path is nice
+    couch_srt:create_coordinator_context(HttpReq0, Path),
+    couch_srt:set_context_handler_fun({?MODULE, ?FUNCTION_NAME}),
+
     {HttpReq2, Response} =
         case before_request(HttpReq0) of
             {ok, HttpReq1} ->
@@ -369,6 +373,7 @@ handle_request_int(MochiReq) ->
 
 before_request(HttpReq) ->
     try
+        couch_srt:set_context_handler_fun({?MODULE, ?FUNCTION_NAME}),
         chttpd_stats:init(),
         chttpd_plugin:before_request(HttpReq)
     catch
@@ -388,6 +393,8 @@ after_request(HttpReq, HttpResp0) ->
     HttpResp2 = update_stats(HttpReq, HttpResp1),
     chttpd_stats:report(HttpReq, HttpResp2),
     maybe_log(HttpReq, HttpResp2),
+    %% NOTE: do not set_context_handler_fun to preserve the Handler
+    couch_srt:destroy_context(),
     HttpResp2.
 
 process_request(#httpd{mochi_req = MochiReq} = HttpReq) ->
@@ -400,6 +407,7 @@ process_request(#httpd{mochi_req = MochiReq} = HttpReq) ->
     RawUri = MochiReq:get(raw_path),
 
     try
+        couch_srt:set_context_handler_fun({?MODULE, ?FUNCTION_NAME}),
         couch_httpd:validate_host(HttpReq),
         check_request_uri_length(RawUri),
         check_url_encoding(RawUri),
@@ -425,10 +433,12 @@ handle_req_after_auth(HandlerKey, HttpReq) ->
             HandlerKey,
             fun chttpd_db:handle_request/1
         ),
+        couch_srt:set_context_handler_fun(HandlerFun),
         AuthorizedReq = chttpd_auth:authorize(
             possibly_hack(HttpReq),
             fun chttpd_auth_request:authorize_request/1
         ),
+        couch_srt:set_context_username(AuthorizedReq),
         {AuthorizedReq, HandlerFun(AuthorizedReq)}
     catch
         ErrorType:Error:Stack ->

src/chttpd/src/chttpd_db.erl

@@ -83,6 +83,7 @@
 
 % Database request handlers
 handle_request(#httpd{path_parts = [DbName | RestParts], method = Method} = Req) ->
+    couch_srt:set_context_dbname(DbName),
     case {Method, RestParts} of
         {'PUT', []} ->
             create_db_req(Req, DbName);
@@ -103,6 +104,7 @@ handle_request(#httpd{path_parts = [DbName | RestParts], method = Method} = Req)
             do_db_req(Req, fun db_req/2);
         {_, [SecondPart | _]} ->
             Handler = chttpd_handlers:db_handler(SecondPart, fun db_req/2),
+            couch_srt:set_context_handler_fun(Handler),
             do_db_req(Req, Handler)
     end.
 

src/chttpd/src/chttpd_httpd_handlers.erl

@@ -20,6 +20,7 @@ url_handler(<<"_utils">>) -> fun chttpd_misc:handle_utils_dir_req/1;
 url_handler(<<"_all_dbs">>) -> fun chttpd_misc:handle_all_dbs_req/1;
 url_handler(<<"_dbs_info">>) -> fun chttpd_misc:handle_dbs_info_req/1;
 url_handler(<<"_active_tasks">>) -> fun chttpd_misc:handle_task_status_req/1;
+url_handler(<<"_active_resources">>) -> fun couch_srt_httpd:handle_resource_status_req/1;
 url_handler(<<"_scheduler">>) -> fun couch_replicator_httpd:handle_scheduler_req/1;
 url_handler(<<"_node">>) -> fun chttpd_node:handle_node_req/1;
 url_handler(<<"_reload_query_servers">>) -> fun chttpd_misc:handle_reload_query_servers_req/1;

src/couch/priv/stats_descriptions.cfg

@@ -306,6 +306,10 @@
     {type, counter},
     {desc, <<"number of couch_server LRU operations skipped">>}
 ]}.
+{[couchdb, couch_server, open], [
+    {type, counter},
+    {desc, <<"number of couch_server open operations invoked">>}
+]}.
 {[couchdb, query_server, vdu_rejects], [
     {type, counter},
     {desc, <<"number of rejections by validate_doc_update function">>}
@@ -422,6 +426,22 @@
     {type, counter},
     {desc, <<"number of legacy checksums found in couch_file instances">>}
 ]}.
+{[couchdb, btree, get_node, kp_node], [
+    {type, counter},
+    {desc, <<"number of couch btree kp_nodes read">>}
+]}.
+{[couchdb, btree, get_node, kv_node], [
+    {type, counter},
+    {desc, <<"number of couch btree kv_nodes read">>}
+]}.
+{[couchdb, btree, write_node, kp_node], [
+    {type, counter},
+    {desc, <<"number of couch btree kp_nodes written">>}
+]}.
+{[couchdb, btree, write_node, kv_node], [
+    {type, counter},
+    {desc, <<"number of couch btree kv_nodes written">>}
+]}.
 {[pread, exceed_eof], [
     {type, counter},
     {desc, <<"number of the attempts to read beyond end of db file">>}

src/couch/src/couch.app.src

@@ -47,6 +47,7 @@
         couch_log,
         couch_event,
         ioq,
+        couch_srt,
         couch_stats,
         couch_dist,
         couch_quickjs

src/couch/src/couch_btree.erl

@@ -472,6 +472,7 @@ reduce_tree_size(kp_node, NodeSize, [{_K, {_P, _Red, Sz}} | NodeList]) ->
 
 get_node(#btree{fd = Fd}, NodePos) ->
     {ok, {NodeType, NodeList}} = couch_file:pread_term(Fd, NodePos),
+    couch_stats:increment_counter([couchdb, btree, get_node, NodeType]),
     {NodeType, NodeList}.
 
 write_node(#btree{fd = Fd, compression = Comp} = Bt, NodeType, NodeList) ->
@@ -480,6 +481,7 @@ write_node(#btree{fd = Fd, compression = Comp} = Bt, NodeType, NodeList) ->
     % now write out each chunk and return the KeyPointer pairs for those nodes
     ToWrite = [{NodeType, Chunk} || Chunk <- Chunks],
     WriteOpts = [{compression, Comp}],
+    couch_stats:increment_counter([couchdb, btree, write_node, NodeType]),
     {ok, PtrSizes} = couch_file:append_terms(Fd, ToWrite, WriteOpts),
     {ok, group_kps(Bt, NodeType, Chunks, PtrSizes)}.
 

src/couch/src/couch_query_servers.erl

@@ -614,6 +614,12 @@ filter_docs(Req, Db, DDoc, FName, Docs) ->
     end.
 
 filter_docs_int(Db, DDoc, FName, JsonReq, JsonDocs) ->
+    %% Count usage in _int version as this can be repeated for OS error
+    %% Pros & cons... might not have actually processed `length(JsonDocs)` docs
+    %% but it certainly undercounts if we count in `filter_docs/5` above
+    %% TODO: replace with couchdb.query_server.*.ddoc_filter stats once we can
+    %% funnel back the stats used in the couchjs process to this caller process
+    couch_srt:js_filtered(length(JsonDocs)),
     [true, Passes] = ddoc_prompt(
         Db,
         DDoc,

src/couch/src/couch_server.erl

@@ -114,6 +114,7 @@ sup_start_link(N) ->
     gen_server:start_link({local, couch_server(N)}, couch_server, [N], []).
 
 open(DbName, Options) ->
+    couch_stats:increment_counter([couchdb, couch_server, open]),
     try
         validate_open_or_create(DbName, Options),
         open_int(DbName, Options)

src/couch_log/src/couch_log_formatter.erl

@@ -470,7 +470,12 @@ format_meta(Meta) ->
         lists:sort(
             maps:fold(
                 fun(K, V, Acc) ->
-                    [to_str(K, V) | Acc]
+                    case to_str(K, V) of
+                        "" ->
+                            Acc;
+                        Str ->
+                            [Str | Acc]
+                    end
                 end,
                 [],
                 Meta
@@ -487,6 +492,9 @@ format_meta(Meta) ->
 %% - maps
 %% However we are not going to try to distinguish lists from string
 %% Atoms would be printed as strings
+%% `null` JSON values are skipped
+to_str(_K, null) ->
+    "";
 to_str(K, _) when not (is_list(K) or is_atom(K)) ->
     "";
 to_str(K, Term) when is_list(Term) ->

src/couch_log/test/eunit/couch_log_formatter_test.erl

@@ -34,11 +34,13 @@ format_report_etoolong_test() ->
 
 format_report_test() ->
     {ok, Entry} = couch_log_formatter:format_report(self(), report123, #{
+        empty => null,
         foo => 123,
         bar => "barStr",
         baz => baz
     }),
     % Rely on `couch_log_formatter:format_meta/1` to sort keys
+    % `empty` is missing as `null` values are skipped
     Formatted = "[bar=\"barStr\" baz=\"baz\" foo=123]",
     ?assertEqual(Formatted, lists:flatten(Entry#log_entry.msg)).