File 1222-erts-Cleanup-trace_call_time_SUITE-bif.patch of Package erlang

Overview Repositories Revisions Requests Users Attributes Meta

File 1222-erts-Cleanup-trace_call_time_SUITE-bif.patch of Package erlang (Revision 9c6f14cb59b6cc96e9e5afb6eccb708c)

Currently displaying revision 9c6f14cb59b6cc96e9e5afb6eccb708c , Show latest

From ab4b26d562c6cb7b711cd3e82f551f49899f253e Mon Sep 17 00:00:00 2001
From: Sverker Eriksson <sverker@erlang.org>
Date: Wed, 8 Mar 2023 15:23:59 +0100
Subject: [PATCH 2/2] erts: Cleanup trace_call_time_SUITE:bif

and get some more results printed for trouble shooting.
---
 erts/emulator/test/trace_call_time_SUITE.erl | 59 ++++++++++++++------
 1 file changed, 42 insertions(+), 17 deletions(-)

diff --git a/erts/emulator/test/trace_call_time_SUITE.erl b/erts/emulator/test/trace_call_time_SUITE.erl
index 124f0e2283..26687129bb 100644
--- a/erts/emulator/test/trace_call_time_SUITE.erl
+++ b/erts/emulator/test/trace_call_time_SUITE.erl
@@ -412,11 +412,21 @@ bif(Config) when is_list(Config) ->
     Pid = setup(),
     {L, Tot1} = execute(Pid, fun() -> with_bif(M) end),
 
-    {call_time,[{Pid,_,S,Us}]} = erlang:trace_info({?MODULE,with_bif,1}, call_time),
-    T1 = Tot1 - (S*1000000 + Us),
-
-    ok = check_trace_info({erlang, binary_to_term, 1}, [{Pid, M - 1, 0, 0}], T1/2),
-    ok = check_trace_info({erlang, term_to_binary, 1}, [{Pid, M - 1, 0, 0}], T1/2),
+    {call_time,[{Pid,_,S,Us}]}=WB = erlang:trace_info({?MODULE,with_bif,1}, call_time),
+    T1 = Tot1 - (S*1000_000 + Us),
+
+    B2T = erlang:trace_info({erlang, binary_to_term, 1}, call_time),
+    T2B = erlang:trace_info({erlang, term_to_binary, 1}, call_time),
+    io:format("with_bif       = ~p\n", [WB]),
+    io:format("binary_to_term = ~p\n", [B2T]),
+    io:format("term_to_binary = ~p\n", [T2B]),
+    Sum = us(WB) + us(B2T) + us(T2B),
+    io:format("Sum  = ~p us\n", [Sum]),
+    io:format("Tot1 = ~p us  Diff = ~p us\n", [Tot1, Tot1-Sum]),
+    ok = check_trace_info_ret({erlang, binary_to_term, 1}, [{Pid, M-1, 0, 0}],
+                              T1/2, B2T),
+    ok = check_trace_info_ret({erlang, term_to_binary, 1}, [{Pid, M-1, 0, 0}],
+                              T1/2, T2B),
 
     % disable term2binary
 
@@ -432,6 +442,9 @@ bif(Config) when is_list(Config) ->
     Pid ! quit,
     ok.
 
+us({call_time,[{_,_,S,Us}]}) ->
+    S*1000_000 + Us.
+
 %% %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
 
 %% Tests tracing of nifs
@@ -712,23 +725,35 @@ seq_r(Start, Stop, Succ, R) ->
     seq_r(Succ(Start), Stop, Succ, [Start | R]).
 
 % Check call time tracing data and print mismatches
-check_trace_info(Mfa, [{Pid, ExpectedC,_,_}] = Expect, Time) ->
-    {call_time,[{Pid,C,S,Us}]} = erlang:trace_info(Mfa, call_time),
+check_trace_info(Mfa, Expect, Time) ->
+    check_trace_info_ret(Mfa, Expect, Time, erlang:trace_info(Mfa, call_time)).
+
+check_trace_info_ret(Mfa, [{Pid, ExpectedC,_,_}] = Expect, Time, TraceInfo) ->
+    {call_time,[{Pid,Cnt,S,Us}]} = TraceInfo,
+
     {Mod, Name, Arity} = Mfa,
     IsBuiltin = erlang:is_builtin(Mod, Name, Arity),
-    if
+    ok = if
         %% Call count on BIFs may exceed number of calls as they often trap to
         %% themselves.
-        IsBuiltin, C >= ExpectedC, S >= 0, Us >= 0,
-          abs(1 - Time/(S*1000000 + Us)) < ?R_ERROR;
-          abs(Time - S*1000000 - Us) < ?US_ERROR ->
+        IsBuiltin, Cnt >= ExpectedC ->
             ok;
-        not IsBuiltin, C =:= ExpectedC, S >= 0, Us >= 0,
-          abs(1 - Time/(S*1000000 + Us)) < ?R_ERROR;
-          abs(Time - S*1000000 - Us) < ?US_ERROR ->
+        not IsBuiltin, Cnt =:= ExpectedC ->
+            ok;
+        true ->
+            io:format("Expected ~p -> {call_time, ~p}~n"
+                      " - got call count ~w~p",
+                      [Mfa, Expect, Cnt]),
+            count_error
+    end,
+
+    true = (S >= 0),
+    true = (Us >= 0),
+    Sum = S*1000_000 + Us,
+    if
+        abs(1 - Time/Sum) < ?R_ERROR; abs(Time - Sum) < ?US_ERROR ->
             ok;
         true ->
-            Sum = S*1000000 + Us,
             io:format("Expected ~p -> {call_time, ~p (Time ~p us)}~n - got ~w "
                       "s. ~w us. = ~w us. - ~w -> delta ~w (ratio ~.2f, "
                       "should be 1.0)~n",
@@ -736,8 +761,8 @@ check_trace_info(Mfa, [{Pid, ExpectedC,_,_}] = Expect, Time) ->
                        S, Us, Sum, Time, Sum - Time, Time/Sum]),
             time_error
     end;
-check_trace_info(Mfa, Expect, _) ->
-    case erlang:trace_info(Mfa, call_time) of
+check_trace_info_ret(Mfa, Expect, _, TraceInfo) ->
+    case TraceInfo of
         {call_time, Expect} ->
             ok;
         Other ->
-- 
2.35.3

Places

File 1222-erts-Cleanup-trace_call_time_SUITE-bif.patch of Package erlang (Revision 9c6f14cb59b6cc96e9e5afb6eccb708c)

Places