[PATCH 0/3] nvme: improve logging

[PATCH 0/3] nvme: improve logging

[Chaitanya Kulkarni]

These code changes are originally posted by
Hannes Reinecke <hare at suse.com> :-
http://lists.infradead.org/pipermail/linux-nvme/2019-April/023336.html

I've added all the comments posted on this patch-series along with my
signoff to the patches. Please keep my sign off if Hannes is okay
with it.

Regards,
-Chaitanya

Changes from V1:
1. Move the NVMe ctrl state array of string to the header file whee
   all controller states are defined.
2. Remvoe extra state_name variable and use the
   nvme_get_ctrl_state_name() when reporting the ctrl state.
3. Add "nvme-mp" prefix to the debug message for multipating code. 
Chaitanya Kulkarni (3):
  nvme: introduce nvme-ctrl state name string array
  nvme: improve logging
  nvme-multipath: improve logging

 drivers/nvme/host/core.c      | 41 ++++++++++++++++++++---------------
 drivers/nvme/host/multipath.c |  5 ++++-
 drivers/nvme/host/nvme.h      | 10 +++++++++
 3 files changed, 37 insertions(+), 19 deletions(-)

-- 
2.17.0

[PATCH V2 1/3] nvme: introduce nvme-ctrl state name string array

[Chaitanya Kulkarni]

From: Hannes Reinecke <hare@suse.com>

This patch intoduces nvme-ctrl state name array which is used inthe the
later patch to improve the logging of the ctrl state.

Signed-off-by: Hannes Reinecke <hare at suse.com>
Signed-off-by: Chaitanya Kulkarni <chaitanya.kulkarni at wdc.com>
---
 drivers/nvme/host/nvme.h | 10 ++++++++++
 1 file changed, 10 insertions(+)

diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
index 527d64545023..01a36bbafed6 100644
--- a/drivers/nvme/host/nvme.h
+++ b/drivers/nvme/host/nvme.h
@@ -146,6 +146,16 @@ enum nvme_ctrl_state {
 	NVME_CTRL_DEAD,
 };
 
+static const char *const nvme_ctrl_state_name[] = {
+	[NVME_CTRL_NEW]         = "new",
+	[NVME_CTRL_LIVE]        = "live",
+	[NVME_CTRL_ADMIN_ONLY]  = "only-admin",
+	[NVME_CTRL_RESETTING]   = "resetting",
+	[NVME_CTRL_CONNECTING]  = "connecting",
+	[NVME_CTRL_DELETING]    = "deleting",
+	[NVME_CTRL_DEAD]        = "dead",
+};
+
 struct nvme_ctrl {
 	bool comp_seen;
 	enum nvme_ctrl_state state;
-- 
2.17.0

[PATCH V2 2/3] nvme: improve logging

[Chaitanya Kulkarni]

From: Hannes Reinecke <hare@suse.com>

Currently nvme is very reluctant if it comes to logging anything,
_unless_ it's an ANA AEN. So this patch tries to remedy this by
decreasing the priority for the ANA AEN logging message, and improve
the logging when calling nvme_reset_ctrl().

Also, print ctrl state transition info.

Signed-off-by: Hannes Reinecke <hare at suse.com>
Signed-off-by: Chaitanya Kulkarni <chaitanya.kulkarni at wdc.com>
---
 drivers/nvme/host/core.c | 41 ++++++++++++++++++++++------------------
 1 file changed, 23 insertions(+), 18 deletions(-)

diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index 3dd043aa6d1f..c17e731f53e3 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -94,6 +94,13 @@ static void nvme_put_subsystem(struct nvme_subsystem *subsys);
 static void nvme_remove_invalid_namespaces(struct nvme_ctrl *ctrl,
 					   unsigned nsid);
 
+static const char *nvme_get_ctrl_state_name(unsigned int state)
+{
+	if ((unsigned int) state < ARRAY_SIZE(nvme_ctrl_state_name))
+		return nvme_ctrl_state_name[state];
+	return "unknown";
+}
+
 static void nvme_set_queue_dying(struct nvme_ns *ns)
 {
 	/*
@@ -119,10 +126,16 @@ static void nvme_queue_scan(struct nvme_ctrl *ctrl)
 
 int nvme_reset_ctrl(struct nvme_ctrl *ctrl)
 {
-	if (!nvme_change_ctrl_state(ctrl, NVME_CTRL_RESETTING))
+	if (!nvme_change_ctrl_state(ctrl, NVME_CTRL_RESETTING)) {
+		dev_warn(ctrl->device, "cannot reset ctrl in state %s\n",
+				nvme_get_ctrl_state_name(ctrl->state));
 		return -EBUSY;
-	if (!queue_work(nvme_reset_wq, &ctrl->reset_work))
+	}
+	if (!queue_work(nvme_reset_wq, &ctrl->reset_work)) {
+		dev_dbg(ctrl->device, "ctrl reset already queued\n");
 		return -EBUSY;
+	}
+
 	return 0;
 }
 EXPORT_SYMBOL_GPL(nvme_reset_ctrl);
@@ -370,8 +383,13 @@ bool nvme_change_ctrl_state(struct nvme_ctrl *ctrl,
 		break;
 	}
 
-	if (changed)
+	if (changed) {
 		ctrl->state = new_state;
+		dev_info(ctrl->device, "state change from (%s -> %s)\n",
+				nvme_get_ctrl_state_name(new_state),
+					nvme_get_ctrl_state_name(ctrl->state));
+
+	}
 
 	spin_unlock_irqrestore(&ctrl->lock, flags);
 	if (changed && ctrl->state == NVME_CTRL_LIVE)
@@ -2960,21 +2978,8 @@ static ssize_t nvme_sysfs_show_state(struct device *dev,
 				     char *buf)
 {
 	struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
-	static const char *const state_name[] = {
-		[NVME_CTRL_NEW]		= "new",
-		[NVME_CTRL_LIVE]	= "live",
-		[NVME_CTRL_ADMIN_ONLY]	= "only-admin",
-		[NVME_CTRL_RESETTING]	= "resetting",
-		[NVME_CTRL_CONNECTING]	= "connecting",
-		[NVME_CTRL_DELETING]	= "deleting",
-		[NVME_CTRL_DEAD]	= "dead",
-	};
-
-	if ((unsigned)ctrl->state < ARRAY_SIZE(state_name) &&
-	    state_name[ctrl->state])
-		return sprintf(buf, "%s\n", state_name[ctrl->state]);
-
-	return sprintf(buf, "unknown state\n");
+
+	return sprintf(buf, "%s\n", nvme_get_ctrl_state_name(ctrl->state));
 }
 
 static DEVICE_ATTR(state, S_IRUGO, nvme_sysfs_show_state, NULL);
-- 
2.17.0

[PATCH V2 3/3] nvme-multipath: improve logging

[Chaitanya Kulkarni]

From: Hannes Reinecke <hare@suse.com>

This patch improves the logging for nvme-multipath code.

Signed-off-by: Hannes Reinecke <hare at suse.com>
Signed-off-by: Chaitanya Kulkarni <chaitanya.kulkarni at wdc.com>
---
 drivers/nvme/host/multipath.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/drivers/nvme/host/multipath.c b/drivers/nvme/host/multipath.c
index f0716f6ce41f..e4929b7b42f9 100644
--- a/drivers/nvme/host/multipath.c
+++ b/drivers/nvme/host/multipath.c
@@ -81,6 +81,9 @@ void nvme_failover_req(struct request *req)
 		 * Reset the controller for any non-ANA error as we don't know
 		 * what caused the error.
 		 */
+		dev_info(ns->ctrl->device,
+				"nvme-mp: status 0x%04x, resetting controller\n",
+				status);
 		nvme_reset_ctrl(ns->ctrl);
 		break;
 	}
@@ -421,7 +424,7 @@ static int nvme_update_ana_state(struct nvme_ctrl *ctrl,
 	unsigned *nr_change_groups = data;
 	struct nvme_ns *ns;
 
-	dev_info(ctrl->device, "ANA group %d: %s.\n",
+	dev_dbg(ctrl->device, "ANA group %d: %s.\n",
 			le32_to_cpu(desc->grpid),
 			nvme_ana_state_names[desc->state]);
 
-- 
2.17.0

[PATCH V2 1/3] nvme: introduce nvme-ctrl state name string array

[Heitke, Kenneth]

On 4/28/2019 9:24 PM, Chaitanya Kulkarni wrote:
> From: Hannes Reinecke <hare at suse.com>
> 
> This patch intoduces nvme-ctrl state name array which is used inthe the
s/intoduces /introduces/
s/inthe/in the/

> later patch to improve the logging of the ctrl state.
> 
> Signed-off-by: Hannes Reinecke <hare at suse.com>
> Signed-off-by: Chaitanya Kulkarni <chaitanya.kulkarni at wdc.com>
> ---
>   drivers/nvme/host/nvme.h | 10 ++++++++++
>   1 file changed, 10 insertions(+)
> 
> diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
> index 527d64545023..01a36bbafed6 100644
> --- a/drivers/nvme/host/nvme.h
> +++ b/drivers/nvme/host/nvme.h
> @@ -146,6 +146,16 @@ enum nvme_ctrl_state {
>   	NVME_CTRL_DEAD,
>   };
>   
> +static const char *const nvme_ctrl_state_name[] = {
> +	[NVME_CTRL_NEW]         = "new",
> +	[NVME_CTRL_LIVE]        = "live",
> +	[NVME_CTRL_ADMIN_ONLY]  = "only-admin",
> +	[NVME_CTRL_RESETTING]   = "resetting",
> +	[NVME_CTRL_CONNECTING]  = "connecting",
> +	[NVME_CTRL_DELETING]    = "deleting",
> +	[NVME_CTRL_DEAD]        = "dead",
> +};

I haven't been paying attention if this was bought up before but won't 
this create multiple copies of this data for every source file the 
includes the header file?

> +
>   struct nvme_ctrl {
>   	bool comp_seen;
>   	enum nvme_ctrl_state state;
> 

[PATCH V2 1/3] nvme: introduce nvme-ctrl state name string array

[Chaitanya Kulkarni]

On 04/29/2019 10:41 AM, Heitke, Kenneth wrote:
>
>
> On 4/28/2019 9:24 PM, Chaitanya Kulkarni wrote:
>> From: Hannes Reinecke <hare at suse.com>
>>
>> This patch intoduces nvme-ctrl state name array which is used inthe the
> s/intoduces /introduces/
> s/inthe/in the/
>
>> later patch to improve the logging of the ctrl state.
>>
>> Signed-off-by: Hannes Reinecke <hare at suse.com>
>> Signed-off-by: Chaitanya Kulkarni <chaitanya.kulkarni at wdc.com>
>> ---
>>    drivers/nvme/host/nvme.h | 10 ++++++++++
>>    1 file changed, 10 insertions(+)
>>
>> diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
>> index 527d64545023..01a36bbafed6 100644
>> --- a/drivers/nvme/host/nvme.h
>> +++ b/drivers/nvme/host/nvme.h
>> @@ -146,6 +146,16 @@ enum nvme_ctrl_state {
>>    	NVME_CTRL_DEAD,
>>    };
>>
>> +static const char *const nvme_ctrl_state_name[] = {
>> +	[NVME_CTRL_NEW]         = "new",
>> +	[NVME_CTRL_LIVE]        = "live",
>> +	[NVME_CTRL_ADMIN_ONLY]  = "only-admin",
>> +	[NVME_CTRL_RESETTING]   = "resetting",
>> +	[NVME_CTRL_CONNECTING]  = "connecting",
>> +	[NVME_CTRL_DELETING]    = "deleting",
>> +	[NVME_CTRL_DEAD]        = "dead",
>> +};
>
> I haven't been paying attention if this was bought up before but won't
> this create multiple copies of this data for every source file the
> includes the header file?
Yes, we did discuss this.
>
>> +
>>    struct nvme_ctrl {
>>    	bool comp_seen;
>>    	enum nvme_ctrl_state state;
>>
>
> _______________________________________________
> Linux-nvme mailing list
> Linux-nvme at lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/linux-nvme
>

[PATCH V2 2/3] nvme: improve logging

[Sagi Grimberg]

> -	if (changed)
> +	if (changed) {
>   		ctrl->state = new_state;
> +		dev_info(ctrl->device, "state change from (%s -> %s)\n",
> +				nvme_get_ctrl_state_name(new_state),
> +					nvme_get_ctrl_state_name(ctrl->state));

dev_info is too chatty... dev_dbg please...

> @@ -2960,21 +2978,8 @@ static ssize_t nvme_sysfs_show_state(struct device *dev,
>   				     char *buf)
>   {
>   	struct nvme_ctrl *ctrl = dev_get_drvdata(dev);
> -	static const char *const state_name[] = {
> -		[NVME_CTRL_NEW]		= "new",
> -		[NVME_CTRL_LIVE]	= "live",
> -		[NVME_CTRL_ADMIN_ONLY]	= "only-admin",
> -		[NVME_CTRL_RESETTING]	= "resetting",
> -		[NVME_CTRL_CONNECTING]	= "connecting",
> -		[NVME_CTRL_DELETING]	= "deleting",
> -		[NVME_CTRL_DEAD]	= "dead",
> -	};

Patch #1 should erase this table here.

> -
> -	if ((unsigned)ctrl->state < ARRAY_SIZE(state_name) &&
> -	    state_name[ctrl->state])
> -		return sprintf(buf, "%s\n", state_name[ctrl->state]);
> -
> -	return sprintf(buf, "unknown state\n");
> +
> +	return sprintf(buf, "%s\n", nvme_get_ctrl_state_name(ctrl->state));
>   }
>   
>   static DEVICE_ATTR(state, S_IRUGO, nvme_sysfs_show_state, NULL);
> 

[PATCH V2 3/3] nvme-multipath: improve logging

[Sagi Grimberg]

Looks fine,

Reviewed-by: Sagi Grimberg <sagi at grimberg.me>

[PATCH V2 1/3] nvme: introduce nvme-ctrl state name string array

[Bart Van Assche]

On Mon, 2019-04-29@22:12 +0000, Chaitanya Kulkarni wrote:
> On 04/29/2019 10:41 AM, Heitke, Kenneth wrote:
> > 
> > 
> > On 4/28/2019 9:24 PM, Chaitanya Kulkarni wrote:
> > > From: Hannes Reinecke <hare at suse.com>
> > > 
> > > This patch intoduces nvme-ctrl state name array which is used inthe the
> > 
> > s/intoduces /introduces/
> > s/inthe/in the/
> > 
> > > later patch to improve the logging of the ctrl state.
> > > 
> > > Signed-off-by: Hannes Reinecke <hare at suse.com>
> > > Signed-off-by: Chaitanya Kulkarni <chaitanya.kulkarni at wdc.com>
> > > ---
> > >    drivers/nvme/host/nvme.h | 10 ++++++++++
> > >    1 file changed, 10 insertions(+)
> > > 
> > > diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
> > > index 527d64545023..01a36bbafed6 100644
> > > --- a/drivers/nvme/host/nvme.h
> > > +++ b/drivers/nvme/host/nvme.h
> > > @@ -146,6 +146,16 @@ enum nvme_ctrl_state {
> > >    	NVME_CTRL_DEAD,
> > >    };
> > > 
> > > +static const char *const nvme_ctrl_state_name[] = {
> > > +	[NVME_CTRL_NEW]         = "new",
> > > +	[NVME_CTRL_LIVE]        = "live",
> > > +	[NVME_CTRL_ADMIN_ONLY]  = "only-admin",
> > > +	[NVME_CTRL_RESETTING]   = "resetting",
> > > +	[NVME_CTRL_CONNECTING]  = "connecting",
> > > +	[NVME_CTRL_DELETING]    = "deleting",
> > > +	[NVME_CTRL_DEAD]        = "dead",
> > > +};
> > 
> > I haven't been paying attention if this was bought up before but won't
> > this create multiple copies of this data for every source file the
> > includes the header file?
> 
> Yes, we did discuss this.

Hi Chaitanya,

In an e-mail from Christoph I found the following recommendation with regard
to the nvme_ctrl_state_name[] array: "Just keep it near the top of multipath.c."
and you replied "Okay, that works too."

Did I perhaps miss something?

Thanks,

Bart.

[PATCH V2 1/3] nvme: introduce nvme-ctrl state name string array

[Sagi Grimberg]

>>> I haven't been paying attention if this was bought up before but won't
>>> this create multiple copies of this data for every source file the
>>> includes the header file?
>>
>> Yes, we did discuss this.
> 
> Hi Chaitanya,
> 
> In an e-mail from Christoph I found the following recommendation with regard
> to the nvme_ctrl_state_name[] array: "Just keep it near the top of multipath.c."
> and you replied "Okay, that works too."
> 
> Did I perhaps miss something?

That was my recollection too...

[PATCH V2 1/3] nvme: introduce nvme-ctrl state name string array

[Chaitanya Kulkarni]

Seems like I missed it. Let me send the V3 along with other comments from Sagi.

?On 4/29/19, 4:29 PM, "Linux-nvme on behalf of Sagi Grimberg" <linux-nvme-bounces@lists.infradead.org on behalf of sagi@grimberg.me> wrote:

    
    >>> I haven't been paying attention if this was bought up before but won't
    >>> this create multiple copies of this data for every source file the
    >>> includes the header file?
    >>
    >> Yes, we did discuss this.
    > 
    > Hi Chaitanya,
    > 
    > In an e-mail from Christoph I found the following recommendation with regard
    > to the nvme_ctrl_state_name[] array: "Just keep it near the top of multipath.c."
    > and you replied "Okay, that works too."
    > 
    > Did I perhaps miss something?
    
    That was my recollection too...
    
    _______________________________________________
    Linux-nvme mailing list
    Linux-nvme at lists.infradead.org
    http://lists.infradead.org/mailman/listinfo/linux-nvme
    

[PATCH V2 3/3] nvme-multipath: improve logging

[Christoph Hellwig]

> +		dev_info(ns->ctrl->device,
> +				"nvme-mp: status 0x%04x, resetting controller\n",
> +				status);

This message still looks a little gibberish to me.

Why not:

	"resetting path due to unhandled error (0x%04x")"

> -	dev_info(ctrl->device, "ANA group %d: %s.\n",
> +	dev_dbg(ctrl->device, "ANA group %d: %s.\n",
>  			le32_to_cpu(desc->grpid),
>  			nvme_ana_state_names[desc->state]);

I've applied this hunk to nvme-5.2, thanks.