erts: Fix caller trace for apply bifs

Bifs that are called through the export entry
using i_call_last could have their cp set to
return_trace, just like any other call. So we
have to unwind the trace stack to get the correct
cp. Not doing this creates a lot of issues for
fprof.

2 files changed, 97 insertions, 36 deletions

diff --git a/erts/emulator/beam/beam_bp.c b/erts/emulator/beam/beam_bp.c
index 950639f7ae..069e7391fd 100644
--- a/erts/emulator/beam/beam_bp.c
+++ b/erts/emulator/beam/beam_bp.c
@@ -642,6 +642,49 @@ erts_clear_export_break(Module* modp, ErtsCodeInfo *ci)
     ASSERT(ci->u.gen_bp == NULL);
 }
 
+/*
+ * If c_p->cp is a trace return instruction, we set cp
+ * to be the place where we again start to execute code.
+ *
+ * cp is used by match spec {caller} to get the calling
+ * function, and if we don't do this fixup it will be
+ * 'undefined'. This has the odd side effect of {caller}
+ * not really being which function is the caller, but
+ * rather which function we are about to return to.
+ */
+static void fixup_cp_before_trace(Process *c_p, int *return_to_trace)
+{
+    Eterm *cpp, *E = c_p->stop;
+    BeamInstr w = *c_p->cp;
+    if (w == (BeamInstr) BeamOp(op_return_trace)) {
+        cpp = &E[2];
+    } else if (w == (BeamInstr) BeamOp(op_i_return_to_trace)) {
+        *return_to_trace = 1;
+        cpp = &E[0];
+    } else if (w == (BeamInstr) BeamOp(op_i_return_time_trace)) {
+        cpp = &E[0];
+    } else {
+        cpp = NULL;
+    }
+    if (cpp) {
+        for (;;) {
+            BeamInstr w = *cp_val(*cpp);
+            if (w == (BeamInstr) BeamOp(op_return_trace)) {
+                cpp += 3;
+            } else if (w == (BeamInstr) BeamOp(op_i_return_to_trace)) {
+                *return_to_trace = 1;
+                cpp += 1;
+            } else if (w == (BeamInstr) BeamOp(op_i_return_time_trace)) {
+                cpp += 2;
+            } else {
+                break;
+            }
+        }
+        c_p->cp = (BeamInstr *) cp_val(*cpp);
+        ASSERT(is_CP(*cpp));
+    }
+}
+
 BeamInstr
 erts_generic_breakpoint(Process* c_p, ErtsCodeInfo *info, Eterm* reg)
 {
@@ -752,6 +795,7 @@ erts_bif_trace(int bif_index, Process* p, Eterm* args, BeamInstr* I)
     GenericBp* g;
     GenericBpData* bp = NULL;
     Uint bp_flags = 0;
+    int return_to_trace = 0;
 
     ERTS_SMP_CHK_HAVE_ONLY_MAIN_PROC_LOCK(p);
 
@@ -767,6 +811,8 @@ erts_bif_trace(int bif_index, Process* p, Eterm* args, BeamInstr* I)
      */
     if (!applying) {
 	p->cp = I;
+    } else {
+        fixup_cp_before_trace(p, &return_to_trace);
     }
     if (bp_flags & (ERTS_BPF_LOCAL_TRACE|ERTS_BPF_GLOBAL_TRACE) &&
 	IS_TRACED_FL(p, F_TRACE_CALLS)) {
@@ -945,49 +991,20 @@ static ErtsTracer
 do_call_trace(Process* c_p, ErtsCodeInfo* info, Eterm* reg,
 	      int local, Binary* ms, ErtsTracer tracer)
 {
-    Eterm* cpp;
     int return_to_trace = 0;
-    BeamInstr w;
     BeamInstr *cp_save = c_p->cp;
     Uint32 flags;
     Uint need = 0;
     Eterm* E = c_p->stop;
 
-    w = *c_p->cp;
-    if (w == (BeamInstr) BeamOp(op_return_trace)) {
-	cpp = &E[2];
-    } else if (w == (BeamInstr) BeamOp(op_i_return_to_trace)) {
-	return_to_trace = 1;
-	cpp = &E[0];
-    } else if (w == (BeamInstr) BeamOp(op_i_return_time_trace)) {
-	cpp = &E[0];
-    } else {
-	cpp = NULL;
-    }
-    if (cpp) {
-	for (;;) {
-	    BeamInstr w = *cp_val(*cpp);
-	    if (w == (BeamInstr) BeamOp(op_return_trace)) {
-		cpp += 3;
-	    } else if (w == (BeamInstr) BeamOp(op_i_return_to_trace)) {
-		return_to_trace = 1;
-		cpp += 1;
-	    } else if (w == (BeamInstr) BeamOp(op_i_return_time_trace)) {
-		cpp += 2;
-	    } else {
-		break;
-	    }
-	}
-	cp_save = c_p->cp;
-	c_p->cp = (BeamInstr *) cp_val(*cpp);
-	ASSERT(is_CP(*cpp));
-    }
+    fixup_cp_before_trace(c_p, &return_to_trace);
+
     ERTS_SMP_UNREQ_PROC_MAIN_LOCK(c_p);
     flags = erts_call_trace(c_p, info, ms, reg, local, &tracer);
     ERTS_SMP_REQ_PROC_MAIN_LOCK(c_p);
-    if (cpp) {
-	c_p->cp = cp_save;
-    }
+
+    /* restore cp after potential fixup */
+    c_p->cp = cp_save;
 
     ASSERT(!ERTS_PROC_IS_EXITING(c_p));
     if ((flags & MATCH_SET_RETURN_TO_TRACE) && !return_to_trace) {
diff --git a/erts/emulator/test/match_spec_SUITE.erl b/erts/emulator/test/match_spec_SUITE.erl
index 92ddc23592..08a7b4560c 100644
--- a/erts/emulator/test/match_spec_SUITE.erl
+++ b/erts/emulator/test/match_spec_SUITE.erl
@@ -21,7 +21,7 @@
 -module(match_spec_SUITE).
 
 -export([all/0, suite/0, not_run/1]).
--export([test_1/1, test_2/1, test_3/1, bad_match_spec_bin/1,
+-export([test_1/1, test_2/1, test_3/1, caller_and_return_to/1, bad_match_spec_bin/1,
 	 trace_control_word/1, silent/1, silent_no_ms/1, silent_test/1,
 	 ms_trace2/1, ms_trace3/1, ms_trace_dead/1, boxed_and_small/1,
 	 destructive_in_test_bif/1, guard_exceptions/1,
@@ -47,7 +47,7 @@ suite() ->
 all() -> 
     case test_server:is_native(match_spec_SUITE) of
 	false ->
-	    [test_1, test_2, test_3, bad_match_spec_bin,
+	    [test_1, test_2, test_3, caller_and_return_to, bad_match_spec_bin,
 	     trace_control_word, silent, silent_no_ms, silent_test, ms_trace2,
 	     ms_trace3, ms_trace_dead, boxed_and_small, destructive_in_test_bif,
 	     guard_exceptions, unary_plus, unary_minus, fpe,
@@ -180,6 +180,50 @@ test_3(Config) when is_list(Config) ->
     collect(P1, [{trace, P1, call, {?MODULE, f2, [a, b]}, [true]}]),
     ok.
 
+%% Test that caller and return to work as they should
+%% There was a bug where caller would be undefined when return_to was set
+%% for r the bif erlang:put().
+caller_and_return_to(Config) ->
+    tr(
+      fun do_put_wrapper/0,
+      fun (Tracee) ->
+              MsgCaller = [{'_',[],[{message,{caller}}]}],
+              1 = erlang:trace(Tracee, true, [call,return_to]),
+              1 = erlang:trace_pattern( {?MODULE,do_put,1}, MsgCaller, [local]),
+              1 = erlang:trace_pattern( {?MODULE,do_the_put,1}, MsgCaller, [local]),
+              1 = erlang:trace_pattern( {erlang,integer_to_list,1}, MsgCaller, [local]),
+              1 = erlang:trace_pattern( {erlang,put,2}, MsgCaller, [local]),
+
+              [{trace,Tracee,call,{?MODULE,do_put,[test]},{?MODULE,do_put_wrapper,0}},
+               {trace,Tracee,call,{?MODULE,do_the_put,[test]},{?MODULE,do_put,1}},
+               {trace,Tracee,call,{erlang,integer_to_list,[1]},{?MODULE,do_the_put,1}},
+               {trace,Tracee,return_to,{?MODULE,do_the_put,1}},
+               {trace,Tracee,call,{erlang,put,[test,"1"]},{?MODULE,do_put,1}},
+               {trace,Tracee,return_to,{?MODULE,do_put,1}},
+
+               %% These last trace messages are a bit strange...
+               %% if call tracing had been enabled for do_put_wrapper
+               %% then caller and return_to would have been {?MODULE,do_put_wrapper,1}
+               %% but since it is not, they are set to do_put instead, but we still
+               %% get the do_put_wrapper return_to message...
+               {trace,Tracee,call,{erlang,integer_to_list,[2]},{?MODULE,do_put,1}},
+               {trace,Tracee,return_to,{?MODULE,do_put,1}},
+               {trace,Tracee,return_to,{?MODULE,do_put_wrapper,0}}
+              ]
+      end),
+    ok.
+
+do_put_wrapper() ->
+    do_put(test),
+    ok.
+
+do_put(Var) ->
+    do_the_put(Var),
+    erlang:integer_to_list(id(2)).
+do_the_put(Var) ->
+    Lst = erlang:integer_to_list(id(1)),
+    erlang:put(Var, Lst).
+
 otp_9422(Config) when is_list(Config) ->
     Laps = 10000,
     Fun1 = fun() -> otp_9422_tracee() end,