[PATCH v2 1/2] platform/chrome: cros_ec_ishtp: skip old cros_ec responses

[PATCH v2 1/2] platform/chrome: cros_ec_ishtp: skip old cros_ec responses

[Mathew King]

From: Jett Rink <jettrink@chromium.org>

The ISHTP layer can give us old responses that we already gave up on. We
do not want to interpret these old responses as the current response we
are waiting for.

The cros_ish should only have one request in flight at a time. We send
the request and wait for the response from the ISH. If the ISH is too
slow to respond we give up on that request and we can send a new
request. The ISH may still send the response to the request that timed
out and without this we treat the old response as the response to the
current command. This is a condition that should not normally happen but
it has been observed with a bad ISH image. So add a token to the request
header which is copied into the response header when the ISH processes
the message to ensure that response is for the current request.

Signed-off-by: Jett Rink <jettrink@chromium.org>
Signed-off-by: Mathew King <mathewk@chromium.org>
---
v2: - Change from using id to token
    - Reword the commit message
---
 drivers/platform/chrome/cros_ec_ishtp.c | 32 ++++++++++++++++++-------
 1 file changed, 23 insertions(+), 9 deletions(-)

diff --git a/drivers/platform/chrome/cros_ec_ishtp.c b/drivers/platform/chrome/cros_ec_ishtp.c
index 93a71e93a2f1..e673a7f738fc 100644
--- a/drivers/platform/chrome/cros_ec_ishtp.c
+++ b/drivers/platform/chrome/cros_ec_ishtp.c
@@ -48,7 +48,8 @@ static const guid_t cros_ish_guid =
 struct header {
 	u8 channel;
 	u8 status;
-	u8 reserved[2];
+	u8 token;
+	u8 reserved;
 } __packed;
 
 struct cros_ish_out_msg {
@@ -90,6 +91,7 @@ static DECLARE_RWSEM(init_lock);
  * data exceeds this value, we log an error.
  * @size: Actual size of data received from firmware.
  * @error: 0 for success, negative error code for a failure in process_recv().
+ * @token: Expected token for response that we are waiting on.
  * @received: Set to true on receiving a valid firmware	response to host command
  * @wait_queue: Wait queue for host to wait for firmware response.
  */
@@ -98,6 +100,7 @@ struct response_info {
 	size_t max_size;
 	size_t size;
 	int error;
+	u8 token;
 	bool received;
 	wait_queue_head_t wait_queue;
 };
@@ -162,6 +165,7 @@ static int ish_send(struct ishtp_cl_data *client_data,
 		    u8 *out_msg, size_t out_size,
 		    u8 *in_msg, size_t in_size)
 {
+	static u8 next_token;
 	int rv;
 	struct header *out_hdr = (struct header *)out_msg;
 	struct ishtp_cl *cros_ish_cl = client_data->cros_ish_cl;
@@ -174,8 +178,11 @@ static int ish_send(struct ishtp_cl_data *client_data,
 	client_data->response.data = in_msg;
 	client_data->response.max_size = in_size;
 	client_data->response.error = 0;
+	client_data->response.token = next_token++;
 	client_data->response.received = false;
 
+	out_hdr->token = client_data->response.token;
+
 	rv = ishtp_cl_send(cros_ish_cl, out_msg, out_size);
 	if (rv) {
 		dev_err(cl_data_to_dev(client_data),
@@ -249,17 +256,23 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
 
 	switch (in_msg->hdr.channel) {
 	case CROS_EC_COMMAND:
-		/* Sanity check */
-		if (!client_data->response.data) {
+		if (client_data->response.received) {
 			dev_err(dev,
-				"Receiving buffer is null. Should be allocated by calling function\n");
-			client_data->response.error = -EINVAL;
-			goto error_wake_up;
+				"Previous firmware message not yet processed\n");
+			goto end_error;
 		}
 
-		if (client_data->response.received) {
+		if (client_data->response.token != in_msg->hdr.token) {
+			dev_err_ratelimited(dev,
+					    "Dropping old response token %d\n",
+					    in_msg->hdr.token);
+			goto end_error;
+		}
+
+		/* Sanity check */
+		if (!client_data->response.data) {
 			dev_err(dev,
-				"Previous firmware message not yet processed\n");
+				"Receiving buffer is null. Should be allocated by calling function\n");
 			client_data->response.error = -EINVAL;
 			goto error_wake_up;
 		}
@@ -289,9 +302,10 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
 		memcpy(client_data->response.data,
 		       rb_in_proc->buffer.data, data_len);
 
+error_wake_up:
 		/* Set flag before waking up the caller */
 		client_data->response.received = true;
-error_wake_up:
+
 		/* Wake the calling thread */
 		wake_up_interruptible(&client_data->response.wait_queue);
 
-- 
2.26.0.110.g2183baf09c-goog

[PATCH v2 2/2] platform/chrome: cros_ec_ishtp: free ishtp buffer before sending event

[Mathew King]

From: Jett Rink <jettrink@chromium.org>

Recycle the ISH buffer before notifying of a response or an event. Often
a new message is sent in response to an event and in high traffic
scenarios this can lead to exhausting all available buffers. We can
ensure we are using the fewest buffers possible by freeing buffers as
soon as they are used.

Signed-off-by: Jett Rink <jettrink@chromium.org>
Signed-off-by: Mathew King <mathewk@chromium.org>
---
v2: Reword the commit message
---
 drivers/platform/chrome/cros_ec_ishtp.c | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)

diff --git a/drivers/platform/chrome/cros_ec_ishtp.c b/drivers/platform/chrome/cros_ec_ishtp.c
index e673a7f738fc..ed794a7ddba9 100644
--- a/drivers/platform/chrome/cros_ec_ishtp.c
+++ b/drivers/platform/chrome/cros_ec_ishtp.c
@@ -303,6 +303,10 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
 		       rb_in_proc->buffer.data, data_len);
 
 error_wake_up:
+		/* Free the buffer since we copied data or didn't need it */
+		ishtp_cl_io_rb_recycle(rb_in_proc);
+		rb_in_proc = NULL;
+
 		/* Set flag before waking up the caller */
 		client_data->response.received = true;
 
@@ -312,12 +316,14 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
 		break;
 
 	case CROS_MKBP_EVENT:
+		/* Free the buffer. This is just an event without data */
+		ishtp_cl_io_rb_recycle(rb_in_proc);
+		rb_in_proc = NULL;
 		/*
 		 * Set timestamp from beginning of function since we actually
 		 * got an incoming MKBP event
 		 */
 		client_data->ec_dev->last_event_time = timestamp;
-		/* The event system doesn't send any data in buffer */
 		schedule_work(&client_data->work_ec_evt);
 
 		break;
@@ -327,8 +333,9 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
 	}
 
 end_error:
-	/* Free the buffer */
-	ishtp_cl_io_rb_recycle(rb_in_proc);
+	/* Free the buffer if we already haven't */
+	if (rb_in_proc)
+		ishtp_cl_io_rb_recycle(rb_in_proc);
 
 	up_read(&init_lock);
 }
-- 
2.26.0.110.g2183baf09c-goog

Re: [PATCH v2 1/2] platform/chrome: cros_ec_ishtp: skip old cros_ec responses

[Enric Balletbo i Serra]

Hi Jett and Mathew,

Thank you for the patch

On 10/4/20 18:23, Mathew King wrote:
> From: Jett Rink <jettrink@chromium.org>
> 
> The ISHTP layer can give us old responses that we already gave up on. We
> do not want to interpret these old responses as the current response we
> are waiting for.
> 
> The cros_ish should only have one request in flight at a time. We send
> the request and wait for the response from the ISH. If the ISH is too
> slow to respond we give up on that request and we can send a new
> request. The ISH may still send the response to the request that timed
> out and without this we treat the old response as the response to the
> current command. This is a condition that should not normally happen but
> it has been observed with a bad ISH image. So add a token to the request
> header which is copied into the response header when the ISH processes
> the message to ensure that response is for the current request.
> 
> Signed-off-by: Jett Rink <jettrink@chromium.org>
> Signed-off-by: Mathew King <mathewk@chromium.org>

Queued for 5.8

> ---
> v2: - Change from using id to token
>     - Reword the commit message
> ---
>  drivers/platform/chrome/cros_ec_ishtp.c | 32 ++++++++++++++++++-------
>  1 file changed, 23 insertions(+), 9 deletions(-)
> 
> diff --git a/drivers/platform/chrome/cros_ec_ishtp.c b/drivers/platform/chrome/cros_ec_ishtp.c
> index 93a71e93a2f1..e673a7f738fc 100644
> --- a/drivers/platform/chrome/cros_ec_ishtp.c
> +++ b/drivers/platform/chrome/cros_ec_ishtp.c
> @@ -48,7 +48,8 @@ static const guid_t cros_ish_guid =
>  struct header {
>  	u8 channel;
>  	u8 status;
> -	u8 reserved[2];
> +	u8 token;
> +	u8 reserved;
>  } __packed;
>  
>  struct cros_ish_out_msg {
> @@ -90,6 +91,7 @@ static DECLARE_RWSEM(init_lock);
>   * data exceeds this value, we log an error.
>   * @size: Actual size of data received from firmware.
>   * @error: 0 for success, negative error code for a failure in process_recv().
> + * @token: Expected token for response that we are waiting on.
>   * @received: Set to true on receiving a valid firmware	response to host command
>   * @wait_queue: Wait queue for host to wait for firmware response.
>   */
> @@ -98,6 +100,7 @@ struct response_info {
>  	size_t max_size;
>  	size_t size;
>  	int error;
> +	u8 token;
>  	bool received;
>  	wait_queue_head_t wait_queue;
>  };
> @@ -162,6 +165,7 @@ static int ish_send(struct ishtp_cl_data *client_data,
>  		    u8 *out_msg, size_t out_size,
>  		    u8 *in_msg, size_t in_size)
>  {
> +	static u8 next_token;
>  	int rv;
>  	struct header *out_hdr = (struct header *)out_msg;
>  	struct ishtp_cl *cros_ish_cl = client_data->cros_ish_cl;
> @@ -174,8 +178,11 @@ static int ish_send(struct ishtp_cl_data *client_data,
>  	client_data->response.data = in_msg;
>  	client_data->response.max_size = in_size;
>  	client_data->response.error = 0;
> +	client_data->response.token = next_token++;
>  	client_data->response.received = false;
>  
> +	out_hdr->token = client_data->response.token;
> +
>  	rv = ishtp_cl_send(cros_ish_cl, out_msg, out_size);
>  	if (rv) {
>  		dev_err(cl_data_to_dev(client_data),
> @@ -249,17 +256,23 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
>  
>  	switch (in_msg->hdr.channel) {
>  	case CROS_EC_COMMAND:
> -		/* Sanity check */
> -		if (!client_data->response.data) {
> +		if (client_data->response.received) {
>  			dev_err(dev,
> -				"Receiving buffer is null. Should be allocated by calling function\n");
> -			client_data->response.error = -EINVAL;
> -			goto error_wake_up;
> +				"Previous firmware message not yet processed\n");
> +			goto end_error;
>  		}
>  
> -		if (client_data->response.received) {
> +		if (client_data->response.token != in_msg->hdr.token) {
> +			dev_err_ratelimited(dev,
> +					    "Dropping old response token %d\n",
> +					    in_msg->hdr.token);
> +			goto end_error;
> +		}
> +
> +		/* Sanity check */
> +		if (!client_data->response.data) {
>  			dev_err(dev,
> -				"Previous firmware message not yet processed\n");
> +				"Receiving buffer is null. Should be allocated by calling function\n");
>  			client_data->response.error = -EINVAL;
>  			goto error_wake_up;
>  		}
> @@ -289,9 +302,10 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
>  		memcpy(client_data->response.data,
>  		       rb_in_proc->buffer.data, data_len);
>  
> +error_wake_up:
>  		/* Set flag before waking up the caller */
>  		client_data->response.received = true;
> -error_wake_up:
> +
>  		/* Wake the calling thread */
>  		wake_up_interruptible(&client_data->response.wait_queue);
>  
> 

Re: [PATCH v2 2/2] platform/chrome: cros_ec_ishtp: free ishtp buffer before sending event

[Enric Balletbo i Serra]

Hi Jett and Mathew,

Thank you for the patch.

On 10/4/20 18:23, Mathew King wrote:
> From: Jett Rink <jettrink@chromium.org>
> 
> Recycle the ISH buffer before notifying of a response or an event. Often
> a new message is sent in response to an event and in high traffic
> scenarios this can lead to exhausting all available buffers. We can
> ensure we are using the fewest buffers possible by freeing buffers as
> soon as they are used.
> 
> Signed-off-by: Jett Rink <jettrink@chromium.org>
> Signed-off-by: Mathew King <mathewk@chromium.org>

Queued for 5.8

> ---
> v2: Reword the commit message
> ---
>  drivers/platform/chrome/cros_ec_ishtp.c | 13 ++++++++++---
>  1 file changed, 10 insertions(+), 3 deletions(-)
> 
> diff --git a/drivers/platform/chrome/cros_ec_ishtp.c b/drivers/platform/chrome/cros_ec_ishtp.c
> index e673a7f738fc..ed794a7ddba9 100644
> --- a/drivers/platform/chrome/cros_ec_ishtp.c
> +++ b/drivers/platform/chrome/cros_ec_ishtp.c
> @@ -303,6 +303,10 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
>  		       rb_in_proc->buffer.data, data_len);
>  
>  error_wake_up:
> +		/* Free the buffer since we copied data or didn't need it */
> +		ishtp_cl_io_rb_recycle(rb_in_proc);
> +		rb_in_proc = NULL;
> +
>  		/* Set flag before waking up the caller */
>  		client_data->response.received = true;
>  
> @@ -312,12 +316,14 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
>  		break;
>  
>  	case CROS_MKBP_EVENT:
> +		/* Free the buffer. This is just an event without data */
> +		ishtp_cl_io_rb_recycle(rb_in_proc);
> +		rb_in_proc = NULL;
>  		/*
>  		 * Set timestamp from beginning of function since we actually
>  		 * got an incoming MKBP event
>  		 */
>  		client_data->ec_dev->last_event_time = timestamp;
> -		/* The event system doesn't send any data in buffer */
>  		schedule_work(&client_data->work_ec_evt);
>  
>  		break;
> @@ -327,8 +333,9 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
>  	}
>  
>  end_error:
> -	/* Free the buffer */
> -	ishtp_cl_io_rb_recycle(rb_in_proc);
> +	/* Free the buffer if we already haven't */
> +	if (rb_in_proc)
> +		ishtp_cl_io_rb_recycle(rb_in_proc);
>  
>  	up_read(&init_lock);
>  }
> 

Re: [PATCH v2 1/2] platform/chrome: cros_ec_ishtp: skip old cros_ec responses

[Jett Rink]

Thank you!


On Tue, Apr 14, 2020 at 10:24 AM Enric Balletbo i Serra
<enric.balletbo@collabora.com> wrote:
>
> Hi Jett and Mathew,
>
> Thank you for the patch
>
> On 10/4/20 18:23, Mathew King wrote:
> > From: Jett Rink <jettrink@chromium.org>
> >
> > The ISHTP layer can give us old responses that we already gave up on. We
> > do not want to interpret these old responses as the current response we
> > are waiting for.
> >
> > The cros_ish should only have one request in flight at a time. We send
> > the request and wait for the response from the ISH. If the ISH is too
> > slow to respond we give up on that request and we can send a new
> > request. The ISH may still send the response to the request that timed
> > out and without this we treat the old response as the response to the
> > current command. This is a condition that should not normally happen but
> > it has been observed with a bad ISH image. So add a token to the request
> > header which is copied into the response header when the ISH processes
> > the message to ensure that response is for the current request.
> >
> > Signed-off-by: Jett Rink <jettrink@chromium.org>
> > Signed-off-by: Mathew King <mathewk@chromium.org>
>
> Queued for 5.8
>
> > ---
> > v2: - Change from using id to token
> >     - Reword the commit message
> > ---
> >  drivers/platform/chrome/cros_ec_ishtp.c | 32 ++++++++++++++++++-------
> >  1 file changed, 23 insertions(+), 9 deletions(-)
> >
> > diff --git a/drivers/platform/chrome/cros_ec_ishtp.c b/drivers/platform/chrome/cros_ec_ishtp.c
> > index 93a71e93a2f1..e673a7f738fc 100644
> > --- a/drivers/platform/chrome/cros_ec_ishtp.c
> > +++ b/drivers/platform/chrome/cros_ec_ishtp.c
> > @@ -48,7 +48,8 @@ static const guid_t cros_ish_guid =
> >  struct header {
> >       u8 channel;
> >       u8 status;
> > -     u8 reserved[2];
> > +     u8 token;
> > +     u8 reserved;
> >  } __packed;
> >
> >  struct cros_ish_out_msg {
> > @@ -90,6 +91,7 @@ static DECLARE_RWSEM(init_lock);
> >   * data exceeds this value, we log an error.
> >   * @size: Actual size of data received from firmware.
> >   * @error: 0 for success, negative error code for a failure in process_recv().
> > + * @token: Expected token for response that we are waiting on.
> >   * @received: Set to true on receiving a valid firmware      response to host command
> >   * @wait_queue: Wait queue for host to wait for firmware response.
> >   */
> > @@ -98,6 +100,7 @@ struct response_info {
> >       size_t max_size;
> >       size_t size;
> >       int error;
> > +     u8 token;
> >       bool received;
> >       wait_queue_head_t wait_queue;
> >  };
> > @@ -162,6 +165,7 @@ static int ish_send(struct ishtp_cl_data *client_data,
> >                   u8 *out_msg, size_t out_size,
> >                   u8 *in_msg, size_t in_size)
> >  {
> > +     static u8 next_token;
> >       int rv;
> >       struct header *out_hdr = (struct header *)out_msg;
> >       struct ishtp_cl *cros_ish_cl = client_data->cros_ish_cl;
> > @@ -174,8 +178,11 @@ static int ish_send(struct ishtp_cl_data *client_data,
> >       client_data->response.data = in_msg;
> >       client_data->response.max_size = in_size;
> >       client_data->response.error = 0;
> > +     client_data->response.token = next_token++;
> >       client_data->response.received = false;
> >
> > +     out_hdr->token = client_data->response.token;
> > +
> >       rv = ishtp_cl_send(cros_ish_cl, out_msg, out_size);
> >       if (rv) {
> >               dev_err(cl_data_to_dev(client_data),
> > @@ -249,17 +256,23 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
> >
> >       switch (in_msg->hdr.channel) {
> >       case CROS_EC_COMMAND:
> > -             /* Sanity check */
> > -             if (!client_data->response.data) {
> > +             if (client_data->response.received) {
> >                       dev_err(dev,
> > -                             "Receiving buffer is null. Should be allocated by calling function\n");
> > -                     client_data->response.error = -EINVAL;
> > -                     goto error_wake_up;
> > +                             "Previous firmware message not yet processed\n");
> > +                     goto end_error;
> >               }
> >
> > -             if (client_data->response.received) {
> > +             if (client_data->response.token != in_msg->hdr.token) {
> > +                     dev_err_ratelimited(dev,
> > +                                         "Dropping old response token %d\n",
> > +                                         in_msg->hdr.token);
> > +                     goto end_error;
> > +             }
> > +
> > +             /* Sanity check */
> > +             if (!client_data->response.data) {
> >                       dev_err(dev,
> > -                             "Previous firmware message not yet processed\n");
> > +                             "Receiving buffer is null. Should be allocated by calling function\n");
> >                       client_data->response.error = -EINVAL;
> >                       goto error_wake_up;
> >               }
> > @@ -289,9 +302,10 @@ static void process_recv(struct ishtp_cl *cros_ish_cl,
> >               memcpy(client_data->response.data,
> >                      rb_in_proc->buffer.data, data_len);
> >
> > +error_wake_up:
> >               /* Set flag before waking up the caller */
> >               client_data->response.received = true;
> > -error_wake_up:
> > +
> >               /* Wake the calling thread */
> >               wake_up_interruptible(&client_data->response.wait_queue);
> >
> >