Commit 8d52c4c2 authored by xupeng-mingtu's avatar xupeng-mingtu Committed by Konrad Sztyber
Browse files

add new trace BDEV_RAID_IO_START and BDEV_RAID_IO_DONE 



Through the both new trace, we can analyze the time consumed by
IO at the RAID layer and the time consumed by each base bdev IO.
This is a trace example of raid1 IO:

BDEV_IO_START       id:    i3481
BDEV_RAID_IO_START  id:    R870 (i3481)
BDEV_IO_START       id:    i3482 (R870)
BDEV_IO_START       id:    i3483 (R870)
BDEV_IO_DONE        id:    i3482 (R870)     time:  14.769
BDEV_IO_DONE        id:    i3483 (R870)     time:  15.319
BDEV_RAID_IO_DONE   id:    R870 (i3481)     time:  16.521
BDEV_IO_DONE        id:    i3481            time:  16.804

Change-Id: I228b660594a39721567e3a0d606b20e8e8b69e1b
Signed-off-by: default avatarXupeng Mingtu <xupeng9@staff.sina.com>
Reviewed-on: https://review.spdk.io/gerrit/c/spdk/spdk/+/24894


Reviewed-by: default avatarArtur Paszkiewicz <artur.paszkiewicz@intel.com>
Reviewed-by: default avatarJim Harris <jim.harris@samsung.com>
Reviewed-by: default avatarKonrad Sztyber <konrad.sztyber@intel.com>
Community-CI: Mellanox Build Bot
Community-CI: Broadcom CI <spdk-ci.pdl@broadcom.com>
Tested-by: default avatarSPDK CI Jenkins <sys_sgci@intel.com>
parent 48b83bb7

include/spdk_internal/trace_defs.h

+6 −0
Original line number Diff line number Diff line
@@ -29,6 +29,7 @@ 
#define OBJECT_NVMF_TCP_IO	0x80

#define OBJECT_NVMF_FC_IO	0xA0

#define OBJECT_BLOB_CB_ARG      0xB0

#define OBJECT_BDEV_RAID_IO     0xC0



/* Trace group definitions */

#define TRACE_GROUP_ISCSI	0x1
@@ -47,6 +48,7 @@ 
#define TRACE_GROUP_BDEV_NVME	0xE

#define TRACE_GROUP_SOCK	0xF

#define TRACE_GROUP_BLOB	0x10

#define TRACE_GROUP_BDEV_RAID	0x11



/* Bdev tracepoint definitions */

#define TRACE_BDEV_IO_START		SPDK_TPOINT_ID(TRACE_GROUP_BDEV, 0x0)
@@ -168,4 +170,8 @@ 
#define TRACE_BLOB_REQ_SET_START        SPDK_TPOINT_ID(TRACE_GROUP_BLOB, 0x0)

#define TRACE_BLOB_REQ_SET_COMPLETE     SPDK_TPOINT_ID(TRACE_GROUP_BLOB, 0x1)



/* Bdev raid tracepoint definitions */

#define TRACE_BDEV_RAID_IO_START	SPDK_TPOINT_ID(TRACE_GROUP_BDEV_RAID, 0x0)

#define TRACE_BDEV_RAID_IO_DONE		SPDK_TPOINT_ID(TRACE_GROUP_BDEV_RAID, 0x1)



#endif /* SPDK_INTERNAL_TRACE_DEFS */

lib/bdev/bdev.c

+2 −0
Original line number Diff line number Diff line
@@ -10633,4 +10633,6 @@ SPDK_TRACE_REGISTER_FN(bdev_trace, "bdev", TRACE_GROUP_BDEV) 
	spdk_trace_tpoint_register_relation(TRACE_BDEV_NVME_IO_DONE, OBJECT_BDEV_IO, 0);

	spdk_trace_tpoint_register_relation(TRACE_BLOB_REQ_SET_START, OBJECT_BDEV_IO, 0);

	spdk_trace_tpoint_register_relation(TRACE_BLOB_REQ_SET_COMPLETE, OBJECT_BDEV_IO, 0);

	spdk_trace_tpoint_register_relation(TRACE_BDEV_RAID_IO_START, OBJECT_BDEV_IO, 0);

	spdk_trace_tpoint_register_relation(TRACE_BDEV_RAID_IO_DONE, OBJECT_BDEV_IO, 0);

}

mk/spdk.lib_deps.mk

+1 −1
Original line number Diff line number Diff line
@@ -153,7 +153,7 @@ DEPDIRS-bdev_null := $(BDEV_DEPS_THREAD) 
DEPDIRS-bdev_nvme = $(BDEV_DEPS_THREAD) accel keyring nvme trace

DEPDIRS-bdev_ocf := $(BDEV_DEPS_THREAD)

DEPDIRS-bdev_passthru := $(BDEV_DEPS_THREAD)

DEPDIRS-bdev_raid := $(BDEV_DEPS_THREAD)

DEPDIRS-bdev_raid := $(BDEV_DEPS_THREAD) trace

ifeq ($(CONFIG_RAID5F),y)

DEPDIRS-bdev_raid += accel

endif

module/bdev/raid/bdev_raid.c

+28 −0
Original line number Diff line number Diff line
@@ -12,6 +12,8 @@ 
#include "spdk/util.h"

#include "spdk/json.h"

#include "spdk/likely.h"

#include "spdk/trace.h"

#include "spdk_internal/trace_defs.h"



#define RAID_OFFSET_BLOCKS_INVALID	UINT64_MAX

#define RAID_BDEV_PROCESS_MAX_QD	16
@@ -606,6 +608,8 @@ raid_bdev_io_complete(struct raid_bdev_io *raid_io, enum spdk_bdev_io_status sta 
	struct spdk_bdev_io *bdev_io = spdk_bdev_io_from_ctx(raid_io);

	int rc;



	spdk_trace_record(TRACE_BDEV_RAID_IO_DONE, 0, 0, (uintptr_t)raid_io, (uintptr_t)bdev_io);



	if (raid_io->split.offset != RAID_OFFSET_BLOCKS_INVALID) {

		struct iovec *split_iov = raid_io->split.iov;

		const struct iovec *split_iov_orig = &raid_io->split.iov_copy;
@@ -938,6 +942,8 @@ raid_bdev_submit_request(struct spdk_io_channel *ch, struct spdk_bdev_io *bdev_i 
			  bdev_io->u.bdev.iovs, bdev_io->u.bdev.iovcnt, bdev_io->u.bdev.md_buf,

			  bdev_io->u.bdev.memory_domain, bdev_io->u.bdev.memory_domain_ctx);



	spdk_trace_record(TRACE_BDEV_RAID_IO_START, 0, 0, (uintptr_t)raid_io, (uintptr_t)bdev_io);



	switch (bdev_io->type) {

	case SPDK_BDEV_IO_TYPE_READ:

		spdk_bdev_io_get_buf(bdev_io, raid_bdev_get_buf_cb,
@@ -3937,3 +3943,25 @@ done: 


/* Log component for bdev raid bdev module */

SPDK_LOG_REGISTER_COMPONENT(bdev_raid)



SPDK_TRACE_REGISTER_FN(bdev_raid_trace, "bdev_raid", TRACE_GROUP_BDEV_RAID)

{

	struct spdk_trace_tpoint_opts opts[] = {

		{

			"BDEV_RAID_IO_START", TRACE_BDEV_RAID_IO_START,

			OWNER_TYPE_NONE, OBJECT_BDEV_RAID_IO, 1,

			{{ "ctx", SPDK_TRACE_ARG_TYPE_PTR, 8 }}

		},

		{

			"BDEV_RAID_IO_DONE", TRACE_BDEV_RAID_IO_DONE,

			OWNER_TYPE_NONE, OBJECT_BDEV_RAID_IO, 0,

			{{ "ctx", SPDK_TRACE_ARG_TYPE_PTR, 8 }}

		}

	};





	spdk_trace_register_object(OBJECT_BDEV_RAID_IO, 'R');

	spdk_trace_register_description_ext(opts, SPDK_COUNTOF(opts));

	spdk_trace_tpoint_register_relation(TRACE_BDEV_IO_START, OBJECT_BDEV_RAID_IO, 1);

	spdk_trace_tpoint_register_relation(TRACE_BDEV_IO_DONE, OBJECT_BDEV_RAID_IO, 0);

}