bdev: add trace points

Signed-off-by: Jim Harris <james.r.harris@intel.com>
Change-Id: I37e7f2fb19fecfe5933b4815d24240954b74b62b

Reviewed-on: https://review.gerrithub.io/424278
Tested-by: SPDK CI Jenkins <sys_sgci@intel.com>
Reviewed-by: Changpeng Liu <changpeng.liu@intel.com>
Reviewed-by: Shuhei Matsumoto <shuhei.matsumoto.xt@hitachi.com>
Reviewed-by: Ben Walker <benjamin.walker@intel.com>
Chandler-Test-Pool: SPDK Automated Test System <sys_sgsw@intel.com>
This commit is contained in:
Jim Harris 2018-08-31 13:13:32 -07:00 committed by Ben Walker
parent 8dfd945b64
commit afaabcce23
5 changed files with 67 additions and 4 deletions

View File

@ -43,7 +43,7 @@ C_SRCS = fio_plugin.c
CFLAGS += -I$(FIO_SOURCE_DIR) CFLAGS += -I$(FIO_SOURCE_DIR)
LDFLAGS += -shared -rdynamic LDFLAGS += -shared -rdynamic
SPDK_LIB_LIST += thread util bdev conf copy rpc jsonrpc json log SPDK_LIB_LIST += thread util bdev conf copy rpc jsonrpc json log trace
LIBS += $(BLOCKDEV_MODULES_LINKER_ARGS) LIBS += $(BLOCKDEV_MODULES_LINKER_ARGS)
LIBS += $(SPDK_LIB_LINKER_ARGS) $(ENV_LINKER_ARGS) LIBS += $(SPDK_LIB_LINKER_ARGS) $(ENV_LINKER_ARGS)

View File

@ -44,6 +44,7 @@
#include "spdk/nvme_spec.h" #include "spdk/nvme_spec.h"
#include "spdk/scsi_spec.h" #include "spdk/scsi_spec.h"
#include "spdk/util.h" #include "spdk/util.h"
#include "spdk/trace.h"
#include "spdk/bdev_module.h" #include "spdk/bdev_module.h"
#include "spdk_internal/log.h" #include "spdk_internal/log.h"
@ -61,6 +62,15 @@ int __itt_init_ittlib(const char *, __itt_group_id);
#define BUF_LARGE_POOL_SIZE 1024 #define BUF_LARGE_POOL_SIZE 1024
#define NOMEM_THRESHOLD_COUNT 8 #define NOMEM_THRESHOLD_COUNT 8
#define ZERO_BUFFER_SIZE 0x100000 #define ZERO_BUFFER_SIZE 0x100000
#define OWNER_BDEV 0x2
#define OBJECT_BDEV_IO 0x2
#define TRACE_GROUP_BDEV 0x3
#define TRACE_BDEV_IO_START SPDK_TPOINT_ID(TRACE_GROUP_BDEV, 0x0)
#define TRACE_BDEV_IO_DONE SPDK_TPOINT_ID(TRACE_GROUP_BDEV, 0x1)
#define SPDK_BDEV_QOS_TIMESLICE_IN_USEC 1000 #define SPDK_BDEV_QOS_TIMESLICE_IN_USEC 1000
#define SPDK_BDEV_QOS_MIN_IO_PER_TIMESLICE 1 #define SPDK_BDEV_QOS_MIN_IO_PER_TIMESLICE 1
#define SPDK_BDEV_QOS_MIN_BYTE_PER_TIMESLICE 512 #define SPDK_BDEV_QOS_MIN_BYTE_PER_TIMESLICE 512
@ -1232,8 +1242,11 @@ _spdk_bdev_io_submit(void *ctx)
struct spdk_bdev_channel *bdev_ch = bdev_io->internal.ch; struct spdk_bdev_channel *bdev_ch = bdev_io->internal.ch;
struct spdk_io_channel *ch = bdev_ch->channel; struct spdk_io_channel *ch = bdev_ch->channel;
struct spdk_bdev_shared_resource *shared_resource = bdev_ch->shared_resource; struct spdk_bdev_shared_resource *shared_resource = bdev_ch->shared_resource;
uint64_t tsc;
bdev_io->internal.submit_tsc = spdk_get_ticks(); tsc = spdk_get_ticks();
bdev_io->internal.submit_tsc = tsc;
spdk_trace_record_tsc(tsc, TRACE_BDEV_IO_START, 0, 0, (uintptr_t)bdev_io, bdev_io->type);
bdev_ch->io_outstanding++; bdev_ch->io_outstanding++;
shared_resource->io_outstanding++; shared_resource->io_outstanding++;
bdev_io->internal.in_submit_request = true; bdev_io->internal.in_submit_request = true;
@ -2691,6 +2704,7 @@ static inline void
_spdk_bdev_io_complete(void *ctx) _spdk_bdev_io_complete(void *ctx)
{ {
struct spdk_bdev_io *bdev_io = ctx; struct spdk_bdev_io *bdev_io = ctx;
uint64_t tsc;
if (spdk_unlikely(bdev_io->internal.in_submit_request || bdev_io->internal.io_submit_ch)) { if (spdk_unlikely(bdev_io->internal.in_submit_request || bdev_io->internal.io_submit_ch)) {
/* /*
@ -2711,17 +2725,20 @@ _spdk_bdev_io_complete(void *ctx)
return; return;
} }
tsc = spdk_get_ticks();
spdk_trace_record_tsc(tsc, TRACE_BDEV_IO_DONE, 0, 0, (uintptr_t)bdev_io, 0);
if (bdev_io->internal.status == SPDK_BDEV_IO_STATUS_SUCCESS) { if (bdev_io->internal.status == SPDK_BDEV_IO_STATUS_SUCCESS) {
switch (bdev_io->type) { switch (bdev_io->type) {
case SPDK_BDEV_IO_TYPE_READ: case SPDK_BDEV_IO_TYPE_READ:
bdev_io->internal.ch->stat.bytes_read += bdev_io->u.bdev.num_blocks * bdev_io->bdev->blocklen; bdev_io->internal.ch->stat.bytes_read += bdev_io->u.bdev.num_blocks * bdev_io->bdev->blocklen;
bdev_io->internal.ch->stat.num_read_ops++; bdev_io->internal.ch->stat.num_read_ops++;
bdev_io->internal.ch->stat.read_latency_ticks += (spdk_get_ticks() - bdev_io->internal.submit_tsc); bdev_io->internal.ch->stat.read_latency_ticks += (tsc - bdev_io->internal.submit_tsc);
break; break;
case SPDK_BDEV_IO_TYPE_WRITE: case SPDK_BDEV_IO_TYPE_WRITE:
bdev_io->internal.ch->stat.bytes_written += bdev_io->u.bdev.num_blocks * bdev_io->bdev->blocklen; bdev_io->internal.ch->stat.bytes_written += bdev_io->u.bdev.num_blocks * bdev_io->bdev->blocklen;
bdev_io->internal.ch->stat.num_write_ops++; bdev_io->internal.ch->stat.num_write_ops++;
bdev_io->internal.ch->stat.write_latency_ticks += (spdk_get_ticks() - bdev_io->internal.submit_tsc); bdev_io->internal.ch->stat.write_latency_ticks += (tsc - bdev_io->internal.submit_tsc);
break; break;
default: default:
break; break;
@ -3631,3 +3648,13 @@ spdk_bdev_set_qos_limit_iops(struct spdk_bdev *bdev, uint64_t ios_per_sec,
} }
SPDK_LOG_REGISTER_COMPONENT("bdev", SPDK_LOG_BDEV) SPDK_LOG_REGISTER_COMPONENT("bdev", SPDK_LOG_BDEV)
SPDK_TRACE_REGISTER_FN(bdev_trace)
{
spdk_trace_register_owner(OWNER_BDEV, 'b');
spdk_trace_register_object(OBJECT_BDEV_IO, 'i');
spdk_trace_register_description("BDEV_IO_START", "", TRACE_BDEV_IO_START, OWNER_BDEV,
OBJECT_BDEV_IO, 1, 0, 0, "type: ");
spdk_trace_register_description("BDEV_IO_DONE", "", TRACE_BDEV_IO_DONE, OWNER_BDEV,
OBJECT_BDEV_IO, 0, 0, 0, "");
}

View File

@ -47,6 +47,18 @@ DEFINE_STUB(spdk_conf_section_get_nmval, char *,
(struct spdk_conf_section *sp, const char *key, int idx1, int idx2), NULL); (struct spdk_conf_section *sp, const char *key, int idx1, int idx2), NULL);
DEFINE_STUB(spdk_conf_section_get_intval, int, (struct spdk_conf_section *sp, const char *key), -1); DEFINE_STUB(spdk_conf_section_get_intval, int, (struct spdk_conf_section *sp, const char *key), -1);
struct spdk_trace_histories *g_trace_histories;
DEFINE_STUB_V(spdk_trace_add_register_fn, (struct spdk_trace_register_fn *reg_fn));
DEFINE_STUB_V(spdk_trace_register_owner, (uint8_t type, char id_prefix));
DEFINE_STUB_V(spdk_trace_register_object, (uint8_t type, char id_prefix));
DEFINE_STUB_V(spdk_trace_register_description, (const char *name, const char *short_name,
uint16_t tpoint_id, uint8_t owner_type,
uint8_t object_type, uint8_t new_object,
uint8_t arg1_is_ptr, uint8_t arg1_is_alias,
const char *arg1_name));
DEFINE_STUB_V(_spdk_trace_record, (uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id,
uint32_t size, uint64_t object_id, uint64_t arg1));
static void static void
_bdev_send_msg(spdk_thread_fn fn, void *ctx, void *thread_ctx) _bdev_send_msg(spdk_thread_fn fn, void *ctx, void *thread_ctx)
{ {

View File

@ -53,6 +53,18 @@ DEFINE_STUB(spdk_conf_section_get_nmval, char *,
(struct spdk_conf_section *sp, const char *key, int idx1, int idx2), NULL); (struct spdk_conf_section *sp, const char *key, int idx1, int idx2), NULL);
DEFINE_STUB(spdk_conf_section_get_intval, int, (struct spdk_conf_section *sp, const char *key), -1); DEFINE_STUB(spdk_conf_section_get_intval, int, (struct spdk_conf_section *sp, const char *key), -1);
struct spdk_trace_histories *g_trace_histories;
DEFINE_STUB_V(spdk_trace_add_register_fn, (struct spdk_trace_register_fn *reg_fn));
DEFINE_STUB_V(spdk_trace_register_owner, (uint8_t type, char id_prefix));
DEFINE_STUB_V(spdk_trace_register_object, (uint8_t type, char id_prefix));
DEFINE_STUB_V(spdk_trace_register_description, (const char *name, const char *short_name,
uint16_t tpoint_id, uint8_t owner_type,
uint8_t object_type, uint8_t new_object,
uint8_t arg1_is_ptr, uint8_t arg1_is_alias,
const char *arg1_name));
DEFINE_STUB_V(_spdk_trace_record, (uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id,
uint32_t size, uint64_t object_id, uint64_t arg1));
struct ut_bdev { struct ut_bdev {
struct spdk_bdev bdev; struct spdk_bdev bdev;
void *io_target; void *io_target;

View File

@ -48,6 +48,18 @@ DEFINE_STUB(spdk_conf_section_get_nmval, char *,
(struct spdk_conf_section *sp, const char *key, int idx1, int idx2), NULL); (struct spdk_conf_section *sp, const char *key, int idx1, int idx2), NULL);
DEFINE_STUB(spdk_conf_section_get_intval, int, (struct spdk_conf_section *sp, const char *key), -1); DEFINE_STUB(spdk_conf_section_get_intval, int, (struct spdk_conf_section *sp, const char *key), -1);
struct spdk_trace_histories *g_trace_histories;
DEFINE_STUB_V(spdk_trace_add_register_fn, (struct spdk_trace_register_fn *reg_fn));
DEFINE_STUB_V(spdk_trace_register_owner, (uint8_t type, char id_prefix));
DEFINE_STUB_V(spdk_trace_register_object, (uint8_t type, char id_prefix));
DEFINE_STUB_V(spdk_trace_register_description, (const char *name, const char *short_name,
uint16_t tpoint_id, uint8_t owner_type,
uint8_t object_type, uint8_t new_object,
uint8_t arg1_is_ptr, uint8_t arg1_is_alias,
const char *arg1_name));
DEFINE_STUB_V(_spdk_trace_record, (uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id,
uint32_t size, uint64_t object_id, uint64_t arg1));
static void static void
_part_send_msg(spdk_thread_fn fn, void *ctx, void *thread_ctx) _part_send_msg(spdk_thread_fn fn, void *ctx, void *thread_ctx)
{ {