[RFC v2 0/3] nvme: add passthrough error logging opt-in

[RFC v2 0/3] nvme: add passthrough error logging opt-in

[Alan Adamson]

v2:
- Included Pankaj Raghav's patch 'nvme: ignore starting sector while error logging for passthrough requests'
  with a couple changes.
- Moved error_logging flag to nvme_ctrl structure
- The entire nvme-debugfs.c does not need to be guarded by #ifdef CONFIG_FAULT_INJECTION_DEBUG_FS.
- Use IS_ENABLED((CONFIG_NVME_ERROR_LOGGING_DEBUG_FS)) to determine if error logging should be
  initialized.
- Various other nits.

  
Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") disabled error
logging for user passthrough commands.  This commit adds the ability to opt in
to passthrough error logging via debugfs.

Currently nvme uses debugfs for nvme fault injection. A change is needed to extend
the nvme debugfs implementation to go beyond error injection.

Move Fault Injection to nvme-debugfs.c.  Add new config parameter (CONFIG_NVME_FAULT_INJECTION_DEBUG_FS)
which enables the compilation of Fault Injection functionality.  Other consumers 
of nvme-debugfs can be added without requiring Fault Injection.

Add new consumer of nvme-debugfs (CONFIG_NVME_ERROR_LOGGING_DEBUG_FS) that provides the
ability of passthrough error logging.

To enable passthrough error logging:
	echo 1 > /sys/kernel/debug/nvme0/error-logging

To disable passthrough error logging:
	echo 0 > /sys/kernel/debug/nvme0/error-logging

By default, passthrough error logging will remain disabled.

Signed-off-by: Alan Adamson <alan.adamson@oracle.com>

[RFC v2 1/3] nvme: move fault injector to nvme-debugfs.c

[Alan Adamson]

Move the nvme fault injector code associated with debugfs into
nvme-debugfs.c (new file) so all nvme debugfs associated can
reside in a common place.

CONFIG_NVME_FAULT_INJECTION_DEBUG_FS needs to be enabled to
be able to use fault injection.

Signed-off-by: Alan Adamson <alan.adamson@oracle.com>
---
 drivers/nvme/host/Kconfig                     |  6 ++
 drivers/nvme/host/Makefile                    |  2 +-
 drivers/nvme/host/core.c                      | 11 ++--
 .../host/{fault_inject.c => nvme-debugfs.c}   | 56 +++++++++----------
 drivers/nvme/host/nvme.h                      | 31 +++++-----
 5 files changed, 59 insertions(+), 47 deletions(-)
 rename drivers/nvme/host/{fault_inject.c => nvme-debugfs.c} (60%)

diff --git a/drivers/nvme/host/Kconfig b/drivers/nvme/host/Kconfig
index 2f6a7f8c94e8..70f380c1ccae 100644
--- a/drivers/nvme/host/Kconfig
+++ b/drivers/nvme/host/Kconfig
@@ -32,6 +32,12 @@ config NVME_VERBOSE_ERRORS
 	   error translation table will grow the kernel image size by
 	   about 4 KB.
 
+config NVME_FAULT_INJECTION_DEBUG_FS
+	bool "NVMe Fault Injection"
+	depends on FAULT_INJECTION_DEBUG_FS
+	help
+	   This enables NVMe Fault Injection through debugfs.
+
 config NVME_HWMON
 	bool "NVMe hardware monitoring"
 	depends on (NVME_CORE=y && HWMON=y) || (NVME_CORE=m && HWMON)
diff --git a/drivers/nvme/host/Makefile b/drivers/nvme/host/Makefile
index e27202d22c7d..c232d7703b65 100644
--- a/drivers/nvme/host/Makefile
+++ b/drivers/nvme/host/Makefile
@@ -15,7 +15,7 @@ nvme-core-$(CONFIG_NVME_VERBOSE_ERRORS)	+= constants.o
 nvme-core-$(CONFIG_TRACING)		+= trace.o
 nvme-core-$(CONFIG_NVME_MULTIPATH)	+= multipath.o
 nvme-core-$(CONFIG_BLK_DEV_ZONED)	+= zns.o
-nvme-core-$(CONFIG_FAULT_INJECTION_DEBUG_FS)	+= fault_inject.o
+nvme-core-$(CONFIG_FAULT_INJECTION_DEBUG_FS)	+= nvme-debugfs.o
 nvme-core-$(CONFIG_NVME_HWMON)		+= hwmon.o
 nvme-core-$(CONFIG_NVME_AUTH)		+= auth.o
 
diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index d4be525f8100..679d87d4f5e8 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -4336,7 +4336,9 @@ static void nvme_alloc_ns(struct nvme_ctrl *ctrl, struct nvme_ns_info *info)
 		nvme_add_ns_cdev(ns);
 
 	nvme_mpath_add_disk(ns, info->anagrpid);
-	nvme_fault_inject_init(&ns->fault_inject, ns->disk->disk_name);
+
+	nvme_debugfs_init(&ns->debugfs, ns->disk->disk_name);
+	nvme_fault_inject_init(&ns->debugfs);
 
 	return;
 
@@ -4367,7 +4369,7 @@ static void nvme_ns_remove(struct nvme_ns *ns)
 
 	clear_bit(NVME_NS_READY, &ns->flags);
 	set_capacity(ns->disk, 0);
-	nvme_fault_inject_fini(&ns->fault_inject);
+	nvme_debugfs_remove(&ns->debugfs);
 
 	/*
 	 * Ensure that !NVME_NS_READY is seen by other threads to prevent
@@ -5064,7 +5066,7 @@ EXPORT_SYMBOL_GPL(nvme_start_ctrl);
 void nvme_uninit_ctrl(struct nvme_ctrl *ctrl)
 {
 	nvme_hwmon_exit(ctrl);
-	nvme_fault_inject_fini(&ctrl->fault_inject);
+	nvme_debugfs_remove(&ctrl->debugfs);
 	dev_pm_qos_hide_latency_tolerance(ctrl->device);
 	cdev_device_del(&ctrl->cdev, ctrl->device);
 	nvme_put_ctrl(ctrl);
@@ -5189,7 +5191,8 @@ int nvme_init_ctrl(struct nvme_ctrl *ctrl, struct device *dev,
 	dev_pm_qos_update_user_latency_tolerance(ctrl->device,
 		min(default_ps_max_latency_us, (unsigned long)S32_MAX));
 
-	nvme_fault_inject_init(&ctrl->fault_inject, dev_name(ctrl->device));
+	nvme_debugfs_init(&ctrl->debugfs, dev_name(ctrl->device));
+	nvme_fault_inject_init(&ctrl->debugfs);
 	nvme_mpath_init_ctrl(ctrl);
 	ret = nvme_auth_init_ctrl(ctrl);
 	if (ret)
diff --git a/drivers/nvme/host/fault_inject.c b/drivers/nvme/host/nvme-debugfs.c
similarity index 60%
rename from drivers/nvme/host/fault_inject.c
rename to drivers/nvme/host/nvme-debugfs.c
index 83d2e6860d38..87f78b864225 100644
--- a/drivers/nvme/host/fault_inject.c
+++ b/drivers/nvme/host/nvme-debugfs.c
@@ -1,13 +1,27 @@
 // SPDX-License-Identifier: GPL-2.0
 /*
- * fault injection support for nvme.
- *
- * Copyright (c) 2018, Oracle and/or its affiliates
+ * Copyright (c) 2023, Oracle and/or its affiliates
  */
 
+#include <linux/kernel.h>
+#include <linux/module.h>
 #include <linux/moduleparam.h>
 #include "nvme.h"
 
+#ifdef CONFIG_FAULT_INJECTION_DEBUG_FS
+void nvme_debugfs_init(struct nvme_debugfs *debugfs,
+		  const char *dev_name)
+{
+	/* create debugfs directory */
+	debugfs->parent = debugfs_create_dir(dev_name, NULL);
+}
+
+void nvme_debugfs_remove(struct nvme_debugfs *debugfs)
+{
+	/* remove debugfs directories */
+	debugfs_remove_recursive(debugfs->parent);
+}
+#ifdef CONFIG_NVME_FAULT_INJECTION_DEBUG_FS
 static DECLARE_FAULT_ATTR(fail_default_attr);
 /* optional fault injection attributes boot time option:
  * nvme_core.fail_request=<interval>,<probability>,<space>,<times>
@@ -15,31 +29,20 @@ static DECLARE_FAULT_ATTR(fail_default_attr);
 static char *fail_request;
 module_param(fail_request, charp, 0000);
 
-void nvme_fault_inject_init(struct nvme_fault_inject *fault_inj,
-			    const char *dev_name)
+void nvme_fault_inject_init(struct nvme_debugfs *debugfs)
 {
-	struct dentry *dir, *parent;
+	struct nvme_fault_inject *fault_inj = &debugfs->fault_inject;
+	struct dentry *dir;
 	struct fault_attr *attr = &fault_inj->attr;
 
 	/* set default fault injection attribute */
 	if (fail_request)
 		setup_fault_attr(&fail_default_attr, fail_request);
 
-	/* create debugfs directory and attribute */
-	parent = debugfs_create_dir(dev_name, NULL);
-	if (!parent) {
-		pr_warn("%s: failed to create debugfs directory\n", dev_name);
-		return;
-	}
-
 	*attr = fail_default_attr;
-	dir = fault_create_debugfs_attr("fault_inject", parent, attr);
-	if (IS_ERR(dir)) {
-		pr_warn("%s: failed to create debugfs attr\n", dev_name);
-		debugfs_remove_recursive(parent);
+	dir = fault_create_debugfs_attr("fault_inject", debugfs->parent, attr);
+	if (IS_ERR(dir))
 		return;
-	}
-	fault_inj->parent = parent;
 
 	/* create debugfs for status code and dont_retry */
 	fault_inj->status = NVME_SC_INVALID_OPCODE;
@@ -48,12 +51,6 @@ void nvme_fault_inject_init(struct nvme_fault_inject *fault_inj,
 	debugfs_create_bool("dont_retry", 0600, dir, &fault_inj->dont_retry);
 }
 
-void nvme_fault_inject_fini(struct nvme_fault_inject *fault_inject)
-{
-	/* remove debugfs directories */
-	debugfs_remove_recursive(fault_inject->parent);
-}
-
 void nvme_should_fail(struct request *req)
 {
 	struct gendisk *disk = req->q->disk;
@@ -64,12 +61,11 @@ void nvme_should_fail(struct request *req)
 		struct nvme_ns *ns = disk->private_data;
 
 		if (ns)
-			fault_inject = &ns->fault_inject;
+			fault_inject = &ns->debugfs.fault_inject;
 		else
 			WARN_ONCE(1, "No namespace found for request\n");
-	} else {
-		fault_inject = &nvme_req(req)->ctrl->fault_inject;
-	}
+	} else
+		fault_inject = &nvme_req(req)->ctrl->debugfs.fault_inject;
 
 	if (fault_inject && should_fail(&fault_inject->attr, 1)) {
 		/* inject status code and DNR bit */
@@ -80,3 +76,5 @@ void nvme_should_fail(struct request *req)
 	}
 }
 EXPORT_SYMBOL_GPL(nvme_should_fail);
+#endif /* CONFIG_NVME_FAULT_INJECTION_DEBUG_FS */
+#endif /* CONFIG_FAULT_INJECTION_DEBUG_FS */
diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
index bf46f122e9e1..53d61723ca59 100644
--- a/drivers/nvme/host/nvme.h
+++ b/drivers/nvme/host/nvme.h
@@ -231,12 +231,16 @@ enum nvme_ctrl_state {
 struct nvme_fault_inject {
 #ifdef CONFIG_FAULT_INJECTION_DEBUG_FS
 	struct fault_attr attr;
-	struct dentry *parent;
 	bool dont_retry;	/* DNR, do not retry */
 	u16 status;		/* status code */
 #endif
 };
 
+struct nvme_debugfs {
+	struct dentry *parent;
+	struct nvme_fault_inject fault_inject;
+};
+
 enum nvme_ctrl_flags {
 	NVME_CTRL_FAILFAST_EXPIRED	= 0,
 	NVME_CTRL_ADMIN_Q_STOPPED	= 1,
@@ -370,7 +374,7 @@ struct nvme_ctrl {
 	struct page *discard_page;
 	unsigned long discard_page_busy;
 
-	struct nvme_fault_inject fault_inject;
+	struct nvme_debugfs debugfs;
 
 	enum nvme_ctrl_type cntrltype;
 	enum nvme_dctype dctype;
@@ -496,8 +500,7 @@ struct nvme_ns {
 	struct cdev		cdev;
 	struct device		cdev_device;
 
-	struct nvme_fault_inject fault_inject;
-
+	struct nvme_debugfs debugfs;
 };
 
 /* NVMe ns supports metadata actions by the controller (generate/strip) */
@@ -598,21 +601,23 @@ static inline void nvme_print_device_info(struct nvme_ctrl *ctrl)
 }
 
 #ifdef CONFIG_FAULT_INJECTION_DEBUG_FS
-void nvme_fault_inject_init(struct nvme_fault_inject *fault_inj,
-			    const char *dev_name);
-void nvme_fault_inject_fini(struct nvme_fault_inject *fault_inject);
+void nvme_debugfs_init(struct nvme_debugfs *debugfs,
+		       const char *dev_name);
+void nvme_debugfs_remove(struct nvme_debugfs *debugfs);
+#else
+static inline void nvme_debugfs_init(struct nvme_debugfs *debugfs,
+			const char *dev_name) {}
+static inline void nvme_debugfs_remove(struct nvme_debugfs *debugfs) {}
+#endif
+#ifdef CONFIG_NVME_FAULT_INJECTION_DEBUG_FS
+void nvme_fault_inject_init(struct nvme_debugfs *debugfs);
 void nvme_should_fail(struct request *req);
 #else
-static inline void nvme_fault_inject_init(struct nvme_fault_inject *fault_inj,
-					  const char *dev_name)
-{
-}
-static inline void nvme_fault_inject_fini(struct nvme_fault_inject *fault_inj)
+static inline void nvme_fault_inject_init(struct nvme_debugfs *debugfs)
 {
 }
 static inline void nvme_should_fail(struct request *req) {}
 #endif
-
 bool nvme_wait_reset(struct nvme_ctrl *ctrl);
 int nvme_try_sched_reset(struct nvme_ctrl *ctrl);
 
-- 
2.31.1

Re: [RFC v2 1/3] nvme: move fault injector to nvme-debugfs.c

[Pankaj Raghav]

Could we still retain the fault_inject.c code to avoid #ifdef for the fault_inject
code in debugfs.c?

We have two options:
- We could have both fault_inject.c and nvme-debugfs.c. Move the fault inject code from
nvme-debugfs.c to fault_inject.c so that we get rid of #ifdefs from nvme-debugfs.c.

- As the code for nvme-debugfs.c itself is not a lot (just 3 small functions including the next
patch) apart from the fault_inject code, we could move them to the header with the appropriate
#ifdefs and conditionally link the fault_inject.c code as before.

Let me know what you think.

--
Pankaj

On 2023-03-24 00:03, Alan Adamson wrote:
> Move the nvme fault injector code associated with debugfs into
> nvme-debugfs.c (new file) so all nvme debugfs associated can
> reside in a common place.
> 
> CONFIG_NVME_FAULT_INJECTION_DEBUG_FS needs to be enabled to
> be able to use fault injection.
> 
> Signed-off-by: Alan Adamson <alan.adamson@oracle.com>
> ---
>  drivers/nvme/host/Kconfig                     |  6 ++
>  drivers/nvme/host/Makefile                    |  2 +-
>  drivers/nvme/host/core.c                      | 11 ++--
>  .../host/{fault_inject.c => nvme-debugfs.c}   | 56 +++++++++----------
>  drivers/nvme/host/nvme.h                      | 31 +++++-----
>  5 files changed, 59 insertions(+), 47 deletions(-)
>  rename drivers/nvme/host/{fault_inject.c => nvme-debugfs.c} (60%)
> 

Re: [RFC v2 1/3] nvme: move fault injector to nvme-debugfs.c

[Christoph Hellwig]

On Thu, Mar 23, 2023 at 04:03:14PM -0700, Alan Adamson wrote:
> Move the nvme fault injector code associated with debugfs into
> nvme-debugfs.c (new file) so all nvme debugfs associated can
> reside in a common place.
> 
> CONFIG_NVME_FAULT_INJECTION_DEBUG_FS needs to be enabled to
> be able to use fault injection.

It feels a bit pointless to me to have a separate file for what
even with the next patch is way under 100 lines of code.

Keith, Sagi, any opinion?

Re: [RFC v2 1/3] nvme: move fault injector to nvme-debugfs.c

[Sagi Grimberg]

>> Move the nvme fault injector code associated with debugfs into
>> nvme-debugfs.c (new file) so all nvme debugfs associated can
>> reside in a common place.
>>
>> CONFIG_NVME_FAULT_INJECTION_DEBUG_FS needs to be enabled to
>> be able to use fault injection.
> 
> It feels a bit pointless to me to have a separate file for what
> even with the next patch is way under 100 lines of code.
> 
> Keith, Sagi, any opinion?

If we add stuff to debugfs other than fault injection, maybe the
file is better off called debugfs.c instead of fault_inject.c

In that case we can have nvme_debugfs_init(ns)/nvme_debugfs_fini that
would do what it needs based on config opts (fault_inject and
error_logging).

I don't see why we need a separate CONFIG_NVME_FAULT_INJECTION_DEBUG_FS
though...

[RFC v2 2/3] nvme: add error logging opt-in

[Alan Adamson]

Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") disabled error
logging for user passthrough commands.  This commit adds the ability to opt-in
to passthrough error logging.

To enable passthrough error logging:
        echo 1 > /sys/kernel/debug/nvme0/error-logging

To disable passthrough error logging:
        echo 0 > /sys/kernel/debug/nvme0/error-logging

By default, passthrough error logging will remain disabled.

CONFIG_NVME_ERROR_LOGGING_DEBUG_FS needs to be enabled to
to enable passthrough error logging.

Signed-off-by: Alan Adamson <alan.adamson@oracle.com>
---
 drivers/nvme/host/Kconfig        |  6 ++++++
 drivers/nvme/host/core.c         | 14 ++++++++++++--
 drivers/nvme/host/nvme-debugfs.c |  7 +++++--
 drivers/nvme/host/nvme.h         |  2 ++
 4 files changed, 25 insertions(+), 4 deletions(-)

diff --git a/drivers/nvme/host/Kconfig b/drivers/nvme/host/Kconfig
index 70f380c1ccae..def7940f6444 100644
--- a/drivers/nvme/host/Kconfig
+++ b/drivers/nvme/host/Kconfig
@@ -38,6 +38,12 @@ config NVME_FAULT_INJECTION_DEBUG_FS
 	help
 	   This enables NVMe Fault Injection through debugfs.
 
+config NVME_ERROR_LOGGING_DEBUG_FS
+	bool "NVMe Passthrough Error Logging"
+	depends on FAULT_INJECTION_DEBUG_FS
+	help
+	   This enables NVMe Passthrough command error logging.
+
 config NVME_HWMON
 	bool "NVMe hardware monitoring"
 	depends on (NVME_CORE=y && HWMON=y) || (NVME_CORE=m && HWMON)
diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index 679d87d4f5e8..48e9abacd80b 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -666,6 +666,8 @@ static inline void nvme_clear_nvme_request(struct request *req)
 /* initialize a passthrough request */
 void nvme_init_request(struct request *req, struct nvme_command *cmd)
 {
+	struct nvme_request *nr = nvme_req(req);
+
 	if (req->q->queuedata)
 		req->timeout = NVME_IO_TIMEOUT;
 	else /* no queuedata implies admin queue */
@@ -678,8 +680,11 @@ void nvme_init_request(struct request *req, struct nvme_command *cmd)
 	if (req->mq_hctx->type == HCTX_TYPE_POLL)
 		req->cmd_flags |= REQ_POLLED;
 	nvme_clear_nvme_request(req);
-	req->rq_flags |= RQF_QUIET;
-	memcpy(nvme_req(req)->cmd, cmd, sizeof(*cmd));
+
+	if (!nr->ctrl->error_logging)
+		req->rq_flags |= RQF_QUIET;
+
+	memcpy(nr->cmd, cmd, sizeof(*cmd));
 }
 EXPORT_SYMBOL_GPL(nvme_init_request);
 
@@ -5193,6 +5198,11 @@ int nvme_init_ctrl(struct nvme_ctrl *ctrl, struct device *dev,
 
 	nvme_debugfs_init(&ctrl->debugfs, dev_name(ctrl->device));
 	nvme_fault_inject_init(&ctrl->debugfs);
+
+	ctrl->error_logging = false;
+	if (IS_ENABLED(CONFIG_NVME_ERROR_LOGGING_DEBUG_FS))
+		nvme_error_logging_init(ctrl);
+
 	nvme_mpath_init_ctrl(ctrl);
 	ret = nvme_auth_init_ctrl(ctrl);
 	if (ret)
diff --git a/drivers/nvme/host/nvme-debugfs.c b/drivers/nvme/host/nvme-debugfs.c
index 87f78b864225..58dadbbfd67c 100644
--- a/drivers/nvme/host/nvme-debugfs.c
+++ b/drivers/nvme/host/nvme-debugfs.c
@@ -8,7 +8,6 @@
 #include <linux/moduleparam.h>
 #include "nvme.h"
 
-#ifdef CONFIG_FAULT_INJECTION_DEBUG_FS
 void nvme_debugfs_init(struct nvme_debugfs *debugfs,
 		  const char *dev_name)
 {
@@ -77,4 +76,8 @@ void nvme_should_fail(struct request *req)
 }
 EXPORT_SYMBOL_GPL(nvme_should_fail);
 #endif /* CONFIG_NVME_FAULT_INJECTION_DEBUG_FS */
-#endif /* CONFIG_FAULT_INJECTION_DEBUG_FS */
+void nvme_error_logging_init(struct nvme_ctrl *ctrl)
+{
+	debugfs_create_bool("error-logging", 0600, ctrl->debugfs.parent,
+		&ctrl->error_logging);
+}
diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
index 53d61723ca59..30eb9715e086 100644
--- a/drivers/nvme/host/nvme.h
+++ b/drivers/nvme/host/nvme.h
@@ -252,6 +252,7 @@ struct nvme_ctrl {
 	bool comp_seen;
 	enum nvme_ctrl_state state;
 	bool identified;
+	bool error_logging;
 	spinlock_t lock;
 	struct mutex scan_lock;
 	const struct nvme_ctrl_ops *ops;
@@ -618,6 +619,7 @@ static inline void nvme_fault_inject_init(struct nvme_debugfs *debugfs)
 }
 static inline void nvme_should_fail(struct request *req) {}
 #endif
+void nvme_error_logging_init(struct nvme_ctrl *ctrl);
 bool nvme_wait_reset(struct nvme_ctrl *ctrl);
 int nvme_try_sched_reset(struct nvme_ctrl *ctrl);
 
-- 
2.31.1

Re: [RFC v2 2/3] nvme: add error logging opt-in

[Christoph Hellwig]

On Thu, Mar 23, 2023 at 04:03:15PM -0700, Alan Adamson wrote:
> Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") disabled error
> logging for user passthrough commands.  This commit adds the ability to opt-in
> to passthrough error logging.
> 
> To enable passthrough error logging:
>         echo 1 > /sys/kernel/debug/nvme0/error-logging
> 
> To disable passthrough error logging:
>         echo 0 > /sys/kernel/debug/nvme0/error-logging
> 
> By default, passthrough error logging will remain disabled.
> 
> CONFIG_NVME_ERROR_LOGGING_DEBUG_FS needs to be enabled to
> to enable passthrough error logging.

Any reason to do this in debugfs vs sysfs which is someting
that we can a handle too much more easily?

Also why do we need a config option for a trivial mount of code?

Re: [RFC v2 2/3] nvme: add error logging opt-in

[Sagi Grimberg]

>> Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") disabled error
>> logging for user passthrough commands.  This commit adds the ability to opt-in
>> to passthrough error logging.
>>
>> To enable passthrough error logging:
>>          echo 1 > /sys/kernel/debug/nvme0/error-logging
>>
>> To disable passthrough error logging:
>>          echo 0 > /sys/kernel/debug/nvme0/error-logging
>>
>> By default, passthrough error logging will remain disabled.
>>
>> CONFIG_NVME_ERROR_LOGGING_DEBUG_FS needs to be enabled to
>> to enable passthrough error logging.
> 
> Any reason to do this in debugfs vs sysfs which is someting
> that we can a handle too much more easily?
> 
> Also why do we need a config option for a trivial mount of code?

I think it is because the fault_inject thing is dependent on a config.
But if we move fault injection to a debugfs init/fini we can hide
this stuff without a config option

Re: [RFC v2 2/3] nvme: add error logging opt-in

[alan.adamson]

On 3/27/23 5:57 PM, Christoph Hellwig wrote:
> On Thu, Mar 23, 2023 at 04:03:15PM -0700, Alan Adamson wrote:
>> Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") disabled error
>> logging for user passthrough commands.  This commit adds the ability to opt-in
>> to passthrough error logging.
>>
>> To enable passthrough error logging:
>>          echo 1 > /sys/kernel/debug/nvme0/error-logging
>>
>> To disable passthrough error logging:
>>          echo 0 > /sys/kernel/debug/nvme0/error-logging
>>
>> By default, passthrough error logging will remain disabled.
>>
>> CONFIG_NVME_ERROR_LOGGING_DEBUG_FS needs to be enabled to
>> to enable passthrough error logging.
> Any reason to do this in debugfs vs sysfs which is someting
> that we can a handle too much more easily?
>
> Also why do we need a config option for a trivial mount of code?
>
Putting it in sysfs may make more sense and not require debugfs to be 
configured.  See below.

Alan


diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index 53ef028596c6..24b4dcbfe819 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -337,6 +337,49 @@ static void nvme_log_error(struct request *req)
                 nr->status & NVME_SC_DNR  ? "DNR "  : "");
  }

+static void nvme_log_error_passthrough(struct request *req)
+{
+    struct nvme_ns *ns = req->q->queuedata;
+    struct nvme_request *nr = nvme_req(req);
+
+    if (ns) {
+        pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) %s%s: "
+               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x cdw14=0x%x 
cdw15=0x%x\n",
+               ns->disk ? ns->disk->disk_name : "?",
+               nvme_get_opcode_str(nr->cmd->common.opcode),
+               nr->cmd->common.opcode,
+               nvme_get_error_status_str(nr->status),
+               nr->status >> 8 & 7,    /* Status Code Type */
+               nr->status & 0xff,    /* Status Code */
+               nr->status & NVME_SC_MORE ? "MORE " : "",
+               nr->status & NVME_SC_DNR  ? "DNR "  : "",
+               nr->cmd->common.cdw10,
+               nr->cmd->common.cdw11,
+               nr->cmd->common.cdw12,
+               nr->cmd->common.cdw13,
+               nr->cmd->common.cdw14,
+               nr->cmd->common.cdw15);
+        return;
+    }
+
+    pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) %s%s: "
+               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x cdw14=0x%x 
cdw15=0x%x\n",
+               dev_name(nr->ctrl->device),
+ nvme_get_admin_opcode_str(nr->cmd->common.opcode),
+               nr->cmd->common.opcode,
+               nvme_get_error_status_str(nr->status),
+               nr->status >> 8 & 7,    /* Status Code Type */
+               nr->status & 0xff,    /* Status Code */
+               nr->status & NVME_SC_MORE ? "MORE " : "",
+               nr->status & NVME_SC_DNR  ? "DNR "  : "",
+                   nr->cmd->common.cdw10,
+                   nr->cmd->common.cdw11,
+                   nr->cmd->common.cdw12,
+                   nr->cmd->common.cdw13,
+                   nr->cmd->common.cdw14,
+                   nr->cmd->common.cdw15);
+}
+
  enum nvme_disposition {
      COMPLETE,
      RETRY,
@@ -381,8 +424,12 @@ static inline void nvme_end_req(struct request *req)
  {
      blk_status_t status = nvme_error_status(nvme_req(req)->status);

-    if (unlikely(nvme_req(req)->status && !(req->rq_flags & RQF_QUIET)))
-        nvme_log_error(req);
+    if (unlikely(nvme_req(req)->status && !(req->rq_flags & RQF_QUIET))) {
+        if (blk_rq_is_passthrough(req))
+            nvme_log_error_passthrough(req);
+        else
+            nvme_log_error(req);
+    }
      nvme_end_req_zoned(req);
      nvme_trace_bio_complete(req);
      if (req->cmd_flags & REQ_NVME_MPATH)
@@ -666,6 +713,8 @@ static inline void nvme_clear_nvme_request(struct 
request *req)
  /* initialize a passthrough request */
  void nvme_init_request(struct request *req, struct nvme_command *cmd)
  {
+    struct nvme_request *nr = nvme_req(req);
+
      if (req->q->queuedata)
          req->timeout = NVME_IO_TIMEOUT;
      else /* no queuedata implies admin queue */
@@ -678,8 +727,10 @@ void nvme_init_request(struct request *req, struct 
nvme_command *cmd)
      if (req->mq_hctx->type == HCTX_TYPE_POLL)
          req->cmd_flags |= REQ_POLLED;
      nvme_clear_nvme_request(req);
-    req->rq_flags |= RQF_QUIET;
-    memcpy(nvme_req(req)->cmd, cmd, sizeof(*cmd));
+    if (!nr->ctrl->error_logging)
+        req->rq_flags |= RQF_QUIET;
+
+    memcpy(nr->cmd, cmd, sizeof(*cmd));
  }
  EXPORT_SYMBOL_GPL(nvme_init_request);

@@ -3418,6 +3469,37 @@ static ssize_t nvme_sysfs_rescan(struct device *dev,
  }
  static DEVICE_ATTR(rescan_controller, S_IWUSR, NULL, nvme_sysfs_rescan);

+static ssize_t nvme_passthrough_show(struct device *dev,
+        struct device_attribute *attr, char *buf)
+{
+    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
+
+    if (ctrl->error_logging)
+        return sysfs_emit(buf, "on\n");
+    else
+        return sysfs_emit(buf, "off\n");
+}
+
+static ssize_t nvme_passthrough_store(struct device *dev,
+        struct device_attribute *attr, const char *buf, size_t count)
+{
+    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
+    int passthrough_enable, err;
+
+    err = kstrtoint(buf, 10, &passthrough_enable);
+    if (err)
+        return -EINVAL;
+
+    if (passthrough_enable)
+        ctrl->error_logging = true;
+    else
+        ctrl->error_logging = false;
+
+    return count;
+}
+
+static DEVICE_ATTR(passthrough_logging, S_IRUGO | S_IWUSR, 
nvme_passthrough_show, nvme_passthrough_store);
+
  static inline struct nvme_ns_head *dev_to_ns_head(struct device *dev)
  {
      struct gendisk *disk = dev_to_disk(dev);
@@ -3926,6 +4008,7 @@ static struct attribute *nvme_dev_attrs[] = {
      &dev_attr_dhchap_secret.attr,
      &dev_attr_dhchap_ctrl_secret.attr,
  #endif
+    &dev_attr_passthrough_logging.attr,
      NULL
  };

@@ -5125,6 +5208,7 @@ int nvme_init_ctrl(struct nvme_ctrl *ctrl, struct 
device *dev,
      int ret;

      ctrl->state = NVME_CTRL_NEW;
+    ctrl->error_logging = false;
      clear_bit(NVME_CTRL_FAILFAST_EXPIRED, &ctrl->flags);
      spin_lock_init(&ctrl->lock);
      mutex_init(&ctrl->scan_lock);
diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
index bf46f122e9e1..dce5e6f7260c 100644
--- a/drivers/nvme/host/nvme.h
+++ b/drivers/nvme/host/nvme.h
@@ -248,6 +248,7 @@ struct nvme_ctrl {
      bool comp_seen;
      enum nvme_ctrl_state state;
      bool identified;
+    bool error_logging;
      spinlock_t lock;
      struct mutex scan_lock;
      const struct nvme_ctrl_ops *ops;
-- 
2.31.1

Re: [RFC v2 2/3] nvme: add error logging opt-in

[Sagi Grimberg]

>>> Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") 
>>> disabled error
>>> logging for user passthrough commands.  This commit adds the ability 
>>> to opt-in
>>> to passthrough error logging.
>>>
>>> To enable passthrough error logging:
>>>          echo 1 > /sys/kernel/debug/nvme0/error-logging
>>>
>>> To disable passthrough error logging:
>>>          echo 0 > /sys/kernel/debug/nvme0/error-logging
>>>
>>> By default, passthrough error logging will remain disabled.
>>>
>>> CONFIG_NVME_ERROR_LOGGING_DEBUG_FS needs to be enabled to
>>> to enable passthrough error logging.
>> Any reason to do this in debugfs vs sysfs which is someting
>> that we can a handle too much more easily?
>>
>> Also why do we need a config option for a trivial mount of code?
>>
> Putting it in sysfs may make more sense and not require debugfs to be 
> configured.  See below.
> 
> Alan
> 
> 
> diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
> index 53ef028596c6..24b4dcbfe819 100644
> --- a/drivers/nvme/host/core.c
> +++ b/drivers/nvme/host/core.c
> @@ -337,6 +337,49 @@ static void nvme_log_error(struct request *req)
>                  nr->status & NVME_SC_DNR  ? "DNR "  : "");
>   }
> 
> +static void nvme_log_error_passthrough(struct request *req)
> +{
> +    struct nvme_ns *ns = req->q->queuedata;
> +    struct nvme_request *nr = nvme_req(req);
> +
> +    if (ns) {
> +        pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) %s%s: "
> +               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x cdw14=0x%x 
> cdw15=0x%x\n",
> +               ns->disk ? ns->disk->disk_name : "?",
> +               nvme_get_opcode_str(nr->cmd->common.opcode),
> +               nr->cmd->common.opcode,
> +               nvme_get_error_status_str(nr->status),
> +               nr->status >> 8 & 7,    /* Status Code Type */
> +               nr->status & 0xff,    /* Status Code */
> +               nr->status & NVME_SC_MORE ? "MORE " : "",
> +               nr->status & NVME_SC_DNR  ? "DNR "  : "",
> +               nr->cmd->common.cdw10,
> +               nr->cmd->common.cdw11,
> +               nr->cmd->common.cdw12,
> +               nr->cmd->common.cdw13,
> +               nr->cmd->common.cdw14,
> +               nr->cmd->common.cdw15);
> +        return;
> +    }
> +
> +    pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) %s%s: "
> +               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x cdw14=0x%x 
> cdw15=0x%x\n",
> +               dev_name(nr->ctrl->device),
> + nvme_get_admin_opcode_str(nr->cmd->common.opcode),
> +               nr->cmd->common.opcode,
> +               nvme_get_error_status_str(nr->status),
> +               nr->status >> 8 & 7,    /* Status Code Type */
> +               nr->status & 0xff,    /* Status Code */
> +               nr->status & NVME_SC_MORE ? "MORE " : "",
> +               nr->status & NVME_SC_DNR  ? "DNR "  : "",
> +                   nr->cmd->common.cdw10,
> +                   nr->cmd->common.cdw11,
> +                   nr->cmd->common.cdw12,
> +                   nr->cmd->common.cdw13,
> +                   nr->cmd->common.cdw14,
> +                   nr->cmd->common.cdw15);
> +}
> +
>   enum nvme_disposition {
>       COMPLETE,
>       RETRY,
> @@ -381,8 +424,12 @@ static inline void nvme_end_req(struct request *req)
>   {
>       blk_status_t status = nvme_error_status(nvme_req(req)->status);
> 
> -    if (unlikely(nvme_req(req)->status && !(req->rq_flags & RQF_QUIET)))
> -        nvme_log_error(req);
> +    if (unlikely(nvme_req(req)->status && !(req->rq_flags & RQF_QUIET))) {
> +        if (blk_rq_is_passthrough(req))
> +            nvme_log_error_passthrough(req);
> +        else
> +            nvme_log_error(req);
> +    }
>       nvme_end_req_zoned(req);
>       nvme_trace_bio_complete(req);
>       if (req->cmd_flags & REQ_NVME_MPATH)
> @@ -666,6 +713,8 @@ static inline void nvme_clear_nvme_request(struct 
> request *req)
>   /* initialize a passthrough request */
>   void nvme_init_request(struct request *req, struct nvme_command *cmd)
>   {
> +    struct nvme_request *nr = nvme_req(req);
> +
>       if (req->q->queuedata)
>           req->timeout = NVME_IO_TIMEOUT;
>       else /* no queuedata implies admin queue */
> @@ -678,8 +727,10 @@ void nvme_init_request(struct request *req, struct 
> nvme_command *cmd)
>       if (req->mq_hctx->type == HCTX_TYPE_POLL)
>           req->cmd_flags |= REQ_POLLED;
>       nvme_clear_nvme_request(req);
> -    req->rq_flags |= RQF_QUIET;
> -    memcpy(nvme_req(req)->cmd, cmd, sizeof(*cmd));
> +    if (!nr->ctrl->error_logging)
> +        req->rq_flags |= RQF_QUIET;
> +
> +    memcpy(nr->cmd, cmd, sizeof(*cmd));
>   }
>   EXPORT_SYMBOL_GPL(nvme_init_request);
> 
> @@ -3418,6 +3469,37 @@ static ssize_t nvme_sysfs_rescan(struct device *dev,
>   }
>   static DEVICE_ATTR(rescan_controller, S_IWUSR, NULL, nvme_sysfs_rescan);
> 
> +static ssize_t nvme_passthrough_show(struct device *dev,
> +        struct device_attribute *attr, char *buf)
> +{
> +    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
> +
> +    if (ctrl->error_logging)
> +        return sysfs_emit(buf, "on\n");
> +    else
> +        return sysfs_emit(buf, "off\n");
> +}
> +
> +static ssize_t nvme_passthrough_store(struct device *dev,
> +        struct device_attribute *attr, const char *buf, size_t count)
> +{
> +    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
> +    int passthrough_enable, err;
> +
> +    err = kstrtoint(buf, 10, &passthrough_enable);
> +    if (err)
> +        return -EINVAL;
> +
> +    if (passthrough_enable)
> +        ctrl->error_logging = true;
> +    else
> +        ctrl->error_logging = false;
> +
> +    return count;
> +}
> +
> +static DEVICE_ATTR(passthrough_logging, S_IRUGO | S_IWUSR, 
> nvme_passthrough_show, nvme_passthrough_store);

Is this something that we need per ctrl? My assumption is that
if someone wants this, one would enable it for all controllers.
Maybe this should be a modparam instead?

Re: [RFC v2 2/3] nvme: add error logging opt-in

[alan.adamson]

On 3/28/23 11:37 PM, Sagi Grimberg wrote:
>
>>>> Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") 
>>>> disabled error
>>>> logging for user passthrough commands.  This commit adds the 
>>>> ability to opt-in
>>>> to passthrough error logging.
>>>>
>>>> To enable passthrough error logging:
>>>>          echo 1 > /sys/kernel/debug/nvme0/error-logging
>>>>
>>>> To disable passthrough error logging:
>>>>          echo 0 > /sys/kernel/debug/nvme0/error-logging
>>>>
>>>> By default, passthrough error logging will remain disabled.
>>>>
>>>> CONFIG_NVME_ERROR_LOGGING_DEBUG_FS needs to be enabled to
>>>> to enable passthrough error logging.
>>> Any reason to do this in debugfs vs sysfs which is someting
>>> that we can a handle too much more easily?
>>>
>>> Also why do we need a config option for a trivial mount of code?
>>>
>> Putting it in sysfs may make more sense and not require debugfs to be 
>> configured.  See below.
>>
>> Alan
>>
>>
>> diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
>> index 53ef028596c6..24b4dcbfe819 100644
>> --- a/drivers/nvme/host/core.c
>> +++ b/drivers/nvme/host/core.c
>> @@ -337,6 +337,49 @@ static void nvme_log_error(struct request *req)
>>                  nr->status & NVME_SC_DNR  ? "DNR "  : "");
>>   }
>>
>> +static void nvme_log_error_passthrough(struct request *req)
>> +{
>> +    struct nvme_ns *ns = req->q->queuedata;
>> +    struct nvme_request *nr = nvme_req(req);
>> +
>> +    if (ns) {
>> +        pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) 
>> %s%s: "
>> +               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x 
>> cdw14=0x%x cdw15=0x%x\n",
>> +               ns->disk ? ns->disk->disk_name : "?",
>> + nvme_get_opcode_str(nr->cmd->common.opcode),
>> +               nr->cmd->common.opcode,
>> +               nvme_get_error_status_str(nr->status),
>> +               nr->status >> 8 & 7,    /* Status Code Type */
>> +               nr->status & 0xff,    /* Status Code */
>> +               nr->status & NVME_SC_MORE ? "MORE " : "",
>> +               nr->status & NVME_SC_DNR  ? "DNR "  : "",
>> +               nr->cmd->common.cdw10,
>> +               nr->cmd->common.cdw11,
>> +               nr->cmd->common.cdw12,
>> +               nr->cmd->common.cdw13,
>> +               nr->cmd->common.cdw14,
>> +               nr->cmd->common.cdw15);
>> +        return;
>> +    }
>> +
>> +    pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) %s%s: "
>> +               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x 
>> cdw14=0x%x cdw15=0x%x\n",
>> +               dev_name(nr->ctrl->device),
>> + nvme_get_admin_opcode_str(nr->cmd->common.opcode),
>> +               nr->cmd->common.opcode,
>> +               nvme_get_error_status_str(nr->status),
>> +               nr->status >> 8 & 7,    /* Status Code Type */
>> +               nr->status & 0xff,    /* Status Code */
>> +               nr->status & NVME_SC_MORE ? "MORE " : "",
>> +               nr->status & NVME_SC_DNR  ? "DNR "  : "",
>> +                   nr->cmd->common.cdw10,
>> +                   nr->cmd->common.cdw11,
>> +                   nr->cmd->common.cdw12,
>> +                   nr->cmd->common.cdw13,
>> +                   nr->cmd->common.cdw14,
>> +                   nr->cmd->common.cdw15);
>> +}
>> +
>>   enum nvme_disposition {
>>       COMPLETE,
>>       RETRY,
>> @@ -381,8 +424,12 @@ static inline void nvme_end_req(struct request 
>> *req)
>>   {
>>       blk_status_t status = nvme_error_status(nvme_req(req)->status);
>>
>> -    if (unlikely(nvme_req(req)->status && !(req->rq_flags & 
>> RQF_QUIET)))
>> -        nvme_log_error(req);
>> +    if (unlikely(nvme_req(req)->status && !(req->rq_flags & 
>> RQF_QUIET))) {
>> +        if (blk_rq_is_passthrough(req))
>> +            nvme_log_error_passthrough(req);
>> +        else
>> +            nvme_log_error(req);
>> +    }
>>       nvme_end_req_zoned(req);
>>       nvme_trace_bio_complete(req);
>>       if (req->cmd_flags & REQ_NVME_MPATH)
>> @@ -666,6 +713,8 @@ static inline void nvme_clear_nvme_request(struct 
>> request *req)
>>   /* initialize a passthrough request */
>>   void nvme_init_request(struct request *req, struct nvme_command *cmd)
>>   {
>> +    struct nvme_request *nr = nvme_req(req);
>> +
>>       if (req->q->queuedata)
>>           req->timeout = NVME_IO_TIMEOUT;
>>       else /* no queuedata implies admin queue */
>> @@ -678,8 +727,10 @@ void nvme_init_request(struct request *req, 
>> struct nvme_command *cmd)
>>       if (req->mq_hctx->type == HCTX_TYPE_POLL)
>>           req->cmd_flags |= REQ_POLLED;
>>       nvme_clear_nvme_request(req);
>> -    req->rq_flags |= RQF_QUIET;
>> -    memcpy(nvme_req(req)->cmd, cmd, sizeof(*cmd));
>> +    if (!nr->ctrl->error_logging)
>> +        req->rq_flags |= RQF_QUIET;
>> +
>> +    memcpy(nr->cmd, cmd, sizeof(*cmd));
>>   }
>>   EXPORT_SYMBOL_GPL(nvme_init_request);
>>
>> @@ -3418,6 +3469,37 @@ static ssize_t nvme_sysfs_rescan(struct device 
>> *dev,
>>   }
>>   static DEVICE_ATTR(rescan_controller, S_IWUSR, NULL, 
>> nvme_sysfs_rescan);
>>
>> +static ssize_t nvme_passthrough_show(struct device *dev,
>> +        struct device_attribute *attr, char *buf)
>> +{
>> +    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
>> +
>> +    if (ctrl->error_logging)
>> +        return sysfs_emit(buf, "on\n");
>> +    else
>> +        return sysfs_emit(buf, "off\n");
>> +}
>> +
>> +static ssize_t nvme_passthrough_store(struct device *dev,
>> +        struct device_attribute *attr, const char *buf, size_t count)
>> +{
>> +    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
>> +    int passthrough_enable, err;
>> +
>> +    err = kstrtoint(buf, 10, &passthrough_enable);
>> +    if (err)
>> +        return -EINVAL;
>> +
>> +    if (passthrough_enable)
>> +        ctrl->error_logging = true;
>> +    else
>> +        ctrl->error_logging = false;
>> +
>> +    return count;
>> +}
>> +
>> +static DEVICE_ATTR(passthrough_logging, S_IRUGO | S_IWUSR, 
>> nvme_passthrough_show, nvme_passthrough_store);
>
> Is this something that we need per ctrl? My assumption is that
> if someone wants this, one would enable it for all controllers.
> Maybe this should be a modparam instead?

Maybe both?  Have the ability to set the system-wide default value via 
modparam and sysfs to change it per ctrl?


Alan

Re: [RFC v2 2/3] nvme: add error logging opt-in

[Sagi Grimberg]

>>>>> Commit d7ac8dca938c ("nvme: quiet user passthrough command errors") 
>>>>> disabled error
>>>>> logging for user passthrough commands.  This commit adds the 
>>>>> ability to opt-in
>>>>> to passthrough error logging.
>>>>>
>>>>> To enable passthrough error logging:
>>>>>          echo 1 > /sys/kernel/debug/nvme0/error-logging
>>>>>
>>>>> To disable passthrough error logging:
>>>>>          echo 0 > /sys/kernel/debug/nvme0/error-logging
>>>>>
>>>>> By default, passthrough error logging will remain disabled.
>>>>>
>>>>> CONFIG_NVME_ERROR_LOGGING_DEBUG_FS needs to be enabled to
>>>>> to enable passthrough error logging.
>>>> Any reason to do this in debugfs vs sysfs which is someting
>>>> that we can a handle too much more easily?
>>>>
>>>> Also why do we need a config option for a trivial mount of code?
>>>>
>>> Putting it in sysfs may make more sense and not require debugfs to be 
>>> configured.  See below.
>>>
>>> Alan
>>>
>>>
>>> diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
>>> index 53ef028596c6..24b4dcbfe819 100644
>>> --- a/drivers/nvme/host/core.c
>>> +++ b/drivers/nvme/host/core.c
>>> @@ -337,6 +337,49 @@ static void nvme_log_error(struct request *req)
>>>                  nr->status & NVME_SC_DNR  ? "DNR "  : "");
>>>   }
>>>
>>> +static void nvme_log_error_passthrough(struct request *req)
>>> +{
>>> +    struct nvme_ns *ns = req->q->queuedata;
>>> +    struct nvme_request *nr = nvme_req(req);
>>> +
>>> +    if (ns) {
>>> +        pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) 
>>> %s%s: "
>>> +               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x 
>>> cdw14=0x%x cdw15=0x%x\n",
>>> +               ns->disk ? ns->disk->disk_name : "?",
>>> + nvme_get_opcode_str(nr->cmd->common.opcode),
>>> +               nr->cmd->common.opcode,
>>> +               nvme_get_error_status_str(nr->status),
>>> +               nr->status >> 8 & 7,    /* Status Code Type */
>>> +               nr->status & 0xff,    /* Status Code */
>>> +               nr->status & NVME_SC_MORE ? "MORE " : "",
>>> +               nr->status & NVME_SC_DNR  ? "DNR "  : "",
>>> +               nr->cmd->common.cdw10,
>>> +               nr->cmd->common.cdw11,
>>> +               nr->cmd->common.cdw12,
>>> +               nr->cmd->common.cdw13,
>>> +               nr->cmd->common.cdw14,
>>> +               nr->cmd->common.cdw15);
>>> +        return;
>>> +    }
>>> +
>>> +    pr_err_ratelimited("%s: %s(0x%x), %s (sct 0x%x / sc 0x%x) %s%s: "
>>> +               "cdw10=0x%x cdw11=0x%x cdw12=0x%x cdw13=0x%x 
>>> cdw14=0x%x cdw15=0x%x\n",
>>> +               dev_name(nr->ctrl->device),
>>> + nvme_get_admin_opcode_str(nr->cmd->common.opcode),
>>> +               nr->cmd->common.opcode,
>>> +               nvme_get_error_status_str(nr->status),
>>> +               nr->status >> 8 & 7,    /* Status Code Type */
>>> +               nr->status & 0xff,    /* Status Code */
>>> +               nr->status & NVME_SC_MORE ? "MORE " : "",
>>> +               nr->status & NVME_SC_DNR  ? "DNR "  : "",
>>> +                   nr->cmd->common.cdw10,
>>> +                   nr->cmd->common.cdw11,
>>> +                   nr->cmd->common.cdw12,
>>> +                   nr->cmd->common.cdw13,
>>> +                   nr->cmd->common.cdw14,
>>> +                   nr->cmd->common.cdw15);
>>> +}
>>> +
>>>   enum nvme_disposition {
>>>       COMPLETE,
>>>       RETRY,
>>> @@ -381,8 +424,12 @@ static inline void nvme_end_req(struct request 
>>> *req)
>>>   {
>>>       blk_status_t status = nvme_error_status(nvme_req(req)->status);
>>>
>>> -    if (unlikely(nvme_req(req)->status && !(req->rq_flags & 
>>> RQF_QUIET)))
>>> -        nvme_log_error(req);
>>> +    if (unlikely(nvme_req(req)->status && !(req->rq_flags & 
>>> RQF_QUIET))) {
>>> +        if (blk_rq_is_passthrough(req))
>>> +            nvme_log_error_passthrough(req);
>>> +        else
>>> +            nvme_log_error(req);
>>> +    }
>>>       nvme_end_req_zoned(req);
>>>       nvme_trace_bio_complete(req);
>>>       if (req->cmd_flags & REQ_NVME_MPATH)
>>> @@ -666,6 +713,8 @@ static inline void nvme_clear_nvme_request(struct 
>>> request *req)
>>>   /* initialize a passthrough request */
>>>   void nvme_init_request(struct request *req, struct nvme_command *cmd)
>>>   {
>>> +    struct nvme_request *nr = nvme_req(req);
>>> +
>>>       if (req->q->queuedata)
>>>           req->timeout = NVME_IO_TIMEOUT;
>>>       else /* no queuedata implies admin queue */
>>> @@ -678,8 +727,10 @@ void nvme_init_request(struct request *req, 
>>> struct nvme_command *cmd)
>>>       if (req->mq_hctx->type == HCTX_TYPE_POLL)
>>>           req->cmd_flags |= REQ_POLLED;
>>>       nvme_clear_nvme_request(req);
>>> -    req->rq_flags |= RQF_QUIET;
>>> -    memcpy(nvme_req(req)->cmd, cmd, sizeof(*cmd));
>>> +    if (!nr->ctrl->error_logging)
>>> +        req->rq_flags |= RQF_QUIET;
>>> +
>>> +    memcpy(nr->cmd, cmd, sizeof(*cmd));
>>>   }
>>>   EXPORT_SYMBOL_GPL(nvme_init_request);
>>>
>>> @@ -3418,6 +3469,37 @@ static ssize_t nvme_sysfs_rescan(struct device 
>>> *dev,
>>>   }
>>>   static DEVICE_ATTR(rescan_controller, S_IWUSR, NULL, 
>>> nvme_sysfs_rescan);
>>>
>>> +static ssize_t nvme_passthrough_show(struct device *dev,
>>> +        struct device_attribute *attr, char *buf)
>>> +{
>>> +    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
>>> +
>>> +    if (ctrl->error_logging)
>>> +        return sysfs_emit(buf, "on\n");
>>> +    else
>>> +        return sysfs_emit(buf, "off\n");
>>> +}
>>> +
>>> +static ssize_t nvme_passthrough_store(struct device *dev,
>>> +        struct device_attribute *attr, const char *buf, size_t count)
>>> +{
>>> +    struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
>>> +    int passthrough_enable, err;
>>> +
>>> +    err = kstrtoint(buf, 10, &passthrough_enable);
>>> +    if (err)
>>> +        return -EINVAL;
>>> +
>>> +    if (passthrough_enable)
>>> +        ctrl->error_logging = true;
>>> +    else
>>> +        ctrl->error_logging = false;
>>> +
>>> +    return count;
>>> +}
>>> +
>>> +static DEVICE_ATTR(passthrough_logging, S_IRUGO | S_IWUSR, 
>>> nvme_passthrough_show, nvme_passthrough_store);
>>
>> Is this something that we need per ctrl? My assumption is that
>> if someone wants this, one would enable it for all controllers.
>> Maybe this should be a modparam instead?
> 
> Maybe both?  Have the ability to set the system-wide default value via 
> modparam and sysfs to change it per ctrl?

Definitely not both. If per controller setting is needed then lets do
that, and if not, lets do a global modparam.

Re: [RFC v2 2/3] nvme: add error logging opt-in

[alan.adamson]

On 3/30/23 6:38 AM, Sagi Grimberg wrote:
>>> Is this something that we need per ctrl? My assumption is that
>>> if someone wants this, one would enable it for all controllers.
>>> Maybe this should be a modparam instead?
>>
>> Maybe both?  Have the ability to set the system-wide default value 
>> via modparam and sysfs to change it per ctrl?
>
> Definitely not both. If per controller setting is needed then lets do
> that, and if not, lets do a global modparam.

I think the use-case for it would be:

- debugging a problematic controller.  So you would only need logging 
enabled for a short time while  debugging that controller.

- Some application  that is sending passthrough commands to a specific 
controller.

Its probably best to enable it per controller.

Alan

[RFC v2 3/3] nvme: ignore starting sector while error logging for passthrough requests

[Alan Adamson]

Error log will print a garbage value as the starting LBA for passthrough
requests and requests with uninitialized starting sector that return an
error.

Signed-off-by: Pankaj Raghav <p.raghav@samsung.com>
Signed-off-by: Alan Adamson <alan.adamson@oracle.com>
---
 drivers/nvme/host/core.c | 29 ++++++++++++++++++++++++++++-
 1 file changed, 28 insertions(+), 1 deletion(-)

diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index 48e9abacd80b..82afe72b7cbd 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -306,6 +306,33 @@ static void nvme_retry_req(struct request *req)
 	blk_mq_delay_kick_requeue_list(req->q, delay);
 }
 
+static inline u64 nvme_log_error_rq_lba(struct nvme_ns *ns, struct request *rq)
+{
+	struct nvme_request *nr = nvme_req(rq);
+
+	if (blk_rq_is_passthrough(rq)) {
+		switch (nr->cmd->common.opcode) {
+		u64 cdw11;
+
+		case nvme_cmd_flush:
+		case nvme_cmd_write:
+		case nvme_cmd_read:
+		case nvme_cmd_write_uncor:
+		case nvme_cmd_compare:
+		case nvme_cmd_write_zeroes:
+		case nvme_cmd_verify:
+			cdw11 = nr->cmd->common.cdw11;
+
+			return nr->cmd->common.cdw10 | (cdw11 << 32);
+		default:
+			return 0;
+		}
+	}
+	if (blk_rq_pos(rq) == (sector_t)-1)
+		return 0;
+	return nvme_sect_to_lba(ns, blk_rq_pos(rq));
+}
+
 static void nvme_log_error(struct request *req)
 {
 	struct nvme_ns *ns = req->q->queuedata;
@@ -316,7 +343,7 @@ static void nvme_log_error(struct request *req)
 		       ns->disk ? ns->disk->disk_name : "?",
 		       nvme_get_opcode_str(nr->cmd->common.opcode),
 		       nr->cmd->common.opcode,
-		       (unsigned long long)nvme_sect_to_lba(ns, blk_rq_pos(req)),
+		       (unsigned long long)nvme_log_error_rq_lba(ns, req),
 		       (unsigned long long)blk_rq_bytes(req) >> ns->lba_shift,
 		       nvme_get_error_status_str(nr->status),
 		       nr->status >> 8 & 7,	/* Status Code Type */
-- 
2.31.1

Re: [RFC v2 3/3] nvme: ignore starting sector while error logging for passthrough requests

[Christoph Hellwig]

Yikes, no.  Anything that needs to poke into details of passthrough
commands is fundamentally wrong.  Maybe we need a separate log
message for passthrough that is just based on the cdw values instead
of trying to decode it.

Re: [RFC v2 3/3] nvme: ignore starting sector while error logging for passthrough requests

[Sagi Grimberg]

> Yikes, no.  Anything that needs to poke into details of passthrough
> commands is fundamentally wrong.  Maybe we need a separate log
> message for passthrough that is just based on the cdw values instead
> of trying to decode it.

Agree

Re: [RFC v2 3/3] nvme: ignore starting sector while error logging for passthrough requests

[alan.adamson]

On 3/28/23 1:56 AM, Sagi Grimberg wrote:
>
>> Yikes, no.  Anything that needs to poke into details of passthrough
>> commands is fundamentally wrong.  Maybe we need a separate log
>> message for passthrough that is just based on the cdw values instead
>> of trying to decode it.
>
> Agree


We can do something like this:

nvme0: Unknown(0x96), Invalid Command Opcode (sct 0x0 / sc 0x1) DNR : 
cdw10=0x1 cdw11=0x0 cdw12=0x0 cdw13=0x0 cdw14=0x0 cdw15=0x0

nvme0n1: Read(0x2), LBA Out of Range (sct 0x0 / sc 0x80) DNR : cdw10=0x0 
cdw11=0x1 cdw12=0x70000 cdw13=0x0 cdw14=0x0 cdw15=0x0


Alan