From 6cb6b59cd4cd5bd4383053e12ae8ab192711c827 Mon Sep 17 00:00:00 2001 From: Lukas Larsson Date: Mon, 8 Feb 2016 18:31:43 +0100 Subject: erts: Extend process and port tracing This commit completes the tracing for processes so that all messages sent by a process (via nifs or otherwise) will be traced. The commit also adds tracing of all types of events from ports. When enabling tracing using erlang:trace, the 'all' flag now also enables tracing on all ports. OTP-13496 --- erts/emulator/beam/atom.names | 7 + erts/emulator/beam/bif.c | 35 ++-- erts/emulator/beam/dist.c | 4 +- erts/emulator/beam/erl_bif_port.c | 24 +-- erts/emulator/beam/erl_bif_trace.c | 70 ++++++-- erts/emulator/beam/erl_message.c | 6 +- erts/emulator/beam/erl_nif.c | 14 +- erts/emulator/beam/erl_port.h | 2 +- erts/emulator/beam/erl_port_task.c | 2 + erts/emulator/beam/erl_process.c | 4 +- erts/emulator/beam/erl_process.h | 19 +- erts/emulator/beam/erl_trace.c | 345 ++++++++++++++++++++++++++++++++----- erts/emulator/beam/erl_trace.h | 17 +- erts/emulator/beam/io.c | 236 +++++++++++++++++++------ erts/emulator/beam/register.c | 6 +- 15 files changed, 628 insertions(+), 163 deletions(-) (limited to 'erts/emulator/beam') diff --git a/erts/emulator/beam/atom.names b/erts/emulator/beam/atom.names index aeea6cc989..bd1005867c 100644 --- a/erts/emulator/beam/atom.names +++ b/erts/emulator/beam/atom.names @@ -161,6 +161,7 @@ atom close atom closed atom code atom command +atom commandv atom compact atom compat_rel atom compile @@ -245,6 +246,9 @@ atom exact_reductions atom exclusive atom exit_status atom existing +atom existing_processes +atom existing_ports +atom existing atom exiting atom exports atom external @@ -404,6 +408,8 @@ atom net_kernel_terminated atom never_utf atom new atom new_index +atom new_processes +atom new_ports atom new_uniq atom newline atom next @@ -543,6 +549,7 @@ atom scheme atom scientific atom scope atom seconds +atom send_to_non_existing_process atom sensitive atom sequential_tracer atom sequential_trace_token diff --git a/erts/emulator/beam/bif.c b/erts/emulator/beam/bif.c index d633a982ca..ed5b2983dd 100644 --- a/erts/emulator/beam/bif.c +++ b/erts/emulator/beam/bif.c @@ -1911,7 +1911,7 @@ static Sint remote_send(Process *p, DistEntry *dep, } if (res >= 0) { - if (IS_TRACED(p)) + if (IS_TRACED_FL(p, F_TRACE_SEND)) trace_send(p, full_to, msg); if (ERTS_PROC_GET_SAVED_CALLS_BUF(p)) save_calls(p, &exp_send); @@ -1930,7 +1930,7 @@ do_send(Process *p, Eterm to, Eterm msg, Eterm *refp, ErtsSendContext* ctx) Eterm* tp; if (is_internal_pid(to)) { - if (IS_TRACED(p)) + if (IS_TRACED_FL(p, F_TRACE_SEND)) trace_send(p, to, msg); if (ERTS_PROC_GET_SAVED_CALLS_BUF(p)) save_calls(p, &exp_send); @@ -1959,7 +1959,7 @@ do_send(Process *p, Eterm to, Eterm msg, Eterm *refp, ErtsSendContext* ctx) rp = erts_proc_lookup_raw(id); if (rp) { - if (IS_TRACED(p)) + if (IS_TRACED_FL(p, F_TRACE_SEND)) trace_send(p, to, msg); if (ERTS_PROC_GET_SAVED_CALLS_BUF(p)) save_calls(p, &exp_send); @@ -1975,7 +1975,7 @@ do_send(Process *p, Eterm to, Eterm msg, Eterm *refp, ErtsSendContext* ctx) goto port_common; } - if (IS_TRACED(p)) + if (IS_TRACED_FL(p, F_TRACE_SEND)) trace_send(p, to, msg); if (ERTS_PROC_GET_SAVED_CALLS_BUF(p)) save_calls(p, &exp_send); @@ -2006,11 +2006,20 @@ do_send(Process *p, Eterm to, Eterm msg, Eterm *refp, ErtsSendContext* ctx) port_common: ret_val = 0; - + if (pt) { int ps_flags = ctx->suspend ? 0 : ERTS_PORT_SIG_FLG_NOSUSPEND; *refp = NIL; + if (IS_TRACED_FL(p, F_TRACE_SEND)) /* trace once only !! */ + trace_send(p, portid, msg); + + if (have_seqtrace(SEQ_TRACE_TOKEN(p))) { + seq_trace_update_send(p); + seq_trace_output(SEQ_TRACE_TOKEN(p), msg, + SEQ_TRACE_SEND, portid, p); + } + switch (erts_port_command(p, ps_flags, pt, msg, refp)) { case ERTS_PORT_OP_CALLER_EXIT: /* We are exiting... */ @@ -2043,18 +2052,10 @@ do_send(Process *p, Eterm to, Eterm msg, Eterm *refp, ErtsSendContext* ctx) break; } } - - if (IS_TRACED(p)) /* trace once only !! */ - trace_send(p, portid, msg); + if (ERTS_PROC_GET_SAVED_CALLS_BUF(p)) save_calls(p, &exp_send); - - if (have_seqtrace(SEQ_TRACE_TOKEN(p))) { - seq_trace_update_send(p); - seq_trace_output(SEQ_TRACE_TOKEN(p), msg, - SEQ_TRACE_SEND, portid, p); - } - + if (ERTS_PROC_IS_EXITING(p)) { KILL_CATCHES(p); /* Must exit */ return SEND_USER_ERROR; @@ -2077,7 +2078,7 @@ do_send(Process *p, Eterm to, Eterm msg, Eterm *refp, ErtsSendContext* ctx) if (dep == erts_this_dist_entry) { Eterm id; erts_deref_dist_entry(dep); - if (IS_TRACED(p)) + if (IS_TRACED_FL(p, F_TRACE_SEND)) trace_send(p, to, msg); if (ERTS_PROC_GET_SAVED_CALLS_BUF(p)) save_calls(p, &exp_send); @@ -2108,7 +2109,7 @@ do_send(Process *p, Eterm to, Eterm msg, Eterm *refp, ErtsSendContext* ctx) } return ret; } else { - if (IS_TRACED(p)) /* XXX Is this really neccessary ??? */ + if (IS_TRACED_FL(p, F_TRACE_SEND)) trace_send(p, to, msg); if (ERTS_PROC_GET_SAVED_CALLS_BUF(p)) save_calls(p, &exp_send); diff --git a/erts/emulator/beam/dist.c b/erts/emulator/beam/dist.c index 8cd3f5fbe6..52fd57e101 100644 --- a/erts/emulator/beam/dist.c +++ b/erts/emulator/beam/dist.c @@ -1723,7 +1723,7 @@ decode_error: } data_error: UnUseTmpHeapNoproc(DIST_CTL_DEFAULT_SIZE); - erts_deliver_port_exit(prt, dep->cid, am_killed, 0); + erts_deliver_port_exit(prt, dep->cid, am_killed, 0, 1); ERTS_SMP_CHK_NO_PROC_LOCKS; return -1; } @@ -2093,7 +2093,7 @@ erts_dist_command(Port *prt, int reds_limit) erts_smp_de_runlock(dep); if (status & ERTS_DE_SFLG_EXITING) { - erts_deliver_port_exit(prt, prt->common.id, am_killed, 0); + erts_deliver_port_exit(prt, prt->common.id, am_killed, 0, 1); erts_deref_dist_entry(dep); return reds + ERTS_PORT_REDS_DIST_CMD_EXIT; } diff --git a/erts/emulator/beam/erl_bif_port.c b/erts/emulator/beam/erl_bif_port.c index eb55bd585e..37f4e1de49 100644 --- a/erts/emulator/beam/erl_bif_port.c +++ b/erts/emulator/beam/erl_bif_port.c @@ -110,6 +110,10 @@ BIF_RETTYPE erts_internal_open_port_2(BIF_ALIST_2) erts_add_link(&ERTS_P_LINKS(port), LINK_PID, BIF_P->common.id); erts_add_link(&ERTS_P_LINKS(BIF_P), LINK_PID, port->common.id); + if (IS_TRACED_FL(BIF_P, F_TRACE_PROCS)) + trace_proc(BIF_P, ERTS_PROC_LOCK_MAIN|ERTS_PROC_LOCK_LINK, BIF_P, + am_link, port->common.id); + erts_smp_proc_unlock(BIF_P, ERTS_PROC_LOCK_LINK); erts_port_release(port); @@ -340,8 +344,7 @@ BIF_RETTYPE erts_internal_port_close_1(BIF_ALIST_1) if (!prt) BIF_RET(am_badarg); - - switch (erts_port_exit(BIF_P, 0, prt, prt->common.id, am_normal, &ref)) { + switch (erts_port_exit(BIF_P, 0, prt, BIF_P->common.id, am_normal, &ref)) { case ERTS_PORT_OP_CALLER_EXIT: case ERTS_PORT_OP_BADARG: case ERTS_PORT_OP_DROPPED: @@ -374,7 +377,7 @@ BIF_RETTYPE erts_internal_port_connect_2(BIF_ALIST_2) ref = NIL; #endif - switch (erts_port_connect(BIF_P, 0, prt, prt->common.id, BIF_ARG_2, &ref)) { + switch (erts_port_connect(BIF_P, 0, prt, BIF_P->common.id, BIF_ARG_2, &ref)) { case ERTS_PORT_OP_CALLER_EXIT: case ERTS_PORT_OP_BADARG: case ERTS_PORT_OP_DROPPED: @@ -929,21 +932,22 @@ open_port(Process* p, Eterm name, Eterm settings, int *err_typep, int *err_nump) DTRACE3(port_open, process_str, name_buf, port_str); } #endif + + if (port && IS_TRACED_FL(port, F_TRACE_PORTS)) + trace_port(port, am_getting_linked, p->common.id); + erts_smp_proc_lock(p, ERTS_PROC_LOCK_MAIN); + if (IS_TRACED_FL(p, F_TRACE_SCHED_PROCS)) { + trace_sched(p, ERTS_PROC_LOCK_MAIN, am_in); + } + if (!port) { DEBUGF(("open_driver returned (%d:%d)\n", err_typep ? *err_typep : 4711, err_nump ? *err_nump : 4711)); - if (IS_TRACED_FL(p, F_TRACE_SCHED_PROCS)) { - trace_sched(p, ERTS_PROC_LOCK_MAIN, am_in); - } goto do_return; } - - if (IS_TRACED_FL(p, F_TRACE_SCHED_PROCS)) { - trace_sched(p, ERTS_PROC_LOCK_MAIN, am_in); - } if (linebuf && port->linebuf == NULL){ port->linebuf = allocate_linebuf(linebuf); diff --git a/erts/emulator/beam/erl_bif_trace.c b/erts/emulator/beam/erl_bif_trace.c index 049899211f..7e2fe7fcd4 100644 --- a/erts/emulator/beam/erl_bif_trace.c +++ b/erts/emulator/beam/erl_bif_trace.c @@ -487,7 +487,8 @@ start_trace(Process *c_p, ErtsTracer tracer, && !ERTS_TRACER_COMPARE(ERTS_TRACER(port), tracer)) { /* This tracee is already being traced, and not by the * tracer to be */ - if (erts_is_tracer_proc_enabled(c_p, ERTS_PROC_LOCKS_ALL, common)) { + if (erts_is_tracer_proc_enabled(c_p, ERTS_PROC_LOCKS_ALL, + common, am_trace_status)) { /* The tracer is still in use */ return 1; } @@ -654,18 +655,27 @@ Eterm erts_internal_trace_3(BIF_ALIST_3) } #endif - if (pid_spec == am_all || pid_spec == am_existing) { + if (pid_spec == am_all || pid_spec == am_existing || + pid_spec == am_ports || pid_spec == am_processes || + pid_spec == am_existing_ports || pid_spec == am_existing_processes + ) { int i; int procs = 0; int ports = 0; int mods = 0; if (mask & (ERTS_PROC_TRACEE_FLAGS & ~ERTS_TRACEE_MODIFIER_FLAGS)) - procs = 1; + procs = pid_spec != am_ports && pid_spec != am_existing_ports; if (mask & (ERTS_PORT_TRACEE_FLAGS & ~ERTS_TRACEE_MODIFIER_FLAGS)) - ports = 1; - if (mask & ERTS_TRACEE_MODIFIER_FLAGS) - mods = 1; + ports = pid_spec != am_processes && pid_spec != am_existing_processes; + if (mask & ERTS_TRACEE_MODIFIER_FLAGS) { + if (pid_spec == am_ports || pid_spec == am_existing_ports) + ports = 1; + else if (pid_spec == am_processes || pid_spec == am_existing_processes) + procs = 1; + else + mods = 1; + } #ifdef ERTS_SMP erts_smp_proc_unlock(p, ERTS_PROC_LOCK_MAIN); @@ -697,17 +707,25 @@ Eterm erts_internal_trace_3(BIF_ALIST_3) if (state & ERTS_PORT_SFLGS_DEAD) continue; start_trace(p, tracer, &tracee_port->common, on, mask); - /* matches are not counted for ports since it would violate compatibility */ - /* This could be a reason to modify this function or make a new one. */ + matches++; } } } - if (pid_spec == am_all || pid_spec == am_new) { - Uint def_flags = mask; + if (pid_spec == am_all || pid_spec == am_new + || pid_spec == am_ports || pid_spec == am_processes + || pid_spec == am_new_ports || pid_spec == am_new_processes + ) { ok = 1; - erts_change_default_tracing(on, &def_flags, tracer); + if (mask & ERTS_PROC_TRACEE_FLAGS && + pid_spec != am_ports && pid_spec != am_new_ports) + erts_change_default_proc_tracing( + on, mask & ERTS_PROC_TRACEE_FLAGS, tracer); + if (mask & ERTS_PORT_TRACEE_FLAGS && + pid_spec != am_processes && pid_spec != am_new_processes) + erts_change_default_port_tracing( + on, mask & ERTS_PORT_TRACEE_FLAGS, tracer); #ifdef HAVE_ERTS_NOW_CPU if (cpu_ts && !on) { @@ -773,7 +791,7 @@ Eterm trace_info_2(BIF_ALIST_2) if (What == am_on_load) { res = trace_info_on_load(p, Key); - } else if (is_atom(What) || is_pid(What)) { + } else if (is_atom(What) || is_pid(What) || is_port(What)) { res = trace_info_pid(p, What, Key); } else if (is_tuple(What)) { res = trace_info_func(p, What, Key); @@ -792,11 +810,32 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) Uint trace_flags = am_false; Eterm* hp; - if (pid_spec == am_new) { + if (pid_spec == am_new || pid_spec == am_new_processes) { + ErtsTracer def_tracer; + erts_get_default_proc_tracing(&trace_flags, &def_tracer); + tracer = erts_tracer_to_term(p, def_tracer); + ERTS_TRACER_CLEAR(&def_tracer); + } else if (pid_spec == am_new_ports) { ErtsTracer def_tracer; - erts_get_default_tracing(&trace_flags, &def_tracer); + erts_get_default_port_tracing(&trace_flags, &def_tracer); tracer = erts_tracer_to_term(p, def_tracer); ERTS_TRACER_CLEAR(&def_tracer); + } else if (is_internal_port(pid_spec)) { + Port *tracee; + tracee = erts_id2port_sflgs(pid_spec, p, ERTS_PROC_LOCK_MAIN, + ERTS_PORT_SFLGS_INVALID_LOOKUP); + + if (!tracee) + return am_undefined; + + if (!ERTS_TRACER_IS_NIL(ERTS_TRACER(tracee))) + erts_is_tracer_proc_enabled(NULL, 0, &tracee->common, am_trace_status); + + tracer = erts_tracer_to_term(p, ERTS_TRACER(tracee)); + trace_flags = ERTS_TRACE_FLAGS(tracee); + + erts_port_release(tracee); + } else if (is_internal_pid(pid_spec)) { Process *tracee; tracee = erts_pid2proc(p, ERTS_PROC_LOCK_MAIN, @@ -806,7 +845,8 @@ trace_info_pid(Process* p, Eterm pid_spec, Eterm key) return am_undefined; if (!ERTS_TRACER_IS_NIL(ERTS_TRACER(tracee))) - erts_is_tracer_proc_enabled(tracee, ERTS_PROC_LOCK_MAIN, &tracee->common); + erts_is_tracer_proc_enabled(tracee, ERTS_PROC_LOCK_MAIN, + &tracee->common, am_trace_status); tracer = erts_tracer_to_term(p, ERTS_TRACER(tracee)); trace_flags = ERTS_TRACE_FLAGS(tracee); diff --git a/erts/emulator/beam/erl_message.c b/erts/emulator/beam/erl_message.c index 1cb02ec274..9beff52835 100644 --- a/erts/emulator/beam/erl_message.c +++ b/erts/emulator/beam/erl_message.c @@ -596,7 +596,7 @@ erts_try_alloc_message_on_heap(Process *pp, #if defined(ERTS_SMP) *plp & ERTS_PROC_LOCK_MAIN #else - 1 + pp #endif ) { #ifdef ERTS_SMP @@ -626,7 +626,7 @@ erts_try_alloc_message_on_heap(Process *pp, *on_heap_p = !0; } #ifdef ERTS_SMP - else if (erts_smp_proc_trylock(pp, ERTS_PROC_LOCK_MAIN) == 0) { + else if (pp && erts_smp_proc_trylock(pp, ERTS_PROC_LOCK_MAIN) == 0) { locked_main = 1; *psp = erts_smp_atomic32_read_nob(&pp->state); *plp |= ERTS_PROC_LOCK_MAIN; @@ -1488,7 +1488,7 @@ erts_factory_message_create(ErtsHeapFactory* factory, int on_heap; erts_aint32_t state; - state = erts_smp_atomic32_read_nob(&proc->state); + state = proc ? erts_smp_atomic32_read_nob(&proc->state) : 0; if (state & ERTS_PSFLG_OFF_HEAP_MSGQ) { msgp = erts_alloc_message(sz, &hp); diff --git a/erts/emulator/beam/erl_nif.c b/erts/emulator/beam/erl_nif.c index f35c08450c..59a2b20ff2 100644 --- a/erts/emulator/beam/erl_nif.c +++ b/erts/emulator/beam/erl_nif.c @@ -417,6 +417,7 @@ enif_send(ErlNifEnv* env, const ErlNifPid* to_pid, ? erts_proc_lookup(receiver) : erts_pid2proc_opt(c_p, ERTS_PROC_LOCK_MAIN, receiver, rp_locks, ERTS_P2P_FLG_INC_REFC)); + if (rp == NULL) { ASSERT(env == NULL || receiver != c_p->common.id); return 0; @@ -450,9 +451,17 @@ enif_send(ErlNifEnv* env, const ErlNifPid* to_pid, } if (!env || !env->tracee) { - erts_queue_message(rp, &rp_locks, mp, msg); + + if (c_p && IS_TRACED_FL(c_p, F_TRACE_SEND)) + trace_send(c_p, receiver, msg); + +#ifndef ERTS_SMP } +#endif + + erts_queue_message(rp, &rp_locks, mp, msg); #ifdef ERTS_SMP + } else { /* This clause is taken when the nif is called in the context of a traced process. We do not know which locks we have @@ -548,6 +557,9 @@ enif_port_command(ErlNifEnv *env, const ErlNifPort* to_port, if (!prt) return 0; + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, env->proc->common.id, am_command, msg); + return erts_port_output_async(prt, env->proc->common.id, msg); } diff --git a/erts/emulator/beam/erl_port.h b/erts/emulator/beam/erl_port.h index 59aa034f48..c2588e718d 100644 --- a/erts/emulator/beam/erl_port.h +++ b/erts/emulator/beam/erl_port.h @@ -944,7 +944,7 @@ erts_schedule_proc2port_signal(Process *, ErtsPortTaskHandle *, ErtsProc2PortSigCallback); -int erts_deliver_port_exit(Port *, Eterm, Eterm, int); +int erts_deliver_port_exit(Port *, Eterm, Eterm, int, int); /* * Port signal flags diff --git a/erts/emulator/beam/erl_port_task.c b/erts/emulator/beam/erl_port_task.c index 30ce181ebb..3102e44c11 100644 --- a/erts/emulator/beam/erl_port_task.c +++ b/erts/emulator/beam/erl_port_task.c @@ -1766,6 +1766,8 @@ erts_port_task_execute(ErtsRunQueue *runq, Port **curr_port_pp) if (!(state & ERTS_PORT_SFLGS_DEAD)) { DTRACE_DRIVER(driver_timeout, pp); LTTNG_DRIVER(driver_timeout, pp); + if (IS_TRACED_FL(pp, F_TRACE_RECEIVE)) + trace_port(pp, am_receive, am_timeout); (*pp->drv_ptr->timeout)((ErlDrvData) pp->drv_data); } } diff --git a/erts/emulator/beam/erl_process.c b/erts/emulator/beam/erl_process.c index e7d0d127e2..1398bc9c61 100644 --- a/erts/emulator/beam/erl_process.c +++ b/erts/emulator/beam/erl_process.c @@ -2312,7 +2312,7 @@ handle_reap_ports(ErtsAuxWorkData *awdp, erts_aint32_t aux_work, int waiting) ERTS_PORT_SFLG_HALT); erts_smp_atomic32_inc_nob(&erts_halt_progress); if (!(state & (ERTS_PORT_SFLG_EXITING|ERTS_PORT_SFLG_CLOSING))) - erts_deliver_port_exit(prt, prt->common.id, am_killed, 0); + erts_deliver_port_exit(prt, prt->common.id, am_killed, 0, 1); } erts_port_release(prt); @@ -11103,7 +11103,7 @@ erl_create_process(Process* parent, /* Parent of process (default group leader). : STORE_NC(&p->htop, &p->off_heap, parent->group_leader); } - erts_get_default_tracing(&ERTS_TRACE_FLAGS(p), &ERTS_TRACER(p)); + erts_get_default_proc_tracing(&ERTS_TRACE_FLAGS(p), &ERTS_TRACER(p)); p->msg.first = NULL; p->msg.last = &p->msg.first; diff --git a/erts/emulator/beam/erl_process.h b/erts/emulator/beam/erl_process.h index 8261ae28f8..61acf5924b 100644 --- a/erts/emulator/beam/erl_process.h +++ b/erts/emulator/beam/erl_process.h @@ -1409,12 +1409,14 @@ extern int erts_system_profile_ts_type; | F_TRACE_SCHED_PORTS | F_TRACE_SCHED_NO \ | F_TRACE_SCHED_EXIT) + #define ERTS_TRACEE_MODIFIER_FLAGS \ - (F_TRACE_SILENT | F_TIMESTAMP_MASK | F_TRACE_SCHED_NO) -#define ERTS_PORT_TRACEE_FLAGS \ - (ERTS_TRACEE_MODIFIER_FLAGS | F_TRACE_PORTS | F_TRACE_SCHED_PORTS) + (F_TRACE_SILENT | F_TIMESTAMP_MASK | F_TRACE_SCHED_NO \ + | F_TRACE_RECEIVE | F_TRACE_SEND) +#define ERTS_PORT_TRACEE_FLAGS \ + (ERTS_TRACEE_MODIFIER_FLAGS | F_TRACE_PORTS | F_TRACE_SCHED_PORTS) #define ERTS_PROC_TRACEE_FLAGS \ - ((TRACEE_FLAGS & ~ERTS_PORT_TRACEE_FLAGS) | ERTS_TRACEE_MODIFIER_FLAGS) + ((TRACEE_FLAGS & ~ERTS_PORT_TRACEE_FLAGS) | ERTS_TRACEE_MODIFIER_FLAGS) #define SEQ_TRACE_FLAG(N) (1 << (ERTS_TRACE_TS_TYPE_BITS + (N))) @@ -2326,14 +2328,17 @@ erts_alloc_message_heap_state(Process *pp, ErlOffHeap **ohpp) { int on_heap; + ErtsMessage *mp; if ((*psp) & ERTS_PSFLG_OFF_HEAP_MSGQ) { - ErtsMessage *mp = erts_alloc_message(sz, hpp); + mp = erts_alloc_message(sz, hpp); *ohpp = sz == 0 ? NULL : &mp->hfrag.off_heap; return mp; } - return erts_try_alloc_message_on_heap(pp, psp, plp, sz, hpp, ohpp, &on_heap); + mp = erts_try_alloc_message_on_heap(pp, psp, plp, sz, hpp, ohpp, &on_heap); + ASSERT(pp || !on_heap); + return mp; } ERTS_GLB_INLINE ErtsMessage * @@ -2343,7 +2348,7 @@ erts_alloc_message_heap(Process *pp, Eterm **hpp, ErlOffHeap **ohpp) { - erts_aint32_t state = erts_smp_atomic32_read_nob(&pp->state); + erts_aint32_t state = pp ? erts_smp_atomic32_read_nob(&pp->state) : 0; return erts_alloc_message_heap_state(pp, &state, plp, sz, hpp, ohpp); } diff --git a/erts/emulator/beam/erl_trace.c b/erts/emulator/beam/erl_trace.c index 1e6ae8c82e..5ba58e9350 100644 --- a/erts/emulator/beam/erl_trace.c +++ b/erts/emulator/beam/erl_trace.c @@ -52,8 +52,10 @@ Export exp_send, exp_receive, exp_timeout; static ErtsTracer system_seq_tracer; -static Uint default_trace_flags; -static ErtsTracer default_tracer; +static Uint default_proc_trace_flags; +static ErtsTracer default_proc_tracer; +static Uint default_port_trace_flags; +static ErtsTracer default_port_tracer; static Eterm system_monitor; static Eterm system_profile; @@ -327,8 +329,10 @@ void erts_init_trace(void) { erts_bif_trace_init(); erts_system_monitor_clear(NULL); erts_system_profile_clear(NULL); - default_trace_flags = F_INITIAL_TRACE_FLAGS; - default_tracer = erts_tracer_nil; + default_proc_trace_flags = F_INITIAL_TRACE_FLAGS; + default_proc_tracer = erts_tracer_nil; + default_port_trace_flags = F_INITIAL_TRACE_FLAGS; + default_port_tracer = erts_tracer_nil; system_seq_tracer = erts_tracer_nil; #ifdef ERTS_SMP init_sys_msg_dispatcher(); @@ -456,56 +460,111 @@ erts_get_system_seq_tracer(void) } static ERTS_INLINE void -get_default_tracing(Uint *flagsp, ErtsTracer *tracerp) +get_default_tracing(Uint *flagsp, ErtsTracer *tracerp, + Uint *default_trace_flags, + ErtsTracer *default_tracer) { - if (!(default_trace_flags & TRACEE_FLAGS)) - ERTS_TRACER_CLEAR(&default_tracer); + if (!(*default_trace_flags & TRACEE_FLAGS)) + ERTS_TRACER_CLEAR(default_tracer); - if (ERTS_TRACER_IS_NIL(default_tracer)) { - default_trace_flags &= ~TRACEE_FLAGS; + if (ERTS_TRACER_IS_NIL(*default_tracer)) { + *default_trace_flags &= ~TRACEE_FLAGS; } else { Eterm nif_result = call_enabled_tracer( - NULL, default_tracer, NULL, + NULL, *default_tracer, NULL, am_trace_status, am_undefined); switch (nif_result) { case am_trace: break; - default: - default_trace_flags &= ~TRACEE_FLAGS; - ERTS_TRACER_CLEAR(&default_tracer); + default: { + ErtsTracer curr_default_tracer = *default_tracer; + if (tracerp) { + /* we only have a rlock, so we have to unlock and then rwlock */ + erts_smp_rwmtx_runlock(&sys_trace_rwmtx); + erts_smp_rwmtx_rwlock(&sys_trace_rwmtx); + } + /* check if someone else changed default tracer + while we got the write lock, if so we don't do + anything. */ + if (curr_default_tracer == *default_tracer) { + *default_trace_flags &= ~TRACEE_FLAGS; + ERTS_TRACER_CLEAR(default_tracer); + } + if (tracerp) { + erts_smp_rwmtx_rwunlock(&sys_trace_rwmtx); + erts_smp_rwmtx_rlock(&sys_trace_rwmtx); + } + } } } if (flagsp) - *flagsp = default_trace_flags; + *flagsp = *default_trace_flags; if (tracerp) { - erts_tracer_update(tracerp,default_tracer); + erts_tracer_update(tracerp,*default_tracer); } } +static ERTS_INLINE void +erts_change_default_tracing(int setflags, Uint flags, + const ErtsTracer tracer, + Uint *default_trace_flags, + ErtsTracer *default_tracer) +{ + if (setflags) + *default_trace_flags |= flags; + else + *default_trace_flags &= ~flags; + + erts_tracer_update(default_tracer, tracer); + + get_default_tracing(NULL, NULL, default_trace_flags, default_tracer); +} + void -erts_change_default_tracing(int setflags, Uint *flagsp, - const ErtsTracer tracer) +erts_change_default_proc_tracing(int setflags, Uint flagsp, + const ErtsTracer tracer) { erts_smp_rwmtx_rwlock(&sys_trace_rwmtx); - if (flagsp) { - if (setflags) - default_trace_flags |= *flagsp; - else - default_trace_flags &= ~(*flagsp); - } - - erts_tracer_update(&default_tracer, tracer); + erts_change_default_tracing( + setflags, flagsp, tracer, + &default_proc_trace_flags, + &default_proc_tracer); + erts_smp_rwmtx_rwunlock(&sys_trace_rwmtx); +} - get_default_tracing(flagsp, NULL); +void +erts_change_default_port_tracing(int setflags, Uint flagsp, + const ErtsTracer tracer) +{ + erts_smp_rwmtx_rwlock(&sys_trace_rwmtx); + erts_change_default_tracing( + setflags, flagsp, tracer, + &default_port_trace_flags, + &default_port_tracer); erts_smp_rwmtx_rwunlock(&sys_trace_rwmtx); } void -erts_get_default_tracing(Uint *flagsp, ErtsTracer *tracerp) +erts_get_default_proc_tracing(Uint *flagsp, ErtsTracer *tracerp) +{ + erts_smp_rwmtx_rlock(&sys_trace_rwmtx); + *tracerp = erts_tracer_nil; /* initialize */ + get_default_tracing( + flagsp, tracerp, + &default_proc_trace_flags, + &default_proc_tracer); + erts_smp_rwmtx_runlock(&sys_trace_rwmtx); +} + +void +erts_get_default_port_tracing(Uint *flagsp, ErtsTracer *tracerp) { erts_smp_rwmtx_rlock(&sys_trace_rwmtx); *tracerp = erts_tracer_nil; /* initialize */ - get_default_tracing(flagsp, tracerp); + get_default_tracing( + flagsp, tracerp, + &default_port_trace_flags, + &default_port_tracer); erts_smp_rwmtx_runlock(&sys_trace_rwmtx); } @@ -710,9 +769,7 @@ trace_send(Process *p, Eterm to, Eterm msg) Eterm operation = am_send; ErtsTracerNif *tnif = NULL; - if (!ARE_TRACE_FLAGS_ON(p, F_TRACE_SEND)) { - return; - } + ASSERT(ARE_TRACE_FLAGS_ON(p, F_TRACE_SEND)); if (is_internal_pid(to)) { if (!erts_proc_lookup(to)) @@ -720,10 +777,8 @@ trace_send(Process *p, Eterm to, Eterm msg) } else if(is_external_pid(to) && external_pid_dist_entry(to) == erts_this_dist_entry) { - char *s; send_to_non_existing_process: - s = "send_to_non_existing_process"; - operation = am_atom_put(s, sys_strlen(s)); + operation = am_send_to_non_existing_process; } if (is_tracer_proc_enabled(p, ERTS_PROC_LOCK_MAIN, &p->common, &tnif, operation)) @@ -1666,9 +1721,11 @@ profile_scheduler_q(Eterm scheduler_id, Eterm state, Eterm no_schedulers, Uint M void trace_port_open(Port *p, Eterm calling_pid, Eterm drv_name) { - - send_to_tracer_nif(NULL, &p->common, calling_pid, NULL, am_open, - p->common.id, drv_name); + ErtsTracerNif *tnif = NULL; + ERTS_SMP_CHK_NO_PROC_LOCKS; + if (is_tracer_proc_enabled(NULL, 0, &p->common, &tnif, am_open)) + send_to_tracer_nif(NULL, &p->common, p->common.id, tnif, am_open, + calling_pid, drv_name); } /* Sends trace message: @@ -1681,10 +1738,208 @@ trace_port_open(Port *p, Eterm calling_pid, Eterm drv_name) { void trace_port(Port *t_p, Eterm what, Eterm data) { + ErtsTracerNif *tnif = NULL; ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(t_p) || erts_thr_progress_is_blocking()); - send_to_tracer_nif(NULL, &t_p->common, t_p->common.id, NULL, - am_open, data, THE_NON_VALUE); + ERTS_SMP_CHK_NO_PROC_LOCKS; + if (is_tracer_proc_enabled(NULL, 0, &t_p->common, &tnif, what)) + send_to_tracer_nif(NULL, &t_p->common, t_p->common.id, tnif, + what, data, THE_NON_VALUE); +} + + +static Eterm +trace_port_tmp_binary(char *bin, Sint sz, Binary **bptrp, Eterm **hp) +{ + if (sz <= ERL_ONHEAP_BIN_LIMIT) { + ErlHeapBin *hb = (ErlHeapBin *)*hp; + hb->thing_word = header_heap_bin(sz); + hb->size = sz; + sys_memcpy(hb->data, bin, sz); + *hp += heap_bin_size(sz); + return make_binary(hb); + } else { + ProcBin* pb = (ProcBin *)*hp; + Binary *bptr = erts_bin_nrml_alloc(sz); + erts_refc_init(&bptr->refc, 1); + sys_memcpy(bptr->orig_bytes, bin, sz); + pb->thing_word = HEADER_PROC_BIN; + pb->size = sz; + pb->next = NULL; + pb->val = bptr; + pb->bytes = (byte*) bptr->orig_bytes; + pb->flags = 0; + *bptrp = bptr; + *hp += PROC_BIN_SIZE; + return make_binary(pb); + } +} + +/* Sends trace message: + * {trace, PortPid, 'receive', {pid(), {command, iolist()}}} + * {trace, PortPid, 'receive', {pid(), {control, pid()}}} + * {trace, PortPid, 'receive', {pid(), exit}} + * + */ +void +trace_port_receive(Port *t_p, Eterm caller, Eterm what, ...) +{ + ErtsTracerNif *tnif = NULL; + ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(t_p) + || erts_thr_progress_is_blocking()); + ERTS_SMP_CHK_NO_PROC_LOCKS; + if (is_tracer_proc_enabled(NULL, 0, &t_p->common, &tnif, am_receive)) { + /* We can use a stack heap here, as the nif is called in the + context of a port */ +#define LOCAL_HEAP_SIZE (3 + 3 + heap_bin_size(ERL_ONHEAP_BIN_LIMIT) + 3) + DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); + + Eterm *hp, data, *orig_hp = NULL; + Binary *bptr = NULL; + va_list args; + UseTmpHeapNoproc(LOCAL_HEAP_SIZE); + hp = local_heap; + + if (what == am_close) { + data = what; + } else { + Eterm arg; + va_start(args, what); + if (what == am_command) { + char *bin = va_arg(args, char *); + Sint sz = va_arg(args, Sint); + va_end(args); + arg = trace_port_tmp_binary(bin, sz, &bptr, &hp); + } else if (what == am_call || what == am_control) { + unsigned int command = va_arg(args, unsigned int); + char *bin = va_arg(args, char *); + Sint sz = va_arg(args, Sint); + Eterm cmd; + va_end(args); + arg = trace_port_tmp_binary(bin, sz, &bptr, &hp); +#if defined(ARCH_32) + if (!IS_USMALL(0, command)) { + *hp = make_pos_bignum_header(1); + BIG_DIGIT(hp, 0) = (Uint)command; + cmd = make_big(hp); + hp += 2; + } else +#endif + { + cmd = make_small((Sint)command); + } + arg = TUPLE2(hp, cmd, arg); + hp += 3; + } else if (what == am_commandv) { + ErlIOVec *evp = va_arg(args, ErlIOVec*); + int i; + va_end(args); + if ((6 + evp->vsize * (2+PROC_BIN_SIZE+ERL_SUB_BIN_SIZE)) > LOCAL_HEAP_SIZE) { + hp = erts_alloc(ERTS_ALC_T_TMP, + (6 + evp->vsize * (2+PROC_BIN_SIZE+ERL_SUB_BIN_SIZE)) * sizeof(Eterm)); + orig_hp = hp; + } + arg = NIL; + /* Convert each element in the ErlIOVec to a sub bin that points + to a procbin. We don't have to increment the proc bin refc as + the port task keeps the reference alive. */ + for (i = evp->vsize-1; i >= 0; i--) { + if (evp->iov[i].iov_len) { + ProcBin* pb = (ProcBin*)hp; + ErlSubBin *sb; + ASSERT(evp->binv[i]); + pb->thing_word = HEADER_PROC_BIN; + pb->val = ErlDrvBinary2Binary(evp->binv[i]); + pb->size = pb->val->orig_size; + pb->next = NULL; + pb->bytes = (byte*) pb->val->orig_bytes; + pb->flags = 0; + hp += PROC_BIN_SIZE; + + sb = (ErlSubBin*) hp; + sb->thing_word = HEADER_SUB_BIN; + sb->size = evp->iov[i].iov_len; + sb->offs = (byte*)(evp->iov[i].iov_base) - pb->bytes; + sb->orig = make_binary(pb); + sb->bitoffs = 0; + sb->bitsize = 0; + sb->is_writable = 0; + hp += ERL_SUB_BIN_SIZE; + + arg = CONS(hp, make_binary(sb), arg); + hp += 2; + } + } + what = am_command; + } else { + arg = va_arg(args, Eterm); + va_end(args); + } + data = TUPLE2(hp, what, arg); + hp += 3; + } + + data = TUPLE2(hp, caller, data); + send_to_tracer_nif(NULL, &t_p->common, t_p->common.id, tnif, + am_receive, data, THE_NON_VALUE); + + if (bptr && erts_refc_dectest(&bptr->refc, 1) == 0) + erts_bin_free(bptr); + + if (orig_hp) + erts_free(ERTS_ALC_T_TMP, orig_hp); + + UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); + } +#undef LOCAL_HEAP_SIZE +} + +void +trace_port_send(Port *t_p, Eterm receiver, Eterm msg, int exists) +{ + ErtsTracerNif *tnif = NULL; + Eterm op = exists ? am_send : am_send_to_non_existing_process; + ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(t_p) + || erts_thr_progress_is_blocking()); + ERTS_SMP_CHK_NO_PROC_LOCKS; + if (is_tracer_proc_enabled(NULL, 0, &t_p->common, &tnif, op)) + send_to_tracer_nif(NULL, &t_p->common, t_p->common.id, tnif, + op, msg, receiver); +} + +void trace_port_send_binary(Port *t_p, Eterm to, Eterm what, char *bin, Sint sz) +{ + ErtsTracerNif *tnif = NULL; + ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(t_p) + || erts_thr_progress_is_blocking()); + ERTS_SMP_CHK_NO_PROC_LOCKS; + if (is_tracer_proc_enabled(NULL, 0, &t_p->common, &tnif, am_send)) { + Eterm msg; + Binary* bptr = NULL; +#define LOCAL_HEAP_SIZE (3 + 3 + heap_bin_size(ERL_ONHEAP_BIN_LIMIT)) + DeclareTmpHeapNoproc(local_heap,LOCAL_HEAP_SIZE); + + Eterm *hp; + + ERTS_CT_ASSERT(heap_bin_size(ERL_ONHEAP_BIN_LIMIT) >= PROC_BIN_SIZE); + UseTmpHeapNoproc(LOCAL_HEAP_SIZE); + hp = local_heap; + + msg = trace_port_tmp_binary(bin, sz, &bptr, &hp); + + msg = TUPLE2(hp, what, msg); + hp += 3; + msg = TUPLE2(hp, t_p->common.id, msg); + hp += 3; + + send_to_tracer_nif(NULL, &t_p->common, t_p->common.id, tnif, + am_send, msg, to); + if (bptr && erts_refc_dectest(&bptr->refc, 1) == 0) + erts_bin_free(bptr); + + UnUseTmpHeapNoproc(LOCAL_HEAP_SIZE); +#undef LOCAL_HEAP_SIZE + } } /* Send {trace_ts, Pid, What, {Mod, Func, Arity}, Timestamp} @@ -1702,9 +1957,13 @@ trace_sched_ports(Port *p, Eterm what) { void trace_sched_ports_where(Port *t_p, Eterm what, Eterm where) { - - send_to_tracer_nif(NULL, &t_p->common, t_p->common.id, - NULL, am_open, where, THE_NON_VALUE); + ErtsTracerNif *tnif = NULL; + ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(t_p) + || erts_thr_progress_is_blocking()); + ERTS_SMP_CHK_NO_PROC_LOCKS; + if (is_tracer_proc_enabled(NULL, 0, &t_p->common, &tnif, what)) + send_to_tracer_nif(NULL, &t_p->common, t_p->common.id, + tnif, what, where, THE_NON_VALUE); } /* Port profiling */ @@ -2523,7 +2782,7 @@ is_tracer_proc_enabled(Process* c_p, ErtsProcLocks c_p_locks, } int erts_is_tracer_proc_enabled(Process* c_p, ErtsProcLocks c_p_locks, - ErtsPTabElementCommon *t_p) + ErtsPTabElementCommon *t_p, Eterm type) { return is_tracer_proc_enabled(c_p, c_p_locks, t_p, NULL, am_trace_status); } diff --git a/erts/emulator/beam/erl_trace.h b/erts/emulator/beam/erl_trace.h index 61f82a6b93..0fefd6f70d 100644 --- a/erts/emulator/beam/erl_trace.h +++ b/erts/emulator/beam/erl_trace.h @@ -68,9 +68,12 @@ ErtsTracer erts_set_system_seq_tracer(Process *c_p, ErtsProcLocks c_p_locks, ErtsTracer new); ErtsTracer erts_get_system_seq_tracer(void); -void erts_change_default_tracing(int setflags, Uint *flagsp, - const ErtsTracer tracerp); -void erts_get_default_tracing(Uint *flagsp, ErtsTracer *tracerp); +void erts_change_default_proc_tracing(int setflags, Uint flagsp, + const ErtsTracer tracerp); +void erts_get_default_proc_tracing(Uint *flagsp, ErtsTracer *tracerp); +void erts_change_default_port_tracing(int setflags, Uint flagsp, + const ErtsTracer tracerp); +void erts_get_default_port_tracing(Uint *flagsp, ErtsTracer *tracerp); void erts_set_system_monitor(Eterm monitor); Eterm erts_get_system_monitor(void); int erts_is_tracer_valid(Process* p); @@ -106,6 +109,9 @@ void trace_sched_ports(Port *pp, Eterm); void trace_sched_ports_where(Port *pp, Eterm, Eterm); void trace_port(Port *, Eterm what, Eterm data); void trace_port_open(Port *, Eterm calling_pid, Eterm drv_name); +void trace_port_receive(Port *, Eterm calling_pid, Eterm tag, ...); +void trace_port_send(Port *, Eterm to, Eterm msg, int exists); +void trace_port_send_binary(Port *, Eterm to, Eterm what, char *bin, Sint sz); /* system_profile */ void erts_set_system_profile(Eterm profile); @@ -177,7 +183,7 @@ int erts_finish_breakpointing(void); /* Nif tracer functions */ int erts_is_tracer_proc_enabled(Process *c_p, ErtsProcLocks c_p_locks, - ErtsPTabElementCommon *t_p); + ErtsPTabElementCommon *t_p, Eterm type); int erts_is_tracer_enabled(Process *c_p, const ErtsTracer tracer); Eterm erts_tracer_to_term(Process *p, ErtsTracer tracer); ErtsTracer erts_term_to_tracer(Eterm prefix, Eterm term); @@ -210,6 +216,7 @@ ERTS_DECLARE_DUMMY(erts_tracer_nil) = NIL; #define ERTS_TRACER_PROC_IS_ENABLED(PROC) \ (!ERTS_TRACER_IS_NIL(ERTS_TRACER(PROC)) \ - && erts_is_tracer_proc_enabled(PROC, ERTS_PROC_LOCK_MAIN, &(PROC)->common)) + && erts_is_tracer_proc_enabled(PROC, ERTS_PROC_LOCK_MAIN, \ + &(PROC)->common, am_trace_status)) #endif /* ERL_TRACE_H__ */ diff --git a/erts/emulator/beam/io.c b/erts/emulator/beam/io.c index a35c305046..18cfb1e641 100644 --- a/erts/emulator/beam/io.c +++ b/erts/emulator/beam/io.c @@ -88,7 +88,7 @@ int erts_port_parallelism = 0; static erts_atomic64_t bytes_in; static erts_atomic64_t bytes_out; -static void deliver_result(Eterm sender, Eterm pid, Eterm res); +static void deliver_result(Port *p, Eterm sender, Eterm pid, Eterm res); static int init_driver(erts_driver_t *, ErlDrvEntry *, DE_Handle *); static void terminate_port(Port *p); static void pdl_init(void); @@ -405,7 +405,7 @@ static Port *create_port(char *name, prt->os_pid = -1; /* Set default tracing */ - erts_get_default_tracing(&ERTS_TRACE_FLAGS(prt), &ERTS_TRACER(prt)); + erts_get_default_port_tracing(&ERTS_TRACE_FLAGS(prt), &ERTS_TRACER(prt)); ERTS_CT_ASSERT(offsetof(Port,common) == 0); @@ -710,7 +710,7 @@ erts_open_driver(erts_driver_t* driver, /* Pointer to driver. */ if (driver->start) { ERTS_MSACC_PUSH_STATE_M(); if (IS_TRACED_FL(port, F_TRACE_SCHED_PORTS)) { - trace_sched_ports_where(port, am_in, am_start); + trace_sched_ports_where(port, am_in, am_open); } port->caller = pid; #ifdef USE_VM_PROBES @@ -754,7 +754,7 @@ erts_open_driver(erts_driver_t* driver, /* Pointer to driver. */ ERTS_MSACC_POP_STATE_M(); port->caller = NIL; if (IS_TRACED_FL(port, F_TRACE_SCHED_PORTS)) { - trace_sched_ports_where(port, am_out, am_start); + trace_sched_ports_where(port, am_out, am_open); } #ifdef ERTS_SMP if (port->xports) @@ -1742,6 +1742,10 @@ call_driver_outputv(int bang_op, ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(prt) || ERTS_IS_CRASH_DUMPING); + + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, caller, am_commandv, evp); + #ifdef USE_VM_PROBES if (DTRACE_ENABLED(driver_outputv)) { DTRACE_FORMAT_COMMON_PID_AND_PORT(caller, prt); @@ -1868,6 +1872,9 @@ call_driver_output(int bang_op, } #endif + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, caller, am_command, bufp, size); + prt->caller = caller; (*drv->output)((ErlDrvData) prt->drv_data, bufp, size); prt->caller = NIL; @@ -2589,7 +2596,10 @@ call_deliver_port_exit(int bang_op, return ERTS_PORT_OP_DROPPED; } - if (!erts_deliver_port_exit(prt, from, reason, bang_op)) + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, from, am_close); + + if (!erts_deliver_port_exit(prt, from, reason, bang_op, broken_link)) return ERTS_PORT_OP_DROPPED; #ifdef USE_VM_PROBES @@ -2660,13 +2670,13 @@ erts_port_exit(Process *c_p, ERTS_PORT_SFLGS_INVALID_LOOKUP, 0, !refp, - am_exit); + am_close); switch (try_imm_drv_call(&try_call_state)) { case ERTS_TRY_IMM_DRV_CALL_OK: { res = call_deliver_port_exit(flags & ERTS_PORT_SIG_FLG_BANG_OP, - from, + c_p ? c_p->common.id : from, prt, try_call_state.state, reason, @@ -2745,8 +2755,11 @@ set_port_connected(int bang_op, return ERTS_PORT_OP_DROPPED; } + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, from, am_connect, connect); + ERTS_PORT_SET_CONNECTED(prt, connect); - deliver_result(prt->common.id, from, am_connected); + deliver_result(prt, prt->common.id, from, am_connected); #ifdef USE_VM_PROBES if(DTRACE_ENABLED(port_command)) { @@ -2768,10 +2781,22 @@ set_port_connected(int bang_op, erts_add_link(&ERTS_P_LINKS(rp), LINK_PID, prt->common.id); erts_add_link(&ERTS_P_LINKS(prt), LINK_PID, connect); + if (IS_TRACED_FL(rp, F_TRACE_PROCS)) + trace_proc(NULL, 0, rp, am_getting_linked, prt->common.id); + ERTS_PORT_SET_CONNECTED(prt, connect); erts_smp_proc_unlock(rp, ERTS_PROC_LOCK_LINK); + if (IS_TRACED_FL(prt, F_TRACE_PORTS)) + trace_port(prt, am_getting_linked, connect); + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, from, am_connect, connect); + if (IS_TRACED_FL(prt, F_TRACE_SEND)) { + Eterm hp[3]; + trace_port_send(prt, from, TUPLE2(hp, prt->common.id, am_connected), 1); + } + #ifdef USE_VM_PROBES if (DTRACE_ENABLED(port_connect)) { DTRACE_CHARBUF(process_str, DTRACE_TERM_BUF_SIZE); @@ -2874,8 +2899,11 @@ static void port_unlink(Port *prt, Eterm from) { ErtsLink *lnk = erts_remove_link(&ERTS_P_LINKS(prt), from); - if (lnk) + if (lnk) { + if (IS_TRACED_FL(prt, F_TRACE_PORTS)) + trace_port(prt, am_getting_unlinked, from); erts_destroy_link(lnk); + } } static int @@ -2945,7 +2973,7 @@ port_link_failure(Eterm port_id, Eterm linker) NIL, NULL, 0); - if (xres >= 0 && IS_TRACED_FL(rp, F_TRACE_PROCS)) { + if (xres >= 0) { /* We didn't exit the process and it is traced */ if (IS_TRACED_FL(rp, F_TRACE_PROCS)) trace_proc(NULL, 0, rp, am_getting_unlinked, port_id); @@ -2959,10 +2987,15 @@ port_link_failure(Eterm port_id, Eterm linker) static void port_link(Port *prt, erts_aint32_t state, Eterm to) { - if (!(state & ERTS_PORT_SFLGS_INVALID_LOOKUP)) + if (IS_TRACED_FL(prt, F_TRACE_PORTS)) + trace_port(prt, am_getting_linked, to); + if (!(state & ERTS_PORT_SFLGS_INVALID_LOOKUP)) { erts_add_link(&ERTS_P_LINKS(prt), LINK_PID, to); - else + } else { port_link_failure(prt->common.id, to); + if (IS_TRACED_FL(prt, F_TRACE_PORTS)) + trace_port(prt, am_unlink, to); + } } static int @@ -2970,8 +3003,13 @@ port_sig_link(Port *prt, erts_aint32_t state, int op, ErtsProc2PortSigData *sigd { if (op == ERTS_PROC2PORT_SIG_EXEC) port_link(prt, state, sigdp->u.link.to); - else + else { + if (IS_TRACED_FL(prt, F_TRACE_PORTS)) + trace_port(prt, am_getting_linked, sigdp->u.link.to); port_link_failure(sigdp->u.link.port, sigdp->u.link.to); + if (IS_TRACED_FL(prt, F_TRACE_PORTS)) + trace_port(prt, am_unlink, sigdp->u.link.to); + } if (sigdp->flags & ERTS_P2P_SIG_DATA_FLG_REPLY) port_sched_op_reply(sigdp->caller, sigdp->ref, am_true); return ERTS_PORT_REDS_LINK; @@ -3391,7 +3429,7 @@ static int read_linebuf(LineBufContext *bp) } static void -deliver_result(Eterm sender, Eterm pid, Eterm res) +deliver_result(Port *prt, Eterm sender, Eterm pid, Eterm res) { Process *rp; ErtsProcLocks rp_locks = 0; @@ -3399,12 +3437,22 @@ deliver_result(Eterm sender, Eterm pid, Eterm res) ERTS_SMP_CHK_NO_PROC_LOCKS; + ASSERT(!prt || prt->common.id == sender); +#ifdef ERTS_SMP + ASSERT(!prt || erts_lc_is_port_locked(prt)); +#endif + ASSERT(is_internal_port(sender) && is_internal_pid(pid)); rp = (scheduler ? erts_proc_lookup(pid) : erts_pid2proc_opt(NULL, 0, pid, 0, ERTS_P2P_FLG_INC_REFC)); + if (prt && IS_TRACED_FL(prt, F_TRACE_SEND)) { + Eterm hp[3]; + trace_port_send(prt, pid, TUPLE2(hp, sender, res), !!rp); + } + if (rp) { Eterm tuple; ErtsMessage *mp; @@ -3449,6 +3497,7 @@ static void deliver_read_message(Port* prt, erts_aint32_t state, Eterm to, ErlOffHeap *ohp; ErtsProcLocks rp_locks = 0; int scheduler = erts_get_scheduler_id() != 0; + int trace_send = IS_TRACED_FL(prt, F_TRACE_SEND); ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(prt)); ERTS_SMP_CHK_NO_PROC_LOCKS; @@ -3471,7 +3520,7 @@ static void deliver_read_message(Port* prt, erts_aint32_t state, Eterm to, if (!rp) return; - mp = erts_alloc_message_heap(rp, &rp_locks, need, &hp, &ohp); + mp = erts_alloc_message_heap(trace_send ? NULL : rp, &rp_locks, need, &hp, &ohp); listp = NIL; if ((state & ERTS_PORT_SFLG_BINARY_IO) == 0) { @@ -3513,6 +3562,9 @@ static void deliver_read_message(Port* prt, erts_aint32_t state, Eterm to, tuple = TUPLE2(hp, prt->common.id, tuple); hp += 3; + if (trace_send) + trace_port_send(prt, to, tuple, 1); + ERL_MESSAGE_TOKEN(mp) = am_undefined; erts_queue_message(rp, &rp_locks, mp, tuple); if (rp_locks) @@ -3593,6 +3645,7 @@ deliver_vec_message(Port* prt, /* Port */ ErtsProcLocks rp_locks = 0; int scheduler = erts_get_scheduler_id() != 0; erts_aint32_t state; + int trace_send = IS_TRACED_FL(prt, F_TRACE_SEND); ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(prt)); ERTS_SMP_CHK_NO_PROC_LOCKS; @@ -3620,7 +3673,7 @@ deliver_vec_message(Port* prt, /* Port */ need += (hlen+csize)*2; } - mp = erts_alloc_message_heap(rp, &rp_locks, need, &hp, &ohp); + mp = erts_alloc_message_heap(trace_send ? NULL : rp, &rp_locks, need, &hp, &ohp); listp = NIL; iov += vsize; @@ -3681,6 +3734,9 @@ deliver_vec_message(Port* prt, /* Port */ tuple = TUPLE2(hp, prt->common.id, tuple); hp += 3; + if (IS_TRACED_FL(prt, F_TRACE_SEND)) + trace_port_send(prt, to, tuple, 1); + ERL_MESSAGE_TOKEN(mp) = am_undefined; erts_queue_message(rp, &rp_locks, mp, tuple); erts_smp_proc_unlock(rp, rp_locks); @@ -3822,6 +3878,11 @@ terminate_port(Port *prt) ASSERT(!prt->xports); #endif } + + if (is_internal_port(send_closed_port_id) + && IS_TRACED_FL(prt, F_TRACE_SEND)) + trace_port_send(prt, connected_id, am_closed, 1); + if(drv->handle != NULL) { erts_smp_rwmtx_rlock(&erts_driver_list_lock); erts_ddll_decrement_port_count(drv->handle); @@ -3853,7 +3914,7 @@ terminate_port(Port *prt) erts_flush_async_exit(erts_halt_code, ""); } if (is_internal_port(send_closed_port_id)) - deliver_result(send_closed_port_id, connected_id, am_closed); + deliver_result(NULL, send_closed_port_id, connected_id, am_closed); } void @@ -3886,7 +3947,7 @@ static void sweep_one_monitor(ErtsMonitor *mon, void *vpsc) typedef struct { - Eterm port; + Port *port; Eterm reason; } SweepContext; @@ -3895,10 +3956,13 @@ static void sweep_one_link(ErtsLink *lnk, void *vpsc) SweepContext *psc = vpsc; DistEntry *dep; Process *rp; - + Eterm port_id = psc->port->common.id; ASSERT(lnk->type == LINK_PID); - + + if (IS_TRACED_FL(psc->port, F_TRACE_PORTS)) + trace_port(psc->port, am_unlink, lnk->pid); + if (is_external_pid(lnk->pid)) { dep = external_pid_dist_entry(lnk->pid); if(dep != erts_this_dist_entry) { @@ -3911,9 +3975,9 @@ static void sweep_one_link(ErtsLink *lnk, void *vpsc) case ERTS_DSIG_PREP_NOT_CONNECTED: break; case ERTS_DSIG_PREP_CONNECTED: - erts_remove_dist_link(&dld, psc->port, lnk->pid, dep); + erts_remove_dist_link(&dld, port_id, lnk->pid, dep); erts_destroy_dist_link(&dld); - code = erts_dsig_send_exit(&dsd, psc->port, lnk->pid, + code = erts_dsig_send_exit(&dsd, port_id, lnk->pid, psc->reason); ASSERT(code == ERTS_DSIG_SEND_OK); break; @@ -3927,23 +3991,25 @@ static void sweep_one_link(ErtsLink *lnk, void *vpsc) ASSERT(is_internal_pid(lnk->pid)); rp = erts_pid2proc(NULL, 0, lnk->pid, rp_locks); if (rp) { - ErtsLink *rlnk = erts_remove_link(&ERTS_P_LINKS(rp), psc->port); + ErtsLink *rlnk = erts_remove_link(&ERTS_P_LINKS(rp), port_id); if (rlnk) { int xres = erts_send_exit_signal(NULL, - psc->port, + port_id, rp, &rp_locks, psc->reason, NIL, NULL, 0); - if (xres >= 0 && IS_TRACED_FL(rp, F_TRACE_PROCS)) { + if (xres >= 0) { + if (rp_locks & ERTS_PROC_LOCKS_XSIG_SEND) { + erts_smp_proc_unlock(rp, ERTS_PROC_LOCKS_XSIG_SEND); + rp_locks &= ~ERTS_PROC_LOCKS_XSIG_SEND; + } /* We didn't exit the process and it is traced */ - if (IS_TRACED_FL(rp, F_TRACE_PROCS)) { - trace_proc(NULL, 0, rp, am_getting_unlinked, - psc->port); - } + if (IS_TRACED_FL(rp, F_TRACE_PROCS)) + trace_proc(NULL, 0, rp, am_getting_unlinked, port_id); } erts_destroy_link(rlnk); } @@ -3965,7 +4031,8 @@ static void sweep_one_link(ErtsLink *lnk, void *vpsc) */ int -erts_deliver_port_exit(Port *p, Eterm from, Eterm reason, int send_closed) +erts_deliver_port_exit(Port *p, Eterm from, Eterm reason, int send_closed, + int drop_normal) { ErtsLink *lnk; Eterm rreason; @@ -3995,8 +4062,10 @@ erts_deliver_port_exit(Port *p, Eterm from, Eterm reason, int send_closed) | ERTS_PORT_SFLG_CLOSING)) return 0; - if (reason == am_normal && from != ERTS_PORT_GET_CONNECTED(p) && from != p->common.id) + if (reason == am_normal && from != ERTS_PORT_GET_CONNECTED(p) + && from != p->common.id && drop_normal) { return 0; + } set_state_flags = ERTS_PORT_SFLG_EXITING; if (send_closed) @@ -4007,9 +4076,8 @@ erts_deliver_port_exit(Port *p, Eterm from, Eterm reason, int send_closed) state = erts_atomic32_read_bor_mb(&p->state, set_state_flags); state |= set_state_flags; - if (IS_TRACED_FL(p, F_TRACE_PORTS)) { + if (IS_TRACED_FL(p, F_TRACE_PORTS)) trace_port(p, am_closed, reason); - } erts_trace_check_exiting(p->common.id); @@ -4019,7 +4087,7 @@ erts_deliver_port_exit(Port *p, Eterm from, Eterm reason, int send_closed) (void) erts_unregister_name(NULL, 0, p, p->common.u.alive.reg->name); { - SweepContext sc = {p->common.id, rreason}; + SweepContext sc = {p, rreason}; lnk = ERTS_P_LINKS(p); ERTS_P_LINKS(p) = NULL; erts_sweep_links(lnk, &sweep_one_link, &sc); @@ -4141,7 +4209,10 @@ call_driver_control(Eterm caller, command, size); } #endif - + + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, caller, am_control, command, bufp, size); + ERTS_MSACC_SET_STATE_CACHED_M(ERTS_MSACC_STATE_PORT); #ifdef USE_LTTNG_VM_TRACEPOINTS @@ -4168,6 +4239,9 @@ call_driver_control(Eterm caller, if (cres < 0) return ERTS_PORT_OP_BADARG; + if (IS_TRACED_FL(prt, F_TRACE_SEND)) + trace_port_send_binary(prt, caller, am_control, *resp_bufp, cres); + *from_size = (ErlDrvSizeT) cres; return ERTS_PORT_OP_DONE; @@ -4577,6 +4651,9 @@ call_driver_call(Eterm caller, } #endif + if (IS_TRACED_FL(prt, F_TRACE_RECEIVE)) + trace_port_receive(prt, caller, am_call, command, bufp, size); + ERTS_MSACC_SET_STATE_CACHED_M(ERTS_MSACC_STATE_PORT); prt->caller = caller; @@ -4595,6 +4672,9 @@ call_driver_call(Eterm caller, || ((byte) (*resp_bufp)[0]) != VERSION_MAGIC) return ERTS_PORT_OP_BADARG; + if (IS_TRACED_FL(prt, F_TRACE_SEND)) + trace_port_send_binary(prt, caller, am_call, *resp_bufp, cres); + *from_size = (ErlDrvSizeT) cres; return ERTS_PORT_OP_DONE; @@ -5038,6 +5118,7 @@ reply_io_bytes(void *vreq) eout = erts_bld_uint64(&hp, NULL, out); msg = TUPLE4(hp, ref, make_small(sched_id), ein, eout); + erts_queue_message(rp, &rp_locks, mp, msg); if (req->sched_id == sched_id) @@ -5509,6 +5590,7 @@ void driver_report_exit(ErlDrvPort ix, int status) ErtsProcLocks rp_locks = 0; int scheduler = erts_get_scheduler_id() != 0; Port* prt = erts_drvport2port(ix); + int trace_send = IS_TRACED_FL(prt, F_TRACE_SEND); if (prt == ERTS_INVALID_ERL_DRV_PORT) return; @@ -5525,12 +5607,15 @@ void driver_report_exit(ErlDrvPort ix, int status) if (!rp) return; - mp = erts_alloc_message_heap(rp, &rp_locks, 3+3, &hp, &ohp); + mp = erts_alloc_message_heap(trace_send ? NULL : rp, &rp_locks, 3+3, &hp, &ohp); tuple = TUPLE2(hp, am_exit_status, make_small(status)); hp += 3; tuple = TUPLE2(hp, prt->common.id, tuple); + if (IS_TRACED_FL(prt, F_TRACE_SEND)) + trace_port_send(prt, pid, tuple, 1); + ERL_MESSAGE_TOKEN(mp) = am_undefined; erts_queue_message(rp, &rp_locks, mp, tuple); @@ -5626,13 +5711,13 @@ cleanup_b2t_states(struct b2t_states__ *b2tsp) */ static int -driver_deliver_term(Eterm to, ErlDrvTermData* data, int len) +driver_deliver_term(Port *prt, Eterm to, ErlDrvTermData* data, int len) { #define HEAP_EXTRA 200 #define ERTS_DDT_FAIL do { res = -1; goto done; } while (0) Uint need = 0; int depth = 0; - int res; + int res = 0; ErlDrvTermData* ptr; ErlDrvTermData* ptr_end; DECLARE_ESTACK(stack); @@ -5851,11 +5936,26 @@ driver_deliver_term(Eterm to, ErlDrvTermData* data, int len) ? erts_proc_lookup(to) : erts_pid2proc_opt(NULL, 0, to, 0, ERTS_P2P_FLG_INC_REFC)); if (!rp) { - res = 0; - goto done; - } + if (!prt || !IS_TRACED_FL(prt, F_TRACE_SEND)) + goto done; + if (!erts_is_tracer_proc_enabled(NULL, 0, &prt->common, am_send)) + goto done; - (void) erts_factory_message_create(&factory, rp, &rp_locks, need); + res = -2; + + /* We allocate a temporary heap to be used to create + the message that may be sent using tracing */ + erts_factory_tmp_init(&factory, erts_alloc(ERTS_ALC_T_DRIVER, need*sizeof(Eterm)), + need, ERTS_ALC_T_DRIVER); + + } else { + /* We force the creation of a heap fragment (rp == NULL) when send + tracing so that we don't have the main lock of the process while + tracing */ + Process *trace_rp = prt && IS_TRACED_FL(prt, F_TRACE_SEND) ? NULL : rp; + (void) erts_factory_message_create(&factory, trace_rp, &rp_locks, need); + res = 1; + } /* * Interpret the instructions and build the term. @@ -6118,23 +6218,40 @@ driver_deliver_term(Eterm to, ErlDrvTermData* data, int len) ESTACK_PUSH(stack, mess); } - res = 1; - done: if (res > 0) { mess = ESTACK_POP(stack); /* get resulting value */ erts_factory_trim_and_close(&factory, &mess, 1); + + if (prt && IS_TRACED_FL(prt, F_TRACE_SEND)) + trace_port_send(prt, to, mess, 1); + /* send message */ ERL_MESSAGE_TOKEN(factory.message) = am_undefined; erts_queue_message(rp, &rp_locks, factory.message, mess); } + else if (res == -2) { + /* this clause only happens when we were requested to + generate a send trace, but the process to send to + did not exist any more */ + mess = ESTACK_POP(stack); /* get resulting value */ + + trace_port_send(prt, to, mess, 0); + + erts_factory_trim_and_close(&factory, &mess, 1); + erts_free(ERTS_ALC_T_DRIVER, factory.hp_start); + res = 0; + } else { if (b2t.ix > b2t.used) b2t.used = b2t.ix; for (b2t.ix = 0; b2t.ix < b2t.used; b2t.ix++) erts_binary2term_abort(&b2t.state[b2t.ix]); - erts_factory_undo(&factory); + if (factory.mode != FACTORY_CLOSED) { + ERL_MESSAGE_TERM(factory.message) = am_undefined; + erts_factory_undo(&factory); + } } if (rp) { if (rp_locks) @@ -6150,7 +6267,8 @@ driver_deliver_term(Eterm to, ErlDrvTermData* data, int len) } static ERTS_INLINE int -deliver_term_check_port(ErlDrvTermData port_id, Eterm *connected_p) +deliver_term_check_port(ErlDrvTermData port_id, Eterm *connected_p, + Port **trace_prt) { #ifdef ERTS_SMP ErtsThrPrgrDelayHandle dhndl = erts_thr_progress_unmanaged_delay(); @@ -6178,8 +6296,11 @@ deliver_term_check_port(ErlDrvTermData port_id, Eterm *connected_p) if (dhndl != ERTS_THR_PRGR_DHANDLE_MANAGED) { erts_thr_progress_unmanaged_continue(dhndl); ETHR_MEMBAR(ETHR_LoadLoad|ETHR_LoadStore); - } + } else #endif + { + *trace_prt = prt; + } ERTS_SMP_LC_ASSERT(dhndl == ERTS_THR_PRGR_DHANDLE_MANAGED ? erts_lc_is_port_locked(prt) : !erts_lc_is_port_locked(prt)); @@ -6190,10 +6311,11 @@ int erl_drv_output_term(ErlDrvTermData port_id, ErlDrvTermData* data, int len) { /* May be called from arbitrary thread */ Eterm connected; - int res = deliver_term_check_port(port_id, &connected); + Port *prt = NULL; + int res = deliver_term_check_port(port_id, &connected, &prt); if (res <= 0) return res; - return driver_deliver_term(connected, data, len); + return driver_deliver_term(prt, connected, data, len); } /* @@ -6217,7 +6339,7 @@ driver_output_term(ErlDrvPort drvport, ErlDrvTermData* data, int len) if (state & ERTS_PORT_SFLG_CLOSING) return 0; - return driver_deliver_term(ERTS_PORT_GET_CONNECTED(prt), data, len); + return driver_deliver_term(prt, ERTS_PORT_GET_CONNECTED(prt), data, len); } int erl_drv_send_term(ErlDrvTermData port_id, @@ -6226,10 +6348,11 @@ int erl_drv_send_term(ErlDrvTermData port_id, int len) { /* May be called from arbitrary thread */ - int res = deliver_term_check_port(port_id, NULL); + Port *prt = NULL; + int res = deliver_term_check_port(port_id, NULL, &prt); if (res <= 0) return res; - return driver_deliver_term(to, data, len); + return driver_deliver_term(prt, to, data, len); } /* @@ -6248,20 +6371,21 @@ driver_send_term(ErlDrvPort drvport, * to make this access safe without using a less efficient * internal data representation for ErlDrvPort. */ + Port* prt = NULL; ERTS_SMP_CHK_NO_PROC_LOCKS; #ifdef ERTS_SMP if (erts_thr_progress_is_managed_thread()) #endif { erts_aint32_t state; - Port* prt = erts_drvport2port_state(drvport, &state); + prt = erts_drvport2port_state(drvport, &state); if (prt == ERTS_INVALID_ERL_DRV_PORT) return -1; /* invalid (dead) */ ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(prt)); if (state & ERTS_PORT_SFLG_CLOSING) return 0; } - return driver_deliver_term(to, data, len); + return driver_deliver_term(prt, to, data, len); } @@ -7437,7 +7561,7 @@ driver_failure_term(ErlDrvPort ix, Eterm term, int eof) if (state & ERTS_PORT_SFLG_CLOSING) { terminate_port(prt); } else if (eof && (state & ERTS_PORT_SFLG_SOFT_EOF)) { - deliver_result(prt->common.id, ERTS_PORT_GET_CONNECTED(prt), am_eof); + deliver_result(prt, prt->common.id, ERTS_PORT_GET_CONNECTED(prt), am_eof); } else { /* XXX UGLY WORK AROUND, Let erts_deliver_port_exit() terminate the port */ if (prt->port_data_lock) @@ -7445,7 +7569,7 @@ driver_failure_term(ErlDrvPort ix, Eterm term, int eof) prt->ioq.size = 0; if (prt->port_data_lock) driver_pdl_unlock(prt->port_data_lock); - erts_deliver_port_exit(prt, prt->common.id, eof ? am_normal : term, 0); + erts_deliver_port_exit(prt, prt->common.id, eof ? am_normal : term, 0, 0); } return 0; } diff --git a/erts/emulator/beam/register.c b/erts/emulator/beam/register.c index f4a889b8f8..e995dcbd8a 100644 --- a/erts/emulator/beam/register.c +++ b/erts/emulator/beam/register.c @@ -538,8 +538,12 @@ int erts_unregister_name(Process *c_p, ERTS_SMP_LC_ASSERT(erts_lc_is_port_locked(port)); rp->pt->common.u.alive.reg = NULL; - + if (IS_TRACED_FL(port, F_TRACE_PORTS)) { + if (current_c_p_locks) { + erts_smp_proc_unlock(c_p, current_c_p_locks); + current_c_p_locks = 0; + } trace_port(port, am_unregister, r.name); } -- cgit v1.2.3