From 1b26176048aea7e73d19dae304e62f5b83248493 Mon Sep 17 00:00:00 2001 From: Daniel Wagner Date: Wed, 6 Mar 2024 09:54:39 +0100 Subject: [PATCH] logging: output ioctl debugging info Instead pushing insane logging infra code into the library, let's keep this stuff in the frontend. This is done by providing our own version of the low level ioctl function as the library is exposing this as weak symbol. This allows us to print the passthru structures and also the timing information. Signed-off-by: Daniel Wagner --- nvme-wrap.c | 6 --- nvme-wrap.h | 1 - nvme.c | 9 +---- util/logging.c | 99 ++++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 101 insertions(+), 14 deletions(-) diff --git a/nvme-wrap.c b/nvme-wrap.c index a61b4890e2..5df562a458 100644 --- a/nvme-wrap.c +++ b/nvme-wrap.c @@ -428,9 +428,3 @@ int nvme_cli_security_receive(struct nvme_dev *dev, return -ENODEV; } - -void nvme_cli_set_debug(struct nvme_dev *dev, bool set) -{ - if (dev->type == NVME_DEV_DIRECT) - nvme_set_debug(set); -} diff --git a/nvme-wrap.h b/nvme-wrap.h index c50df1427f..c18115d224 100644 --- a/nvme-wrap.h +++ b/nvme-wrap.h @@ -147,5 +147,4 @@ int nvme_cli_security_send(struct nvme_dev *dev, int nvme_cli_security_receive(struct nvme_dev *dev, struct nvme_security_receive_args* args); -void nvme_cli_set_debug(struct nvme_dev *dev, bool set); #endif /* _NVME_WRAP_H */ diff --git a/nvme.c b/nvme.c index 509a15eca5..f75c3ba147 100644 --- a/nvme.c +++ b/nvme.c @@ -373,8 +373,8 @@ int parse_and_open(struct nvme_dev **dev, int argc, char **argv, ret = get_dev(dev, argc, argv, O_RDONLY); if (ret < 0) argconfig_print_help(desc, opts); - else if (argconfig_parse_seen(opts, "verbose")) - nvme_cli_set_debug(*dev, true); + else + log_level = map_log_level(verbose_level, false); return ret; } @@ -3224,7 +3224,6 @@ static int list_subsys(int argc, char **argv, struct command *cmd, if (argconfig_parse_seen(opts, "verbose")) flags |= VERBOSE; - log_level = map_log_level(verbose_level, false); r = nvme_create_root(stderr, log_level); if (!r) { @@ -3283,8 +3282,6 @@ static int list(int argc, char **argv, struct command *cmd, struct plugin *plugi if (argconfig_parse_seen(opts, "verbose")) flags |= VERBOSE; - log_level = map_log_level(verbose_level, false); - r = nvme_create_root(stderr, log_level); if (!r) { nvme_show_error("Failed to create topology root: %s", nvme_strerror(errno)); @@ -8866,8 +8863,6 @@ static int show_topology_cmd(int argc, char **argv, struct command *command, str return -EINVAL; } - log_level = map_log_level(verbose_level, false); - r = nvme_create_root(stderr, log_level); if (!r) { nvme_show_error("Failed to create topology root: %s", nvme_strerror(errno)); diff --git a/util/logging.c b/util/logging.c index 9316d3e18b..cf3336f4b9 100644 --- a/util/logging.c +++ b/util/logging.c @@ -1,5 +1,15 @@ // SPDX-License-Identifier: GPL-2.0-or-later +#include + +#include +#include +#include +#include +#include + +#include + #include "logging.h" int log_level; @@ -33,3 +43,92 @@ int map_log_level(int verbose, bool quiet) return log_level; } + +static void nvme_show_common(struct nvme_passthru_cmd *cmd) +{ + printf("opcode : %02x\n", cmd->opcode); + printf("flags : %02x\n", cmd->flags); + printf("rsvd1 : %04x\n", cmd->rsvd1); + printf("nsid : %08x\n", cmd->nsid); + printf("cdw2 : %08x\n", cmd->cdw2); + printf("cdw3 : %08x\n", cmd->cdw3); + printf("data_len : %08x\n", cmd->data_len); + printf("metadata_len : %08x\n", cmd->metadata_len); + printf("addr : %"PRIx64"\n", (uint64_t)(uintptr_t)cmd->addr); + printf("metadata : %"PRIx64"\n", (uint64_t)(uintptr_t)cmd->metadata); + printf("cdw10 : %08x\n", cmd->cdw10); + printf("cdw11 : %08x\n", cmd->cdw11); + printf("cdw12 : %08x\n", cmd->cdw12); + printf("cdw13 : %08x\n", cmd->cdw13); + printf("cdw14 : %08x\n", cmd->cdw14); + printf("cdw15 : %08x\n", cmd->cdw15); + printf("timeout_ms : %08x\n", cmd->timeout_ms); +} + +static void nvme_show_command(struct nvme_passthru_cmd *cmd, int err, struct timeval start, + struct timeval end) +{ + nvme_show_common(cmd); + printf("result : %08x\n", cmd->result); + printf("err : %d\n", err); + printf("latency : %lu us\n", + (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_usec - start.tv_usec)); +} + +static void nvme_show_command64(struct nvme_passthru_cmd64 *cmd, int err, struct timeval start, + struct timeval end) +{ + nvme_show_common((struct nvme_passthru_cmd *)cmd); + printf("result : %"PRIx64"\n", (uint64_t)(uintptr_t)cmd->result); + printf("err : %d\n", err); + printf("latency : %lu us\n", + (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_usec - start.tv_usec)); +} + +int nvme_submit_passthru(int fd, unsigned long ioctl_cmd, + struct nvme_passthru_cmd *cmd, __u32 *result) +{ + struct timeval start; + struct timeval end; + int err; + + if (log_level >= LOG_DEBUG) + gettimeofday(&start, NULL); + + err = ioctl(fd, ioctl_cmd, cmd); + + if (log_level >= LOG_DEBUG) { + gettimeofday(&end, NULL); + nvme_show_command(cmd, err, start, end); + } + + if (err >= 0 && result) + *result = cmd->result; + + return err; +} + +int nvme_submit_passthru64(int fd, unsigned long ioctl_cmd, + struct nvme_passthru_cmd64 *cmd, + __u64 *result) +{ + struct timeval start; + struct timeval end; + int err; + + if (log_level >= LOG_DEBUG) + gettimeofday(&start, NULL); + + + err = ioctl(fd, ioctl_cmd, cmd); + + if (log_level >= LOG_DEBUG) { + gettimeofday(&end, NULL); + nvme_show_command64(cmd, err, start, end); + } + + if (err >= 0 && result) + *result = cmd->result; + + return err; +}