diff --git a/include/spdk_internal/usdt.h b/include/spdk_internal/usdt.h index 70326420f..d25c2890c 100644 --- a/include/spdk_internal/usdt.h +++ b/include/spdk_internal/usdt.h @@ -17,11 +17,21 @@ #include -#define SPDK_DTRACE_PROBE(name) DTRACE_PROBE1(spdk,name,spdk_get_ticks()) -#define SPDK_DTRACE_PROBE1(name,a1) DTRACE_PROBE2(spdk,name,spdk_get_ticks(),a1) -#define SPDK_DTRACE_PROBE2(name,a1,a2) DTRACE_PROBE3(spdk,name,spdk_get_ticks(),a1,a2) -#define SPDK_DTRACE_PROBE3(name,a1,a2,a3) DTRACE_PROBE4(spdk,name,spdk_get_ticks(),a1,a2,a3) -#define SPDK_DTRACE_PROBE4(name,a1,a2,a3,a4) DTRACE_PROBE5(spdk,name,spdk_get_ticks(),a1,a2,a3,a4) +#define SPDK_DTRACE_PROBE(name) DTRACE_PROBE1(spdk,name,0) +#define SPDK_DTRACE_PROBE1(name,a1) DTRACE_PROBE2(spdk,name,0,a1) +#define SPDK_DTRACE_PROBE2(name,a1,a2) DTRACE_PROBE3(spdk,name,0,a1,a2) +#define SPDK_DTRACE_PROBE3(name,a1,a2,a3) DTRACE_PROBE4(spdk,name,0,a1,a2,a3) +#define SPDK_DTRACE_PROBE4(name,a1,a2,a3,a4) DTRACE_PROBE5(spdk,name,0,a1,a2,a3,a4) + +/* These variants implicitly add a TSC argument at the front of the caller's arguments. + * These are useful for scripts that require an exact timestamp for correlating + * USDT events with those captured by the lower-overhead SPDK tracing framework. + */ +#define SPDK_DTRACE_PROBE_TICKS(name) DTRACE_PROBE1(spdk,name,spdk_get_ticks()) +#define SPDK_DTRACE_PROBE1_TICKS(name,a1) DTRACE_PROBE2(spdk,name,spdk_get_ticks(),a1) +#define SPDK_DTRACE_PROBE2_TICKS(name,a1,a2) DTRACE_PROBE3(spdk,name,spdk_get_ticks(),a1,a2) +#define SPDK_DTRACE_PROBE3_TICKS(name,a1,a2,a3) DTRACE_PROBE4(spdk,name,spdk_get_ticks(),a1,a2,a3) +#define SPDK_DTRACE_PROBE4_TICKS(name,a1,a2,a3,a4) DTRACE_PROBE5(spdk,name,spdk_get_ticks(),a1,a2,a3,a4) #else @@ -31,6 +41,12 @@ #define SPDK_DTRACE_PROBE3(...) #define SPDK_DTRACE_PROBE4(...) +#define SPDK_DTRACE_PROBE_TICKS(...) +#define SPDK_DTRACE_PROBE1_TICKS(...) +#define SPDK_DTRACE_PROBE2_TICKS(...) +#define SPDK_DTRACE_PROBE3_TICKS(...) +#define SPDK_DTRACE_PROBE4_TICKS(...) + #endif #endif /* SPDK_INTERNAL_USDT_H */ diff --git a/lib/nvmf/ctrlr.c b/lib/nvmf/ctrlr.c index 47640254f..84800509e 100644 --- a/lib/nvmf/ctrlr.c +++ b/lib/nvmf/ctrlr.c @@ -255,8 +255,8 @@ ctrlr_add_qpair_and_send_rsp(struct spdk_nvmf_qpair *qpair, rsp->status_code_specific.success.cntlid); spdk_nvmf_request_complete(req); - SPDK_DTRACE_PROBE4(nvmf_ctrlr_add_qpair, qpair, qpair->qid, ctrlr->subsys->subnqn, - ctrlr->hostnqn); + SPDK_DTRACE_PROBE4_TICKS(nvmf_ctrlr_add_qpair, qpair, qpair->qid, ctrlr->subsys->subnqn, + ctrlr->hostnqn); } static int @@ -374,8 +374,8 @@ nvmf_ctrlr_create(struct spdk_nvmf_subsystem *subsystem, ctrlr->cntlid = connect_data->cntlid; } - SPDK_DTRACE_PROBE3(nvmf_ctrlr_create, ctrlr, subsystem->subnqn, - spdk_thread_get_id(req->qpair->group->thread)); + SPDK_DTRACE_PROBE3_TICKS(nvmf_ctrlr_create, ctrlr, subsystem->subnqn, + spdk_thread_get_id(req->qpair->group->thread)); STAILQ_INIT(&ctrlr->async_events); TAILQ_INIT(&ctrlr->log_head); @@ -522,8 +522,8 @@ _nvmf_ctrlr_destruct(void *ctx) struct spdk_nvmf_reservation_log *log, *log_tmp; struct spdk_nvmf_async_event_completion *event, *event_tmp; - SPDK_DTRACE_PROBE3(nvmf_ctrlr_destruct, ctrlr, ctrlr->subsys->subnqn, - spdk_thread_get_id(ctrlr->thread)); + SPDK_DTRACE_PROBE3_TICKS(nvmf_ctrlr_destruct, ctrlr, ctrlr->subsys->subnqn, + spdk_thread_get_id(ctrlr->thread)); assert(spdk_get_thread() == ctrlr->thread); assert(ctrlr->in_destruct); @@ -567,8 +567,8 @@ nvmf_ctrlr_add_io_qpair(void *ctx) struct spdk_nvmf_ctrlr *ctrlr = qpair->ctrlr; struct spdk_nvmf_qpair *admin_qpair = ctrlr->admin_qpair; - SPDK_DTRACE_PROBE4(nvmf_ctrlr_add_io_qpair, ctrlr, req->qpair, req->qpair->qid, - spdk_thread_get_id(ctrlr->thread)); + SPDK_DTRACE_PROBE4_TICKS(nvmf_ctrlr_add_io_qpair, ctrlr, req->qpair, req->qpair->qid, + spdk_thread_get_id(ctrlr->thread)); /* Unit test will check qpair->ctrlr after calling spdk_nvmf_ctrlr_connect. * For error case, the value should be NULL. So set it to NULL at first. @@ -4218,9 +4218,9 @@ nvmf_ctrlr_process_io_cmd(struct spdk_nvmf_request *req) } if (spdk_likely(ctrlr->listener != NULL)) { - SPDK_DTRACE_PROBE3(nvmf_request_io_exec_path, req, - ctrlr->listener->trid->traddr, - ctrlr->listener->trid->trsvcid); + SPDK_DTRACE_PROBE3_TICKS(nvmf_request_io_exec_path, req, + ctrlr->listener->trid->traddr, + ctrlr->listener->trid->trsvcid); } /* scan-build falsely reporting dereference of null pointer */ diff --git a/lib/nvmf/nvmf.c b/lib/nvmf/nvmf.c index dda534098..a24d94442 100644 --- a/lib/nvmf/nvmf.c +++ b/lib/nvmf/nvmf.c @@ -126,7 +126,7 @@ nvmf_tgt_destroy_poll_group(void *io_device, void *ctx_buf) struct spdk_nvmf_tgt *tgt = io_device; struct spdk_nvmf_poll_group *group = ctx_buf; - SPDK_DTRACE_PROBE1(nvmf_destroy_poll_group, spdk_thread_get_id(group->thread)); + SPDK_DTRACE_PROBE1_TICKS(nvmf_destroy_poll_group, spdk_thread_get_id(group->thread)); pthread_mutex_lock(&tgt->mutex); TAILQ_REMOVE(&tgt->poll_groups, group, link); @@ -155,7 +155,8 @@ nvmf_poll_group_add_transport(struct spdk_nvmf_poll_group *group, SPDK_ERRLOG("Unable to create poll group for transport\n"); return -1; } - SPDK_DTRACE_PROBE2(nvmf_transport_poll_group_create, transport, spdk_thread_get_id(group->thread)); + SPDK_DTRACE_PROBE2_TICKS(nvmf_transport_poll_group_create, transport, + spdk_thread_get_id(group->thread)); tgroup->group = group; TAILQ_INSERT_TAIL(&group->tgroups, tgroup, link); @@ -181,7 +182,7 @@ nvmf_tgt_create_poll_group(void *io_device, void *ctx_buf) group->poller = SPDK_POLLER_REGISTER(nvmf_poll_group_poll, group, 0); - SPDK_DTRACE_PROBE1(nvmf_create_poll_group, spdk_thread_get_id(thread)); + SPDK_DTRACE_PROBE1_TICKS(nvmf_create_poll_group, spdk_thread_get_id(thread)); TAILQ_FOREACH(transport, &tgt->transports, link) { rc = nvmf_poll_group_add_transport(group, transport); @@ -253,7 +254,7 @@ nvmf_tgt_destroy_poll_group_qpairs(struct spdk_nvmf_poll_group *group) { struct nvmf_qpair_disconnect_many_ctx *ctx; - SPDK_DTRACE_PROBE1(nvmf_destroy_poll_group_qpairs, spdk_thread_get_id(group->thread)); + SPDK_DTRACE_PROBE1_TICKS(nvmf_destroy_poll_group_qpairs, spdk_thread_get_id(group->thread)); ctx = calloc(1, sizeof(struct nvmf_qpair_disconnect_many_ctx)); if (!ctx) { @@ -784,7 +785,7 @@ spdk_nvmf_tgt_add_transport(struct spdk_nvmf_tgt *tgt, { struct spdk_nvmf_tgt_add_transport_ctx *ctx; - SPDK_DTRACE_PROBE2(nvmf_tgt_add_transport, transport, tgt->name); + SPDK_DTRACE_PROBE2_TICKS(nvmf_tgt_add_transport, transport, tgt->name); if (spdk_nvmf_tgt_get_transport(tgt, transport->ops->name)) { cb_fn(cb_arg, -EEXIST); @@ -842,7 +843,7 @@ spdk_nvmf_tgt_pause_polling(struct spdk_nvmf_tgt *tgt, spdk_nvmf_tgt_pause_polli { struct nvmf_tgt_pause_ctx *ctx; - SPDK_DTRACE_PROBE2(nvmf_tgt_pause_polling, tgt, tgt->name); + SPDK_DTRACE_PROBE2_TICKS(nvmf_tgt_pause_polling, tgt, tgt->name); switch (tgt->state) { case NVMF_TGT_PAUSING: @@ -902,7 +903,7 @@ spdk_nvmf_tgt_resume_polling(struct spdk_nvmf_tgt *tgt, spdk_nvmf_tgt_resume_pol { struct nvmf_tgt_pause_ctx *ctx; - SPDK_DTRACE_PROBE2(nvmf_tgt_resume_polling, tgt, tgt->name); + SPDK_DTRACE_PROBE2_TICKS(nvmf_tgt_resume_polling, tgt, tgt->name); switch (tgt->state) { case NVMF_TGT_PAUSING: @@ -1080,7 +1081,7 @@ spdk_nvmf_poll_group_add(struct spdk_nvmf_poll_group *group, /* We add the qpair to the group only it is successfully added into the tgroup */ if (rc == 0) { - SPDK_DTRACE_PROBE2(nvmf_poll_group_add_qpair, qpair, spdk_thread_get_id(group->thread)); + SPDK_DTRACE_PROBE2_TICKS(nvmf_poll_group_add_qpair, qpair, spdk_thread_get_id(group->thread)); TAILQ_INSERT_TAIL(&group->qpairs, qpair, link); nvmf_qpair_set_state(qpair, SPDK_NVMF_QPAIR_ACTIVE); } @@ -1156,8 +1157,8 @@ spdk_nvmf_poll_group_remove(struct spdk_nvmf_qpair *qpair) struct spdk_nvmf_transport_poll_group *tgroup; int rc; - SPDK_DTRACE_PROBE2(nvmf_poll_group_remove_qpair, qpair, - spdk_thread_get_id(qpair->group->thread)); + SPDK_DTRACE_PROBE2_TICKS(nvmf_poll_group_remove_qpair, qpair, + spdk_thread_get_id(qpair->group->thread)); nvmf_qpair_set_state(qpair, SPDK_NVMF_QPAIR_ERROR); /* Find the tgroup and remove the qpair from the tgroup */ @@ -1285,7 +1286,7 @@ spdk_nvmf_qpair_disconnect(struct spdk_nvmf_qpair *qpair, nvmf_qpair_disconnect_ return 0; } - SPDK_DTRACE_PROBE2(nvmf_qpair_disconnect, qpair, spdk_thread_get_id(group->thread)); + SPDK_DTRACE_PROBE2_TICKS(nvmf_qpair_disconnect, qpair, spdk_thread_get_id(group->thread)); assert(qpair->state == SPDK_NVMF_QPAIR_ACTIVE); nvmf_qpair_set_state(qpair, SPDK_NVMF_QPAIR_DEACTIVATING); @@ -1302,7 +1303,7 @@ spdk_nvmf_qpair_disconnect(struct spdk_nvmf_qpair *qpair, nvmf_qpair_disconnect_ /* Check for outstanding I/O */ if (!TAILQ_EMPTY(&qpair->outstanding)) { - SPDK_DTRACE_PROBE2(nvmf_poll_group_drain_qpair, qpair, spdk_thread_get_id(group->thread)); + SPDK_DTRACE_PROBE2_TICKS(nvmf_poll_group_drain_qpair, qpair, spdk_thread_get_id(group->thread)); qpair->state_cb = _nvmf_qpair_destroy; qpair->state_cb_arg = qpair_ctx; nvmf_qpair_abort_pending_zcopy_reqs(qpair); @@ -1539,8 +1540,8 @@ fini: cb_fn(cb_arg, rc); } - SPDK_DTRACE_PROBE2(nvmf_poll_group_add_subsystem, spdk_thread_get_id(group->thread), - subsystem->subnqn); + SPDK_DTRACE_PROBE2_TICKS(nvmf_poll_group_add_subsystem, spdk_thread_get_id(group->thread), + subsystem->subnqn); return rc; } @@ -1626,8 +1627,8 @@ nvmf_poll_group_remove_subsystem(struct spdk_nvmf_poll_group *group, struct nvmf_qpair_disconnect_many_ctx *ctx; uint32_t i; - SPDK_DTRACE_PROBE3(nvmf_poll_group_remove_subsystem, group, spdk_thread_get_id(group->thread), - subsystem->subnqn); + SPDK_DTRACE_PROBE3_TICKS(nvmf_poll_group_remove_subsystem, group, spdk_thread_get_id(group->thread), + subsystem->subnqn); ctx = calloc(1, sizeof(struct nvmf_qpair_disconnect_many_ctx)); if (!ctx) { diff --git a/scripts/bpf/trace.py b/scripts/bpf/trace.py index 81dbd32ab..dc2bf42e9 100755 --- a/scripts/bpf/trace.py +++ b/scripts/bpf/trace.py @@ -107,7 +107,7 @@ class DTrace: files = subprocess.check_output(['git', 'ls-files', '*.[ch]', ':!:include/spdk_internal/usdt.h']) files = filter(lambda f: len(f) > 0, str(files, 'ascii').split('\n')) - regex = re.compile(r'SPDK_DTRACE_PROBE([0-9]*)\((\w+)') + regex = re.compile(r'SPDK_DTRACE_PROBE([0-9]*)_TICKS\((\w+)') probes = {} for fname in files: