From d92f0f75caf311608f5f0e19d4b3db349609b4e8 Mon Sep 17 00:00:00 2001 From: Daniel Verkamp Date: Fri, 25 Aug 2017 13:37:02 -0700 Subject: [PATCH] log: rename SPDK_TRACELOG to SPDK_DEBUGLOG This matches the name to the behavior and prepares for addition of a new log macro for "info" log level. Change-Id: I94ccd49face4309d3368e399528776ab140748c4 Signed-off-by: Daniel Verkamp Reviewed-on: https://review.gerrithub.io/375833 Tested-by: SPDK Automated Test System Reviewed-by: Ben Walker Reviewed-by: Jim Harris --- include/spdk_internal/log.h | 4 +- lib/bdev/aio/bdev_aio.c | 4 +- lib/bdev/bdev.c | 12 ++-- lib/bdev/gpt/gpt.c | 6 +- lib/bdev/gpt/vbdev_gpt.c | 6 +- lib/bdev/malloc/bdev_malloc.c | 4 +- lib/bdev/malloc/bdev_malloc_rpc.c | 2 +- lib/bdev/null/bdev_null_rpc.c | 2 +- lib/bdev/nvme/bdev_nvme.c | 16 ++--- lib/bdev/rbd/bdev_rbd_rpc.c | 2 +- lib/bdev/split/vbdev_split.c | 8 +-- lib/blob/blobstore.c | 26 +++---- lib/blob/request.c | 20 +++--- lib/blobfs/blobfs.c | 32 ++++----- lib/event/reactor.c | 2 +- lib/event/rpc/app_rpc.c | 4 +- lib/iscsi/conn.c | 20 +++--- lib/iscsi/init_grp.c | 16 ++--- lib/iscsi/iscsi.c | 112 +++++++++++++++--------------- lib/iscsi/iscsi_subsystem.c | 50 ++++++------- lib/iscsi/param.c | 44 ++++++------ lib/iscsi/portal_grp.c | 24 +++---- lib/iscsi/tgt_node.c | 40 +++++------ lib/jsonrpc/jsonrpc_server.c | 12 ++-- lib/jsonrpc/jsonrpc_server_tcp.c | 8 +-- lib/log/rpc/log_rpc.c | 8 +-- lib/net/net_rpc.c | 4 +- lib/nvme/nvme_ctrlr.c | 38 +++++----- lib/nvme/nvme_ns.c | 4 +- lib/nvme/nvme_pcie.c | 24 +++---- lib/nvme/nvme_rdma.c | 28 ++++---- lib/nvmf/ctrlr.c | 98 +++++++++++++------------- lib/nvmf/ctrlr_bdev.c | 4 +- lib/nvmf/ctrlr_discovery.c | 2 +- lib/nvmf/nvmf.c | 8 +-- lib/nvmf/rdma.c | 48 ++++++------- lib/nvmf/request.c | 24 +++---- lib/nvmf/subsystem.c | 6 +- lib/scsi/scsi_bdev.c | 44 ++++++------ lib/vhost/vhost.c | 4 +- lib/vhost/vhost_blk.c | 30 ++++---- lib/vhost/vhost_iommu.c | 4 +- lib/vhost/vhost_rpc.c | 12 ++-- lib/vhost/vhost_scsi.c | 24 +++---- test/unit/lib/log/log.c/log_ut.c | 2 +- 45 files changed, 446 insertions(+), 446 deletions(-) diff --git a/include/spdk_internal/log.h b/include/spdk_internal/log.h index c57cd4564..894199baa 100644 --- a/include/spdk_internal/log.h +++ b/include/spdk_internal/log.h @@ -64,7 +64,7 @@ __attribute__((constructor)) static void register_trace_flag_##flag(void) \ spdk_log_register_trace_flag(str, &flag); \ } -#define SPDK_TRACELOG(FLAG, ...) \ +#define SPDK_DEBUGLOG(FLAG, ...) \ do { \ extern struct spdk_trace_flag FLAG; \ if (FLAG.enabled) { \ @@ -82,7 +82,7 @@ __attribute__((constructor)) static void register_trace_flag_##flag(void) \ #else #define SPDK_LOG_REGISTER_TRACE_FLAG(str, flag) -#define SPDK_TRACELOG(...) do { } while (0) +#define SPDK_DEBUGLOG(...) do { } while (0) #define SPDK_TRACEDUMP(...) do { } while (0) #endif diff --git a/lib/bdev/aio/bdev_aio.c b/lib/bdev/aio/bdev_aio.c index cba88d72a..504c89fbe 100644 --- a/lib/bdev/aio/bdev_aio.c +++ b/lib/bdev/aio/bdev_aio.c @@ -112,7 +112,7 @@ bdev_aio_readv(struct file_disk *fdisk, struct spdk_io_channel *ch, iocb->data = aio_task; aio_task->len = nbytes; - SPDK_TRACELOG(SPDK_TRACE_AIO, "read %d iovs size %lu to off: %#lx\n", + SPDK_DEBUGLOG(SPDK_TRACE_AIO, "read %d iovs size %lu to off: %#lx\n", iovcnt, nbytes, offset); rc = io_submit(aio_ch->io_ctx, 1, &iocb); @@ -138,7 +138,7 @@ bdev_aio_writev(struct file_disk *fdisk, struct spdk_io_channel *ch, iocb->data = aio_task; aio_task->len = len; - SPDK_TRACELOG(SPDK_TRACE_AIO, "write %d iovs size %lu from off: %#lx\n", + SPDK_DEBUGLOG(SPDK_TRACE_AIO, "write %d iovs size %lu from off: %#lx\n", iovcnt, len, offset); rc = io_submit(aio_ch->io_ctx, 1, &iocb); diff --git a/lib/bdev/bdev.c b/lib/bdev/bdev.c index feaa8cd3b..6f367922d 100644 --- a/lib/bdev/bdev.c +++ b/lib/bdev/bdev.c @@ -138,7 +138,7 @@ spdk_bdev_first(void) bdev = TAILQ_FIRST(&g_bdev_mgr.bdevs); if (bdev) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Starting bdev iteration at %s\n", bdev->name); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Starting bdev iteration at %s\n", bdev->name); } return bdev; @@ -151,7 +151,7 @@ spdk_bdev_next(struct spdk_bdev *prev) bdev = TAILQ_NEXT(prev, link); if (bdev) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Continuing bdev iteration at %s\n", bdev->name); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Continuing bdev iteration at %s\n", bdev->name); } return bdev; @@ -179,7 +179,7 @@ spdk_bdev_first_leaf(void) bdev = _bdev_next_leaf(TAILQ_FIRST(&g_bdev_mgr.bdevs)); if (bdev) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Starting bdev iteration at %s\n", bdev->name); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Starting bdev iteration at %s\n", bdev->name); } return bdev; @@ -193,7 +193,7 @@ spdk_bdev_next_leaf(struct spdk_bdev *prev) bdev = _bdev_next_leaf(TAILQ_NEXT(prev, link)); if (bdev) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Continuing bdev iteration at %s\n", bdev->name); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Continuing bdev iteration at %s\n", bdev->name); } return bdev; @@ -1422,7 +1422,7 @@ _spdk_bdev_register(struct spdk_bdev *bdev) sizeof(struct spdk_bdev_channel)); pthread_mutex_init(&bdev->mutex, NULL); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Inserting bdev %s into list\n", bdev->name); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Inserting bdev %s into list\n", bdev->name); TAILQ_INSERT_TAIL(&g_bdev_mgr.bdevs, bdev, link); TAILQ_FOREACH(module, &g_bdev_mgr.bdev_modules, tailq) { @@ -1459,7 +1459,7 @@ spdk_bdev_unregister(struct spdk_bdev *bdev) int rc; bool do_destruct = true; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Removing bdev %s from list\n", bdev->name); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Removing bdev %s from list\n", bdev->name); pthread_mutex_lock(&bdev->mutex); diff --git a/lib/bdev/gpt/gpt.c b/lib/bdev/gpt/gpt.c index 794196879..0629c2526 100644 --- a/lib/bdev/gpt/gpt.c +++ b/lib/bdev/gpt/gpt.c @@ -167,7 +167,7 @@ spdk_gpt_check_mbr(struct spdk_gpt *gpt) mbr = (struct spdk_mbr *)gpt->buf; if (from_le16(&mbr->mbr_signature) != SPDK_MBR_SIGNATURE) { - SPDK_TRACELOG(SPDK_TRACE_GPT_PARSE, "Signature mismatch, provided=%x," + SPDK_DEBUGLOG(SPDK_TRACE_GPT_PARSE, "Signature mismatch, provided=%x," "expected=%x\n", from_le16(&mbr->disk_signature), SPDK_MBR_SIGNATURE); return -1; @@ -184,7 +184,7 @@ spdk_gpt_check_mbr(struct spdk_gpt *gpt) if (ret == GPT_PROTECTIVE_MBR) { expected_start_lba = GPT_PRIMARY_PARTITION_TABLE_LBA; if (from_le32(&mbr->partitions[primary_partition].start_lba) != expected_start_lba) { - SPDK_TRACELOG(SPDK_TRACE_GPT_PARSE, "start lba mismatch, provided=%u, expected=%u\n", + SPDK_DEBUGLOG(SPDK_TRACE_GPT_PARSE, "start lba mismatch, provided=%u, expected=%u\n", from_le32(&mbr->partitions[primary_partition].start_lba), expected_start_lba); return -1; @@ -217,7 +217,7 @@ spdk_gpt_parse(struct spdk_gpt *gpt) rc = spdk_gpt_check_mbr(gpt); if (rc) { - SPDK_TRACELOG(SPDK_TRACE_GPT_PARSE, "Failed to detect gpt in MBR\n"); + SPDK_DEBUGLOG(SPDK_TRACE_GPT_PARSE, "Failed to detect gpt in MBR\n"); return rc; } diff --git a/lib/bdev/gpt/vbdev_gpt.c b/lib/bdev/gpt/vbdev_gpt.c index 93d1a4e77..4a702b0b6 100644 --- a/lib/bdev/gpt/vbdev_gpt.c +++ b/lib/bdev/gpt/vbdev_gpt.c @@ -410,7 +410,7 @@ vbdev_gpt_create_bdevs(struct spdk_gpt_bdev *gpt_bdev) d->disk.fn_table = &vbdev_gpt_fn_table; d->disk.module = SPDK_GET_BDEV_MODULE(gpt); - SPDK_TRACELOG(SPDK_TRACE_VBDEV_GPT, "gpt vbdev %s: base bdev: %s offset_bytes: " + SPDK_DEBUGLOG(SPDK_TRACE_VBDEV_GPT, "gpt vbdev %s: base bdev: %s offset_bytes: " "%" PRIu64 " offset_blocks: %" PRIu64 "\n", d->disk.name, spdk_bdev_get_name(base_bdev), d->offset_bytes, d->offset_blocks); @@ -444,7 +444,7 @@ spdk_gpt_bdev_complete(struct spdk_bdev_io *bdev_io, bool status, void *arg) rc = spdk_gpt_parse(&gpt_bdev->gpt); if (rc) { - SPDK_TRACELOG(SPDK_TRACE_VBDEV_GPT, "Failed to parse gpt\n"); + SPDK_DEBUGLOG(SPDK_TRACE_VBDEV_GPT, "Failed to parse gpt\n"); goto end; } @@ -456,7 +456,7 @@ spdk_gpt_bdev_complete(struct spdk_bdev_io *bdev_io, bool status, void *arg) rc = vbdev_gpt_create_bdevs(gpt_bdev); if (rc < 0) { - SPDK_TRACELOG(SPDK_TRACE_VBDEV_GPT, "Failed to split dev=%s by gpt table\n", + SPDK_DEBUGLOG(SPDK_TRACE_VBDEV_GPT, "Failed to split dev=%s by gpt table\n", spdk_bdev_get_name(bdev)); } diff --git a/lib/bdev/malloc/bdev_malloc.c b/lib/bdev/malloc/bdev_malloc.c index deb7bc4e5..8ba8db871 100644 --- a/lib/bdev/malloc/bdev_malloc.c +++ b/lib/bdev/malloc/bdev_malloc.c @@ -174,7 +174,7 @@ bdev_malloc_readv(struct malloc_disk *mdisk, struct spdk_io_channel *ch, return; } - SPDK_TRACELOG(SPDK_TRACE_MALLOC, "read %lu bytes from offset %#lx\n", + SPDK_DEBUGLOG(SPDK_TRACE_MALLOC, "read %lu bytes from offset %#lx\n", len, offset); task->status = SPDK_BDEV_IO_STATUS_SUCCESS; @@ -209,7 +209,7 @@ bdev_malloc_writev(struct malloc_disk *mdisk, struct spdk_io_channel *ch, return; } - SPDK_TRACELOG(SPDK_TRACE_MALLOC, "wrote %lu bytes to offset %#lx\n", + SPDK_DEBUGLOG(SPDK_TRACE_MALLOC, "wrote %lu bytes to offset %#lx\n", len, offset); task->status = SPDK_BDEV_IO_STATUS_SUCCESS; diff --git a/lib/bdev/malloc/bdev_malloc_rpc.c b/lib/bdev/malloc/bdev_malloc_rpc.c index 43e3afd74..ceefb4ec5 100644 --- a/lib/bdev/malloc/bdev_malloc_rpc.c +++ b/lib/bdev/malloc/bdev_malloc_rpc.c @@ -58,7 +58,7 @@ spdk_rpc_construct_malloc_bdev(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_construct_malloc_decoders, SPDK_COUNTOF(rpc_construct_malloc_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } diff --git a/lib/bdev/null/bdev_null_rpc.c b/lib/bdev/null/bdev_null_rpc.c index 3af418043..2c64e0e4a 100644 --- a/lib/bdev/null/bdev_null_rpc.c +++ b/lib/bdev/null/bdev_null_rpc.c @@ -62,7 +62,7 @@ spdk_rpc_construct_null_bdev(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_construct_null_decoders, SPDK_COUNTOF(rpc_construct_null_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } diff --git a/lib/bdev/nvme/bdev_nvme.c b/lib/bdev/nvme/bdev_nvme.c index 630104363..3ac32d7c7 100644 --- a/lib/bdev/nvme/bdev_nvme.c +++ b/lib/bdev/nvme/bdev_nvme.c @@ -165,7 +165,7 @@ bdev_nvme_readv(struct nvme_bdev *nbdev, struct spdk_io_channel *ch, { struct nvme_io_channel *nvme_ch = spdk_io_channel_get_ctx(ch); - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "read %lu bytes with offset %#lx\n", + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "read %lu bytes with offset %#lx\n", nbytes, offset); return bdev_nvme_queue_cmd(nbdev, nvme_ch->qpair, bio, BDEV_DISK_READ, @@ -179,7 +179,7 @@ bdev_nvme_writev(struct nvme_bdev *nbdev, struct spdk_io_channel *ch, { struct nvme_io_channel *nvme_ch = spdk_io_channel_get_ctx(ch); - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "write %lu bytes with offset %#lx\n", + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "write %lu bytes with offset %#lx\n", len, offset); return bdev_nvme_queue_cmd(nbdev, nvme_ch->qpair, bio, BDEV_DISK_WRITE, @@ -680,7 +680,7 @@ static bool hotplug_probe_cb(void *cb_ctx, const struct spdk_nvme_transport_id *trid, struct spdk_nvme_ctrlr_opts *opts) { - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "Attaching to %s\n", trid->traddr); + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "Attaching to %s\n", trid->traddr); return true; } @@ -704,7 +704,7 @@ probe_cb(void *cb_ctx, const struct spdk_nvme_transport_id *trid, struct spdk_nvme_ctrlr_opts *opts) { - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "Probing device %s\n", trid->traddr); + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "Probing device %s\n", trid->traddr); if (nvme_ctrlr_get(trid)) { SPDK_ERRLOG("A controller with the provided trid (traddr: %s) already exists.\n", @@ -726,7 +726,7 @@ probe_cb(void *cb_ctx, const struct spdk_nvme_transport_id *trid, } if (!claim_device) { - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "Not claiming device at %s\n", trid->traddr); + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "Not claiming device at %s\n", trid->traddr); return false; } @@ -813,7 +813,7 @@ attach_cb(void *cb_ctx, const struct spdk_nvme_transport_id *trid, return; } - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "Attached to %s (%s)\n", trid->traddr, name); + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "Attached to %s (%s)\n", trid->traddr, name); nvme_ctrlr = calloc(1, sizeof(*nvme_ctrlr)); if (nvme_ctrlr == NULL) { @@ -1106,12 +1106,12 @@ nvme_ctrlr_create_bdevs(struct nvme_ctrlr *nvme_ctrlr) for (ns_id = 1; ns_id <= num_ns; ns_id++) { ns = spdk_nvme_ctrlr_get_ns(ctrlr, ns_id); if (!ns) { - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "Skipping invalid NS %d\n", ns_id); + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "Skipping invalid NS %d\n", ns_id); continue; } if (!spdk_nvme_ns_is_active(ns)) { - SPDK_TRACELOG(SPDK_TRACE_BDEV_NVME, "Skipping inactive NS %d\n", ns_id); + SPDK_DEBUGLOG(SPDK_TRACE_BDEV_NVME, "Skipping inactive NS %d\n", ns_id); continue; } diff --git a/lib/bdev/rbd/bdev_rbd_rpc.c b/lib/bdev/rbd/bdev_rbd_rpc.c index f939b7cf4..4c9c68164 100644 --- a/lib/bdev/rbd/bdev_rbd_rpc.c +++ b/lib/bdev/rbd/bdev_rbd_rpc.c @@ -67,7 +67,7 @@ spdk_rpc_construct_rbd_bdev(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_construct_rbd_decoders, SPDK_COUNTOF(rpc_construct_rbd_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } diff --git a/lib/bdev/split/vbdev_split.c b/lib/bdev/split/vbdev_split.c index e7fbadc51..b712fc5c2 100644 --- a/lib/bdev/split/vbdev_split.c +++ b/lib/bdev/split/vbdev_split.c @@ -285,11 +285,11 @@ vbdev_split_create(struct spdk_bdev *base_bdev, uint64_t split_count, uint64_t s return -1; } split_size_blocks = (split_size_mb * mb) / base_bdev->blocklen; - SPDK_TRACELOG(SPDK_TRACE_VBDEV_SPLIT, "Split size %" PRIu64 " MB specified by user\n", + SPDK_DEBUGLOG(SPDK_TRACE_VBDEV_SPLIT, "Split size %" PRIu64 " MB specified by user\n", split_size_mb); } else { split_size_blocks = base_bdev->blockcnt / split_count; - SPDK_TRACELOG(SPDK_TRACE_VBDEV_SPLIT, "Split size not specified by user\n"); + SPDK_DEBUGLOG(SPDK_TRACE_VBDEV_SPLIT, "Split size not specified by user\n"); } split_size_bytes = split_size_blocks * base_bdev->blocklen; @@ -301,7 +301,7 @@ vbdev_split_create(struct spdk_bdev *base_bdev, uint64_t split_count, uint64_t s split_count = max_split_count; } - SPDK_TRACELOG(SPDK_TRACE_VBDEV_SPLIT, "base_bdev: %s split_count: %" PRIu64 + SPDK_DEBUGLOG(SPDK_TRACE_VBDEV_SPLIT, "base_bdev: %s split_count: %" PRIu64 " split_size_bytes: %" PRIu64 "\n", spdk_bdev_get_name(base_bdev), split_count, split_size_bytes); @@ -361,7 +361,7 @@ vbdev_split_create(struct spdk_bdev *base_bdev, uint64_t split_count, uint64_t s d->disk.fn_table = &vbdev_split_fn_table; d->disk.module = SPDK_GET_BDEV_MODULE(split); - SPDK_TRACELOG(SPDK_TRACE_VBDEV_SPLIT, "Split vbdev %s: base bdev: %s offset_bytes: " + SPDK_DEBUGLOG(SPDK_TRACE_VBDEV_SPLIT, "Split vbdev %s: base bdev: %s offset_bytes: " "%" PRIu64 " offset_blocks: %" PRIu64 "\n", d->disk.name, spdk_bdev_get_name(base_bdev), d->offset_bytes, d->offset_blocks); diff --git a/lib/blob/blobstore.c b/lib/blob/blobstore.c index bafc34fcd..dd6251d5d 100644 --- a/lib/blob/blobstore.c +++ b/lib/blob/blobstore.c @@ -58,7 +58,7 @@ _spdk_bs_claim_cluster(struct spdk_blob_store *bs, uint32_t cluster_num) assert(spdk_bit_array_get(bs->used_clusters, cluster_num) == false); assert(bs->num_free_clusters > 0); - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Claiming cluster %u\n", cluster_num); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Claiming cluster %u\n", cluster_num); spdk_bit_array_set(bs->used_clusters, cluster_num); bs->num_free_clusters--; @@ -71,7 +71,7 @@ _spdk_bs_release_cluster(struct spdk_blob_store *bs, uint32_t cluster_num) assert(spdk_bit_array_get(bs->used_clusters, cluster_num) == true); assert(bs->num_free_clusters < bs->total_clusters); - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Releasing cluster %u\n", cluster_num); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Releasing cluster %u\n", cluster_num); spdk_bit_array_clear(bs->used_clusters, cluster_num); bs->num_free_clusters++; @@ -905,7 +905,7 @@ _spdk_resize_blob(struct spdk_blob *blob, uint64_t sz) lfc = 0; for (i = blob->active.num_clusters; i < sz; i++) { lfc = spdk_bit_array_find_first_clear(bs->used_clusters, lfc); - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Claiming cluster %lu for blob %lu\n", lfc, blob->id); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Claiming cluster %lu for blob %lu\n", lfc, blob->id); _spdk_bs_claim_cluster(bs, lfc); blob->active.clusters[i] = _spdk_bs_cluster_to_lba(bs, lfc); lfc++; @@ -1002,7 +1002,7 @@ _spdk_blob_persist(spdk_bs_sequence_t *seq, struct spdk_blob *blob, ctx->pages[i - 1].next = page_num; blob->active.pages[i] = page_num; spdk_bit_array_set(bs->used_md_pages, page_num); - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Claiming page %u for blob %lu\n", page_num, blob->id); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Claiming page %u for blob %lu\n", page_num, blob->id); page_num++; } @@ -1556,7 +1556,7 @@ spdk_bs_load(struct spdk_bs_dev *dev, struct spdk_bs_load_ctx *ctx; struct spdk_bs_opts opts = {}; - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Loading blobstore from dev %p\n", dev); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Loading blobstore from dev %p\n", dev); spdk_bs_opts_init(&opts); @@ -1647,7 +1647,7 @@ spdk_bs_init(struct spdk_bs_dev *dev, struct spdk_bs_opts *o, struct spdk_bs_opts opts = {}; int rc; - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Initializing blobstore on dev %p\n", dev); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Initializing blobstore on dev %p\n", dev); if ((SPDK_BS_PAGE_SIZE % dev->blocklen) != 0) { SPDK_ERRLOG("unsupported dev block length of %d\n", @@ -1887,7 +1887,7 @@ spdk_bs_unload(struct spdk_blob_store *bs, spdk_bs_op_complete cb_fn, void *cb_a spdk_bs_sequence_t *seq; struct spdk_bs_unload_ctx *ctx; - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Syncing blobstore\n"); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Syncing blobstore\n"); ctx = calloc(1, sizeof(*ctx)); if (!ctx) { @@ -2032,7 +2032,7 @@ void spdk_bs_md_create_blob(struct spdk_blob_store *bs, */ id = (1ULL << 32) | page_idx; - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Creating blob with id %lu at page %u\n", id, page_idx); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Creating blob with id %lu at page %u\n", id, page_idx); blob = _spdk_blob_alloc(bs, id); if (!blob) { @@ -2065,7 +2065,7 @@ spdk_bs_md_resize_blob(struct spdk_blob *blob, uint64_t sz) assert(blob != NULL); - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Resizing blob %lu to %lu clusters\n", blob->id, sz); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Resizing blob %lu to %lu clusters\n", blob->id, sz); if (sz == blob->active.num_clusters) { return 0; @@ -2114,7 +2114,7 @@ spdk_bs_md_delete_blob(struct spdk_blob_store *bs, spdk_blob_id blobid, struct spdk_bs_cpl cpl; spdk_bs_sequence_t *seq; - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Deleting blob %lu\n", blobid); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Deleting blob %lu\n", blobid); blob = _spdk_blob_lookup(bs, blobid); if (blob) { @@ -2167,7 +2167,7 @@ void spdk_bs_md_open_blob(struct spdk_blob_store *bs, spdk_blob_id blobid, spdk_bs_sequence_t *seq; uint32_t page_num; - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Opening blob %lu\n", blobid); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Opening blob %lu\n", blobid); blob = _spdk_blob_lookup(bs, blobid); if (blob) { @@ -2219,7 +2219,7 @@ void spdk_bs_md_sync_blob(struct spdk_blob *blob, assert(blob != NULL); - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Syncing blob %lu\n", blob->id); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Syncing blob %lu\n", blob->id); assert(blob->state != SPDK_BLOB_STATE_LOADING && blob->state != SPDK_BLOB_STATE_SYNCING); @@ -2272,7 +2272,7 @@ void spdk_bs_md_close_blob(struct spdk_blob **b, blob = *b; assert(blob != NULL); - SPDK_TRACELOG(SPDK_TRACE_BLOB, "Closing blob %lu\n", blob->id); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB, "Closing blob %lu\n", blob->id); assert(blob->state != SPDK_BLOB_STATE_LOADING && blob->state != SPDK_BLOB_STATE_SYNCING); diff --git a/lib/blob/request.c b/lib/blob/request.c index 3f985e24d..153f32445 100644 --- a/lib/blob/request.c +++ b/lib/blob/request.c @@ -130,7 +130,7 @@ spdk_bs_sequence_read(spdk_bs_sequence_t *seq, void *payload, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)seq; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Reading %u blocks from LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Reading %u blocks from LBA %lu\n", lba_count, lba); set->u.sequence.cb_fn = cb_fn; set->u.sequence.cb_arg = cb_arg; @@ -147,7 +147,7 @@ spdk_bs_sequence_write(spdk_bs_sequence_t *seq, void *payload, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)seq; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Writing %u blocks to LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Writing %u blocks to LBA %lu\n", lba_count, lba); set->u.sequence.cb_fn = cb_fn; set->u.sequence.cb_arg = cb_arg; @@ -164,7 +164,7 @@ spdk_bs_sequence_readv(spdk_bs_sequence_t *seq, struct iovec *iov, int iovcnt, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)seq; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Reading %u blocks from LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Reading %u blocks from LBA %lu\n", lba_count, lba); set->u.sequence.cb_fn = cb_fn; set->u.sequence.cb_arg = cb_arg; @@ -181,7 +181,7 @@ spdk_bs_sequence_writev(spdk_bs_sequence_t *seq, struct iovec *iov, int iovcnt, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)seq; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Writing %u blocks to LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Writing %u blocks to LBA %lu\n", lba_count, lba); set->u.sequence.cb_fn = cb_fn; set->u.sequence.cb_arg = cb_arg; @@ -197,7 +197,7 @@ spdk_bs_sequence_flush(spdk_bs_sequence_t *seq, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)seq; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Flushing\n"); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Flushing\n"); set->u.sequence.cb_fn = cb_fn; set->u.sequence.cb_arg = cb_arg; @@ -214,7 +214,7 @@ spdk_bs_sequence_unmap(spdk_bs_sequence_t *seq, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)seq; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Unmapping %u blocks at LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Unmapping %u blocks at LBA %lu\n", lba_count, lba); set->u.sequence.cb_fn = cb_fn; set->u.sequence.cb_arg = cb_arg; @@ -291,7 +291,7 @@ spdk_bs_batch_read(spdk_bs_batch_t *batch, void *payload, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)batch; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Reading %u blocks from LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Reading %u blocks from LBA %lu\n", lba_count, lba); set->u.batch.outstanding_ops++; channel->dev->read(channel->dev, channel->dev_channel, payload, lba, lba_count, @@ -305,7 +305,7 @@ spdk_bs_batch_write(spdk_bs_batch_t *batch, void *payload, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)batch; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Writing %u blocks to LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Writing %u blocks to LBA %lu\n", lba_count, lba); set->u.batch.outstanding_ops++; channel->dev->write(channel->dev, channel->dev_channel, payload, lba, lba_count, @@ -318,7 +318,7 @@ spdk_bs_batch_flush(spdk_bs_batch_t *batch) struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)batch; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Flushing\n"); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Flushing\n"); set->u.batch.outstanding_ops++; channel->dev->flush(channel->dev, channel->dev_channel, @@ -332,7 +332,7 @@ spdk_bs_batch_unmap(spdk_bs_batch_t *batch, struct spdk_bs_request_set *set = (struct spdk_bs_request_set *)batch; struct spdk_bs_channel *channel = set->channel; - SPDK_TRACELOG(SPDK_TRACE_BLOB_RW, "Unmapping %u blocks at LBA %lu\n", lba_count, lba); + SPDK_DEBUGLOG(SPDK_TRACE_BLOB_RW, "Unmapping %u blocks at LBA %lu\n", lba_count, lba); set->u.batch.outstanding_ops++; channel->dev->unmap(channel->dev, channel->dev_channel, lba, lba_count, diff --git a/lib/blobfs/blobfs.c b/lib/blobfs/blobfs.c index b12d58a3d..94ffb0518 100644 --- a/lib/blobfs/blobfs.c +++ b/lib/blobfs/blobfs.c @@ -44,10 +44,10 @@ #include "spdk_internal/log.h" #define BLOBFS_TRACE(file, str, args...) \ - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s " str, file->name, ##args) + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s " str, file->name, ##args) #define BLOBFS_TRACE_RW(file, str, args...) \ - SPDK_TRACELOG(SPDK_TRACE_BLOBFS_RW, "file=%s " str, file->name, ##args) + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS_RW, "file=%s " str, file->name, ##args) #define BLOBFS_CACHE_SIZE (4ULL * 1024 * 1024 * 1024) @@ -533,7 +533,7 @@ iter_cb(void *ctx, struct spdk_blob *blob, int rc) f->length = *length; f->length_flushed = *length; f->append_pos = *length; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "added file %s length=%ju\n", f->name, f->length); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "added file %s length=%ju\n", f->name, f->length); spdk_bs_md_iter_next(fs->bs, &blob, iter_cb, req); } @@ -810,7 +810,7 @@ __fs_create_file_done(void *arg, int fserrno) args->rc = fserrno; sem_post(args->sem); - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.create.name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.create.name); } static void @@ -819,7 +819,7 @@ __fs_create_file(void *arg) struct spdk_fs_request *req = arg; struct spdk_fs_cb_args *args = &req->args; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.create.name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.create.name); spdk_fs_create_file_async(args->fs, args->op.create.name, __fs_create_file_done, req); } @@ -831,7 +831,7 @@ spdk_fs_create_file(struct spdk_filesystem *fs, struct spdk_io_channel *_channel struct spdk_fs_cb_args *args; int rc; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s\n", name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s\n", name); req = alloc_fs_request(channel); assert(req != NULL); @@ -948,7 +948,7 @@ __fs_open_file_done(void *arg, struct spdk_file *file, int bserrno) args->file = file; args->rc = bserrno; sem_post(args->sem); - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.open.name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.open.name); } static void @@ -957,7 +957,7 @@ __fs_open_file(void *arg) struct spdk_fs_request *req = arg; struct spdk_fs_cb_args *args = &req->args; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.open.name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s\n", args->op.open.name); spdk_fs_open_file_async(args->fs, args->op.open.name, args->op.open.flags, __fs_open_file_done, req); } @@ -971,7 +971,7 @@ spdk_fs_open_file(struct spdk_filesystem *fs, struct spdk_io_channel *_channel, struct spdk_fs_cb_args *args; int rc; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s\n", name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s\n", name); req = alloc_fs_request(channel); assert(req != NULL); @@ -1051,7 +1051,7 @@ spdk_fs_rename_file_async(struct spdk_filesystem *fs, struct spdk_fs_request *req; struct spdk_fs_cb_args *args; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "old=%s new=%s\n", old_name, new_name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "old=%s new=%s\n", old_name, new_name); if (strnlen(new_name, SPDK_FILE_NAME_MAX + 1) == SPDK_FILE_NAME_MAX + 1) { cb_fn(cb_arg, -ENAMETOOLONG); return; @@ -1147,7 +1147,7 @@ spdk_fs_delete_file_async(struct spdk_filesystem *fs, const char *name, struct spdk_fs_request *req; struct spdk_fs_cb_args *args; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s\n", name); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s\n", name); if (strnlen(name, SPDK_FILE_NAME_MAX + 1) == SPDK_FILE_NAME_MAX + 1) { cb_fn(cb_arg, -ENAMETOOLONG); @@ -1263,7 +1263,7 @@ uint64_t spdk_file_get_length(struct spdk_file *file) { assert(file != NULL); - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s length=0x%jx\n", file->name, file->length); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s length=0x%jx\n", file->name, file->length); return file->length; } @@ -1292,7 +1292,7 @@ spdk_file_truncate_async(struct spdk_file *file, uint64_t length, struct spdk_fs_request *req; struct spdk_fs_cb_args *args; - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s old=0x%jx new=0x%jx\n", file->name, file->length, length); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s old=0x%jx new=0x%jx\n", file->name, file->length, length); if (length == file->length) { cb_fn(cb_arg, 0); return; @@ -1472,7 +1472,7 @@ spdk_file_read_async(struct spdk_file *file, struct spdk_io_channel *channel, void *payload, uint64_t offset, uint64_t length, spdk_file_op_complete cb_fn, void *cb_arg) { - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "file=%s offset=%jx length=%jx\n", + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "file=%s offset=%jx length=%jx\n", file->name, offset, length); __readwrite(file, channel, payload, offset, length, cb_fn, cb_arg, 1); } @@ -1595,7 +1595,7 @@ cache_insert_buffer(struct spdk_file *file, uint64_t offset) buf = calloc(1, sizeof(*buf)); if (buf == NULL) { - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "calloc failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "calloc failed\n"); return NULL; } @@ -1640,7 +1640,7 @@ cache_append_buffer(struct spdk_file *file) last = cache_insert_buffer(file, file->append_pos); if (last == NULL) { - SPDK_TRACELOG(SPDK_TRACE_BLOBFS, "cache_insert_buffer failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_BLOBFS, "cache_insert_buffer failed\n"); return NULL; } diff --git a/lib/event/reactor.c b/lib/event/reactor.c index 1e54e7dff..1ef6e7e87 100644 --- a/lib/event/reactor.c +++ b/lib/event/reactor.c @@ -266,7 +266,7 @@ get_rusage(void *arg) } if (rusage.ru_nvcsw != reactor->rusage.ru_nvcsw || rusage.ru_nivcsw != reactor->rusage.ru_nivcsw) { - SPDK_TRACELOG(SPDK_TRACE_REACTOR, + SPDK_DEBUGLOG(SPDK_TRACE_REACTOR, "Reactor %d: %ld voluntary context switches and %ld involuntary context switches in the last second.\n", reactor->lcore, rusage.ru_nvcsw - reactor->rusage.ru_nvcsw, rusage.ru_nivcsw - reactor->rusage.ru_nivcsw); diff --git a/lib/event/rpc/app_rpc.c b/lib/event/rpc/app_rpc.c index c5f31a25d..a57a8c0f4 100644 --- a/lib/event/rpc/app_rpc.c +++ b/lib/event/rpc/app_rpc.c @@ -74,7 +74,7 @@ spdk_rpc_kill_instance(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_kill_instance_decoders, SPDK_COUNTOF(rpc_kill_instance_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } @@ -91,7 +91,7 @@ spdk_rpc_kill_instance(struct spdk_jsonrpc_request *request, goto invalid; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "sending signal %d\n", signals[i].signal); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "sending signal %d\n", signals[i].signal); kill(getpid(), signals[i].signal); free_rpc_kill_instance(&req); diff --git a/lib/iscsi/conn.c b/lib/iscsi/conn.c index c7b8c89e6..40947f671 100644 --- a/lib/iscsi/conn.c +++ b/lib/iscsi/conn.c @@ -345,7 +345,7 @@ int spdk_initialize_iscsi_conns(void) int conns_array_fd; int i, rc; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_init\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_init\n"); rc = pthread_mutex_init(&g_conns_mutex, NULL); if (rc != 0) { @@ -638,13 +638,13 @@ static void spdk_iscsi_remove_conn(struct spdk_iscsi_conn *conn) if (sess->connections == 0) { /* cleanup last connection */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "cleanup last conn free sess\n"); spdk_free_sess(sess); } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "cleanup free conn\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "cleanup free conn\n"); spdk_iscsi_conn_free(conn); } @@ -858,7 +858,7 @@ spdk_iscsi_drop_conns(struct spdk_iscsi_conn *conn, const char *conn_match, const char *xconn_match; int i, num; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_drop_conns\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_drop_conns\n"); num = 0; pthread_mutex_lock(&g_conns_mutex); @@ -892,12 +892,12 @@ spdk_iscsi_drop_conns(struct spdk_iscsi_conn *conn, const char *conn_match, SPDK_ERRLOG("exiting conn by %s (%s)\n", xconn_match, xconn->initiator_addr); if (xconn->sess != NULL) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "TSIH=%u\n", xconn->sess->tsih); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "TSIH=%u\n", xconn->sess->tsih); } else { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "TSIH=xx\n"); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "TSIH=xx\n"); } - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "CID=%u\n", xconn->cid); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CID=%u\n", xconn->cid); xconn->state = ISCSI_CONN_STATE_EXITING; num++; } @@ -1229,7 +1229,7 @@ spdk_iscsi_conn_flush_pdus_internal(struct spdk_iscsi_conn *conn) if ((conn->full_feature) && (conn->sess->ErrorRecoveryLevel >= 1) && spdk_iscsi_is_deferred_free_pdu(pdu)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "stat_sn=%d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "stat_sn=%d\n", from_be32(&pdu->bhs.stat_sn)); TAILQ_INSERT_TAIL(&conn->snack_pdu_list, pdu, tailq); @@ -1508,7 +1508,7 @@ void spdk_iscsi_conn_idle_do_work(void *arg) spdk_net_framework_clear_socket_association(tconn->sock); spdk_event_call(spdk_iscsi_conn_get_migrate_event(tconn, &lcore)); __sync_fetch_and_add(&g_num_connections[lcore], 1); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "add conn id = %d, cid = %d poller = %p to lcore = %d active\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add conn id = %d, cid = %d poller = %p to lcore = %d active\n", tconn->id, tconn->cid, &tconn->poller, lcore); } } /* for each conn in idle list */ @@ -1533,7 +1533,7 @@ __add_idle_conn(void *arg1, void *arg2) rc = add_idle_conn(conn); if (rc == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "add conn id = %d, cid = %d poller = %p to idle\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add conn id = %d, cid = %d poller = %p to idle\n", conn->id, conn->cid, conn->poller); conn->is_idle = 1; STAILQ_INSERT_TAIL(&g_idle_conn_list_head, conn, link); diff --git a/lib/iscsi/init_grp.c b/lib/iscsi/init_grp.c index 747688cde..525c431f3 100644 --- a/lib/iscsi/init_grp.c +++ b/lib/iscsi/init_grp.c @@ -56,11 +56,11 @@ spdk_iscsi_init_grp_create_from_configfile(struct spdk_conf_section *sp) char **initiators = NULL, **netmasks = NULL; int tag = spdk_conf_section_get_num(sp); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "add initiator group %d\n", tag); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add initiator group %d\n", tag); val = spdk_conf_section_get_val(sp, "Comment"); if (val != NULL) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Comment %s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Comment %s\n", val); } /* counts number of definitions */ @@ -105,7 +105,7 @@ spdk_iscsi_init_grp_create_from_configfile(struct spdk_conf_section *sp) rc = -EINVAL; goto cleanup; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "InitiatorName %s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "InitiatorName %s\n", val); initiators[i] = strdup(val); if (!initiators[i]) { perror("initiator name copy"); @@ -126,7 +126,7 @@ spdk_iscsi_init_grp_create_from_configfile(struct spdk_conf_section *sp) rc = -EINVAL; goto cleanup; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Netmask %s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Netmask %s\n", val); netmasks[i] = strdup(val); if (!netmasks[i]) { perror("initiator netmask copy"); @@ -196,7 +196,7 @@ spdk_iscsi_init_grp_create_from_initiator_list(int tag, goto cleanup; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add initiator group (from initiator list) tag=%d, #initiators=%d, #masks=%d\n", tag, num_initiator_names, num_initiator_masks); @@ -215,12 +215,12 @@ spdk_iscsi_init_grp_create_from_initiator_list(int tag, ig->nnetmasks = num_initiator_masks; ig->initiators = initiator_names; for (i = 0; i < num_initiator_names; i++) - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "InitiatorName %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "InitiatorName %s\n", ig->initiators[i]); ig->netmasks = initiator_masks; for (i = 0; i < num_initiator_masks; i++) - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Netmask %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Netmask %s\n", ig->netmasks[i]); ig->state = GROUP_INIT; @@ -317,7 +317,7 @@ spdk_iscsi_init_grp_array_destroy(void) { struct spdk_iscsi_init_grp *ig, *tmp; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_init_grp_array_destroy\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_init_grp_array_destroy\n"); pthread_mutex_lock(&g_spdk_iscsi.mutex); TAILQ_FOREACH_SAFE(ig, &g_spdk_iscsi.ig_head, tailq, tmp) { ig->state = GROUP_DESTROY; diff --git a/lib/iscsi/iscsi.c b/lib/iscsi/iscsi.c index 9be408a6e..88f00051b 100644 --- a/lib/iscsi/iscsi.c +++ b/lib/iscsi/iscsi.c @@ -671,7 +671,7 @@ spdk_iscsi_append_param(struct spdk_iscsi_conn *conn, const char *key, if (param == NULL) { param = spdk_iscsi_param_find(conn->sess->params, key); if (param == NULL) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "no key %.64s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "no key %.64s\n", key); return data_len; } @@ -732,7 +732,7 @@ spdk_iscsi_chap_get_authinfo(struct iscsi_chap_auth *auth, const char *authfile, val = spdk_conf_section_get_val(sp, "Comment"); if (val != NULL) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Comment %s\n", val); } for (i = 0; ; i++) { @@ -784,7 +784,7 @@ spdk_iscsi_get_authinfo(struct spdk_iscsi_conn *conn, const char *authuser) ag_tag = g_spdk_iscsi.discovery_auth_group; pthread_mutex_unlock(&g_spdk_iscsi.mutex); } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "ag_tag=%d\n", ag_tag); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "ag_tag=%d\n", ag_tag); pthread_mutex_lock(&g_spdk_iscsi.mutex); authfile = strdup(g_spdk_iscsi.authfile); @@ -870,7 +870,7 @@ spdk_iscsi_auth_params(struct spdk_iscsi_conn *conn, goto error_return; } /* selected algorithm is 5 (MD5) */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "got CHAP_A=%s\n", new_val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "got CHAP_A=%s\n", new_val); total = spdk_iscsi_append_text(conn, "CHAP_A", new_val, data, alloc_len, total); @@ -914,7 +914,7 @@ spdk_iscsi_auth_params(struct spdk_iscsi_conn *conn, SPDK_ERRLOG("response format error\n"); goto error_return; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "got CHAP_N/CHAP_R\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "got CHAP_N/CHAP_R\n"); rc = spdk_iscsi_get_authinfo(conn, val); if (rc < 0) { @@ -944,7 +944,7 @@ spdk_iscsi_auth_params(struct spdk_iscsi_conn *conn, tgtmd5, SPDK_MD5DIGEST_LEN); #if 0 - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "tgtmd5=%s, resmd5=%s\n", in_val, response); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "tgtmd5=%s, resmd5=%s\n", in_val, response); spdk_dump("tgtmd5", tgtmd5, SPDK_MD5DIGEST_LEN); spdk_dump("resmd5", resmd5, SPDK_MD5DIGEST_LEN); #endif @@ -980,7 +980,7 @@ spdk_iscsi_auth_params(struct spdk_iscsi_conn *conn, spdk_dump("MChallenge", conn->auth.chap_mchallenge, conn->auth.chap_mchallenge_len); #endif - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "got CHAP_I/CHAP_C\n"); if (conn->auth.muser == NULL || conn->auth.msecret == NULL) { @@ -1019,7 +1019,7 @@ spdk_iscsi_auth_params(struct spdk_iscsi_conn *conn, conn->auth.chap_phase = ISCSI_CHAP_PHASE_END; } else { /* not found CHAP keys */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "start CHAP\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "start CHAP\n"); conn->auth.chap_phase = ISCSI_CHAP_PHASE_WAIT_A; } @@ -1058,15 +1058,15 @@ spdk_iscsi_reject(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu, memset(data, 0, alloc_len); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Reject PDU reason=%d\n", reason); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Reject PDU reason=%d\n", reason); if (conn->sess != NULL) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "StatSN=%u, ExpCmdSN=%u, MaxCmdSN=%u\n", conn->StatSN, conn->sess->ExpCmdSN, conn->sess->MaxCmdSN); } else { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "StatSN=%u\n", conn->StatSN); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "StatSN=%u\n", conn->StatSN); } memcpy(data, &pdu->bhs, ISCSI_BHS_LEN); @@ -1354,7 +1354,7 @@ spdk_iscsi_op_login_check_session(struct spdk_iscsi_conn *conn, rsph = (struct iscsi_bhs_login_rsp *)&rsp_pdu->bhs; /* check existing session */ - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "isid=%"PRIx64", tsih=%u, cid=%u\n", + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "isid=%"PRIx64", tsih=%u, cid=%u\n", spdk_iscsi_get_isid(rsph->isid), from_be16(&rsph->tsih), cid); if (rsph->tsih != 0) { /* multiple connections */ @@ -1535,7 +1535,7 @@ spdk_iscsi_op_login_session_type(struct spdk_iscsi_conn *conn, return SPDK_ISCSI_LOGIN_ERROR_RESPONSE; } } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Session Type: %s\n", session_type_str); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Session Type: %s\n", session_type_str); return 0; } @@ -1571,9 +1571,9 @@ spdk_iscsi_op_login_initialize_port(struct spdk_iscsi_conn *conn, "%s,i,0x%12.12" PRIx64, val, spdk_iscsi_get_isid(rsph->isid)); spdk_strlwr(conn->initiator_name); spdk_strlwr(initiator_port_name); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Initiator name: %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Initiator name: %s\n", conn->initiator_name); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Initiator port: %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Initiator port: %s\n", initiator_port_name); return 0; @@ -1860,7 +1860,7 @@ spdk_iscsi_op_login_rsp_init(struct spdk_iscsi_conn *conn, SPDK_TRACEDUMP(SPDK_TRACE_DEBUG, "PDU", (uint8_t *)&pdu->bhs, ISCSI_BHS_LEN); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "T=%d, C=%d, CSG=%d, NSG=%d, Min=%d, Max=%d, ITT=%x\n", ISCSI_BHS_LOGIN_GET_TBIT(rsph->flags), ISCSI_BHS_LOGIN_GET_CBIT(rsph->flags), @@ -1869,14 +1869,14 @@ spdk_iscsi_op_login_rsp_init(struct spdk_iscsi_conn *conn, reqh->version_min, reqh->version_max, from_be32(&rsph->itt)); if (conn->sess != NULL) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CmdSN=%u, ExpStatSN=%u, StatSN=%u, ExpCmdSN=%u," "MaxCmdSN=%u\n", rsp_pdu->cmd_sn, from_be32(&rsph->stat_sn), conn->StatSN, conn->sess->ExpCmdSN, conn->sess->MaxCmdSN); } else { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CmdSN=%u, ExpStatSN=%u, StatSN=%u\n", rsp_pdu->cmd_sn, from_be32(&rsph->stat_sn), conn->StatSN); @@ -1973,7 +1973,7 @@ spdk_iscsi_op_login_rsp_handle_csg_bit(struct spdk_iscsi_conn *conn, } else { if (conn->auth.chap_phase != ISCSI_CHAP_PHASE_END) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CHAP phase not " "complete"); } @@ -2263,10 +2263,10 @@ spdk_iscsi_op_text(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) pdu->cmd_sn = CmdSN; ExpStatSN = from_be32(&reqh->exp_stat_sn); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "I=%d, F=%d, C=%d, ITT=%x, TTT=%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "I=%d, F=%d, C=%d, ITT=%x, TTT=%x\n", reqh->immediate, F_bit, C_bit, task_tag, from_be32(&reqh->ttt)); - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CmdSN=%u, ExpStatSN=%u, StatSN=%u, ExpCmdSN=%u, MaxCmdSN=%u\n", CmdSN, ExpStatSN, conn->StatSN, conn->sess->ExpCmdSN, conn->sess->MaxCmdSN); @@ -2277,7 +2277,7 @@ spdk_iscsi_op_text(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) return -1; #else /* StarPort have a bug */ - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "StatSN(%u) rewound\n", ExpStatSN); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "StatSN(%u) rewound\n", ExpStatSN); conn->StatSN = ExpStatSN; #endif } @@ -2454,7 +2454,7 @@ spdk_iscsi_op_logout(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) pdu->cmd_sn = CmdSN; ExpStatSN = from_be32(&reqh->exp_stat_sn); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "reason=%d, ITT=%x, cid=%d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "reason=%d, ITT=%x, cid=%d\n", reason, task_tag, cid); if (reqh->reason != 0 && conn->sess->session_type == SESSION_TYPE_DISCOVERY) { @@ -2465,23 +2465,23 @@ spdk_iscsi_op_logout(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) if (conn->sess != NULL) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CmdSN=%u, ExpStatSN=%u, StatSN=%u, ExpCmdSN=%u, MaxCmdSN=%u\n", CmdSN, ExpStatSN, conn->StatSN, conn->sess->ExpCmdSN, conn->sess->MaxCmdSN); if (CmdSN != conn->sess->ExpCmdSN) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "CmdSN(%u) might have dropped\n", CmdSN); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CmdSN(%u) might have dropped\n", CmdSN); /* ignore error */ } } else { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CmdSN=%u, ExpStatSN=%u, StatSN=%u\n", CmdSN, ExpStatSN, conn->StatSN); } if (ExpStatSN != conn->StatSN) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "StatSN(%u/%u) might have dropped\n", + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "StatSN(%u/%u) might have dropped\n", ExpStatSN, conn->StatSN); /* ignore error */ } @@ -2743,19 +2743,19 @@ spdk_iscsi_transfer_in(struct spdk_iscsi_conn *conn, if (data_len < transfer_len) { /* underflow */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Underflow %u/%u\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Underflow %u/%u\n", data_len, transfer_len); residual_len = transfer_len - data_len; transfer_len = data_len; datain_flag |= ISCSI_DATAIN_UNDERFLOW; } else if (data_len > transfer_len) { /* overflow */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Overflow %u/%u\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Overflow %u/%u\n", data_len, transfer_len); residual_len = data_len - transfer_len; datain_flag |= ISCSI_DATAIN_OVERFLOW; } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Transfer %u\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Transfer %u\n", transfer_len); residual_len = 0; } @@ -2800,10 +2800,10 @@ spdk_iscsi_transfer_in(struct spdk_iscsi_conn *conn, datain_flag &= ~ISCSI_DATAIN_STATUS; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Transfer=%d, Offset=%d, Len=%d\n", sequence_end, offset, len); - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "StatSN=%u, DataSN=%u, Offset=%u, Len=%d\n", conn->StatSN, DataSN, offset, len); @@ -3171,18 +3171,18 @@ void spdk_iscsi_task_response(struct spdk_iscsi_conn *conn, (task->scsi.status == SPDK_SCSI_STATUS_GOOD)) { if (data_len < transfer_len) { /* underflow */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Underflow %zu/%u\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Underflow %zu/%u\n", data_len, transfer_len); residual_len = transfer_len - data_len; U_bit = 1; } else if (data_len > transfer_len) { /* overflow */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Overflow %zu/%u\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Overflow %zu/%u\n", data_len, transfer_len); residual_len = data_len - transfer_len; O_bit = 1; } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Transfer %u\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Transfer %u\n", transfer_len); } } @@ -3277,11 +3277,11 @@ spdk_iscsi_op_task(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) task_tag = from_be32(&reqh->itt); ref_task_tag = from_be32(&reqh->ref_task_tag); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "I=%d, func=%d, ITT=%x, ref TT=%x, LUN=0x%16.16"PRIx64"\n", reqh->immediate, function, task_tag, ref_task_tag, lun); - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "StatSN=%u, ExpCmdSN=%u, MaxCmdSN=%u\n", conn->StatSN, conn->sess->ExpCmdSN, conn->sess->MaxCmdSN); @@ -3417,10 +3417,10 @@ spdk_iscsi_op_nopout(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) CmdSN = from_be32(&reqh->cmd_sn); pdu->cmd_sn = CmdSN; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "I=%d, ITT=%x, TTT=%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "I=%d, ITT=%x, TTT=%x\n", I_bit, task_tag, transfer_tag); - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "CmdSN=%u, StatSN=%u, ExpCmdSN=%u, MaxCmdSN=%u\n", CmdSN, conn->StatSN, conn->sess->ExpCmdSN, conn->sess->MaxCmdSN); @@ -3443,7 +3443,7 @@ spdk_iscsi_op_nopout(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) if (task_tag == 0xffffffffU) { if (I_bit == 1) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "got NOPOUT ITT=0xffffffff\n"); return SPDK_SUCCESS; } else { @@ -3702,7 +3702,7 @@ spdk_iscsi_handle_recovery_datain(struct spdk_iscsi_conn *conn, task = spdk_iscsi_task_get_primary(task); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_handle_recovery_datain\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_handle_recovery_datain\n"); if (beg_run < task->acked_data_sn) { SPDK_ERRLOG("ITT: 0x%08x, DATA IN SNACK requests retransmission of" @@ -3760,7 +3760,7 @@ spdk_iscsi_handle_status_snack(struct spdk_iscsi_conn *conn, beg_run = from_be32(&reqh->beg_run); run_length = from_be32(&reqh->run_len); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "beg_run=%d, run_length=%d, conn->StatSN=" + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "beg_run=%d, run_length=%d, conn->StatSN=" "%d, conn->exp_statsn=%d\n", beg_run, run_length, conn->StatSN, conn->exp_statsn); @@ -3823,7 +3823,7 @@ spdk_iscsi_handle_data_ack(struct spdk_iscsi_conn *conn, task = NULL; datain_header = NULL; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "beg_run=%d,transfer_tag=%d,run_len=%d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "beg_run=%d,transfer_tag=%d,run_len=%d\n", beg_run, transfer_tag, run_length); task = spdk_get_scsi_task_from_ttt(conn, transfer_tag); @@ -3859,7 +3859,7 @@ spdk_iscsi_handle_data_ack(struct spdk_iscsi_conn *conn, } } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Received Data ACK SNACK for TTT: 0x%08x," + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Received Data ACK SNACK for TTT: 0x%08x," " updated acked DataSN to 0x%08x.\n", transfer_tag, (task->acked_data_sn - 1)); @@ -3919,7 +3919,7 @@ spdk_iscsi_send_r2t_recovery(struct spdk_iscsi_conn *conn, /* remove the r2t pdu from the snack_list */ pdu = spdk_iscsi_remove_r2t_pdu_from_snack_list(conn, task, r2t_sn); if (!pdu) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "No pdu is found\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "No pdu is found\n"); return -1; } @@ -3981,7 +3981,7 @@ spdk_iscsi_op_snack(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) } type = reqh->flags & ISCSI_FLAG_SNACK_TYPE_MASK; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "The value of type is %d\n", type); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "The value of type is %d\n", type); switch (type) { case 0: @@ -3990,7 +3990,7 @@ spdk_iscsi_op_snack(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) beg_run = from_be32(&reqh->beg_run); run_length = from_be32(&reqh->run_len); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "beg_run=%d, run_length=%d, " + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "beg_run=%d, run_length=%d, " "task_tag=%x, transfer_tag=%u\n", beg_run, run_length, task_tag, from_be32(&reqh->ttt)); @@ -4157,7 +4157,7 @@ static int spdk_iscsi_op_data(struct spdk_iscsi_conn *conn, } if (lun_dev == NULL) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "LUN %d is removed, complete the task immediately\n", lun_i); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "LUN %d is removed, complete the task immediately\n", lun_i); subtask->scsi.transfer_len = subtask->scsi.length; spdk_scsi_task_process_null_lun(&subtask->scsi); spdk_iscsi_task_cpl(&subtask->scsi); @@ -4236,10 +4236,10 @@ int spdk_iscsi_send_nopin(struct spdk_iscsi_conn *conn) return SPDK_SUCCESS; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "send NOPIN isid=%"PRIx64", tsih=%u, cid=%u\n", conn->sess->isid, conn->sess->tsih, conn->cid); - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "StatSN=%u, ExpCmdSN=%u, MaxCmdSN=%u\n", conn->StatSN, conn->sess->ExpCmdSN, conn->sess->MaxCmdSN); @@ -4304,7 +4304,7 @@ spdk_iscsi_execute(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) reqh = (struct iscsi_bhs_scsi_req *)&pdu->bhs; pdu->cmd_sn = from_be32(&reqh->cmd_sn); - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "opcode %x\n", opcode); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "opcode %x\n", opcode); if (opcode == ISCSI_OP_LOGIN) { rc = spdk_iscsi_op_login(conn, pdu); @@ -4343,7 +4343,7 @@ spdk_iscsi_execute(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) pdu->cmd_sn, sess->ExpCmdSN, sess->MaxCmdSN); if (sess->ErrorRecoveryLevel >= 1) - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Skip the error in" + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Skip the error in" " ERL 1 and 2\n"); else return SPDK_PDU_FATAL; @@ -4353,7 +4353,7 @@ spdk_iscsi_execute(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) SPDK_ERRLOG("CmdSN(%u) error ExpCmdSN=%u\n", pdu->cmd_sn, sess->ExpCmdSN); if (sess->ErrorRecoveryLevel >= 1) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Skip the error in" + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Skip the error in" " ERL 1 and 2\n"); } else if (opcode != ISCSI_OP_NOPOUT) { /* @@ -4367,7 +4367,7 @@ spdk_iscsi_execute(struct spdk_iscsi_conn *conn, struct spdk_iscsi_pdu *pdu) ExpStatSN = from_be32(&reqh->exp_stat_sn); if (SN32_GT(ExpStatSN, conn->StatSN)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "StatSN(%u) advanced\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "StatSN(%u) advanced\n", ExpStatSN); ExpStatSN = conn->StatSN; } @@ -4653,7 +4653,7 @@ spdk_append_iscsi_sess(struct spdk_iscsi_conn *conn, { struct spdk_iscsi_sess *sess; - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "append session: init port name=%s, tsih=%u, cid=%u\n", initiator_port_name, tsih, cid); @@ -4678,7 +4678,7 @@ spdk_append_iscsi_sess(struct spdk_iscsi_conn *conn, return -1; } - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "Connections (tsih %d): %d\n", sess->tsih, sess->connections); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "Connections (tsih %d): %d\n", sess->tsih, sess->connections); conn->sess = sess; /* diff --git a/lib/iscsi/iscsi_subsystem.c b/lib/iscsi/iscsi_subsystem.c index 4e5a6a127..988c10c05 100644 --- a/lib/iscsi/iscsi_subsystem.c +++ b/lib/iscsi/iscsi_subsystem.c @@ -563,7 +563,7 @@ spdk_iscsi_app_read_parameters(void) unsigned long flush_timeout = 0; /* Process parameters */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_app_read_parameters\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_app_read_parameters\n"); sp = spdk_conf_find_section(NULL, "iSCSI"); if (sp == NULL) { SPDK_ERRLOG("iSCSI config section not found.\n"); @@ -572,7 +572,7 @@ spdk_iscsi_app_read_parameters(void) val = spdk_conf_section_get_val(sp, "Comment"); if (val != NULL) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Comment %s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Comment %s\n", val); } val = spdk_conf_section_get_val(sp, "AuthFile"); @@ -585,7 +585,7 @@ spdk_iscsi_app_read_parameters(void) perror("authfile"); return -ENOMEM; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "AuthFile %s\n", g_spdk_iscsi.authfile); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "AuthFile %s\n", g_spdk_iscsi.authfile); /* ISCSI Global */ val = spdk_conf_section_get_val(sp, "NodeBase"); @@ -600,7 +600,7 @@ spdk_iscsi_app_read_parameters(void) return -ENOMEM; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "NodeBase %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "NodeBase %s\n", g_spdk_iscsi.nodebase); MaxSessions = spdk_conf_section_get_intval(sp, "MaxSessions"); @@ -612,7 +612,7 @@ spdk_iscsi_app_read_parameters(void) return -1; } g_spdk_iscsi.MaxSessions = MaxSessions; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "MaxSessions %d\n", g_spdk_iscsi.MaxSessions); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "MaxSessions %d\n", g_spdk_iscsi.MaxSessions); g_spdk_iscsi.session = spdk_dma_zmalloc(sizeof(void *) * g_spdk_iscsi.MaxSessions, 0, NULL); if (!g_spdk_iscsi.session) { @@ -625,7 +625,7 @@ spdk_iscsi_app_read_parameters(void) MaxConnectionsPerSession = DEFAULT_MAX_CONNECTIONS_PER_SESSION; } g_spdk_iscsi.MaxConnectionsPerSession = MaxConnectionsPerSession; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "MaxConnectionsPerSession %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "MaxConnectionsPerSession %d\n", g_spdk_iscsi.MaxConnectionsPerSession); if (MaxConnectionsPerSession > 0xffff) { @@ -646,7 +646,7 @@ spdk_iscsi_app_read_parameters(void) DefaultTime2Wait = DEFAULT_DEFAULTTIME2WAIT; } g_spdk_iscsi.DefaultTime2Wait = DefaultTime2Wait; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "DefaultTime2Wait %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DefaultTime2Wait %d\n", g_spdk_iscsi.DefaultTime2Wait); DefaultTime2Retain = spdk_conf_section_get_intval(sp, "DefaultTime2Retain"); @@ -654,7 +654,7 @@ spdk_iscsi_app_read_parameters(void) DefaultTime2Retain = DEFAULT_DEFAULTTIME2RETAIN; } g_spdk_iscsi.DefaultTime2Retain = DefaultTime2Retain; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "DefaultTime2Retain %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DefaultTime2Retain %d\n", g_spdk_iscsi.DefaultTime2Retain); /* check size limit - RFC3720(12.15, 12.16, 12.17) */ @@ -672,15 +672,15 @@ spdk_iscsi_app_read_parameters(void) } g_spdk_iscsi.FirstBurstLength = SPDK_ISCSI_FIRST_BURST_LENGTH; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "FirstBurstLength %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "FirstBurstLength %d\n", g_spdk_iscsi.FirstBurstLength); g_spdk_iscsi.MaxBurstLength = SPDK_ISCSI_MAX_BURST_LENGTH; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "MaxBurstLength %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "MaxBurstLength %d\n", g_spdk_iscsi.MaxBurstLength); g_spdk_iscsi.MaxRecvDataSegmentLength = SPDK_ISCSI_MAX_RECV_DATA_SEGMENT_LENGTH; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "MaxRecvDataSegmentLength %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "MaxRecvDataSegmentLength %d\n", g_spdk_iscsi.MaxRecvDataSegmentLength); /* check size limit (up to 24bits - RFC3720(12.12)) */ @@ -719,7 +719,7 @@ spdk_iscsi_app_read_parameters(void) return -1; } g_spdk_iscsi.InitialR2T = InitialR2T; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "InitialR2T %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "InitialR2T %s\n", g_spdk_iscsi.InitialR2T ? "Yes" : "No"); val = spdk_conf_section_get_val(sp, "ImmediateData"); @@ -734,7 +734,7 @@ spdk_iscsi_app_read_parameters(void) return -1; } g_spdk_iscsi.ImmediateData = ImmediateData; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "ImmediateData %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "ImmediateData %s\n", g_spdk_iscsi.ImmediateData ? "Yes" : "No"); val = spdk_conf_section_get_val(sp, "DataPDUInOrder"); @@ -754,7 +754,7 @@ spdk_iscsi_app_read_parameters(void) return -1; } g_spdk_iscsi.DataPDUInOrder = DataPDUInOrder; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "DataPDUInOrder %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DataPDUInOrder %s\n", g_spdk_iscsi.DataPDUInOrder ? "Yes" : "No"); /* This option is only for test. @@ -773,7 +773,7 @@ spdk_iscsi_app_read_parameters(void) return -1; } g_spdk_iscsi.AllowDuplicateIsid = AllowDuplicateIsid; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "AllowDuplicateIsid %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "AllowDuplicateIsid %s\n", g_spdk_iscsi.AllowDuplicateIsid ? "Yes" : "No"); val = spdk_conf_section_get_val(sp, "DataSequenceInOrder"); @@ -793,7 +793,7 @@ spdk_iscsi_app_read_parameters(void) return -1; } g_spdk_iscsi.DataSequenceInOrder = DataSequenceInOrder; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "DataSequenceInOrder %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DataSequenceInOrder %s\n", g_spdk_iscsi.DataSequenceInOrder ? "Yes" : "No"); ErrorRecoveryLevel = spdk_conf_section_get_intval(sp, "ErrorRecoveryLevel"); @@ -804,7 +804,7 @@ spdk_iscsi_app_read_parameters(void) return -1; } g_spdk_iscsi.ErrorRecoveryLevel = ErrorRecoveryLevel; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "ErrorRecoveryLevel %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "ErrorRecoveryLevel %d\n", g_spdk_iscsi.ErrorRecoveryLevel); timeout = spdk_conf_section_get_intval(sp, "Timeout"); @@ -812,7 +812,7 @@ spdk_iscsi_app_read_parameters(void) timeout = DEFAULT_TIMEOUT; } g_spdk_iscsi.timeout = timeout; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Timeout %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Timeout %d\n", g_spdk_iscsi.timeout); val = spdk_conf_section_get_val(sp, "FlushTimeout"); @@ -823,7 +823,7 @@ spdk_iscsi_app_read_parameters(void) flush_timeout = DEFAULT_FLUSH_TIMEOUT; } g_spdk_iscsi.flush_timeout = flush_timeout * (spdk_get_ticks_hz() >> 20); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "FlushTimeout %"PRIu64"\n", g_spdk_iscsi.flush_timeout); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "FlushTimeout %"PRIu64"\n", g_spdk_iscsi.flush_timeout); nopininterval = spdk_conf_section_get_intval(sp, "NopInInterval"); if (nopininterval < 0) { @@ -836,7 +836,7 @@ spdk_iscsi_app_read_parameters(void) } g_spdk_iscsi.nopininterval = nopininterval; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "NopInInterval %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "NopInInterval %d\n", g_spdk_iscsi.nopininterval); val = spdk_conf_section_get_val(sp, "DiscoveryAuthMethod"); @@ -872,13 +872,13 @@ spdk_iscsi_app_read_parameters(void) } } if (g_spdk_iscsi.no_discovery_auth != 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DiscoveryAuthMethod None\n"); } else if (g_spdk_iscsi.req_discovery_auth == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DiscoveryAuthMethod Auto\n"); } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DiscoveryAuthMethod %s %s\n", g_spdk_iscsi.req_discovery_auth ? "CHAP" : "", g_spdk_iscsi.req_discovery_auth_mutual ? "Mutual" : ""); @@ -906,10 +906,10 @@ spdk_iscsi_app_read_parameters(void) g_spdk_iscsi.discovery_auth_group = ag_tag_i; } if (g_spdk_iscsi.discovery_auth_group == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DiscoveryAuthGroup None\n"); } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "DiscoveryAuthGroup AuthGroup%d\n", g_spdk_iscsi.discovery_auth_group); } diff --git a/lib/iscsi/param.c b/lib/iscsi/param.c index ef8e76796..d180905e6 100644 --- a/lib/iscsi/param.c +++ b/lib/iscsi/param.c @@ -101,7 +101,7 @@ spdk_iscsi_param_del(struct iscsi_param **params, const char *key) { struct iscsi_param *param, *prev_param = NULL; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "del %s\n", key); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "del %s\n", key); if (params == NULL || key == NULL) return 0; for (param = *params; param != NULL; param = param->next) { @@ -127,7 +127,7 @@ spdk_iscsi_param_add(struct iscsi_param **params, const char *key, { struct iscsi_param *param, *last_param; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "add %s=%s, list=[%s], type=%d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add %s=%s, list=[%s], type=%d\n", key, val, list, type); if (key == NULL) return -1; @@ -168,7 +168,7 @@ spdk_iscsi_param_set(struct iscsi_param *params, const char *key, { struct iscsi_param *param; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set %s=%s\n", key, val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set %s=%s\n", key, val); param = spdk_iscsi_param_find(params, key); if (param == NULL) { SPDK_ERRLOG("no key %s\n", key); @@ -188,7 +188,7 @@ spdk_iscsi_param_set_int(struct iscsi_param *params, const char *key, uint32_t v char buf[MAX_TMPBUF]; struct iscsi_param *param; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set %s=%d\n", key, val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set %s=%d\n", key, val); param = spdk_iscsi_param_find(params, key); if (param == NULL) { SPDK_ERRLOG("no key %s\n", key); @@ -532,7 +532,7 @@ spdk_iscsi_special_param_construction(struct spdk_iscsi_conn *conn, return -1; } - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "returning MaxRecvDataSegmentLength=%d\n", g_spdk_iscsi.MaxRecvDataSegmentLength); len = snprintf((char *)data + total, alloc_len - total, @@ -602,7 +602,7 @@ spdk_iscsi_construct_data_from_param(struct iscsi_param *param, char *new_val, return -1; } - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "negotiated %s=%s\n", + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "negotiated %s=%s\n", param->key, new_val); len = snprintf((char *)data + total, alloc_len - total, "%s=%s", param->key, new_val); @@ -640,7 +640,7 @@ static char *spdk_iscsi_negotiate_param_list(int *add_param_value, *val_end = '\0'; } if (strcasecmp(in_start, val_start) == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "match %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "match %s\n", val_start); flag = 1; break; @@ -692,7 +692,7 @@ static char *spdk_iscsi_negotiate_param_numerical(int *add_param_value, min_i = (min_val != NULL) ? (int)strtol(min_val, NULL, 10) : 0; max_i = (max_val != NULL) ? (int)strtol(max_val, NULL, 10) : 0; if (val_i < min_i || val_i > max_i) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "key %.64s reject\n", param->key); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "key %.64s reject\n", param->key); new_val = NULL; } else { switch (param->type) { @@ -822,7 +822,7 @@ spdk_iscsi_negotiate_param_init(struct spdk_iscsi_conn *conn, if ((strncasecmp(param->key, "X-", 2) == 0) || (strncasecmp(param->key, "X#", 2) == 0)) { /* Extension Key */ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "extension key %.64s\n", param->key); } else { @@ -1073,7 +1073,7 @@ spdk_iscsi_copy_param2var(struct spdk_iscsi_conn *conn) SPDK_ERRLOG("Getval MaxRecvDataSegmentLength failed\n"); return -1; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "copy MaxRecvDataSegmentLength=%s\n", val); conn->MaxRecvDataSegmentLength = (int)strtol(val, NULL, 10); if (conn->MaxRecvDataSegmentLength > SPDK_ISCSI_MAX_SEND_DATA_SEGMENT_LENGTH) { @@ -1086,10 +1086,10 @@ spdk_iscsi_copy_param2var(struct spdk_iscsi_conn *conn) return -1; } if (strcasecmp(val, "CRC32C") == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set HeaderDigest=1\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set HeaderDigest=1\n"); conn->header_digest = 1; } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set HeaderDigest=0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set HeaderDigest=0\n"); conn->header_digest = 0; } val = spdk_iscsi_param_get_val(conn->params, "DataDigest"); @@ -1098,10 +1098,10 @@ spdk_iscsi_copy_param2var(struct spdk_iscsi_conn *conn) return -1; } if (strcasecmp(val, "CRC32C") == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set DataDigest=1\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set DataDigest=1\n"); conn->data_digest = 1; } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set DataDigest=0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set DataDigest=0\n"); conn->data_digest = 0; } @@ -1110,28 +1110,28 @@ spdk_iscsi_copy_param2var(struct spdk_iscsi_conn *conn) SPDK_ERRLOG("Getval MaxConnections failed\n"); return -1; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "copy MaxConnections=%s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "copy MaxConnections=%s\n", val); conn->sess->MaxConnections = (uint32_t) strtol(val, NULL, 10); val = spdk_iscsi_param_get_val(conn->sess->params, "MaxOutstandingR2T"); if (val == NULL) { SPDK_ERRLOG("Getval MaxOutstandingR2T failed\n"); return -1; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "copy MaxOutstandingR2T=%s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "copy MaxOutstandingR2T=%s\n", val); conn->sess->MaxOutstandingR2T = (uint32_t) strtol(val, NULL, 10); val = spdk_iscsi_param_get_val(conn->sess->params, "FirstBurstLength"); if (val == NULL) { SPDK_ERRLOG("Getval FirstBurstLength failed\n"); return -1; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "copy FirstBurstLength=%s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "copy FirstBurstLength=%s\n", val); conn->sess->FirstBurstLength = (uint32_t) strtol(val, NULL, 10); val = spdk_iscsi_param_get_val(conn->sess->params, "MaxBurstLength"); if (val == NULL) { SPDK_ERRLOG("Getval MaxBurstLength failed\n"); return -1; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "copy MaxBurstLength=%s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "copy MaxBurstLength=%s\n", val); conn->sess->MaxBurstLength = (uint32_t) strtol(val, NULL, 10); val = spdk_iscsi_param_get_val(conn->sess->params, "InitialR2T"); if (val == NULL) { @@ -1139,10 +1139,10 @@ spdk_iscsi_copy_param2var(struct spdk_iscsi_conn *conn) return -1; } if (strcasecmp(val, "Yes") == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set InitialR2T=1\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set InitialR2T=1\n"); conn->sess->InitialR2T = 1; } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set InitialR2T=0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set InitialR2T=0\n"); conn->sess->InitialR2T = 0; } val = spdk_iscsi_param_get_val(conn->sess->params, "ImmediateData"); @@ -1151,10 +1151,10 @@ spdk_iscsi_copy_param2var(struct spdk_iscsi_conn *conn) return -1; } if (strcasecmp(val, "Yes") == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set ImmediateData=1\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set ImmediateData=1\n"); conn->sess->ImmediateData = 1; } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "set ImmediateData=0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "set ImmediateData=0\n"); conn->sess->ImmediateData = 0; } return 0; diff --git a/lib/iscsi/portal_grp.c b/lib/iscsi/portal_grp.c index c9fd7ebc9..d79672578 100644 --- a/lib/iscsi/portal_grp.c +++ b/lib/iscsi/portal_grp.c @@ -77,7 +77,7 @@ spdk_iscsi_portal_destroy(struct spdk_iscsi_portal *p) { assert(p != NULL); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_destroy\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_destroy\n"); free(p->host); free(p->port); free(p); @@ -267,7 +267,7 @@ spdk_iscsi_portal_grp_destroy(struct spdk_iscsi_portal_grp *pg) assert(pg != NULL); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_destroy\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_destroy\n"); while (!TAILQ_EMPTY(&pg->head)) { p = TAILQ_FIRST(&pg->head); TAILQ_REMOVE(&pg->head, p, tailq); @@ -299,7 +299,7 @@ spdk_iscsi_portal_grp_create_from_portal_list(int tag, int i = 0, rc = 0, port; struct spdk_iscsi_portal_grp *pg; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "add portal group (from portal list) %d\n", tag); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add portal group (from portal list) %d\n", tag); if (num_portals > MAX_PORTAL) { SPDK_ERRLOG("%d > MAX_PORTAL\n", num_portals); @@ -315,7 +315,7 @@ spdk_iscsi_portal_grp_create_from_portal_list(int tag, for (i = 0; i < num_portals; i++) { struct spdk_iscsi_portal *p = portal_list[i]; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "RIndex=%d, Host=%s, Port=%s, Tag=%d\n", i, p->host, p->port, tag); @@ -361,12 +361,12 @@ spdk_iscsi_portal_grp_create_from_configfile(struct spdk_conf_section *sp) char *label, *portal; int portals = 0, i = 0, rc = 0; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "add portal group (from config file) %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add portal group (from config file) %d\n", spdk_conf_section_get_num(sp)); val = spdk_conf_section_get_val(sp, "Comment"); if (val != NULL) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "Comment %s\n", val); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "Comment %s\n", val); } /* counts number of definitions */ @@ -415,7 +415,7 @@ spdk_iscsi_portal_grp_create_from_configfile(struct spdk_conf_section *sp) goto error_out; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "RIndex=%d, Host=%s, Port=%s, Tag=%d\n", i, p->host, p->port, spdk_conf_section_get_num(sp)); @@ -488,7 +488,7 @@ spdk_iscsi_portal_grp_array_destroy(void) { struct spdk_iscsi_portal_grp *pg, *tmp; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_array_destroy\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_array_destroy\n"); pthread_mutex_lock(&g_spdk_iscsi.mutex); TAILQ_FOREACH_SAFE(pg, &g_spdk_iscsi.pg_head, tailq, tmp) { pg->state = GROUP_DESTROY; @@ -507,7 +507,7 @@ spdk_iscsi_portal_grp_open(struct spdk_iscsi_portal_grp *pg) TAILQ_FOREACH(p, &pg->head, tailq) { if (p->sock < 0) { - SPDK_TRACELOG(SPDK_TRACE_NET, "open host %s, port %s, tag %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_NET, "open host %s, port %s, tag %d\n", p->host, p->port, pg->tag); port = (int)strtol(p->port, NULL, 0); sock = spdk_sock_listen(p->host, port); @@ -527,7 +527,7 @@ spdk_iscsi_portal_grp_open_all(void) struct spdk_iscsi_portal_grp *pg; int rc; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_open_all\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_open_all\n"); pthread_mutex_lock(&g_spdk_iscsi.mutex); TAILQ_FOREACH(pg, &g_spdk_iscsi.pg_head, tailq) { rc = spdk_iscsi_portal_grp_open(pg); @@ -547,7 +547,7 @@ spdk_iscsi_portal_grp_close(struct spdk_iscsi_portal_grp *pg) TAILQ_FOREACH(p, &pg->head, tailq) { if (p->sock >= 0) { - SPDK_TRACELOG(SPDK_TRACE_NET, "close host %s, port %s, tag %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_NET, "close host %s, port %s, tag %d\n", p->host, p->port, pg->tag); close(p->sock); p->sock = -1; @@ -562,7 +562,7 @@ spdk_iscsi_portal_grp_close_all(void) struct spdk_iscsi_portal_grp *pg; int rc; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_close_all\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_portal_grp_close_all\n"); pthread_mutex_lock(&g_spdk_iscsi.mutex); TAILQ_FOREACH(pg, &g_spdk_iscsi.pg_head, tailq) { rc = spdk_iscsi_portal_grp_close(pg); diff --git a/lib/iscsi/tgt_node.c b/lib/iscsi/tgt_node.c index 13daedb67..233480eaa 100644 --- a/lib/iscsi/tgt_node.c +++ b/lib/iscsi/tgt_node.c @@ -85,8 +85,8 @@ spdk_iscsi_tgt_node_allow_ipv6(const char *netmask, const char *addr) } #if 0 - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "input %s\n", addr); - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "mask %s / %d\n", mask, bits); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "input %s\n", addr); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "mask %s / %d\n", mask, bits); #endif /* presentation to network order binary */ @@ -187,7 +187,7 @@ spdk_iscsi_tgt_node_access(struct spdk_iscsi_conn *conn, return 0; pg = conn->portal->group; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "pg=%d, iqn=%s, addr=%s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "pg=%d, iqn=%s, addr=%s\n", pg->tag, iqn, addr); for (i = 0; i < target->maxmap; i++) { /* skip excluding self portal group tag */ @@ -201,7 +201,7 @@ spdk_iscsi_tgt_node_access(struct spdk_iscsi_conn *conn, && (strcasecmp(&igp->initiators[j][1], "ALL") == 0 || strcasecmp(&igp->initiators[j][1], iqn) == 0)) { /* NG */ - SPDK_TRACELOG(SPDK_TRACE_ISCSI, + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "access denied from %s (%s) to %s (%s:%s,%d)\n", iqn, addr, target->name, conn->portal->host, conn->portal->port, conn->portal->group->tag); @@ -216,7 +216,7 @@ spdk_iscsi_tgt_node_access(struct spdk_iscsi_conn *conn, return 1; } for (k = 0; k < igp->nnetmasks; k++) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "netmask=%s, addr=%s\n", igp->netmasks[k], addr); rc = spdk_iscsi_tgt_node_allow_netmask(igp->netmasks[k], addr); @@ -231,7 +231,7 @@ spdk_iscsi_tgt_node_access(struct spdk_iscsi_conn *conn, } /* NG */ - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "access denied from %s (%s) to %s (%s:%s,%d)\n", + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "access denied from %s (%s) to %s (%s:%s,%d)\n", iqn, addr, target->name, conn->portal->host, conn->portal->port, conn->portal->group->tag); return 0; @@ -304,7 +304,7 @@ spdk_iscsi_portal_grp_is_visible(struct spdk_iscsi_tgt_node *target, /* iqn is initiator group? */ igp = target->map[match_idx].ig; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "iqn=%s, pg=%d, ig=%d\n", iqn, pg_tag, igp->tag); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "iqn=%s, pg=%d, ig=%d\n", iqn, pg_tag, igp->tag); for (j = 0; j < igp->ninitiators; j++) { if (igp->initiators[j][0] == '!' @@ -388,7 +388,7 @@ spdk_iscsi_send_tgts(struct spdk_iscsi_conn *conn, const char *iiqn, } rc = spdk_iscsi_portal_grp_is_visible(target, iiqn, pg_tag); if (rc == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "SKIP pg=%d, iqn=%s for %s from %s (%s)\n", pg_tag, tiqn, target->name, iiqn, iaddr); goto skip_pg_tag; @@ -427,7 +427,7 @@ spdk_iscsi_send_tgts(struct spdk_iscsi_conn *conn, const char *iiqn, continue; } } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "TargetAddress=%s:%s,%d\n", host, p->port, pg->tag); len = snprintf((char *) data + total, @@ -462,7 +462,7 @@ spdk_iscsi_find_tgt_node(const char *target_name) return target; } } - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "can't find target %s\n", target_name); + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "can't find target %s\n", target_name); return NULL; } @@ -743,7 +743,7 @@ spdk_iscsi_tgt_node_construct(int target_index, target->data_digest = data_digest; if (queue_depth > SPDK_ISCSI_MAX_QUEUE_DEPTH) { - SPDK_TRACELOG(SPDK_TRACE_ISCSI, "QueueDepth %d > Max %d. Using %d instead.\n", + SPDK_DEBUGLOG(SPDK_TRACE_ISCSI, "QueueDepth %d > Max %d. Using %d instead.\n", queue_depth, SPDK_ISCSI_MAX_QUEUE_DEPTH, SPDK_ISCSI_MAX_QUEUE_DEPTH); queue_depth = SPDK_ISCSI_MAX_QUEUE_DEPTH; @@ -779,7 +779,7 @@ spdk_cf_add_iscsi_tgt_node(struct spdk_conf_section *sp) target_num = spdk_conf_section_get_num(sp); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "add unit %d\n", target_num); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "add unit %d\n", target_num); data_digest = 0; header_digest = 0; @@ -866,11 +866,11 @@ spdk_cf_add_iscsi_tgt_node(struct spdk_conf_section *sp) } } if (auth_chap_disabled == 1) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "AuthMethod None\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "AuthMethod None\n"); } else if (auth_chap_required == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "AuthMethod Auto\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "AuthMethod Auto\n"); } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "AuthMethod CHAP %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "AuthMethod CHAP %s\n", auth_chap_mutual ? "Mutual" : ""); } @@ -895,9 +895,9 @@ spdk_cf_add_iscsi_tgt_node(struct spdk_conf_section *sp) } } if (auth_group == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "AuthGroup None\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "AuthGroup None\n"); } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "AuthGroup AuthGroup%d\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "AuthGroup AuthGroup%d\n", auth_group); } @@ -921,9 +921,9 @@ spdk_cf_add_iscsi_tgt_node(struct spdk_conf_section *sp) } } if (header_digest == 0 && data_digest == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "UseDigest Auto\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "UseDigest Auto\n"); } else { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "UseDigest %s %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "UseDigest %s %s\n", header_digest ? "Header" : "", data_digest ? "Data" : ""); } @@ -976,7 +976,7 @@ int spdk_iscsi_init_tgt_nodes(void) struct spdk_conf_section *sp; int rc; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_iscsi_init_tgt_nodes\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_iscsi_init_tgt_nodes\n"); sp = spdk_conf_first_section(NULL); while (sp != NULL) { diff --git a/lib/jsonrpc/jsonrpc_server.c b/lib/jsonrpc/jsonrpc_server.c index 0514d6458..5e4ab2344 100644 --- a/lib/jsonrpc/jsonrpc_server.c +++ b/lib/jsonrpc/jsonrpc_server.c @@ -90,7 +90,7 @@ parse_single_request(struct spdk_jsonrpc_request *request, struct spdk_json_val request->id.len = req.id->len; memcpy(request->id.start, req.id->start, req.id->len); } else { - SPDK_TRACELOG(SPDK_TRACE_RPC, "JSON-RPC request id too long (%u)\n", + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "JSON-RPC request id too long (%u)\n", req.id->len); invalid = true; } @@ -132,7 +132,7 @@ spdk_jsonrpc_parse_request(struct spdk_jsonrpc_server_conn *conn, void *json, si request = calloc(1, sizeof(*request)); if (request == NULL) { - SPDK_TRACELOG(SPDK_TRACE_RPC, "Out of memory allocating request\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "Out of memory allocating request\n"); return -1; } @@ -146,7 +146,7 @@ spdk_jsonrpc_parse_request(struct spdk_jsonrpc_server_conn *conn, void *json, si request->send_len = 0; if (rc < 0 || rc > SPDK_JSONRPC_MAX_VALUES) { - SPDK_TRACELOG(SPDK_TRACE_RPC, "JSON parse error\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "JSON parse error\n"); spdk_jsonrpc_server_handle_error(request, SPDK_JSONRPC_ERROR_PARSE_ERROR); /* @@ -160,7 +160,7 @@ spdk_jsonrpc_parse_request(struct spdk_jsonrpc_server_conn *conn, void *json, si rc = spdk_json_parse(json, size, conn->values, SPDK_JSONRPC_MAX_VALUES, &end, SPDK_JSON_PARSE_FLAG_DECODE_IN_PLACE); if (rc < 0 || rc > SPDK_JSONRPC_MAX_VALUES) { - SPDK_TRACELOG(SPDK_TRACE_RPC, "JSON parse error on second pass\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "JSON parse error on second pass\n"); spdk_jsonrpc_server_handle_error(request, SPDK_JSONRPC_ERROR_PARSE_ERROR); return -1; } @@ -170,10 +170,10 @@ spdk_jsonrpc_parse_request(struct spdk_jsonrpc_server_conn *conn, void *json, si if (conn->values[0].type == SPDK_JSON_VAL_OBJECT_BEGIN) { parse_single_request(request, conn->values); } else if (conn->values[0].type == SPDK_JSON_VAL_ARRAY_BEGIN) { - SPDK_TRACELOG(SPDK_TRACE_RPC, "Got batch array (not currently supported)\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "Got batch array (not currently supported)\n"); spdk_jsonrpc_server_handle_error(request, SPDK_JSONRPC_ERROR_INVALID_REQUEST); } else { - SPDK_TRACELOG(SPDK_TRACE_RPC, "top-level JSON value was not array or object\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "top-level JSON value was not array or object\n"); spdk_jsonrpc_server_handle_error(request, SPDK_JSONRPC_ERROR_INVALID_REQUEST); } diff --git a/lib/jsonrpc/jsonrpc_server_tcp.c b/lib/jsonrpc/jsonrpc_server_tcp.c index b82577976..f4d10898c 100644 --- a/lib/jsonrpc/jsonrpc_server_tcp.c +++ b/lib/jsonrpc/jsonrpc_server_tcp.c @@ -230,12 +230,12 @@ spdk_jsonrpc_server_conn_recv(struct spdk_jsonrpc_server_conn *conn) return 0; } spdk_strerror_r(errno, buf, sizeof(buf)); - SPDK_TRACELOG(SPDK_TRACE_RPC, "recv() failed: %s\n", buf); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "recv() failed: %s\n", buf); return -1; } if (rc == 0) { - SPDK_TRACELOG(SPDK_TRACE_RPC, "remote closed connection\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "remote closed connection\n"); return -1; } @@ -300,7 +300,7 @@ more: } spdk_strerror_r(errno, buf, sizeof(buf)); - SPDK_TRACELOG(SPDK_TRACE_RPC, "send() failed: %s\n", buf); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "send() failed: %s\n", buf); return -1; } @@ -349,7 +349,7 @@ spdk_jsonrpc_server_poll(struct spdk_jsonrpc_server *server) } if (conn->outstanding_requests == 0) { - SPDK_TRACELOG(SPDK_TRACE_RPC, "all outstanding requests completed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RPC, "all outstanding requests completed\n"); spdk_jsonrpc_server_conn_remove(conn); } } diff --git a/lib/log/rpc/log_rpc.c b/lib/log/rpc/log_rpc.c index 1b840922c..512978689 100644 --- a/lib/log/rpc/log_rpc.c +++ b/lib/log/rpc/log_rpc.c @@ -59,12 +59,12 @@ spdk_rpc_set_trace_flag(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_trace_flag_decoders, SPDK_COUNTOF(rpc_trace_flag_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } if (req.flag == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "flag was 0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "flag was 0\n"); goto invalid; } @@ -95,12 +95,12 @@ spdk_rpc_clear_trace_flag(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_trace_flag_decoders, SPDK_COUNTOF(rpc_trace_flag_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } if (req.flag == 0) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "flag was 0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "flag was 0\n"); goto invalid; } diff --git a/lib/net/net_rpc.c b/lib/net/net_rpc.c index 07bf614ca..d6b5ed112 100644 --- a/lib/net/net_rpc.c +++ b/lib/net/net_rpc.c @@ -65,7 +65,7 @@ spdk_rpc_add_ip_address(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_ip_address_decoders, SPDK_COUNTOF(rpc_ip_address_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } @@ -100,7 +100,7 @@ spdk_rpc_delete_ip_address(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_ip_address_decoders, SPDK_COUNTOF(rpc_ip_address_decoders), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); goto invalid; } diff --git a/lib/nvme/nvme_ctrlr.c b/lib/nvme/nvme_ctrlr.c index 79d2c888e..6fab01c92 100644 --- a/lib/nvme/nvme_ctrlr.c +++ b/lib/nvme/nvme_ctrlr.c @@ -462,7 +462,7 @@ nvme_ctrlr_shutdown(struct spdk_nvme_ctrlr *ctrlr) } if (csts.bits.shst == SPDK_NVME_SHST_COMPLETE) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "shutdown complete\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "shutdown complete\n"); return; } @@ -559,11 +559,11 @@ nvme_ctrlr_set_state(struct spdk_nvme_ctrlr *ctrlr, enum nvme_ctrlr_state state, { ctrlr->state = state; if (timeout_in_ms == NVME_TIMEOUT_INFINITE) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "setting state to %s (no timeout)\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "setting state to %s (no timeout)\n", nvme_ctrlr_state_string(ctrlr->state)); ctrlr->state_timeout_tsc = NVME_TIMEOUT_INFINITE; } else { - SPDK_TRACELOG(SPDK_TRACE_NVME, "setting state to %s (timeout %" PRIu64 " ms)\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "setting state to %s (timeout %" PRIu64 " ms)\n", nvme_ctrlr_state_string(ctrlr->state), timeout_in_ms); ctrlr->state_timeout_tsc = spdk_get_ticks() + (timeout_in_ms * spdk_get_ticks_hz()) / 1000; } @@ -660,11 +660,11 @@ nvme_ctrlr_identify(struct spdk_nvme_ctrlr *ctrlr) * controller supports. */ ctrlr->max_xfer_size = nvme_transport_ctrlr_get_max_xfer_size(ctrlr); - SPDK_TRACELOG(SPDK_TRACE_NVME, "transport max_xfer_size %u\n", ctrlr->max_xfer_size); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "transport max_xfer_size %u\n", ctrlr->max_xfer_size); if (ctrlr->cdata.mdts > 0) { ctrlr->max_xfer_size = spdk_min(ctrlr->max_xfer_size, ctrlr->min_page_size * (1 << (ctrlr->cdata.mdts))); - SPDK_TRACELOG(SPDK_TRACE_NVME, "MDTS max_xfer_size %u\n", ctrlr->max_xfer_size); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "MDTS max_xfer_size %u\n", ctrlr->max_xfer_size); } return 0; @@ -760,7 +760,7 @@ nvme_ctrlr_set_keep_alive_timeout(struct spdk_nvme_ctrlr *ctrlr) } if (ctrlr->cdata.kas == 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "Controller KAS is 0 - not enabling Keep Alive\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Controller KAS is 0 - not enabling Keep Alive\n"); ctrlr->opts.keep_alive_timeout_ms = 0; return 0; } @@ -786,7 +786,7 @@ nvme_ctrlr_set_keep_alive_timeout(struct spdk_nvme_ctrlr *ctrlr) } if (ctrlr->opts.keep_alive_timeout_ms != status.cpl.cdw0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "Controller adjusted keep alive timeout to %u ms\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Controller adjusted keep alive timeout to %u ms\n", status.cpl.cdw0); } @@ -796,7 +796,7 @@ nvme_ctrlr_set_keep_alive_timeout(struct spdk_nvme_ctrlr *ctrlr) if (keep_alive_interval_ms == 0) { keep_alive_interval_ms = 1; } - SPDK_TRACELOG(SPDK_TRACE_NVME, "Sending keep alive every %u ms\n", keep_alive_interval_ms); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Sending keep alive every %u ms\n", keep_alive_interval_ms); ctrlr->keep_alive_interval_ticks = (keep_alive_interval_ms * spdk_get_ticks_hz()) / UINT64_C(1000); @@ -1232,7 +1232,7 @@ nvme_ctrlr_process_init(struct spdk_nvme_ctrlr *ctrlr) /* While a device is resetting, it may be unable to service MMIO reads * temporarily. Allow for this case. */ - SPDK_TRACELOG(SPDK_TRACE_NVME, "Get registers failed while waiting for CSTS.RDY == 0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Get registers failed while waiting for CSTS.RDY == 0\n"); goto init_timeout; } SPDK_ERRLOG("Failed to read CC and CSTS in state %d\n", ctrlr->state); @@ -1249,7 +1249,7 @@ nvme_ctrlr_process_init(struct spdk_nvme_ctrlr *ctrlr) case NVME_CTRLR_STATE_INIT: /* Begin the hardware initialization by making sure the controller is disabled. */ if (cc.bits.en) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "CC.EN = 1\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "CC.EN = 1\n"); /* * Controller is currently enabled. We need to disable it to cause a reset. * @@ -1257,13 +1257,13 @@ nvme_ctrlr_process_init(struct spdk_nvme_ctrlr *ctrlr) * Wait for the ready bit to be 1 before disabling the controller. */ if (csts.bits.rdy == 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "CC.EN = 1 && CSTS.RDY = 0 - waiting for reset to complete\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "CC.EN = 1 && CSTS.RDY = 0 - waiting for reset to complete\n"); nvme_ctrlr_set_state(ctrlr, NVME_CTRLR_STATE_DISABLE_WAIT_FOR_READY_1, ready_timeout_in_ms); return 0; } /* CC.EN = 1 && CSTS.RDY == 1, so we can immediately disable the controller. */ - SPDK_TRACELOG(SPDK_TRACE_NVME, "Setting CC.EN = 0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Setting CC.EN = 0\n"); cc.bits.en = 0; if (nvme_ctrlr_set_cc(ctrlr, &cc)) { SPDK_ERRLOG("set_cc() failed\n"); @@ -1277,13 +1277,13 @@ nvme_ctrlr_process_init(struct spdk_nvme_ctrlr *ctrlr) * Not using sleep() to avoid blocking other controller's initialization. */ if (ctrlr->quirks & NVME_QUIRK_DELAY_BEFORE_CHK_RDY) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "Applying quirk: delay 2 seconds before reading registers\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Applying quirk: delay 2 seconds before reading registers\n"); ctrlr->sleep_timeout_tsc = spdk_get_ticks() + 2 * spdk_get_ticks_hz(); } return 0; } else { if (csts.bits.rdy == 1) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "CC.EN = 0 && CSTS.RDY = 1 - waiting for shutdown to complete\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "CC.EN = 0 && CSTS.RDY = 1 - waiting for shutdown to complete\n"); } nvme_ctrlr_set_state(ctrlr, NVME_CTRLR_STATE_DISABLE_WAIT_FOR_READY_0, ready_timeout_in_ms); @@ -1293,9 +1293,9 @@ nvme_ctrlr_process_init(struct spdk_nvme_ctrlr *ctrlr) case NVME_CTRLR_STATE_DISABLE_WAIT_FOR_READY_1: if (csts.bits.rdy == 1) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "CC.EN = 1 && CSTS.RDY = 1 - disabling controller\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "CC.EN = 1 && CSTS.RDY = 1 - disabling controller\n"); /* CC.EN = 1 && CSTS.RDY = 1, so we can set CC.EN = 0 now. */ - SPDK_TRACELOG(SPDK_TRACE_NVME, "Setting CC.EN = 0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Setting CC.EN = 0\n"); cc.bits.en = 0; if (nvme_ctrlr_set_cc(ctrlr, &cc)) { SPDK_ERRLOG("set_cc() failed\n"); @@ -1309,7 +1309,7 @@ nvme_ctrlr_process_init(struct spdk_nvme_ctrlr *ctrlr) case NVME_CTRLR_STATE_DISABLE_WAIT_FOR_READY_0: if (csts.bits.rdy == 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "CC.EN = 0 && CSTS.RDY = 0\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "CC.EN = 0 && CSTS.RDY = 0\n"); nvme_ctrlr_set_state(ctrlr, NVME_CTRLR_STATE_ENABLE, ready_timeout_in_ms); /* * Delay 100us before setting CC.EN = 1. Some NVMe SSDs miss CC.EN getting @@ -1321,14 +1321,14 @@ nvme_ctrlr_process_init(struct spdk_nvme_ctrlr *ctrlr) break; case NVME_CTRLR_STATE_ENABLE: - SPDK_TRACELOG(SPDK_TRACE_NVME, "Setting CC.EN = 1\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Setting CC.EN = 1\n"); rc = nvme_ctrlr_enable(ctrlr); nvme_ctrlr_set_state(ctrlr, NVME_CTRLR_STATE_ENABLE_WAIT_FOR_READY_1, ready_timeout_in_ms); return rc; case NVME_CTRLR_STATE_ENABLE_WAIT_FOR_READY_1: if (csts.bits.rdy == 1) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "CC.EN = 1 && CSTS.RDY = 1 - controller is ready\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "CC.EN = 1 && CSTS.RDY = 1 - controller is ready\n"); /* * The controller has been enabled. * Perform the rest of initialization in nvme_ctrlr_start() serially. diff --git a/lib/nvme/nvme_ns.c b/lib/nvme/nvme_ns.c index a787db7f2..de0d22645 100644 --- a/lib/nvme/nvme_ns.c +++ b/lib/nvme/nvme_ns.c @@ -88,13 +88,13 @@ int nvme_ns_identify_update(struct spdk_nvme_ns *ns) if (nsdata->noiob) { ns->sectors_per_stripe = nsdata->noiob; - SPDK_TRACELOG(SPDK_TRACE_NVME, "ns %u optimal IO boundary %" PRIu32 " blocks\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "ns %u optimal IO boundary %" PRIu32 " blocks\n", ns->id, ns->sectors_per_stripe); } else if (ns->ctrlr->quirks & NVME_INTEL_QUIRK_STRIPING && ns->ctrlr->cdata.vs[3] != 0) { ns->sectors_per_stripe = (1ULL << ns->ctrlr->cdata.vs[3]) * ns->ctrlr->min_page_size / ns->sector_size; - SPDK_TRACELOG(SPDK_TRACE_NVME, "ns %u stripe size quirk %" PRIu32 " blocks\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "ns %u stripe size quirk %" PRIu32 " blocks\n", ns->id, ns->sectors_per_stripe); } else { ns->sectors_per_stripe = 0; diff --git a/lib/nvme/nvme_pcie.c b/lib/nvme/nvme_pcie.c index 0850ddcd0..dec7bdc1d 100644 --- a/lib/nvme/nvme_pcie.c +++ b/lib/nvme/nvme_pcie.c @@ -234,7 +234,7 @@ _nvme_pcie_hotplug_monitor(void *cb_ctx, spdk_nvme_probe_cb probe_cb, while (spdk_get_uevent(hotplug_fd, &event) > 0) { if (event.subsystem == SPDK_NVME_UEVENT_SUBSYSTEM_UIO) { if (event.action == SPDK_NVME_UEVENT_ADD) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "add nvme address: %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "add nvme address: %s\n", event.traddr); if (spdk_process_is_primary()) { if (!spdk_pci_addr_parse(&pci_addr, event.traddr)) { @@ -253,7 +253,7 @@ _nvme_pcie_hotplug_monitor(void *cb_ctx, spdk_nvme_probe_cb probe_cb, if (in_list == false) { return 0; } - SPDK_TRACELOG(SPDK_TRACE_NVME, "remove nvme address: %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "remove nvme address: %s\n", event.traddr); nvme_ctrlr_fail(ctrlr, true); @@ -641,7 +641,7 @@ nvme_pcie_ctrlr_scan(const struct spdk_nvme_transport_id *trid, if (hotplug_fd < 0) { hotplug_fd = spdk_uevent_connect(); if (hotplug_fd < 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "Failed to open uevent netlink socket\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Failed to open uevent netlink socket\n"); } } else { _nvme_pcie_hotplug_monitor(cb_ctx, probe_cb, remove_cb); @@ -1530,11 +1530,11 @@ nvme_pcie_prp_list_append(struct nvme_tracker *tr, uint32_t *prp_index, void *vi uint64_t phys_addr; uint32_t i; - SPDK_TRACELOG(SPDK_TRACE_NVME, "prp_index:%u virt_addr:%p len:%u\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "prp_index:%u virt_addr:%p len:%u\n", *prp_index, virt_addr, (uint32_t)len); if (spdk_unlikely(((uintptr_t)virt_addr & 3) != 0)) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "virt_addr %p not dword aligned\n", virt_addr); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "virt_addr %p not dword aligned\n", virt_addr); return -EINVAL; } @@ -1547,28 +1547,28 @@ nvme_pcie_prp_list_append(struct nvme_tracker *tr, uint32_t *prp_index, void *vi * so prp_index == count is valid. */ if (spdk_unlikely(i > SPDK_COUNTOF(tr->u.prp))) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "out of PRP entries\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "out of PRP entries\n"); return -EINVAL; } phys_addr = spdk_vtophys(virt_addr); if (spdk_unlikely(phys_addr == SPDK_VTOPHYS_ERROR)) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "vtophys(%p) failed\n", virt_addr); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "vtophys(%p) failed\n", virt_addr); return -EINVAL; } if (i == 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "prp1 = %p\n", (void *)phys_addr); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "prp1 = %p\n", (void *)phys_addr); cmd->dptr.prp.prp1 = phys_addr; seg_len = page_size - ((uintptr_t)virt_addr & page_mask); } else { if ((phys_addr & page_mask) != 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "PRP %u not page aligned (%p)\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "PRP %u not page aligned (%p)\n", i, virt_addr); return -EINVAL; } - SPDK_TRACELOG(SPDK_TRACE_NVME, "prp[%u] = %p\n", i - 1, (void *)phys_addr); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "prp[%u] = %p\n", i - 1, (void *)phys_addr); tr->u.prp[i - 1] = phys_addr; seg_len = page_size; } @@ -1584,10 +1584,10 @@ nvme_pcie_prp_list_append(struct nvme_tracker *tr, uint32_t *prp_index, void *vi cmd->dptr.prp.prp2 = 0; } else if (i == 2) { cmd->dptr.prp.prp2 = tr->u.prp[0]; - SPDK_TRACELOG(SPDK_TRACE_NVME, "prp2 = %p\n", (void *)cmd->dptr.prp.prp2); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "prp2 = %p\n", (void *)cmd->dptr.prp.prp2); } else { cmd->dptr.prp.prp2 = tr->prp_sgl_bus_addr; - SPDK_TRACELOG(SPDK_TRACE_NVME, "prp2 = %p (PRP list)\n", (void *)cmd->dptr.prp.prp2); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "prp2 = %p (PRP list)\n", (void *)cmd->dptr.prp.prp2); } *prp_index = i; diff --git a/lib/nvme/nvme_rdma.c b/lib/nvme/nvme_rdma.c index 2662d43e7..d4cff07ff 100644 --- a/lib/nvme/nvme_rdma.c +++ b/lib/nvme/nvme_rdma.c @@ -228,7 +228,7 @@ nvme_rdma_qpair_init(struct nvme_rdma_qpair *rqpair) #define nvme_rdma_trace_ibv_sge(sg_list) \ if (sg_list) { \ - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "local addr %p length 0x%x lkey 0x%x\n", \ + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "local addr %p length 0x%x lkey 0x%x\n", \ (void *)(sg_list)->addr, (sg_list)->length, (sg_list)->lkey); \ } @@ -522,7 +522,7 @@ nvme_rdma_connect(struct nvme_rdma_qpair *rqpair) return -1; } - SPDK_TRACELOG(SPDK_TRACE_NVME, "Requested queue depth %d. Actually got queue depth %d.\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Requested queue depth %d. Actually got queue depth %d.\n", rqpair->num_entries, accept_data->crqsize); rqpair->num_entries = spdk_min(rqpair->num_entries, accept_data->crqsize); @@ -724,11 +724,11 @@ nvme_rdma_qpair_connect(struct nvme_rdma_qpair *rqpair) return -1; } - SPDK_TRACELOG(SPDK_TRACE_NVME, "adrfam %d ai_family %d\n", ctrlr->trid.adrfam, family); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "adrfam %d ai_family %d\n", ctrlr->trid.adrfam, family); memset(&sin, 0, sizeof(struct sockaddr_storage)); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "trsvcid is %s\n", ctrlr->trid.trsvcid); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "trsvcid is %s\n", ctrlr->trid.trsvcid); rc = nvme_rdma_parse_addr(&sin, family, ctrlr->trid.traddr, ctrlr->trid.trsvcid); if (rc != 0) { SPDK_ERRLOG("nvme_rdma_parse_addr() failed\n"); @@ -760,20 +760,20 @@ nvme_rdma_qpair_connect(struct nvme_rdma_qpair *rqpair) } rc = nvme_rdma_alloc_reqs(rqpair); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "rc =%d\n", rc); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "rc =%d\n", rc); if (rc) { SPDK_ERRLOG("Unable to allocate rqpair RDMA requests\n"); return -1; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "RDMA requests allocated\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "RDMA requests allocated\n"); rc = nvme_rdma_alloc_rsps(rqpair); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "rc =%d\n", rc); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "rc =%d\n", rc); if (rc < 0) { SPDK_ERRLOG("Unable to allocate rqpair RDMA responses\n"); return -1; } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "RDMA responses allocated\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "RDMA responses allocated\n"); rc = nvme_rdma_register_mem(rqpair); if (rc < 0) { @@ -1135,17 +1135,17 @@ nvme_rdma_discovery_probe(struct spdk_nvmf_discovery_log_page_entry *entry, len = spdk_strlen_pad(entry->traddr, sizeof(entry->traddr), ' '); memcpy(trid.traddr, entry->traddr, len); if (spdk_str_chomp(trid.traddr) != 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "Trailing newlines removed from discovery TRADDR\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Trailing newlines removed from discovery TRADDR\n"); } /* Convert trsvcid to a null terminated string. */ len = spdk_strlen_pad(entry->trsvcid, sizeof(entry->trsvcid), ' '); memcpy(trid.trsvcid, entry->trsvcid, len); if (spdk_str_chomp(trid.trsvcid) != 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "Trailing newlines removed from discovery TRSVCID\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "Trailing newlines removed from discovery TRSVCID\n"); } - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "subnqn=%s, trtype=%u, traddr=%s, trsvcid=%s\n", + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "subnqn=%s, trtype=%u, traddr=%s, trsvcid=%s\n", trid.subnqn, trid.trtype, trid.traddr, trid.trsvcid); @@ -1224,7 +1224,7 @@ nvme_rdma_ctrlr_scan(const struct spdk_nvme_transport_id *discovery_trid, do { rc = nvme_fabrics_get_log_discovery_page(discovery_ctrlr, buffer, sizeof(buffer), log_page_offset); if (rc < 0) { - SPDK_TRACELOG(SPDK_TRACE_NVME, "nvme_fabrics_get_log_discovery_page error\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVME, "nvme_fabrics_get_log_discovery_page error\n"); nvme_ctrlr_destruct(discovery_ctrlr); return rc; } @@ -1297,7 +1297,7 @@ struct spdk_nvme_ctrlr *nvme_rdma_ctrlr_construct(const struct spdk_nvme_transpo nvme_ctrlr_init_cap(&rctrlr->ctrlr, &cap); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "succesully initialized the nvmf ctrlr\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "succesully initialized the nvmf ctrlr\n"); return &rctrlr->ctrlr; } @@ -1473,7 +1473,7 @@ nvme_rdma_qpair_process_completions(struct spdk_nvme_qpair *qpair, switch (wc[i].opcode) { case IBV_WC_RECV: - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "CQ recv completion\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "CQ recv completion\n"); reaped++; diff --git a/lib/nvmf/ctrlr.c b/lib/nvmf/ctrlr.c index 6f69fcc05..12ecbd1e1 100644 --- a/lib/nvmf/ctrlr.c +++ b/lib/nvmf/ctrlr.c @@ -128,10 +128,10 @@ spdk_nvmf_ctrlr_create(struct spdk_nvmf_subsystem *subsystem, ctrlr->vcprop.csts.raw = 0; ctrlr->vcprop.csts.bits.rdy = 0; /* Init controller as not ready */ - SPDK_TRACELOG(SPDK_TRACE_NVMF, "cap 0x%" PRIx64 "\n", ctrlr->vcprop.cap.raw); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "vs 0x%x\n", ctrlr->vcprop.vs.raw); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "cc 0x%x\n", ctrlr->vcprop.cc.raw); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "csts 0x%x\n", ctrlr->vcprop.csts.raw); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "cap 0x%" PRIx64 "\n", ctrlr->vcprop.cap.raw); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "vs 0x%x\n", ctrlr->vcprop.vs.raw); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "cc 0x%x\n", ctrlr->vcprop.cc.raw); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "csts 0x%x\n", ctrlr->vcprop.csts.raw); TAILQ_INSERT_TAIL(&subsystem->ctrlrs, ctrlr, link); return ctrlr; @@ -218,12 +218,12 @@ spdk_nvmf_ctrlr_connect(struct spdk_nvmf_qpair *qpair, #define INVALID_CONNECT_CMD(field) invalid_connect_response(rsp, 0, offsetof(struct spdk_nvmf_fabric_connect_cmd, field)) #define INVALID_CONNECT_DATA(field) invalid_connect_response(rsp, 1, offsetof(struct spdk_nvmf_fabric_connect_data, field)) - SPDK_TRACELOG(SPDK_TRACE_NVMF, "recfmt 0x%x qid %u sqsize %u\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "recfmt 0x%x qid %u sqsize %u\n", cmd->recfmt, cmd->qid, cmd->sqsize); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Connect data:\n"); - SPDK_TRACELOG(SPDK_TRACE_NVMF, " cntlid: 0x%04x\n", data->cntlid); - SPDK_TRACELOG(SPDK_TRACE_NVMF, " hostid: %08x-%04x-%04x-%02x%02x-%04x%08x ***\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Connect data:\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, " cntlid: 0x%04x\n", data->cntlid); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, " hostid: %08x-%04x-%04x-%02x%02x-%04x%08x ***\n", ntohl(*(uint32_t *)&data->hostid[0]), ntohs(*(uint16_t *)&data->hostid[4]), ntohs(*(uint16_t *)&data->hostid[6]), @@ -231,8 +231,8 @@ spdk_nvmf_ctrlr_connect(struct spdk_nvmf_qpair *qpair, data->hostid[9], ntohs(*(uint16_t *)&data->hostid[10]), ntohl(*(uint32_t *)&data->hostid[12])); - SPDK_TRACELOG(SPDK_TRACE_NVMF, " subnqn: \"%s\"\n", data->subnqn); - SPDK_TRACELOG(SPDK_TRACE_NVMF, " hostnqn: \"%s\"\n", data->hostnqn); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, " subnqn: \"%s\"\n", data->subnqn); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, " hostnqn: \"%s\"\n", data->hostnqn); tgt = qpair->transport->tgt; @@ -259,7 +259,7 @@ spdk_nvmf_ctrlr_connect(struct spdk_nvmf_qpair *qpair, if (cmd->qid == 0) { qpair->type = QPAIR_TYPE_AQ; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Connect Admin Queue for controller ID 0x%x\n", data->cntlid); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Connect Admin Queue for controller ID 0x%x\n", data->cntlid); if (data->cntlid != 0xFFFF) { /* This NVMf target only supports dynamic mode. */ @@ -279,7 +279,7 @@ spdk_nvmf_ctrlr_connect(struct spdk_nvmf_qpair *qpair, struct spdk_nvmf_ctrlr *tmp; qpair->type = QPAIR_TYPE_IOQ; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Connect I/O Queue for controller id 0x%x\n", data->cntlid); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Connect I/O Queue for controller id 0x%x\n", data->cntlid); ctrlr = NULL; TAILQ_FOREACH(tmp, &subsystem->ctrlrs, link) { @@ -340,7 +340,7 @@ spdk_nvmf_ctrlr_connect(struct spdk_nvmf_qpair *qpair, rsp->status.sc = SPDK_NVME_SC_SUCCESS; rsp->status_code_specific.success.cntlid = ctrlr->cntlid; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "connect capsule response: cntlid = 0x%04x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "connect capsule response: cntlid = 0x%04x\n", rsp->status_code_specific.success.cntlid); } @@ -406,8 +406,8 @@ nvmf_prop_set_cc(struct spdk_nvmf_ctrlr *ctrlr, uint64_t value) cc.raw = (uint32_t)value; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "cur CC: 0x%08x\n", ctrlr->vcprop.cc.raw); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "new CC: 0x%08x\n", cc.raw); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "cur CC: 0x%08x\n", ctrlr->vcprop.cc.raw); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "new CC: 0x%08x\n", cc.raw); /* * Calculate which bits changed between the current and new CC. @@ -417,7 +417,7 @@ nvmf_prop_set_cc(struct spdk_nvmf_ctrlr *ctrlr, uint64_t value) if (diff.bits.en) { if (cc.bits.en) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Property Set CC Enable!\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Property Set CC Enable!\n"); ctrlr->vcprop.cc.bits.en = 1; ctrlr->vcprop.csts.bits.rdy = 1; } else { @@ -430,7 +430,7 @@ nvmf_prop_set_cc(struct spdk_nvmf_ctrlr *ctrlr, uint64_t value) if (diff.bits.shn) { if (cc.bits.shn == SPDK_NVME_SHN_NORMAL || cc.bits.shn == SPDK_NVME_SHN_ABRUPT) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Property Set CC Shutdown %u%ub!\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Property Set CC Shutdown %u%ub!\n", cc.bits.shn >> 1, cc.bits.shn & 1); ctrlr->vcprop.cc.bits.shn = cc.bits.shn; ctrlr->vcprop.cc.bits.en = 0; @@ -447,14 +447,14 @@ nvmf_prop_set_cc(struct spdk_nvmf_ctrlr *ctrlr, uint64_t value) } if (diff.bits.iosqes) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Prop Set IOSQES = %u (%u bytes)\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Prop Set IOSQES = %u (%u bytes)\n", cc.bits.iosqes, 1u << cc.bits.iosqes); ctrlr->vcprop.cc.bits.iosqes = cc.bits.iosqes; diff.bits.iosqes = 0; } if (diff.bits.iocqes) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Prop Set IOCQES = %u (%u bytes)\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Prop Set IOCQES = %u (%u bytes)\n", cc.bits.iocqes, 1u << cc.bits.iocqes); ctrlr->vcprop.cc.bits.iocqes = cc.bits.iocqes; diff.bits.iocqes = 0; @@ -523,7 +523,7 @@ spdk_nvmf_property_get(struct spdk_nvmf_ctrlr *ctrlr, response->status.sc = 0; response->value.u64 = 0; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "size %d, offset 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "size %d, offset 0x%x\n", cmd->attrib.size, cmd->ofst); if (cmd->attrib.size != SPDK_NVMF_PROP_SIZE_4 && @@ -539,7 +539,7 @@ spdk_nvmf_property_get(struct spdk_nvmf_ctrlr *ctrlr, return; } - SPDK_TRACELOG(SPDK_TRACE_NVMF, "name: %s\n", prop->name); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "name: %s\n", prop->name); if (cmd->attrib.size != prop->size) { SPDK_ERRLOG("offset 0x%x size mismatch: cmd %u, prop %u\n", cmd->ofst, cmd->attrib.size, prop->size); @@ -548,7 +548,7 @@ spdk_nvmf_property_get(struct spdk_nvmf_ctrlr *ctrlr, } response->value.u64 = prop->get_cb(ctrlr); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "response value: 0x%" PRIx64 "\n", response->value.u64); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "response value: 0x%" PRIx64 "\n", response->value.u64); } void @@ -559,7 +559,7 @@ spdk_nvmf_property_set(struct spdk_nvmf_ctrlr *ctrlr, const struct nvmf_prop *prop; uint64_t value; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "size %d, offset 0x%x, value 0x%" PRIx64 "\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "size %d, offset 0x%x, value 0x%" PRIx64 "\n", cmd->attrib.size, cmd->ofst, cmd->value.u64); prop = find_prop(cmd->ofst); @@ -569,7 +569,7 @@ spdk_nvmf_property_set(struct spdk_nvmf_ctrlr *ctrlr, return; } - SPDK_TRACELOG(SPDK_TRACE_NVMF, "name: %s\n", prop->name); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "name: %s\n", prop->name); if (cmd->attrib.size != prop->size) { SPDK_ERRLOG("offset 0x%x size mismatch: cmd %u, prop %u\n", cmd->ofst, cmd->attrib.size, prop->size); @@ -634,7 +634,7 @@ spdk_nvmf_ctrlr_get_features_host_identifier(struct spdk_nvmf_request *req) struct spdk_nvme_cmd *cmd = &req->cmd->nvme_cmd; struct spdk_nvme_cpl *response = &req->rsp->nvme_cpl; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Get Features - Host Identifier\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Get Features - Host Identifier\n"); if (!(cmd->cdw11 & 1)) { /* NVMe over Fabrics requires EXHID=1 (128-bit/16-byte host ID) */ SPDK_ERRLOG("Get Features - Host Identifier with EXHID=0 not allowed\n"); @@ -659,7 +659,7 @@ spdk_nvmf_ctrlr_set_features_keep_alive_timer(struct spdk_nvmf_request *req) struct spdk_nvme_cmd *cmd = &req->cmd->nvme_cmd; struct spdk_nvme_cpl *rsp = &req->rsp->nvme_cpl; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Set Features - Keep Alive Timer (%u ms)\n", cmd->cdw11); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Set Features - Keep Alive Timer (%u ms)\n", cmd->cdw11); if (cmd->cdw11 == 0) { rsp->status.sc = SPDK_NVME_SC_KEEP_ALIVE_INVALID; @@ -669,7 +669,7 @@ spdk_nvmf_ctrlr_set_features_keep_alive_timer(struct spdk_nvmf_request *req) ctrlr->kato = cmd->cdw11; } - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Set Features - Keep Alive Timer set to %u ms\n", ctrlr->kato); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Set Features - Keep Alive Timer set to %u ms\n", ctrlr->kato); return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; } @@ -680,7 +680,7 @@ spdk_nvmf_ctrlr_get_features_keep_alive_timer(struct spdk_nvmf_request *req) struct spdk_nvmf_ctrlr *ctrlr = req->qpair->ctrlr; struct spdk_nvme_cpl *rsp = &req->rsp->nvme_cpl; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Get Features - Keep Alive Timer\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Get Features - Keep Alive Timer\n"); rsp->cdw0 = ctrlr->kato; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; } @@ -692,7 +692,7 @@ spdk_nvmf_ctrlr_set_features_number_of_queues(struct spdk_nvmf_request *req) struct spdk_nvme_cpl *rsp = &req->rsp->nvme_cpl; uint32_t nr_io_queues; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Set Features - Number of Queues, cdw11 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Set Features - Number of Queues, cdw11 0x%x\n", req->cmd->nvme_cmd.cdw11); /* Extra 1 connection for Admin queue */ @@ -700,7 +700,7 @@ spdk_nvmf_ctrlr_set_features_number_of_queues(struct spdk_nvmf_request *req) /* verify that the contoller is ready to process commands */ if (ctrlr->num_qpairs > 1) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Queue pairs already active!\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Queue pairs already active!\n"); rsp->status.sc = SPDK_NVME_SC_COMMAND_SEQUENCE_ERROR; } else { /* Number of IO queues has a zero based value */ @@ -718,7 +718,7 @@ spdk_nvmf_ctrlr_get_features_number_of_queues(struct spdk_nvmf_request *req) struct spdk_nvme_cpl *rsp = &req->rsp->nvme_cpl; uint32_t nr_io_queues; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Get Features - Number of Queues\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Get Features - Number of Queues\n"); nr_io_queues = ctrlr->max_qpairs_allowed - 1; @@ -734,7 +734,7 @@ spdk_nvmf_ctrlr_get_features_write_cache(struct spdk_nvmf_request *req) { struct spdk_nvme_cpl *rsp = &req->rsp->nvme_cpl; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Get Features - Write Cache\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Get Features - Write Cache\n"); rsp->cdw0 = 1; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; } @@ -745,7 +745,7 @@ spdk_nvmf_ctrlr_set_features_async_event_configuration(struct spdk_nvmf_request struct spdk_nvmf_ctrlr *ctrlr = req->qpair->ctrlr; struct spdk_nvme_cmd *cmd = &req->cmd->nvme_cmd; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Set Features - Async Event Configuration, cdw11 0x%08x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Set Features - Async Event Configuration, cdw11 0x%08x\n", cmd->cdw11); ctrlr->async_event_config.raw = cmd->cdw11; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; @@ -757,7 +757,7 @@ spdk_nvmf_ctrlr_get_features_async_event_configuration(struct spdk_nvmf_request struct spdk_nvmf_ctrlr *ctrlr = req->qpair->ctrlr; struct spdk_nvme_cpl *rsp = &req->rsp->nvme_cpl; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Get Features - Async Event Configuration\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Get Features - Async Event Configuration\n"); rsp->cdw0 = ctrlr->async_event_config.raw; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; } @@ -768,11 +768,11 @@ spdk_nvmf_ctrlr_async_event_request(struct spdk_nvmf_request *req) struct spdk_nvmf_ctrlr *ctrlr = req->qpair->ctrlr; struct spdk_nvme_cpl *rsp = &req->rsp->nvme_cpl; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Async Event Request\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Async Event Request\n"); /* Only one asynchronous event is supported for now */ if (ctrlr->aer_req != NULL) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "AERL exceeded\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "AERL exceeded\n"); rsp->status.sct = SPDK_NVME_SCT_COMMAND_SPECIFIC; rsp->status.sc = SPDK_NVME_SC_ASYNC_EVENT_REQUEST_LIMIT_EXCEEDED; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; @@ -819,7 +819,7 @@ spdk_nvmf_ctrlr_get_log_page(struct spdk_nvmf_request *req) } lid = cmd->cdw10 & 0xFF; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Get log page: LID=0x%02X offset=0x%" PRIx64 " len=0x%" PRIx64 "\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Get log page: LID=0x%02X offset=0x%" PRIx64 " len=0x%" PRIx64 "\n", lid, offset, len); if (subsystem->subtype == SPDK_NVMF_SUBTYPE_DISCOVERY) { @@ -888,8 +888,8 @@ spdk_nvmf_ctrlr_identify_ctrlr(struct spdk_nvmf_ctrlr *ctrlr, struct spdk_nvme_c cdata->sgls.sgl_offset = 1; spdk_strcpy_pad(cdata->subnqn, subsystem->subnqn, sizeof(cdata->subnqn), '\0'); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "ctrlr data: maxcmd 0x%x\n", cdata->maxcmd); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "sgls data: 0x%x\n", *(uint32_t *)&cdata->sgls); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "ctrlr data: maxcmd 0x%x\n", cdata->maxcmd); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "sgls data: 0x%x\n", *(uint32_t *)&cdata->sgls); /* * NVM subsystem fields (reserved for discovery subsystems) @@ -924,15 +924,15 @@ spdk_nvmf_ctrlr_identify_ctrlr(struct spdk_nvmf_ctrlr *ctrlr, struct spdk_nvme_c cdata->oncs.dsm = spdk_nvmf_ctrlr_dsm_supported(ctrlr); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "ext ctrlr data: ioccsz 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "ext ctrlr data: ioccsz 0x%x\n", cdata->nvmf_specific.ioccsz); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "ext ctrlr data: iorcsz 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "ext ctrlr data: iorcsz 0x%x\n", cdata->nvmf_specific.iorcsz); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "ext ctrlr data: icdoff 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "ext ctrlr data: icdoff 0x%x\n", cdata->nvmf_specific.icdoff); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "ext ctrlr data: ctrattr 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "ext ctrlr data: ctrattr 0x%x\n", *(uint8_t *)&cdata->nvmf_specific.ctrattr); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "ext ctrlr data: msdbd 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "ext ctrlr data: msdbd 0x%x\n", cdata->nvmf_specific.msdbd); } @@ -1023,13 +1023,13 @@ spdk_nvmf_ctrlr_abort(struct spdk_nvmf_request *req) struct spdk_nvmf_qpair *qpair; struct spdk_nvmf_request *req_to_abort; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "abort sqid=%u cid=%u\n", sqid, cid); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "abort sqid=%u cid=%u\n", sqid, cid); rsp->cdw0 = 1; /* Command not aborted */ qpair = spdk_nvmf_ctrlr_get_qpair(ctrlr, sqid); if (qpair == NULL) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "sqid %u not found\n", sqid); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "sqid %u not found\n", sqid); rsp->status.sct = SPDK_NVME_SCT_GENERIC; rsp->status.sc = SPDK_NVME_SC_INVALID_FIELD; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; @@ -1042,14 +1042,14 @@ spdk_nvmf_ctrlr_abort(struct spdk_nvmf_request *req) */ req_to_abort = spdk_nvmf_qpair_get_request(qpair, cid); if (req_to_abort == NULL) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "cid %u not found\n", cid); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "cid %u not found\n", cid); rsp->status.sct = SPDK_NVME_SCT_GENERIC; rsp->status.sc = SPDK_NVME_SC_INVALID_FIELD; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; } if (spdk_nvmf_request_abort(req_to_abort) == 0) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "abort ctrlr=%p req=%p sqid=%u cid=%u successful\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "abort ctrlr=%p req=%p sqid=%u cid=%u successful\n", ctrlr, req_to_abort, sqid, cid); rsp->cdw0 = 0; /* Command successfully aborted */ } @@ -1111,7 +1111,7 @@ spdk_nvmf_ctrlr_set_features(struct spdk_nvmf_request *req) static int spdk_nvmf_ctrlr_keep_alive(struct spdk_nvmf_request *req) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Keep Alive\n"); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Keep Alive\n"); /* * To handle keep alive just clear or reset the * ctrlr based keep alive duration counter. diff --git a/lib/nvmf/ctrlr_bdev.c b/lib/nvmf/ctrlr_bdev.c index aa129d419..62a421f09 100644 --- a/lib/nvmf/ctrlr_bdev.c +++ b/lib/nvmf/ctrlr_bdev.c @@ -71,7 +71,7 @@ spdk_nvmf_ctrlr_dsm_supported(struct spdk_nvmf_ctrlr *ctrlr) } if (!spdk_bdev_io_type_supported(ns->bdev, SPDK_BDEV_IO_TYPE_UNMAP)) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Subsystem %s namespace %u (%s) does not support unmap - not enabling DSM\n", spdk_nvmf_subsystem_get_nqn(subsystem), ns->id, spdk_bdev_get_name(ns->bdev)); @@ -79,7 +79,7 @@ spdk_nvmf_ctrlr_dsm_supported(struct spdk_nvmf_ctrlr *ctrlr) } } - SPDK_TRACELOG(SPDK_TRACE_NVMF, "All devices in Subsystem %s support unmap - enabling DSM\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "All devices in Subsystem %s support unmap - enabling DSM\n", spdk_nvmf_subsystem_get_nqn(subsystem)); return true; } diff --git a/lib/nvmf/ctrlr_discovery.c b/lib/nvmf/ctrlr_discovery.c index 75519cee1..7d8145cba 100644 --- a/lib/nvmf/ctrlr_discovery.c +++ b/lib/nvmf/ctrlr_discovery.c @@ -62,7 +62,7 @@ nvmf_update_discovery_log(struct spdk_nvmf_tgt *tgt) struct spdk_nvmf_discovery_log_page *disc_log; size_t cur_size; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Generating log page for genctr %" PRIu64 "\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Generating log page for genctr %" PRIu64 "\n", tgt->discovery_genctr); cur_size = sizeof(struct spdk_nvmf_discovery_log_page); diff --git a/lib/nvmf/nvmf.c b/lib/nvmf/nvmf.c index a3b06ff92..deeee8c38 100644 --- a/lib/nvmf/nvmf.c +++ b/lib/nvmf/nvmf.c @@ -83,12 +83,12 @@ spdk_nvmf_tgt_create(struct spdk_nvmf_tgt_opts *opts) TAILQ_INIT(&tgt->listen_addrs); TAILQ_INIT(&tgt->transports); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Max Queue Pairs Per Controller: %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Max Queue Pairs Per Controller: %d\n", tgt->opts.max_qpairs_per_ctrlr); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Max Queue Depth: %d\n", tgt->opts.max_queue_depth); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Max In Capsule Data: %d bytes\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Max Queue Depth: %d\n", tgt->opts.max_queue_depth); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Max In Capsule Data: %d bytes\n", tgt->opts.in_capsule_data_size); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Max I/O Size: %d bytes\n", tgt->opts.max_io_size); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Max I/O Size: %d bytes\n", tgt->opts.max_io_size); return tgt; } diff --git a/lib/nvmf/rdma.c b/lib/nvmf/rdma.c index 67fa7e008..952f4c871 100644 --- a/lib/nvmf/rdma.c +++ b/lib/nvmf/rdma.c @@ -343,7 +343,7 @@ spdk_nvmf_rdma_qpair_create(struct spdk_nvmf_transport *transport, id->context = qpair; rdma_qpair->cm_id = id; - SPDK_TRACELOG(SPDK_TRACE_RDMA, "New RDMA Connection: %p\n", qpair); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "New RDMA Connection: %p\n", qpair); rdma_qpair->reqs = calloc(max_queue_depth, sizeof(*rdma_qpair->reqs)); rdma_qpair->recvs = calloc(max_queue_depth, sizeof(*rdma_qpair->recvs)); @@ -375,11 +375,11 @@ spdk_nvmf_rdma_qpair_create(struct spdk_nvmf_transport *transport, spdk_nvmf_rdma_qpair_destroy(rdma_qpair); return NULL; } - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Command Array: %p Length: %lx LKey: %x\n", + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Command Array: %p Length: %lx LKey: %x\n", rdma_qpair->cmds, max_queue_depth * sizeof(*rdma_qpair->cmds), rdma_qpair->cmds_mr->lkey); - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Completion Array: %p Length: %lx LKey: %x\n", + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Completion Array: %p Length: %lx LKey: %x\n", rdma_qpair->cpls, max_queue_depth * sizeof(*rdma_qpair->cpls), rdma_qpair->cpls_mr->lkey); - SPDK_TRACELOG(SPDK_TRACE_RDMA, "In Capsule Data Array: %p Length: %x LKey: %x\n", + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "In Capsule Data Array: %p Length: %x LKey: %x\n", rdma_qpair->bufs, max_queue_depth * rtransport->in_capsule_data_size, rdma_qpair->bufs_mr->lkey); for (i = 0; i < max_queue_depth; i++) { @@ -460,7 +460,7 @@ request_transfer_in(struct spdk_nvmf_request *req) rdma_qpair->cur_rdma_rw_depth++; - SPDK_TRACELOG(SPDK_TRACE_RDMA, "RDMA READ POSTED. Request: %p Connection: %p\n", req, qpair); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "RDMA READ POSTED. Request: %p Connection: %p\n", req, qpair); spdk_trace_record(TRACE_RDMA_READ_START, 0, 0, (uintptr_t)req, 0); rdma_req->data.wr.opcode = IBV_WR_RDMA_READ; @@ -500,7 +500,7 @@ request_transfer_out(struct spdk_nvmf_request *req) /* Post the capsule to the recv buffer */ assert(rdma_req->recv != NULL); - SPDK_TRACELOG(SPDK_TRACE_RDMA, "RDMA RECV POSTED. Recv: %p Connection: %p\n", rdma_req->recv, + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "RDMA RECV POSTED. Recv: %p Connection: %p\n", rdma_req->recv, rdma_qpair); rc = ibv_post_recv(rdma_qpair->cm_id->qp, &rdma_req->recv->wr, &bad_recv_wr); if (rc) { @@ -517,7 +517,7 @@ request_transfer_out(struct spdk_nvmf_request *req) if (rsp->status.sc == SPDK_NVME_SC_SUCCESS && req->xfer == SPDK_NVME_DATA_CONTROLLER_TO_HOST) { - SPDK_TRACELOG(SPDK_TRACE_RDMA, "RDMA WRITE POSTED. Request: %p Connection: %p\n", req, qpair); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "RDMA WRITE POSTED. Request: %p Connection: %p\n", req, qpair); spdk_trace_record(TRACE_RDMA_WRITE_START, 0, 0, (uintptr_t)req, 0); rdma_qpair->cur_rdma_rw_depth++; @@ -527,7 +527,7 @@ request_transfer_out(struct spdk_nvmf_request *req) send_wr = &rdma_req->data.wr; } - SPDK_TRACELOG(SPDK_TRACE_RDMA, "RDMA SEND POSTED. Request: %p Connection: %p\n", req, qpair); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "RDMA SEND POSTED. Request: %p Connection: %p\n", req, qpair); spdk_trace_record(TRACE_NVMF_IO_COMPLETE, 0, 0, (uintptr_t)req, 0); /* Send the completion */ @@ -575,33 +575,33 @@ nvmf_rdma_connect(struct spdk_nvmf_transport *transport, struct rdma_cm_event *e } private_data = rdma_param->private_data; - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Connect Recv on fabric intf name %s, dev_name %s\n", + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Connect Recv on fabric intf name %s, dev_name %s\n", event->id->verbs->device->name, event->id->verbs->device->dev_name); port = event->listen_id->context; - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Listen Id was %p with verbs %p. ListenAddr: %p\n", + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Listen Id was %p with verbs %p. ListenAddr: %p\n", event->listen_id, event->listen_id->verbs, port); /* Figure out the supported queue depth. This is a multi-step process * that takes into account hardware maximums, host provided values, * and our target's internal memory limits */ - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Calculating Queue Depth\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Calculating Queue Depth\n"); /* Start with the maximum queue depth allowed by the target */ max_queue_depth = rtransport->max_queue_depth; max_rw_depth = rtransport->max_queue_depth; - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Target Max Queue Depth: %d\n", rtransport->max_queue_depth); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Target Max Queue Depth: %d\n", rtransport->max_queue_depth); /* Next check the local NIC's hardware limitations */ - SPDK_TRACELOG(SPDK_TRACE_RDMA, + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Local NIC Max Send/Recv Queue Depth: %d Max Read/Write Queue Depth: %d\n", port->device->attr.max_qp_wr, port->device->attr.max_qp_rd_atom); max_queue_depth = spdk_min(max_queue_depth, port->device->attr.max_qp_wr); max_rw_depth = spdk_min(max_rw_depth, port->device->attr.max_qp_rd_atom); /* Next check the remote NIC's hardware limitations */ - SPDK_TRACELOG(SPDK_TRACE_RDMA, + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Host (Initiator) NIC Max Incoming RDMA R/W operations: %d Max Outgoing RDMA R/W operations: %d\n", rdma_param->initiator_depth, rdma_param->responder_resources); if (rdma_param->initiator_depth > 0) { @@ -612,13 +612,13 @@ nvmf_rdma_connect(struct spdk_nvmf_transport *transport, struct rdma_cm_event *e * optional. */ if (rdma_param->private_data != NULL && rdma_param->private_data_len >= sizeof(struct spdk_nvmf_rdma_request_private_data)) { - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Host Receive Queue Size: %d\n", private_data->hrqsize); - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Host Send Queue Size: %d\n", private_data->hsqsize); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Host Receive Queue Size: %d\n", private_data->hrqsize); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Host Send Queue Size: %d\n", private_data->hsqsize); max_queue_depth = spdk_min(max_queue_depth, private_data->hrqsize); max_queue_depth = spdk_min(max_queue_depth, private_data->hsqsize + 1); } - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Final Negotiated Queue Depth: %d R/W Depth: %d\n", + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Final Negotiated Queue Depth: %d R/W Depth: %d\n", max_queue_depth, max_rw_depth); /* Init the NVMf rdma transport connection */ @@ -644,7 +644,7 @@ nvmf_rdma_connect(struct spdk_nvmf_transport *transport, struct rdma_cm_event *e SPDK_ERRLOG("Error %d on rdma_accept\n", errno); goto err2; } - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Sent back the accept\n"); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Sent back the accept\n"); /* Add this RDMA connection to the global list until a CONNECT capsule * is received. */ @@ -694,7 +694,7 @@ nvmf_rdma_disconnect(struct rdma_cm_event *evt) */ TAILQ_FOREACH_SAFE(r, &g_pending_conns, link, t) { if (r == rdma_qpair) { - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Received disconnect for qpair %p before first SEND ack\n", + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Received disconnect for qpair %p before first SEND ack\n", rdma_qpair); TAILQ_REMOVE(&g_pending_conns, rdma_qpair, link); break; @@ -855,7 +855,7 @@ spdk_nvmf_rdma_request_parse_sgl(struct spdk_nvmf_rdma_transport *rtransport, rdma_req->req.data = spdk_mempool_get(rtransport->data_buf_pool); if (!rdma_req->req.data) { /* No available buffers. Queue this request up. */ - SPDK_TRACELOG(SPDK_TRACE_RDMA, "No available large data buffers. Queueing request %p\n", rdma_req); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "No available large data buffers. Queueing request %p\n", rdma_req); return 0; } @@ -867,7 +867,7 @@ spdk_nvmf_rdma_request_parse_sgl(struct spdk_nvmf_rdma_transport *rtransport, rdma_req->data.wr.wr.rdma.rkey = sgl->keyed.key; rdma_req->data.wr.wr.rdma.remote_addr = sgl->address; - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Request %p took buffer from central pool\n", rdma_req); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Request %p took buffer from central pool\n", rdma_req); return 0; } else if (sgl->generic.type == SPDK_NVME_SGL_TYPE_DATA_BLOCK && @@ -875,7 +875,7 @@ spdk_nvmf_rdma_request_parse_sgl(struct spdk_nvmf_rdma_transport *rtransport, uint64_t offset = sgl->address; uint32_t max_len = rtransport->in_capsule_data_size; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "In-capsule data: offset 0x%" PRIx64 ", length 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "In-capsule data: offset 0x%" PRIx64 ", length 0x%x\n", offset, sgl->unkeyed.length); if (offset > max_len) { @@ -926,7 +926,7 @@ spdk_nvmf_rdma_request_process(struct spdk_nvmf_rdma_transport *rtransport, do { prev_state = rdma_req->state; - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Request %p entering state %d\n", rdma_req, prev_state); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Request %p entering state %d\n", rdma_req, prev_state); switch (rdma_req->state) { case RDMA_REQUEST_STATE_FREE: @@ -1374,7 +1374,7 @@ spdk_nvmf_rdma_accept(struct spdk_nvmf_transport *transport) while (1) { rc = rdma_get_cm_event(rtransport->event_channel, &event); if (rc == 0) { - SPDK_TRACELOG(SPDK_TRACE_RDMA, "Acceptor Event: %s\n", CM_EVENT_STR[event->event]); + SPDK_DEBUGLOG(SPDK_TRACE_RDMA, "Acceptor Event: %s\n", CM_EVENT_STR[event->event]); switch (event->event) { case RDMA_CM_EVENT_CONNECT_REQUEST: diff --git a/lib/nvmf/request.c b/lib/nvmf/request.c index 1c87ebeae..c306b02df 100644 --- a/lib/nvmf/request.c +++ b/lib/nvmf/request.c @@ -54,7 +54,7 @@ spdk_nvmf_request_complete(struct spdk_nvmf_request *req) response->status.p = 0; response->cid = req->cmd->nvme_cmd.cid; - SPDK_TRACELOG(SPDK_TRACE_NVMF, + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "cpl: cid=%u cdw0=0x%08x rsvd1=%u status=0x%04x\n", response->cid, response->cdw0, response->rsvd1, *(uint16_t *)&response->status); @@ -104,7 +104,7 @@ spdk_nvmf_handle_connect(struct spdk_nvmf_request *req) spdk_nvmf_ctrlr_connect(qpair, connect, connect_data, response); - SPDK_TRACELOG(SPDK_TRACE_NVMF, "connect capsule response: cntlid = 0x%04x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "connect capsule response: cntlid = 0x%04x\n", response->status_code_specific.success.cntlid); spdk_nvmf_request_complete(req); @@ -195,7 +195,7 @@ nvmf_process_fabrics_command(struct spdk_nvmf_request *req) if (cap_hdr->fctype == SPDK_NVMF_FABRIC_COMMAND_CONNECT) { return nvmf_process_connect(req); } else { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Got fctype 0x%x, expected Connect\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Got fctype 0x%x, expected Connect\n", cap_hdr->fctype); req->rsp->nvme_cpl.status.sc = SPDK_NVME_SC_COMMAND_SEQUENCE_ERROR; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; @@ -211,7 +211,7 @@ nvmf_process_fabrics_command(struct spdk_nvmf_request *req) case SPDK_NVMF_FABRIC_COMMAND_PROPERTY_GET: return nvmf_process_property_get(req); default: - SPDK_TRACELOG(SPDK_TRACE_NVMF, "recv capsule header type invalid [%x]!\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "recv capsule header type invalid [%x]!\n", cap_hdr->fctype); req->rsp->nvme_cpl.status.sc = SPDK_NVME_SC_INVALID_OPCODE; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; @@ -219,7 +219,7 @@ nvmf_process_fabrics_command(struct spdk_nvmf_request *req) } else { /* Controller session is established, and this is an I/O queue */ /* For now, no I/O-specific Fabrics commands are implemented (other than Connect) */ - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Unexpected I/O fctype 0x%x\n", cap_hdr->fctype); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Unexpected I/O fctype 0x%x\n", cap_hdr->fctype); req->rsp->nvme_cpl.status.sc = SPDK_NVME_SC_INVALID_OPCODE; return SPDK_NVMF_REQUEST_EXEC_STATUS_COMPLETE; } @@ -235,35 +235,35 @@ nvmf_trace_command(union nvmf_h2c_msg *h2c_msg, enum spdk_nvmf_qpair_type qpair_ if (cmd->opc == SPDK_NVME_OPC_FABRIC) { opc = cap_hdr->fctype; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "%s Fabrics cmd: fctype 0x%02x cid %u\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "%s Fabrics cmd: fctype 0x%02x cid %u\n", qpair_type == QPAIR_TYPE_AQ ? "Admin" : "I/O", cap_hdr->fctype, cap_hdr->cid); } else { opc = cmd->opc; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "%s cmd: opc 0x%02x fuse %u cid %u nsid %u cdw10 0x%08x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "%s cmd: opc 0x%02x fuse %u cid %u nsid %u cdw10 0x%08x\n", qpair_type == QPAIR_TYPE_AQ ? "Admin" : "I/O", cmd->opc, cmd->fuse, cmd->cid, cmd->nsid, cmd->cdw10); if (cmd->mptr) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "mptr 0x%" PRIx64 "\n", cmd->mptr); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "mptr 0x%" PRIx64 "\n", cmd->mptr); } if (cmd->psdt != SPDK_NVME_PSDT_SGL_MPTR_CONTIG && cmd->psdt != SPDK_NVME_PSDT_SGL_MPTR_SGL) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "psdt %u\n", cmd->psdt); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "psdt %u\n", cmd->psdt); } } if (spdk_nvme_opc_get_data_transfer(opc) != SPDK_NVME_DATA_NONE) { if (sgl->generic.type == SPDK_NVME_SGL_TYPE_KEYED_DATA_BLOCK) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "SGL: Keyed%s: addr 0x%" PRIx64 " key 0x%x len 0x%x\n", sgl->generic.subtype == SPDK_NVME_SGL_SUBTYPE_INVALIDATE_KEY ? " (Inv)" : "", sgl->address, sgl->keyed.key, sgl->keyed.length); } else if (sgl->generic.type == SPDK_NVME_SGL_TYPE_DATA_BLOCK) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "SGL: Data block: %s 0x%" PRIx64 " len 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "SGL: Data block: %s 0x%" PRIx64 " len 0x%x\n", sgl->unkeyed.subtype == SPDK_NVME_SGL_SUBTYPE_OFFSET ? "offs" : "addr", sgl->address, sgl->unkeyed.length); } else { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "SGL type 0x%x subtype 0x%x\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "SGL type 0x%x subtype 0x%x\n", sgl->generic.type, sgl->generic.subtype); } } diff --git a/lib/nvmf/subsystem.c b/lib/nvmf/subsystem.c index c6acc95ff..d03587351 100644 --- a/lib/nvmf/subsystem.c +++ b/lib/nvmf/subsystem.c @@ -196,7 +196,7 @@ spdk_nvmf_delete_subsystem(struct spdk_nvmf_subsystem *subsystem) return; } - SPDK_TRACELOG(SPDK_TRACE_NVMF, "subsystem is %p\n", subsystem); + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "subsystem is %p\n", subsystem); TAILQ_FOREACH_SAFE(listener, &subsystem->listeners, link, listener_tmp) { TAILQ_REMOVE(&subsystem->listeners, listener, link); @@ -427,7 +427,7 @@ spdk_nvmf_subsystem_add_ns(struct spdk_nvmf_subsystem *subsystem, struct spdk_bd } ns->allocated = true; - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Subsystem %s: bdev %s assigned nsid %" PRIu32 "\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Subsystem %s: bdev %s assigned nsid %" PRIu32 "\n", spdk_nvmf_subsystem_get_nqn(subsystem), spdk_bdev_get_name(bdev), nsid); @@ -507,7 +507,7 @@ spdk_nvmf_subsystem_set_sn(struct spdk_nvmf_subsystem *subsystem, const char *sn max_len = sizeof(subsystem->sn) - 1; len = strlen(sn); if (len > max_len) { - SPDK_TRACELOG(SPDK_TRACE_NVMF, "Invalid sn \"%s\": length %zu > max %zu\n", + SPDK_DEBUGLOG(SPDK_TRACE_NVMF, "Invalid sn \"%s\": length %zu > max %zu\n", sn, len, max_len); return -1; } diff --git a/lib/scsi/scsi_bdev.c b/lib/scsi/scsi_bdev.c index a0cf9c200..6a456132b 100644 --- a/lib/scsi/scsi_bdev.c +++ b/lib/scsi/scsi_bdev.c @@ -654,7 +654,7 @@ spdk_bdev_scsi_inquiry(struct spdk_bdev *bdev, struct spdk_scsi_task *task, default: if (pc >= 0xc0 && pc <= 0xff) { - SPDK_TRACELOG(SPDK_TRACE_SCSI, "Vendor specific INQUIRY VPD page 0x%x\n", pc); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "Vendor specific INQUIRY VPD page 0x%x\n", pc); } else { SPDK_ERRLOG("unsupported INQUIRY VPD page 0x%x\n", pc); } @@ -827,7 +827,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x01: /* Read-Write Error Recovery */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Read-Write Error Recovery\n"); if (subpage != 0x00) break; @@ -837,7 +837,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x02: /* Disconnect-Reconnect */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Disconnect-Reconnect\n"); if (subpage != 0x00) break; @@ -859,7 +859,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x07: /* Verify Error Recovery */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Verify Error Recovery\n"); if (subpage != 0x00) @@ -871,7 +871,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x08: { /* Caching */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, "MODE_SENSE Caching\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Caching\n"); if (subpage != 0x00) break; @@ -895,7 +895,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, switch (subpage) { case 0x00: /* Control */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Control\n"); plen = 0x0a + 2; mode_sense_page_init(cp, plen, page, subpage); @@ -903,7 +903,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x01: /* Control Extension */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Control Extension\n"); plen = 0x1c + 4; mode_sense_page_init(cp, plen, page, subpage); @@ -940,7 +940,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x10: /* XOR Control */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, "MODE_SENSE XOR Control\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE XOR Control\n"); if (subpage != 0x00) break; plen = 0x16 + 2; @@ -968,7 +968,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x1a: /* Power Condition */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Power Condition\n"); if (subpage != 0x00) break; @@ -981,7 +981,7 @@ spdk_bdev_scsi_mode_sense_page(struct spdk_bdev *bdev, break; case 0x1c: /* Informational Exceptions Control */ - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SENSE Informational Exceptions Control\n"); if (subpage != 0x00) break; @@ -1181,7 +1181,7 @@ spdk_bdev_scsi_mode_select_page(struct spdk_bdev *bdev, case 0x08: { /* Caching */ //int wce; - SPDK_TRACELOG(SPDK_TRACE_SCSI, "MODE_SELECT Caching\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SELECT Caching\n"); if (subpage != 0x00) break; @@ -1198,7 +1198,7 @@ spdk_bdev_scsi_mode_select_page(struct spdk_bdev *bdev, //rc = fcntl(fd, F_GETFL, 0); //if (rc != -1) { // if (wce) { - // SPDK_TRACELOG(SPDK_TRACE_SCSI, "MODE_SELECT Writeback cache enable\n"); + // SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "MODE_SELECT Writeback cache enable\n"); // rc = fcntl(fd, F_SETFL, (rc & ~O_FSYNC)); // bdev->write_cache = 1; // } else { @@ -1266,7 +1266,7 @@ spdk_bdev_scsi_read_write_lba_check(struct spdk_scsi_task *primary, */ if (lba >= bdev_num_blocks || cmd_num_blocks > bdev_num_blocks || lba > (bdev_num_blocks - cmd_num_blocks)) { - SPDK_TRACELOG(SPDK_TRACE_SCSI, "end of media\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "end of media\n"); spdk_scsi_task_set_status(task, SPDK_SCSI_STATUS_CHECK_CONDITION, SPDK_SCSI_SENSE_ILLEGAL_REQUEST, SPDK_SCSI_ASC_LOGICAL_BLOCK_ADDRESS_OUT_OF_RANGE, @@ -1306,7 +1306,7 @@ spdk_bdev_scsi_read(struct spdk_bdev *bdev, offset = lba * blen; nbytes = task->length; - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "Read: lba=%"PRIu64", len=%"PRIu64"\n", lba, (uint64_t)task->length / blen); @@ -1342,7 +1342,7 @@ spdk_bdev_scsi_write(struct spdk_bdev *bdev, offset = lba * blen; nbytes = ((uint64_t)len) * blen; - SPDK_TRACELOG(SPDK_TRACE_SCSI, + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "Write: lba=%"PRIu64", len=%u\n", lba, len); @@ -1377,7 +1377,7 @@ spdk_bdev_scsi_write(struct spdk_bdev *bdev, } } - SPDK_TRACELOG(SPDK_TRACE_SCSI, "Wrote %"PRIu64"/%"PRIu64" bytes\n", + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "Wrote %"PRIu64"/%"PRIu64" bytes\n", (uint64_t)task->length, nbytes); task->status = SPDK_SCSI_STATUS_GOOD; @@ -1798,7 +1798,7 @@ spdk_bdev_scsi_process_primary(struct spdk_bdev *bdev, int sel; sel = cdb[2]; - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "sel=%x\n", sel); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "sel=%x\n", sel); alloc_len = from_be32(&cdb[6]); rc = spdk_bdev_scsi_check_len(task, alloc_len, 16); @@ -1964,12 +1964,12 @@ spdk_bdev_scsi_process_primary(struct spdk_bdev *bdev, } case SPDK_SPC_LOG_SELECT: - SPDK_TRACELOG(SPDK_TRACE_SCSI, "LOG_SELECT\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "LOG_SELECT\n"); cmd_parsed = 1; /* FALLTHROUGH */ case SPDK_SPC_LOG_SENSE: if (!cmd_parsed) { - SPDK_TRACELOG(SPDK_TRACE_SCSI, "LOG_SENSE\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "LOG_SENSE\n"); } /* INVALID COMMAND OPERATION CODE */ @@ -1981,12 +1981,12 @@ spdk_bdev_scsi_process_primary(struct spdk_bdev *bdev, break; case SPDK_SPC_TEST_UNIT_READY: - SPDK_TRACELOG(SPDK_TRACE_SCSI, "TEST_UNIT_READY\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "TEST_UNIT_READY\n"); cmd_parsed = 1; /* FALLTHROUGH */ case SPDK_SBC_START_STOP_UNIT: if (!cmd_parsed) { - SPDK_TRACELOG(SPDK_TRACE_SCSI, "START_STOP_UNIT\n"); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "START_STOP_UNIT\n"); } rc = 0; @@ -2020,7 +2020,7 @@ spdk_bdev_scsi_execute(struct spdk_bdev *bdev, struct spdk_scsi_task *task) if ((rc = spdk_bdev_scsi_process_block(bdev, task)) == SPDK_SCSI_TASK_UNKNOWN) { if ((rc = spdk_bdev_scsi_process_primary(bdev, task)) == SPDK_SCSI_TASK_UNKNOWN) { - SPDK_TRACELOG(SPDK_TRACE_SCSI, "unsupported SCSI OP=0x%x\n", task->cdb[0]); + SPDK_DEBUGLOG(SPDK_TRACE_SCSI, "unsupported SCSI OP=0x%x\n", task->cdb[0]); /* INVALID COMMAND OPERATION CODE */ spdk_scsi_task_set_status(task, SPDK_SCSI_STATUS_CHECK_CONDITION, SPDK_SCSI_SENSE_ILLEGAL_REQUEST, diff --git a/lib/vhost/vhost.c b/lib/vhost/vhost.c index 5c4051a8a..cbe8f4bff 100644 --- a/lib/vhost/vhost.c +++ b/lib/vhost/vhost.c @@ -87,7 +87,7 @@ spdk_vhost_vq_avail_ring_get(struct rte_vhost_vring *vq, uint16_t *reqs, uint16_ reqs[i] = vq->avail->ring[(last_idx + i) & size_mask]; } - SPDK_TRACELOG(SPDK_TRACE_VHOST_RING, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_RING, "AVAIL: last_idx=%"PRIu16" avail_idx=%"PRIu16" count=%"PRIu16"\n", last_idx, avail_idx, count); @@ -113,7 +113,7 @@ spdk_vhost_vq_used_ring_enqueue(struct spdk_vhost_dev *vdev, struct rte_vhost_vr struct vring_used *used = vq->used; uint16_t last_idx = vq->last_used_idx & (vq->size - 1); - SPDK_TRACELOG(SPDK_TRACE_VHOST_RING, "USED: last_idx=%"PRIu16" req id=%"PRIu16" len=%"PRIu32"\n", + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_RING, "USED: last_idx=%"PRIu16" req id=%"PRIu16" len=%"PRIu32"\n", vq->last_used_idx, id, len); vq->last_used_idx++; diff --git a/lib/vhost/vhost_blk.c b/lib/vhost/vhost_blk.c index 86c243148..6b47a06c6 100644 --- a/lib/vhost/vhost_blk.c +++ b/lib/vhost/vhost_blk.c @@ -82,7 +82,7 @@ spdk_vhost_blk_get_tasks(struct spdk_vhost_blk_dev *bvdev, struct spdk_vhost_blk assert(res_count == count); for (res_count = 0; res_count < count; res_count++) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK_TASK, "GET task %p\n", tasks[res_count]); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK_TASK, "GET task %p\n", tasks[res_count]); } } @@ -93,7 +93,7 @@ spdk_vhost_blk_put_tasks(struct spdk_vhost_blk_dev *bvdev, struct spdk_vhost_blk size_t res_count; for (res_count = 0; res_count < count; res_count++) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK_TASK, "PUT task %p\n", tasks[res_count]); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK_TASK, "PUT task %p\n", tasks[res_count]); } res_count = spdk_ring_enqueue(bvdev->tasks_pool, (void **)tasks, count); @@ -112,7 +112,7 @@ invalid_blk_request(struct spdk_vhost_blk_task *task, uint8_t status) spdk_vhost_vq_used_ring_enqueue(&task->bvdev->vdev, task->vq, task->req_idx, 0); spdk_vhost_blk_put_tasks(task->bvdev, &task, 1); - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK_DATA, "Invalid request (status=%" PRIu8")\n", status); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK_DATA, "Invalid request (status=%" PRIu8")\n", status); } /* @@ -136,13 +136,13 @@ blk_iovs_setup(struct spdk_vhost_dev *vdev, struct rte_vhost_vring *vq, uint16_t * Should not happen if request is well formatted, otherwise this is a BUG. */ if (spdk_unlikely(cnt == *iovs_cnt)) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "Max IOVs in request reached (req_idx = %"PRIu16").\n", + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "Max IOVs in request reached (req_idx = %"PRIu16").\n", req_idx); return -1; } if (spdk_unlikely(spdk_vhost_vring_desc_to_iov(vdev, iovs, &cnt, desc))) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "Invalid descriptor %" PRIu16" (req_idx = %"PRIu16").\n", + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "Invalid descriptor %" PRIu16" (req_idx = %"PRIu16").\n", req_idx, cnt); return -1; } @@ -178,7 +178,7 @@ blk_request_finish(bool success, struct spdk_vhost_blk_task *task) *task->status = success ? VIRTIO_BLK_S_OK : VIRTIO_BLK_S_IOERR; spdk_vhost_vq_used_ring_enqueue(&task->bvdev->vdev, task->vq, task->req_idx, task->length); - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "Finished task (%p) req_idx=%d\n status: %s\n", task, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "Finished task (%p) req_idx=%d\n status: %s\n", task, task->req_idx, success ? "OK" : "FAIL"); spdk_vhost_blk_put_tasks(task->bvdev, &task, 1); } @@ -209,7 +209,7 @@ process_blk_request(struct spdk_vhost_blk_task *task, struct spdk_vhost_blk_dev task->status = NULL; if (blk_iovs_setup(&bvdev->vdev, vq, req_idx, task->iovs, &task->iovcnt, &task->length)) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "Invalid request (req_idx = %"PRIu16").\n", req_idx); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "Invalid request (req_idx = %"PRIu16").\n", req_idx); /* Only READ and WRITE are supported for now. */ invalid_blk_request(task, VIRTIO_BLK_S_UNSUPP); return -1; @@ -217,7 +217,7 @@ process_blk_request(struct spdk_vhost_blk_task *task, struct spdk_vhost_blk_dev iov = &task->iovs[0]; if (spdk_unlikely(iov->iov_len != sizeof(*req))) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "First descriptor size is %zu but expected %zu (req_idx = %"PRIu16").\n", iov->iov_len, sizeof(*req), req_idx); invalid_blk_request(task, VIRTIO_BLK_S_UNSUPP); @@ -228,7 +228,7 @@ process_blk_request(struct spdk_vhost_blk_task *task, struct spdk_vhost_blk_dev iov = &task->iovs[task->iovcnt - 1]; if (spdk_unlikely(iov->iov_len != 1)) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "Last descriptor size is %zu but expected %d (req_idx = %"PRIu16").\n", iov->iov_len, 1, req_idx); invalid_blk_request(task, VIRTIO_BLK_S_UNSUPP); @@ -264,7 +264,7 @@ process_blk_request(struct spdk_vhost_blk_task *task, struct spdk_vhost_blk_dev &task->iovs[1], task->iovcnt, req->sector * 512, task->length, blk_request_complete_cb, task); } else { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "Device is in read-only mode!\n"); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "Device is in read-only mode!\n"); rc = -1; } @@ -283,7 +283,7 @@ process_blk_request(struct spdk_vhost_blk_task *task, struct spdk_vhost_blk_dev blk_request_finish(true, task); break; default: - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "Not supported request type '%"PRIu32"'.\n", type); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "Not supported request type '%"PRIu32"'.\n", type); invalid_blk_request(task, VIRTIO_BLK_S_UNSUPP); return -1; } @@ -306,14 +306,14 @@ process_vq(struct spdk_vhost_blk_dev *bvdev, struct rte_vhost_vring *vq) spdk_vhost_blk_get_tasks(bvdev, tasks, reqs_cnt); for (i = 0; i < reqs_cnt; i++) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "====== Starting processing request idx %"PRIu16"======\n", + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "====== Starting processing request idx %"PRIu16"======\n", reqs[i]); rc = process_blk_request(tasks[i], bvdev, vq, reqs[i]); if (rc == 0) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "====== Task %p req_idx %d submitted ======\n", tasks[i], + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "====== Task %p req_idx %d submitted ======\n", tasks[i], reqs[i]); } else { - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK, "====== Task %p req_idx %d failed ======\n", tasks[i], reqs[i]); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK, "====== Task %p req_idx %d failed ======\n", tasks[i], reqs[i]); } } } @@ -343,7 +343,7 @@ no_bdev_process_vq(struct spdk_vhost_blk_dev *bvdev, struct rte_vhost_vring *vq) iovcnt = SPDK_COUNTOF(iovs); if (blk_iovs_setup(&bvdev->vdev, vq, req_idx, iovs, &iovcnt, &length) == 0) { *(volatile uint8_t *)iovs[iovcnt - 1].iov_base = VIRTIO_BLK_S_IOERR; - SPDK_TRACELOG(SPDK_TRACE_VHOST_BLK_DATA, "Aborting request %" PRIu16"\n", req_idx); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_BLK_DATA, "Aborting request %" PRIu16"\n", req_idx); } spdk_vhost_vq_used_ring_enqueue(&bvdev->vdev, vq, req_idx, 0); diff --git a/lib/vhost/vhost_iommu.c b/lib/vhost/vhost_iommu.c index b14e864ef..74b83a91b 100644 --- a/lib/vhost/vhost_iommu.c +++ b/lib/vhost/vhost_iommu.c @@ -134,7 +134,7 @@ vfio_pci_memory_region_map(int vfio_container_fd, uint64_t vaddr, uint64_t phys_ dma_map.iova = phys_addr; dma_map.size = size; - SPDK_TRACELOG(SPDK_TRACE_VHOST_VFIO, "MAP vaddr:%p phys:%p len:%#"PRIx64"\n", (void *)vaddr, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_VFIO, "MAP vaddr:%p phys:%p len:%#"PRIx64"\n", (void *)vaddr, (void *)phys_addr, size); ret = ioctl(vfio_container_fd, VFIO_IOMMU_MAP_DMA, &dma_map); @@ -158,7 +158,7 @@ vfio_pci_memory_region_unmap(int vfio_container_fd, uint64_t phys_addr, uint64_t dma_unmap.iova = phys_addr; dma_unmap.size = size; - SPDK_TRACELOG(SPDK_TRACE_VHOST_VFIO, "UNMAP phys:%p len:%#"PRIx64"\n", (void *)phys_addr, size); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_VFIO, "UNMAP phys:%p len:%#"PRIx64"\n", (void *)phys_addr, size); ret = ioctl(vfio_container_fd, VFIO_IOMMU_UNMAP_DMA, &dma_unmap); if (ret) { diff --git a/lib/vhost/vhost_rpc.c b/lib/vhost/vhost_rpc.c index d3e86c705..609f2e473 100644 --- a/lib/vhost/vhost_rpc.c +++ b/lib/vhost/vhost_rpc.c @@ -72,7 +72,7 @@ spdk_rpc_construct_vhost_scsi_controller(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_construct_vhost_ctrlr, SPDK_COUNTOF(rpc_construct_vhost_ctrlr), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); rc = -EINVAL; goto invalid; } @@ -127,7 +127,7 @@ spdk_rpc_remove_vhost_scsi_controller(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_remove_vhost_ctrlr, SPDK_COUNTOF(rpc_remove_vhost_ctrlr), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); rc = -EINVAL; goto invalid; } @@ -192,7 +192,7 @@ spdk_rpc_add_vhost_scsi_lun(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_vhost_add_lun, SPDK_COUNTOF(rpc_vhost_add_lun), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); rc = -EINVAL; goto invalid; } @@ -249,7 +249,7 @@ spdk_rpc_remove_vhost_scsi_dev(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_vhost_remove_dev, SPDK_COUNTOF(rpc_vhost_remove_dev), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); rc = -EINVAL; goto invalid; } @@ -316,7 +316,7 @@ spdk_rpc_construct_vhost_blk_controller(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_construct_vhost_blk_ctrlr, SPDK_COUNTOF(rpc_construct_vhost_blk_ctrlr), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); rc = -EINVAL; goto invalid; } @@ -372,7 +372,7 @@ spdk_rpc_remove_vhost_blk_controller(struct spdk_jsonrpc_request *request, if (spdk_json_decode_object(params, rpc_remove_vhost_blk_ctrlr, SPDK_COUNTOF(rpc_remove_vhost_blk_ctrlr), &req)) { - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "spdk_json_decode_object failed\n"); rc = -EINVAL; goto invalid; } diff --git a/lib/vhost/vhost_scsi.c b/lib/vhost/vhost_scsi.c index 0aad25cbb..044a42f0f 100644 --- a/lib/vhost/vhost_scsi.c +++ b/lib/vhost/vhost_scsi.c @@ -306,7 +306,7 @@ submit_completion(struct spdk_vhost_scsi_task *task) { spdk_vhost_vq_used_ring_enqueue(&task->svdev->vdev, task->vq, task->req_idx, task->scsi.data_transferred); - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI, "Finished task (%p) req_idx=%d\n", task, task->req_idx); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI, "Finished task (%p) req_idx=%d\n", task, task->req_idx); spdk_vhost_scsi_task_put(task); } @@ -363,7 +363,7 @@ invalid_request(struct spdk_vhost_scsi_task *task) spdk_vhost_vq_used_ring_enqueue(&task->svdev->vdev, task->vq, task->req_idx, 0); spdk_vhost_scsi_task_put(task); - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI, "Invalid request (status=%" PRIu8")\n", + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI, "Invalid request (status=%" PRIu8")\n", task->resp ? task->resp->response : -1); } @@ -405,7 +405,7 @@ process_ctrl_request(struct spdk_vhost_scsi_task *task) desc = spdk_vhost_vq_get_desc(task->vq, task->req_idx); ctrl_req = spdk_vhost_gpa_to_vva(&task->svdev->vdev, desc->addr); - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI_QUEUE, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI_QUEUE, "Processing controlq descriptor: desc %d/%p, desc_addr %p, len %d, flags %d, last_used_idx %d; kickfd %d; size %d\n", task->req_idx, desc, (void *)desc->addr, desc->len, desc->flags, task->vq->last_used_idx, task->vq->kickfd, task->vq->size); @@ -431,14 +431,14 @@ process_ctrl_request(struct spdk_vhost_scsi_task *task) switch (ctrl_req->subtype) { case VIRTIO_SCSI_T_TMF_LOGICAL_UNIT_RESET: /* Handle LUN reset */ - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI_QUEUE, "LUN reset\n"); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI_QUEUE, "LUN reset\n"); mgmt_task_submit(task, SPDK_SCSI_TASK_FUNC_LUN_RESET); return; default: task->tmf_resp->response = VIRTIO_SCSI_S_ABORTED; /* Unsupported command */ - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI_QUEUE, "Unsupported TMF command %x\n", ctrl_req->subtype); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI_QUEUE, "Unsupported TMF command %x\n", ctrl_req->subtype); break; } break; @@ -450,7 +450,7 @@ process_ctrl_request(struct spdk_vhost_scsi_task *task) break; } default: - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI_QUEUE, "Unsupported control command %x\n", ctrl_req->type); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI_QUEUE, "Unsupported control command %x\n", ctrl_req->type); break; } @@ -499,7 +499,7 @@ task_data_setup(struct spdk_vhost_scsi_task *task, /* * TEST UNIT READY command and some others might not contain any payload and this is not an error. */ - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI_DATA, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI_DATA, "No payload descriptors for FROM DEV command req_idx=%"PRIu16".\n", task->req_idx); SPDK_TRACEDUMP(SPDK_TRACE_VHOST_SCSI_DATA, "CDB=", (*req)->cdb, VIRTIO_SCSI_CDB_SIZE); task->scsi.iovcnt = 1; @@ -530,7 +530,7 @@ task_data_setup(struct spdk_vhost_scsi_task *task, } } } else { - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI_DATA, "TO DEV"); + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI_DATA, "TO DEV"); /* * TO_DEV (WRITE):[RD_req][RD_buf0]...[RD_bufN][WR_resp] * No need to check descriptor WR flag as this is done while setting scsi.dxfer_dir. @@ -642,7 +642,7 @@ process_requestq(struct spdk_vhost_scsi_dev *svdev, struct rte_vhost_vring *vq) spdk_vhost_get_tasks(svdev, tasks, reqs_cnt); for (i = 0; i < reqs_cnt; i++) { - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI, "====== Starting processing request idx %"PRIu16"======\n", + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI, "====== Starting processing request idx %"PRIu16"======\n", reqs[i]); task = tasks[i]; @@ -653,15 +653,15 @@ process_requestq(struct spdk_vhost_scsi_dev *svdev, struct rte_vhost_vring *vq) result = process_request(task); if (likely(result == 0)) { task_submit(task); - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI, "====== Task %p req_idx %d submitted ======\n", task, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI, "====== Task %p req_idx %d submitted ======\n", task, task->req_idx); } else if (result > 0) { spdk_vhost_scsi_task_cpl(&task->scsi); - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI, "====== Task %p req_idx %d finished early ======\n", task, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI, "====== Task %p req_idx %d finished early ======\n", task, task->req_idx); } else { invalid_request(task); - SPDK_TRACELOG(SPDK_TRACE_VHOST_SCSI, "====== Task %p req_idx %d failed ======\n", task, + SPDK_DEBUGLOG(SPDK_TRACE_VHOST_SCSI, "====== Task %p req_idx %d failed ======\n", task, task->req_idx); } } diff --git a/test/unit/lib/log/log.c/log_ut.c b/test/unit/lib/log/log.c/log_ut.c index cf432d17c..2393903bc 100644 --- a/test/unit/lib/log/log.c/log_ut.c +++ b/test/unit/lib/log/log.c/log_ut.c @@ -65,7 +65,7 @@ log_test(void) spdk_log_open(); spdk_log_set_trace_flag("debug"); SPDK_WARNLOG("log warning unit test\n"); - SPDK_TRACELOG(SPDK_TRACE_DEBUG, "log trace test\n"); + SPDK_DEBUGLOG(SPDK_TRACE_DEBUG, "log trace test\n"); SPDK_TRACEDUMP(SPDK_TRACE_DEBUG, "log trace dump test:", "trace dump", 10); spdk_trace_dump("spdk dump test:", "spdk dump", 9);