This is an automated email from the ASF dual-hosted git repository. vatamane pushed a commit to branch add-couchjs-call-counts in repository https://gitbox.apache.org/repos/asf/couchdb.git
commit 4c061213743db516754ed37a2d3d7b6e7c336227 Author: Nick Vatamaniuc <[email protected]> AuthorDate: Tue Oct 3 15:17:38 2023 -0400 Add calls counts to couch_js engine time stats Just tracking total time spent in each individual query prompt may be ambiguous, unless we also keep track of the number of calls of each prompt type. For instance, if we notice the total time spent per some call increasing, it could be because the JS engine got slower, or, because some other bottleneck was removed and now we can run more total map calls per unit of time. To disambiguate between these cases let's also track the total number of calls. This way users would be able to estimate the average time spent per call more accurately. --- src/couch/priv/stats_descriptions.cfg | 40 +++++++++++++++++++++++++++++++++ src/couch/src/couch_os_process.erl | 1 + src/couch/test/eunit/couch_js_tests.erl | 27 ++++++++++++++++++++-- 3 files changed, 66 insertions(+), 2 deletions(-) diff --git a/src/couch/priv/stats_descriptions.cfg b/src/couch/priv/stats_descriptions.cfg index 578b4c65b..2d40518e2 100644 --- a/src/couch/priv/stats_descriptions.cfg +++ b/src/couch/priv/stats_descriptions.cfg @@ -370,6 +370,46 @@ {type, counter}, {desc, <<"accumulated number of microseconds spent processing other requests">>} ]}. +{[couchdb, query_server, calls, spawn_proc], [ + {type, counter}, + {desc, <<"number of spawned query processes">>} +]}. +{[couchdb, query_server, calls, map], [ + {type, counter}, + {desc, <<"number of map_doc requests">>} +]}. +{[couchdb, query_server, calls, reduce], [ + {type, counter}, + {desc, <<"number of reduce requests">>} +]}. +{[couchdb, query_server, calls, reset], [ + {type, counter}, + {desc, <<"number of reset requests">>} +]}. +{[couchdb, query_server, calls, add_fun], [ + {type, counter}, + {desc, <<"number of add_fun requests">>} +]}. +{[couchdb, query_server, calls, ddoc_new], [ + {type, counter}, + {desc, <<"number of ddoc new requests">>} +]}. +{[couchdb, query_server, calls, ddoc_vdu], [ + {type, counter}, + {desc, <<"number of vdu requests">>} +]}. +{[couchdb, query_server, calls, ddoc_filter], [ + {type, counter}, + {desc, <<"number of filter requests">>} +]}. +{[couchdb, query_server, calls, ddoc_other], [ + {type, counter}, + {desc, <<"number of other ddoc requests">>} +]}. +{[couchdb, query_server, calls, other], [ + {type, counter}, + {desc, <<"number of other requests">>} +]}. {[couchdb, legacy_checksums], [ {type, counter}, {desc, <<"number of legacy checksums found in couch_file instances">>} diff --git a/src/couch/src/couch_os_process.erl b/src/couch/src/couch_os_process.erl index 0302cb01d..19e6417b0 100644 --- a/src/couch/src/couch_os_process.erl +++ b/src/couch/src/couch_os_process.erl @@ -254,4 +254,5 @@ bump_cmd_time_stat(Cmd, USec) when is_list(Cmd), is_integer(USec) -> end. bump_time_stat(Stat, USec) when is_atom(Stat), is_integer(USec) -> + couch_stats:increment_counter([couchdb, query_server, calls, Stat]), couch_stats:increment_counter([couchdb, query_server, time, Stat], USec). diff --git a/src/couch/test/eunit/couch_js_tests.erl b/src/couch/test/eunit/couch_js_tests.erl index 94a02b1ea..9bade6b9c 100644 --- a/src/couch/test/eunit/couch_js_tests.erl +++ b/src/couch/test/eunit/couch_js_tests.erl @@ -28,7 +28,7 @@ couch_js_test_() -> ?TDEF(should_roundtrip_modified_utf8), ?TDEF(should_replace_broken_utf16), ?TDEF(should_allow_js_string_mutations), - ?TDEF(should_bump_timing_stats), + ?TDEF(should_bump_timing_and_call_stats), ?TDEF(should_exit_on_oom, 60000), ?TDEF(should_exit_on_internal_error, 60000) ]) @@ -228,41 +228,51 @@ should_allow_js_string_mutations(_) -> couch_query_servers:ret_os_process(Proc). %% erlfmt-ignore -should_bump_timing_stats(_) -> +should_bump_timing_and_call_stats(_) -> Proc = couch_query_servers:get_os_process(<<"javascript">>), ?assert(sample_time(spawn_proc) > 0), ResetTime = sample_time(reset), + ResetCalls = sample_calls(reset), true = prompt(Proc, [<<"reset">>]), ?assert(sample_time(reset) > ResetTime), + ?assertEqual(ResetCalls + 1, sample_calls(reset)), AddFunTime = sample_time(add_fun), + AddFunCalls = sample_calls(add_fun), true = prompt(Proc, [ <<"add_fun">>, <<"function(doc) {emit(doc.x, doc.y);}">> ]), ?assert(sample_time(add_fun) > AddFunTime), + ?assertEqual(AddFunCalls + 1, sample_calls(add_fun)), MapTime = sample_time(map), + MapCalls = sample_calls(map), [[[1, 2]]] = prompt(Proc, [ <<"map_doc">>, {[{<<"x">>, 1}, {<<"y">>, 2}]} ]), ?assert(sample_time(map) > MapTime), + ?assertEqual(MapCalls + 1, sample_calls(map)), ReduceTime = sample_time(reduce), + ReduceCalls = sample_calls(reduce), [true, [2]] = prompt(Proc, [ <<"reduce">>, [<<"function(k, v) {return sum(v);}">>], [[1, 2]] ]), ?assert(sample_time(reduce)> ReduceTime), + ?assertEqual(ReduceCalls + 1, sample_calls(reduce)), ReduceTime1 = sample_time(reduce), + ReduceCalls1 = sample_calls(reduce), [true, [7]] = prompt(Proc, [ <<"rereduce">>, [<<"function(k, v) {return sum(v);}">>], [3, 4] ]), ?assert(sample_time(reduce) > ReduceTime1), + ?assertEqual(ReduceCalls1 + 1, sample_calls(reduce)), FilterFun = <<"function(doc, req) {return true;}">>, UpdateFun = <<"function(doc, req) {return [null, 'something'];}">>, @@ -277,6 +287,7 @@ should_bump_timing_stats(_) -> }, NewDDocTime = sample_time(ddoc_new), + NewDDocCalls = sample_calls(ddoc_new), true = prompt(Proc, [ <<"ddoc">>, <<"new">>, @@ -284,8 +295,10 @@ should_bump_timing_stats(_) -> DDoc ]), ?assert(sample_time(ddoc_new) > NewDDocTime), + ?assertEqual(NewDDocCalls + 1, sample_calls(ddoc_new)), VduTime = sample_time(ddoc_vdu), + VduCalls = sample_calls(ddoc_vdu), 1 = prompt(Proc, [ <<"ddoc">>, DDocId, @@ -293,8 +306,10 @@ should_bump_timing_stats(_) -> [#{}, #{}] ]), ?assert(sample_time(ddoc_vdu) > VduTime), + ?assertEqual(VduCalls + 1, sample_calls(ddoc_vdu)), FilterTime = sample_time(ddoc_filter), + FilterCalls = sample_calls(ddoc_filter), [true, [true]] = prompt(Proc, [ <<"ddoc">>, DDocId, @@ -302,8 +317,10 @@ should_bump_timing_stats(_) -> [[#{}], #{}] ]), ?assert(sample_time(ddoc_filter) > FilterTime), + ?assertEqual(FilterCalls + 1, sample_calls(ddoc_filter)), DDocOtherTime = sample_time(ddoc_other), + DDocOtherCalls = sample_calls(ddoc_other), prompt(Proc, [ <<"ddoc">>, DDocId, @@ -311,13 +328,16 @@ should_bump_timing_stats(_) -> [null, #{}] ]), ?assert(sample_time(ddoc_other) > DDocOtherTime), + ?assertEqual(DDocOtherCalls + 1, sample_calls(ddoc_other)), OtherTime = sample_time(other), + OtherCalls = sample_calls(other), true = prompt(Proc, [ <<"add_lib">>, #{<<"foo">> => <<"exports.bar = 42;">>} ]), ?assert(sample_time(other) > OtherTime), + ?assertEqual(OtherCalls + 1, sample_calls(other)), couch_query_servers:ret_os_process(Proc). @@ -394,5 +414,8 @@ trigger_oom(Proc) -> sample_time(Stat) -> couch_stats:sample([couchdb, query_server, time, Stat]). +sample_calls(Stat) -> + couch_stats:sample([couchdb, query_server, calls, Stat]). + prompt(Proc, Cmd) -> couch_query_servers:proc_prompt(Proc, Cmd).
