diff --git a/lib/blobfs/blobfs.c b/lib/blobfs/blobfs.c index c24238fc1..2eb6ca8ee 100644 --- a/lib/blobfs/blobfs.c +++ b/lib/blobfs/blobfs.c @@ -43,6 +43,7 @@ #include "spdk/env.h" #include "spdk/util.h" #include "spdk_internal/log.h" +#include "spdk/trace.h" #define BLOBFS_TRACE(file, str, args...) \ SPDK_DEBUGLOG(SPDK_LOG_BLOBFS, "file=%s " str, file->name, ##args) @@ -60,6 +61,36 @@ static int g_fs_count = 0; static pthread_mutex_t g_cache_init_lock = PTHREAD_MUTEX_INITIALIZER; static pthread_spinlock_t g_caches_lock; +#define TRACE_GROUP_BLOBFS 0x7 +#define TRACE_BLOBFS_XATTR_START SPDK_TPOINT_ID(TRACE_GROUP_BLOBFS, 0x0) +#define TRACE_BLOBFS_XATTR_END SPDK_TPOINT_ID(TRACE_GROUP_BLOBFS, 0x1) +#define TRACE_BLOBFS_OPEN SPDK_TPOINT_ID(TRACE_GROUP_BLOBFS, 0x2) +#define TRACE_BLOBFS_CLOSE SPDK_TPOINT_ID(TRACE_GROUP_BLOBFS, 0x3) + +SPDK_TRACE_REGISTER_FN(blobfs_trace, "blobfs", TRACE_GROUP_BLOBFS) +{ + spdk_trace_register_description("BLOBFS_XATTR_START", "", + TRACE_BLOBFS_XATTR_START, + OWNER_NONE, OBJECT_NONE, 0, + SPDK_TRACE_ARG_TYPE_STR, + "file: "); + spdk_trace_register_description("BLOBFS_XATTR_END", "", + TRACE_BLOBFS_XATTR_END, + OWNER_NONE, OBJECT_NONE, 0, + SPDK_TRACE_ARG_TYPE_STR, + "file: "); + spdk_trace_register_description("BLOBFS_OPEN", "", + TRACE_BLOBFS_OPEN, + OWNER_NONE, OBJECT_NONE, 0, + SPDK_TRACE_ARG_TYPE_STR, + "file: "); + spdk_trace_register_description("BLOBFS_CLOSE", "", + TRACE_BLOBFS_CLOSE, + OWNER_NONE, OBJECT_NONE, 0, + SPDK_TRACE_ARG_TYPE_STR, + "file: "); +} + void spdk_cache_buffer_free(struct cache_buffer *cache_buffer) { @@ -73,6 +104,7 @@ struct spdk_file { struct spdk_filesystem *fs; struct spdk_blob *blob; char *name; + uint64_t trace_arg_name; uint64_t length; bool is_deleted; bool open_for_writing; @@ -618,6 +650,14 @@ fs_load_done(void *ctx, int bserrno) } +static void +_file_build_trace_arg_name(struct spdk_file *f) +{ + f->trace_arg_name = 0; + memcpy(&f->trace_arg_name, f->name, + spdk_min(sizeof(f->trace_arg_name), strlen(f->name))); +} + static void iter_cb(void *ctx, struct spdk_blob *blob, int rc) { @@ -664,6 +704,7 @@ iter_cb(void *ctx, struct spdk_blob *blob, int rc) } f->name = strdup(name); + _file_build_trace_arg_name(f); f->blobid = spdk_blob_get_id(blob); f->length = *length; f->length_flushed = *length; @@ -1016,6 +1057,7 @@ spdk_fs_create_file_async(struct spdk_filesystem *fs, const char *name, args->arg = cb_arg; file->name = strdup(name); + _file_build_trace_arg_name(file); spdk_bs_create_blob(fs->bs, fs_create_blob_create_cb, args); } @@ -1079,6 +1121,7 @@ fs_open_blob_done(void *ctx, struct spdk_blob *blob, int bserrno) req = TAILQ_FIRST(&f->open_requests); args = &req->args; TAILQ_REMOVE(&f->open_requests, req, args.op.open.tailq); + spdk_trace_record(TRACE_BLOBFS_OPEN, 0, 0, 0, f->trace_arg_name); args->fn.file_op_with_handle(args->arg, f, bserrno); free_fs_request(req); } @@ -1255,6 +1298,7 @@ __spdk_fs_md_rename_file(struct spdk_fs_request *req) free(f->name); f->name = strdup(args->op.rename.new_name); + _file_build_trace_arg_name(f); args->file = f; spdk_bs_open_blob(args->fs->bs, f->blobid, fs_rename_blob_open_cb, req); } @@ -1956,6 +2000,8 @@ __file_cache_finish_sync(void *ctx, int bserrno) sync_req = TAILQ_FIRST(&file->sync_requests); sync_args = &sync_req->args; assert(sync_args->op.sync.offset <= file->length_flushed); + spdk_trace_record(TRACE_BLOBFS_XATTR_END, 0, sync_args->op.sync.offset, + 0, file->trace_arg_name); BLOBFS_TRACE(file, "sync done offset=%jx\n", sync_args->op.sync.offset); TAILQ_REMOVE(&file->sync_requests, sync_req, args.op.sync.tailq); pthread_spin_unlock(&file->lock); @@ -1988,6 +2034,8 @@ __check_sync_reqs(struct spdk_file *file) sizeof(file->length_flushed)); pthread_spin_unlock(&file->lock); + spdk_trace_record(TRACE_BLOBFS_XATTR_START, 0, file->length_flushed, + 0, file->trace_arg_name); spdk_blob_sync_md(file->blob, __file_cache_finish_sync, file); } else { pthread_spin_unlock(&file->lock); @@ -2545,6 +2593,8 @@ __file_close_async_done(void *ctx, int bserrno) struct spdk_fs_cb_args *args = &req->args; struct spdk_file *file = args->file; + spdk_trace_record(TRACE_BLOBFS_CLOSE, 0, 0, 0, file->trace_arg_name); + if (file->is_deleted) { spdk_fs_delete_file_async(file->fs, file->name, blob_delete_cb, ctx); return; diff --git a/test/unit/lib/blobfs/blobfs_async_ut/blobfs_async_ut.c b/test/unit/lib/blobfs/blobfs_async_ut/blobfs_async_ut.c index 947f75fbc..d7b4aabd5 100644 --- a/test/unit/lib/blobfs/blobfs_async_ut/blobfs_async_ut.c +++ b/test/unit/lib/blobfs/blobfs_async_ut/blobfs_async_ut.c @@ -49,6 +49,14 @@ struct spdk_filesystem *g_fs; struct spdk_file *g_file; int g_fserrno; +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_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, 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)); /* Return NULL to test hardcoded defaults. */ struct spdk_conf_section * diff --git a/test/unit/lib/blobfs/blobfs_sync_ut/blobfs_sync_ut.c b/test/unit/lib/blobfs/blobfs_sync_ut/blobfs_sync_ut.c index 35f602353..502cfb204 100644 --- a/test/unit/lib/blobfs/blobfs_sync_ut/blobfs_sync_ut.c +++ b/test/unit/lib/blobfs/blobfs_sync_ut/blobfs_sync_ut.c @@ -50,6 +50,14 @@ struct spdk_filesystem *g_fs; struct spdk_file *g_file; int g_fserrno; struct spdk_thread *g_dispatch_thread = NULL; +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_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, 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)); /* Return NULL to test hardcoded defaults. */ struct spdk_conf_section *