[PATCH 1/3] ipmi: Reset response handler when failing to send the command

[PATCH 1/3] ipmi: Reset response handler when failing to send the command

[Markus Boehme]

When failing to send a command we don't expect a response. Clear the
`null_user_handler` like is done in the success path.

Signed-off-by: Markus Boehme <markubo@amazon.com>
---
 drivers/char/ipmi/ipmi_msghandler.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/drivers/char/ipmi/ipmi_msghandler.c b/drivers/char/ipmi/ipmi_msghandler.c
index 737c0b6..2b213c9 100644
--- a/drivers/char/ipmi/ipmi_msghandler.c
+++ b/drivers/char/ipmi/ipmi_msghandler.c
@@ -2433,7 +2433,7 @@ static int __get_device_id(struct ipmi_smi *intf, struct bmc_device *bmc)
 
 	rv = send_get_device_id_cmd(intf);
 	if (rv)
-		return rv;
+		goto out_reset_handler;
 
 	wait_event(intf->waitq, bmc->dyn_id_set != 2);
 
@@ -2443,6 +2443,7 @@ static int __get_device_id(struct ipmi_smi *intf, struct bmc_device *bmc)
 	/* dyn_id_set makes the id data available. */
 	smp_rmb();
 
+out_reset_handler:
 	intf->null_user_handler = NULL;
 
 	return rv;
@@ -3329,6 +3330,7 @@ static int __scan_channels(struct ipmi_smi *intf, struct ipmi_device_id *id)
 			dev_warn(intf->si_dev,
 				 "Error sending channel information for channel 0, %d\n",
 				 rv);
+			intf->null_user_handler = NULL;
 			return -EIO;
 		}
 
-- 
2.7.4

[PATCH 2/3] ipmi: Add timeout waiting for device GUID

[Markus Boehme]

We have observed hosts with misbehaving BMCs that receive a Get Device
GUID command but don't respond. This leads to an indefinite wait in the
ipmi_msghandler's __get_guid function, showing up as hung task messages
for modprobe.

According to IPMI 2.0 specification chapter 20, the implementation of
the Get Device GUID command is optional. Therefore, add a timeout to
waiting for its response and treat the lack of one the same as missing a
device GUID.

Signed-off-by: Stefan Nuernberger <snu@amazon.com>
Signed-off-by: Markus Boehme <markubo@amazon.com>
---
 drivers/char/ipmi/ipmi_msghandler.c | 16 ++++++++++++----
 1 file changed, 12 insertions(+), 4 deletions(-)

diff --git a/drivers/char/ipmi/ipmi_msghandler.c b/drivers/char/ipmi/ipmi_msghandler.c
index 2b213c9..2a2e8b2 100644
--- a/drivers/char/ipmi/ipmi_msghandler.c
+++ b/drivers/char/ipmi/ipmi_msghandler.c
@@ -3184,18 +3184,26 @@ static void guid_handler(struct ipmi_smi *intf, struct ipmi_recv_msg *msg)
 
 static void __get_guid(struct ipmi_smi *intf)
 {
-	int rv;
+	long rv;
 	struct bmc_device *bmc = intf->bmc;
 
 	bmc->dyn_guid_set = 2;
 	intf->null_user_handler = guid_handler;
 	rv = send_guid_cmd(intf, 0);
-	if (rv)
+	if (rv) {
 		/* Send failed, no GUID available. */
 		bmc->dyn_guid_set = 0;
-	else
-		wait_event(intf->waitq, bmc->dyn_guid_set != 2);
+		goto out;
+	}
 
+	rv = wait_event_timeout(intf->waitq, bmc->dyn_guid_set != 2, 5 * HZ);
+	if (rv == 0) {
+		dev_warn_once(intf->si_dev,
+			      "Timed out waiting for GUID. Assuming GUID is not available.\n");
+		bmc->dyn_guid_set = 0;
+	}
+
+out:
 	/* dyn_guid_set makes the guid data available. */
 	smp_rmb();
 
-- 
2.7.4

Re: [PATCH 2/3] ipmi: Add timeout waiting for device GUID

[Corey Minyard]

On Mon, Sep 07, 2020 at 06:25:36PM +0200, Markus Boehme wrote:
> We have observed hosts with misbehaving BMCs that receive a Get Device
> GUID command but don't respond. This leads to an indefinite wait in the
> ipmi_msghandler's __get_guid function, showing up as hung task messages
> for modprobe.
> 
> According to IPMI 2.0 specification chapter 20, the implementation of
> the Get Device GUID command is optional. Therefore, add a timeout to
> waiting for its response and treat the lack of one the same as missing a
> device GUID.

This patch looks good.  It's a little bit of a rewrite, but the reasons
are obvious.

-corey

> 
> Signed-off-by: Stefan Nuernberger <snu@amazon.com>
> Signed-off-by: Markus Boehme <markubo@amazon.com>
> ---
>  drivers/char/ipmi/ipmi_msghandler.c | 16 ++++++++++++----
>  1 file changed, 12 insertions(+), 4 deletions(-)
> 
> diff --git a/drivers/char/ipmi/ipmi_msghandler.c b/drivers/char/ipmi/ipmi_msghandler.c
> index 2b213c9..2a2e8b2 100644
> --- a/drivers/char/ipmi/ipmi_msghandler.c
> +++ b/drivers/char/ipmi/ipmi_msghandler.c
> @@ -3184,18 +3184,26 @@ static void guid_handler(struct ipmi_smi *intf, struct ipmi_recv_msg *msg)
>  
>  static void __get_guid(struct ipmi_smi *intf)
>  {
> -	int rv;
> +	long rv;
>  	struct bmc_device *bmc = intf->bmc;
>  
>  	bmc->dyn_guid_set = 2;
>  	intf->null_user_handler = guid_handler;
>  	rv = send_guid_cmd(intf, 0);
> -	if (rv)
> +	if (rv) {
>  		/* Send failed, no GUID available. */
>  		bmc->dyn_guid_set = 0;
> -	else
> -		wait_event(intf->waitq, bmc->dyn_guid_set != 2);
> +		goto out;
> +	}
>  
> +	rv = wait_event_timeout(intf->waitq, bmc->dyn_guid_set != 2, 5 * HZ);
> +	if (rv == 0) {
> +		dev_warn_once(intf->si_dev,
> +			      "Timed out waiting for GUID. Assuming GUID is not available.\n");
> +		bmc->dyn_guid_set = 0;
> +	}
> +
> +out:
>  	/* dyn_guid_set makes the guid data available. */
>  	smp_rmb();
>  
> -- 
> 2.7.4
> 

[PATCH 3/3] ipmi: Add timeout waiting for channel information

[Markus Boehme]

We have observed hosts with misbehaving BMCs that receive a Get Channel
Info command but don't respond. This leads to an indefinite wait in the
ipmi_msghandler's __scan_channels function, showing up as hung task
messages for modprobe.

Add a timeout waiting for the channel scan to complete. If the scan
fails to complete within that time, treat that like IPMI 1.0 and only
assume the presence of the primary IPMB channel at channel number 0.

Signed-off-by: Stefan Nuernberger <snu@amazon.com>
Signed-off-by: Markus Boehme <markubo@amazon.com>
---
 drivers/char/ipmi/ipmi_msghandler.c | 72 ++++++++++++++++++++-----------------
 1 file changed, 39 insertions(+), 33 deletions(-)

diff --git a/drivers/char/ipmi/ipmi_msghandler.c b/drivers/char/ipmi/ipmi_msghandler.c
index 2a2e8b2..9de9ba6 100644
--- a/drivers/char/ipmi/ipmi_msghandler.c
+++ b/drivers/char/ipmi/ipmi_msghandler.c
@@ -3315,46 +3315,52 @@ channel_handler(struct ipmi_smi *intf, struct ipmi_recv_msg *msg)
  */
 static int __scan_channels(struct ipmi_smi *intf, struct ipmi_device_id *id)
 {
-	int rv;
+	long rv;
+	unsigned int set;
 
-	if (ipmi_version_major(id) > 1
-			|| (ipmi_version_major(id) == 1
-			    && ipmi_version_minor(id) >= 5)) {
-		unsigned int set;
+	if (ipmi_version_major(id) == 1 && ipmi_version_minor(id) < 5) {
+		set = intf->curr_working_cset;
+		goto single_ipmb_channel;
+	}
 
-		/*
-		 * Start scanning the channels to see what is
-		 * available.
-		 */
-		set = !intf->curr_working_cset;
-		intf->curr_working_cset = set;
-		memset(&intf->wchannels[set], 0,
-		       sizeof(struct ipmi_channel_set));
-
-		intf->null_user_handler = channel_handler;
-		intf->curr_channel = 0;
-		rv = send_channel_info_cmd(intf, 0);
-		if (rv) {
-			dev_warn(intf->si_dev,
-				 "Error sending channel information for channel 0, %d\n",
-				 rv);
-			intf->null_user_handler = NULL;
-			return -EIO;
-		}
+	/*
+	 * Start scanning the channels to see what is
+	 * available.
+	 */
+	set = !intf->curr_working_cset;
+	intf->curr_working_cset = set;
+	memset(&intf->wchannels[set], 0, sizeof(struct ipmi_channel_set));
 
-		/* Wait for the channel info to be read. */
-		wait_event(intf->waitq, intf->channels_ready);
+	intf->null_user_handler = channel_handler;
+	intf->curr_channel = 0;
+	rv = send_channel_info_cmd(intf, 0);
+	if (rv) {
+		dev_warn(intf->si_dev,
+			 "Error sending channel information for channel 0, %ld\n",
+			 rv);
 		intf->null_user_handler = NULL;
-	} else {
-		unsigned int set = intf->curr_working_cset;
+		return -EIO;
+	}
 
-		/* Assume a single IPMB channel at zero. */
-		intf->wchannels[set].c[0].medium = IPMI_CHANNEL_MEDIUM_IPMB;
-		intf->wchannels[set].c[0].protocol = IPMI_CHANNEL_PROTOCOL_IPMB;
-		intf->channel_list = intf->wchannels + set;
-		intf->channels_ready = true;
+	/* Wait for the channel info to be read. */
+	rv = wait_event_timeout(intf->waitq, intf->channels_ready, 5 * HZ);
+	if (rv == 0) {
+		dev_warn(intf->si_dev,
+			 "Timed out waiting for channel information. Assuming a single IPMB channel at 0.\n");
+		goto single_ipmb_channel;
 	}
 
+	goto out;
+
+single_ipmb_channel:
+	/* Assume a single IPMB channel at zero. */
+	intf->wchannels[set].c[0].medium = IPMI_CHANNEL_MEDIUM_IPMB;
+	intf->wchannels[set].c[0].protocol = IPMI_CHANNEL_PROTOCOL_IPMB;
+	intf->channel_list = intf->wchannels + set;
+	intf->channels_ready = true;
+
+out:
+	intf->null_user_handler = NULL;
 	return 0;
 }
 
-- 
2.7.4

Re: [PATCH 3/3] ipmi: Add timeout waiting for channel information

[Corey Minyard]

On Mon, Sep 07, 2020 at 06:25:37PM +0200, Markus Boehme wrote:
> We have observed hosts with misbehaving BMCs that receive a Get Channel
> Info command but don't respond. This leads to an indefinite wait in the
> ipmi_msghandler's __scan_channels function, showing up as hung task
> messages for modprobe.
> 
> Add a timeout waiting for the channel scan to complete. If the scan
> fails to complete within that time, treat that like IPMI 1.0 and only
> assume the presence of the primary IPMB channel at channel number 0.

This patch is a significant rewrite of the function.  This makes me a
little uncomfortable.  It's generally better to fix the bug in a minimal
patch.  It would be easier to read if you had two patches, one to
restructure the code and one to fix the bug.

One comment inline, but it doesn't matter, because...

While thinking about this, I realized an issue with these patches.
There should be timers in the lower layers that detect that the BMC does
not respond and should return an error response.  This is supposed to be
guaranteed by the lower layer, you shouldn't need timers here.  In fact,
if you abort with a timer here, you should get a lower layer reponds
later, causing other issues.

So, this is wrong.  If you are never getting a response, there is a bug
in the lower layer.  If you are not getting the error response as
quickly as you would like, I'm not sure what to do about that.

The first patch, of course, is an obvious bug fix.  I'll include that.

-corey

> 
> Signed-off-by: Stefan Nuernberger <snu@amazon.com>
> Signed-off-by: Markus Boehme <markubo@amazon.com>
> ---
>  drivers/char/ipmi/ipmi_msghandler.c | 72 ++++++++++++++++++++-----------------
>  1 file changed, 39 insertions(+), 33 deletions(-)
> 
> diff --git a/drivers/char/ipmi/ipmi_msghandler.c b/drivers/char/ipmi/ipmi_msghandler.c
> index 2a2e8b2..9de9ba6 100644
> --- a/drivers/char/ipmi/ipmi_msghandler.c
> +++ b/drivers/char/ipmi/ipmi_msghandler.c
> @@ -3315,46 +3315,52 @@ channel_handler(struct ipmi_smi *intf, struct ipmi_recv_msg *msg)
>   */
>  static int __scan_channels(struct ipmi_smi *intf, struct ipmi_device_id *id)
>  {
> -	int rv;
> +	long rv;
> +	unsigned int set;
>  
> -	if (ipmi_version_major(id) > 1
> -			|| (ipmi_version_major(id) == 1
> -			    && ipmi_version_minor(id) >= 5)) {
> -		unsigned int set;
> +	if (ipmi_version_major(id) == 1 && ipmi_version_minor(id) < 5) {

This is incorrect, it will not correctly handle IPMI 0.x BMCs.  Yes,
they exist.

> +		set = intf->curr_working_cset;
> +		goto single_ipmb_channel;
> +	}
>  
> -		/*
> -		 * Start scanning the channels to see what is
> -		 * available.
> -		 */
> -		set = !intf->curr_working_cset;
> -		intf->curr_working_cset = set;
> -		memset(&intf->wchannels[set], 0,
> -		       sizeof(struct ipmi_channel_set));
> -
> -		intf->null_user_handler = channel_handler;
> -		intf->curr_channel = 0;
> -		rv = send_channel_info_cmd(intf, 0);
> -		if (rv) {
> -			dev_warn(intf->si_dev,
> -				 "Error sending channel information for channel 0, %d\n",
> -				 rv);
> -			intf->null_user_handler = NULL;
> -			return -EIO;
> -		}
> +	/*
> +	 * Start scanning the channels to see what is
> +	 * available.
> +	 */
> +	set = !intf->curr_working_cset;
> +	intf->curr_working_cset = set;
> +	memset(&intf->wchannels[set], 0, sizeof(struct ipmi_channel_set));
>  
> -		/* Wait for the channel info to be read. */
> -		wait_event(intf->waitq, intf->channels_ready);
> +	intf->null_user_handler = channel_handler;
> +	intf->curr_channel = 0;
> +	rv = send_channel_info_cmd(intf, 0);
> +	if (rv) {
> +		dev_warn(intf->si_dev,
> +			 "Error sending channel information for channel 0, %ld\n",
> +			 rv);
>  		intf->null_user_handler = NULL;
> -	} else {
> -		unsigned int set = intf->curr_working_cset;
> +		return -EIO;
> +	}
>  
> -		/* Assume a single IPMB channel at zero. */
> -		intf->wchannels[set].c[0].medium = IPMI_CHANNEL_MEDIUM_IPMB;
> -		intf->wchannels[set].c[0].protocol = IPMI_CHANNEL_PROTOCOL_IPMB;
> -		intf->channel_list = intf->wchannels + set;
> -		intf->channels_ready = true;
> +	/* Wait for the channel info to be read. */
> +	rv = wait_event_timeout(intf->waitq, intf->channels_ready, 5 * HZ);
> +	if (rv == 0) {
> +		dev_warn(intf->si_dev,
> +			 "Timed out waiting for channel information. Assuming a single IPMB channel at 0.\n");
> +		goto single_ipmb_channel;
>  	}
>  
> +	goto out;
> +
> +single_ipmb_channel:
> +	/* Assume a single IPMB channel at zero. */
> +	intf->wchannels[set].c[0].medium = IPMI_CHANNEL_MEDIUM_IPMB;
> +	intf->wchannels[set].c[0].protocol = IPMI_CHANNEL_PROTOCOL_IPMB;
> +	intf->channel_list = intf->wchannels + set;
> +	intf->channels_ready = true;
> +
> +out:
> +	intf->null_user_handler = NULL;
>  	return 0;
>  }
>  
> -- 
> 2.7.4
> 

Re: [PATCH 3/3] ipmi: Add timeout waiting for channel information

[Boehme, Markus]

Hey Corey, thanks for taking a look!

On Mon, 2020-09-07 at 19:34 -0500, Corey Minyard wrote:
> On Mon, Sep 07, 2020 at 06:25:37PM +0200, Markus Boehme wrote:
> > 
> > We have observed hosts with misbehaving BMCs that receive a Get Channel
> > Info command but don't respond. This leads to an indefinite wait in the
> > ipmi_msghandler's __scan_channels function, showing up as hung task
> > messages for modprobe.
> > 
> > Add a timeout waiting for the channel scan to complete. If the scan
> > fails to complete within that time, treat that like IPMI 1.0 and only
> > assume the presence of the primary IPMB channel at channel number 0.
> [...]
> While thinking about this, I realized an issue with these patches.
> There should be timers in the lower layers that detect that the BMC does
> not respond and should return an error response.  This is supposed to be
> guaranteed by the lower layer, you shouldn't need timers here.  In fact,
> if you abort with a timer here, you should get a lower layer reponds
> later, causing other issues.
> 
> So, this is wrong.  If you are never getting a response, there is a bug
> in the lower layer.  If you are not getting the error response as
> quickly as you would like, I'm not sure what to do about that.
> 

I see. I might not be able to get hold of more hosts behaving this way,
but if I do, I'll dig deeper into why the lower layer timeouts didn't
save us here. Thanks for the pointer.



> > Signed-off-by: Stefan Nuernberger <snu@amazon.com>
> > Signed-off-by: Markus Boehme <markubo@amazon.com>
> > ---
> >  drivers/char/ipmi/ipmi_msghandler.c | 72 ++++++++++++++++++++-----------------
> >  1 file changed, 39 insertions(+), 33 deletions(-)
> > 
> > diff --git a/drivers/char/ipmi/ipmi_msghandler.c b/drivers/char/ipmi/ipmi_msghandler.c
> > index 2a2e8b2..9de9ba6 100644
> > --- a/drivers/char/ipmi/ipmi_msghandler.c
> > +++ b/drivers/char/ipmi/ipmi_msghandler.c
> > @@ -3315,46 +3315,52 @@ channel_handler(struct ipmi_smi *intf, struct ipmi_recv_msg *msg)
> >   */
> >  static int __scan_channels(struct ipmi_smi *intf, struct ipmi_device_id *id)
> >  {
> > -     int rv;
> > +     long rv;
> > +     unsigned int set;
> > 
> > -     if (ipmi_version_major(id) > 1
> > -                     || (ipmi_version_major(id) == 1
> > -                         && ipmi_version_minor(id) >= 5)) {
> > -             unsigned int set;
> > +     if (ipmi_version_major(id) == 1 && ipmi_version_minor(id) < 5) {
> This is incorrect, it will not correctly handle IPMI 0.x BMCs.  Yes,
> they exist.

Interesting! I wasn't aware of those. Searching the web doesn't turn up
much and the spec doesn't mention them either. Are these pre-release
implementations of the IPMI 1.0 spec or some kind of "IPMI light"?

Markus



Amazon Development Center Germany GmbH
Krausenstr. 38
10117 Berlin
Geschaeftsfuehrung: Christian Schlaeger, Jonathan Weiss
Eingetragen am Amtsgericht Charlottenburg unter HRB 149173 B
Sitz: Berlin
Ust-ID: DE 289 237 879

Re: [Openipmi-developer] [PATCH 3/3] ipmi: Add timeout waiting for channel information

[Corey Minyard]

On Thu, Sep 10, 2020 at 11:08:40AM +0000, Boehme, Markus via Openipmi-developer wrote:
> > > -                         && ipmi_version_minor(id) >= 5)) {
> > > -             unsigned int set;
> > > +     if (ipmi_version_major(id) == 1 && ipmi_version_minor(id) < 5) {
> > This is incorrect, it will not correctly handle IPMI 0.x BMCs.  Yes,
> > they exist.
> 
> Interesting! I wasn't aware of those. Searching the web doesn't turn up
> much and the spec doesn't mention them either. Are these pre-release
> implementations of the IPMI 1.0 spec or some kind of "IPMI light"?

There was an 0.9 version of the spec that some machines implemented.
It's not really a "light" version, it's just a really early version.  I
don't know how many machine out there still implement it, but I try to
keep them working if I can.

Thanks,

-corey

> 
> Markus

Re: [PATCH 1/3] ipmi: Reset response handler when failing to send the command

[Corey Minyard]

On Mon, Sep 07, 2020 at 06:25:35PM +0200, Markus Boehme wrote:
> When failing to send a command we don't expect a response. Clear the
> `null_user_handler` like is done in the success path.

This is correct.  I guess, from the next two patches, I know how you
found this.

I can incude this, but I will ask some questions in the later patches.

-corey

> 
> Signed-off-by: Markus Boehme <markubo@amazon.com>
> ---
>  drivers/char/ipmi/ipmi_msghandler.c | 4 +++-
>  1 file changed, 3 insertions(+), 1 deletion(-)
> 
> diff --git a/drivers/char/ipmi/ipmi_msghandler.c b/drivers/char/ipmi/ipmi_msghandler.c
> index 737c0b6..2b213c9 100644
> --- a/drivers/char/ipmi/ipmi_msghandler.c
> +++ b/drivers/char/ipmi/ipmi_msghandler.c
> @@ -2433,7 +2433,7 @@ static int __get_device_id(struct ipmi_smi *intf, struct bmc_device *bmc)
>  
>  	rv = send_get_device_id_cmd(intf);
>  	if (rv)
> -		return rv;
> +		goto out_reset_handler;
>  
>  	wait_event(intf->waitq, bmc->dyn_id_set != 2);
>  
> @@ -2443,6 +2443,7 @@ static int __get_device_id(struct ipmi_smi *intf, struct bmc_device *bmc)
>  	/* dyn_id_set makes the id data available. */
>  	smp_rmb();
>  
> +out_reset_handler:
>  	intf->null_user_handler = NULL;
>  
>  	return rv;
> @@ -3329,6 +3330,7 @@ static int __scan_channels(struct ipmi_smi *intf, struct ipmi_device_id *id)
>  			dev_warn(intf->si_dev,
>  				 "Error sending channel information for channel 0, %d\n",
>  				 rv);
> +			intf->null_user_handler = NULL;
>  			return -EIO;
>  		}
>  
> -- 
> 2.7.4
>