From 74b522f8cd54a3db9337a64a0f0763ee200ef23e Mon Sep 17 00:00:00 2001 From: Sverker Eriksson Date: Tue, 1 Oct 2024 16:57:44 +0200 Subject: [PATCH] fixup! DEBUG: Measure latency of calls to trace:function --- erts/emulator/beam/erl_bif_info.c | 5 --- erts/emulator/beam/erl_bif_trace.c | 18 ---------- erts/emulator/beam/erl_trace.h | 2 -- erts/emulator/test/trace_sessions.erl | 52 +++++++-------------------- 4 files changed, 12 insertions(+), 65 deletions(-) diff --git a/erts/emulator/beam/erl_bif_info.c b/erts/emulator/beam/erl_bif_info.c index b8538e6b9012..8608c9cca1e4 100644 --- a/erts/emulator/beam/erl_bif_info.c +++ b/erts/emulator/beam/erl_bif_info.c @@ -4447,11 +4447,6 @@ BIF_RETTYPE erts_debug_get_internal_state_1(BIF_ALIST_1) Eterm* tp = tuple_val(BIF_ARG_1); switch (arityval(tp[0])) { case 2: { - if (tp[1] == am_session) { - Eterm get_session_thr_prog_latency(Process*, Eterm session); - return get_session_thr_prog_latency(BIF_P, tp[2]); - } - else if (ERTS_IS_ATOM_STR("node_and_dist_references", tp[1])) { if (tp[2] == am_blocked && erts_is_multi_scheduling_blocked() > 0) { diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 0b9f5f171187..a7614403155e 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -505,7 +505,6 @@ trace_pattern(Process* p, ErtsTraceSession *session, ASSERT(matches >= 0); ASSERT(finish_bp.stager == NULL); finish_bp.stager = p; - erts_staging_trace_session->bp_finish = erts_get_monotonic_time(p->scheduler_data); erts_schedule_code_barrier(&finish_bp.barrier, smp_bp_finisher, NULL); erts_proc_inc_refc(p); erts_suspend(p, ERTS_PROC_LOCK_MAIN, NULL); @@ -528,20 +527,6 @@ trace_pattern(Process* p, ErtsTraceSession *session, } } -Eterm get_session_thr_prog_latency(Process *p, Eterm session); - -Eterm get_session_thr_prog_latency(Process *p, Eterm session) -{ - ErtsTraceSession *s; - if (!term_to_session(session, &s, 0)) { - BIF_ERROR(p, BADARG); - } else { - ErtsMonotonicTime usec = ERTS_MONOTONIC_TO_USEC__(s->bp_finish); - erts_deref_trace_session(s); - return make_small(usec); - } -} - static void smp_bp_finisher(void* null) { if (erts_finish_breakpointing()) { /* Not done */ @@ -576,9 +561,6 @@ static void smp_bp_finisher(void* null) #endif erts_release_code_mod_permission(); if (p) { - session->bp_finish = (erts_get_monotonic_time(p->scheduler_data) - - session->bp_finish); - /* * Operation initiated by BIF call which did refc++ * to keep session alive during entire call. diff --git a/erts/emulator/beam/erl_trace.h b/erts/emulator/beam/erl_trace.h index 8faacdf6f1d2..adbdd93099fb 100644 --- a/erts/emulator/beam/erl_trace.h +++ b/erts/emulator/beam/erl_trace.h @@ -122,8 +122,6 @@ typedef struct ErtsTraceSession { struct erts_system_monitor_flags_t flags; } system_monitor; - ErtsMonotonicTime bp_finish; - #ifdef DEBUG erts_refc_t dbg_bp_refc; /* Number of breakpoints */ erts_refc_t dbg_p_refc; /* Number of processes and ports */ diff --git a/erts/emulator/test/trace_sessions.erl b/erts/emulator/test/trace_sessions.erl index 918c4f0068b1..790aad3c9ac6 100644 --- a/erts/emulator/test/trace_sessions.erl +++ b/erts/emulator/test/trace_sessions.erl @@ -255,8 +255,8 @@ init_group([pre_session|Tail], Config) -> %% Set a dummy call_count on all (local) functions. trace:function(S, {'_','_','_'}, true, [local]), - %% Re-set a dummy global call trace on all exported functions. - set_dummy_global(S, Config), + %% Re-set a dummy global call trace on exported functions. + set_dummy_global_trace(S, Config), %% Set a dummy send trace on all processes and ports %% but disable send trace to not get any messages. @@ -314,10 +314,10 @@ end_per_testcase(Config) -> -set_dummy_global(S, Config) -> +set_dummy_global_trace(S, Config) -> %% Modules = [M || M <- erlang:loaded(), %% erlang:function_exported(M, module_info, 1)], - %% Do trace_pattern on all loaded modules takes too long time + %% Calling trace_pattern on all loaded modules takes too long time %% on some machines. Do it on a subset of modules instead. %% Set a dummy global call trace on some exported functions. @@ -325,42 +325,14 @@ set_dummy_global(S, Config) -> Modules = [erlang, ets, lists, maps, SuiteModule], io:format("~w modules to trace...\n", [length(Modules)]), - WasAvail = erts_debug:set_internal_state(available_internal_state, true), - Result = try set_dummy_global(S, Modules, 1, []) - after - erts_debug:set_internal_state(available_internal_state, WasAvail) - end, - - io:format("\nModule sorted totals:\n", []), [begin - Percent = case ModTot of - 0 -> 0; - _ -> (100*ThrProgTot) div ModTot - end, - io:format("~10w ~10w ~3w%: ~w #~w", [ModTot, ThrProgTot, Percent, Module, N]) + {Micros, 1} = timer:tc(fun() -> + trace:function(S, {Mod, Func, Arity}, + true, [global]) + end), + io:format("~10w: ~w:~w/~w", [Micros, Mod, Func, Arity]) end - || {ModTot, ThrProgTot, Module, N} <- Result], - ok. + || Mod <- Modules, + {Func, Arity} <- Mod:module_info(exports)], - -set_dummy_global(_S, [], _N, Acc) -> - lists:sort(Acc); -set_dummy_global(S, [Module|Tail], N, Acc) -> - test_server_ctrl:print_timestamp(minor, atom_to_list(Module)), - %%io:format("\nModule #~w: ~w\n", [N, Module]), - - Before = erlang:monotonic_time(microsecond), - ThrProgTot = - lists:foldl(fun({Func, Arity}, ThrProgAcc) -> - {Micros, _} = timer:tc(fun() -> - trace:function(S, {Module, Func, Arity}, true, [global]) - end), - ThrProg = erts_debug:get_internal_state({session, S}), - io:format("~10w~10w: ~w:~w/~w", [Micros, ThrProg, Module, Func, Arity]), - ThrProgAcc + ThrProg - end, - 0, - Module:module_info(exports)), - - ModTot = erlang:monotonic_time(microsecond) - Before, - set_dummy_global(S, Tail, N+1, [{ModTot,ThrProgTot,Module,N} | Acc]). + ok.