ceph-devel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v6 0/3] libceph: fix sparse-read failure bug
@ 2024-01-25  2:39 xiubli
  2024-01-25  2:39 ` [PATCH v6 1/3] libceph: fail the sparse-read if the data length doesn't match xiubli
                   ` (2 more replies)
  0 siblings, 3 replies; 7+ messages in thread
From: xiubli @ 2024-01-25  2:39 UTC (permalink / raw)
  To: ceph-devel; +Cc: idryomov, jlayton, vshankar, mchangir, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

V6:
- minor fix from Jeff's comments.

V5:
- remove sr_total_resid and reuse total_resid instead.

V4:
- remove the sr_resid_elen field
- improved the 'read_partial_sparse_msg_data()'

V3:
- rename read_sparse_msg_XX to read_partial_sparse_msg_XX
- fix the sparse-read bug in the messager v1 code.

V2:
- fix the sparse-read bug in the sparse-read code instead


Xiubo Li (3):
  libceph: fail the sparse-read if the data length doesn't match
  libceph: rename read_sparse_msg_XX to read_partial_sparse_msg_XX
  libceph: just wait for more data to be available on the socket

 include/linux/ceph/messenger.h |  2 +-
 net/ceph/messenger_v1.c        | 33 +++++++++++++++++----------------
 net/ceph/messenger_v2.c        |  4 ++--
 net/ceph/osd_client.c          | 20 ++++++++++++--------
 4 files changed, 32 insertions(+), 27 deletions(-)

-- 
2.43.0


^ permalink raw reply	[flat|nested] 7+ messages in thread

* [PATCH v6 1/3] libceph: fail the sparse-read if the data length doesn't match
  2024-01-25  2:39 [PATCH v6 0/3] libceph: fix sparse-read failure bug xiubli
@ 2024-01-25  2:39 ` xiubli
  2024-01-25  2:39 ` [PATCH v6 2/3] libceph: rename read_sparse_msg_XX to read_partial_sparse_msg_XX xiubli
  2024-01-25  2:39 ` [PATCH v6 3/3] libceph: just wait for more data to be available on the socket xiubli
  2 siblings, 0 replies; 7+ messages in thread
From: xiubli @ 2024-01-25  2:39 UTC (permalink / raw)
  To: ceph-devel; +Cc: idryomov, jlayton, vshankar, mchangir, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

Once this happens that means there have bugs.

URL: https://tracker.ceph.com/issues/63586
Signed-off-by: Xiubo Li <xiubli@redhat.com>
Reviewed-by: Jeff Layton <jlayton@kernel.org>
---
 net/ceph/osd_client.c | 11 +++++++++--
 1 file changed, 9 insertions(+), 2 deletions(-)

diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
index 9be80d01c1dc..837b69541376 100644
--- a/net/ceph/osd_client.c
+++ b/net/ceph/osd_client.c
@@ -5857,8 +5857,8 @@ static int osd_sparse_read(struct ceph_connection *con,
 	struct ceph_osd *o = con->private;
 	struct ceph_sparse_read *sr = &o->o_sparse_read;
 	u32 count = sr->sr_count;
-	u64 eoff, elen;
-	int ret;
+	u64 eoff, elen, len = 0;
+	int i, ret;
 
 	switch (sr->sr_state) {
 	case CEPH_SPARSE_READ_HDR:
@@ -5909,6 +5909,13 @@ static int osd_sparse_read(struct ceph_connection *con,
 		/* Convert sr_datalen to host-endian */
 		sr->sr_datalen = le32_to_cpu((__force __le32)sr->sr_datalen);
 		sr->sr_state = CEPH_SPARSE_READ_DATA;
+		for (i = 0; i < count; i++)
+			len += sr->sr_extent[i].len;
+		if (sr->sr_datalen != len) {
+			pr_warn_ratelimited("data len %u != extent len %llu\n",
+					    sr->sr_datalen, len);
+			return -EREMOTEIO;
+		}
 		fallthrough;
 	case CEPH_SPARSE_READ_DATA:
 		if (sr->sr_index >= count) {
-- 
2.43.0


^ permalink raw reply related	[flat|nested] 7+ messages in thread

* [PATCH v6 2/3] libceph: rename read_sparse_msg_XX to read_partial_sparse_msg_XX
  2024-01-25  2:39 [PATCH v6 0/3] libceph: fix sparse-read failure bug xiubli
  2024-01-25  2:39 ` [PATCH v6 1/3] libceph: fail the sparse-read if the data length doesn't match xiubli
@ 2024-01-25  2:39 ` xiubli
  2024-01-25  2:39 ` [PATCH v6 3/3] libceph: just wait for more data to be available on the socket xiubli
  2 siblings, 0 replies; 7+ messages in thread
From: xiubli @ 2024-01-25  2:39 UTC (permalink / raw)
  To: ceph-devel; +Cc: idryomov, jlayton, vshankar, mchangir, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

Actually the read_sparse_msg_XX functions allow to continue reading
and parsing the socket buffer when handling of short receives.

Just rename it with _partial_ prefixed.

URL: https://tracker.ceph.com/issues/63586
Signed-off-by: Xiubo Li <xiubli@redhat.com>
---
 net/ceph/messenger_v1.c | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/net/ceph/messenger_v1.c b/net/ceph/messenger_v1.c
index f9a50d7f0d20..4cb60bacf5f5 100644
--- a/net/ceph/messenger_v1.c
+++ b/net/ceph/messenger_v1.c
@@ -991,7 +991,7 @@ static inline int read_partial_message_section(struct ceph_connection *con,
 	return read_partial_message_chunk(con, section, sec_len, crc);
 }
 
-static int read_sparse_msg_extent(struct ceph_connection *con, u32 *crc)
+static int read_partial_sparse_msg_extent(struct ceph_connection *con, u32 *crc)
 {
 	struct ceph_msg_data_cursor *cursor = &con->in_msg->cursor;
 	bool do_bounce = ceph_test_opt(from_msgr(con->msgr), RXBOUNCE);
@@ -1026,7 +1026,7 @@ static int read_sparse_msg_extent(struct ceph_connection *con, u32 *crc)
 	return 1;
 }
 
-static int read_sparse_msg_data(struct ceph_connection *con)
+static int read_partial_sparse_msg_data(struct ceph_connection *con)
 {
 	struct ceph_msg_data_cursor *cursor = &con->in_msg->cursor;
 	bool do_datacrc = !ceph_test_opt(from_msgr(con->msgr), NOCRC);
@@ -1043,7 +1043,7 @@ static int read_sparse_msg_data(struct ceph_connection *con)
 							 con->v1.in_sr_len,
 							 &crc);
 		else if (cursor->sr_resid > 0)
-			ret = read_sparse_msg_extent(con, &crc);
+			ret = read_partial_sparse_msg_extent(con, &crc);
 
 		if (ret <= 0) {
 			if (do_datacrc)
@@ -1254,7 +1254,7 @@ static int read_partial_message(struct ceph_connection *con)
 			return -EIO;
 
 		if (m->sparse_read)
-			ret = read_sparse_msg_data(con);
+			ret = read_partial_sparse_msg_data(con);
 		else if (ceph_test_opt(from_msgr(con->msgr), RXBOUNCE))
 			ret = read_partial_msg_data_bounce(con);
 		else
-- 
2.43.0


^ permalink raw reply related	[flat|nested] 7+ messages in thread

* [PATCH v6 3/3] libceph: just wait for more data to be available on the socket
  2024-01-25  2:39 [PATCH v6 0/3] libceph: fix sparse-read failure bug xiubli
  2024-01-25  2:39 ` [PATCH v6 1/3] libceph: fail the sparse-read if the data length doesn't match xiubli
  2024-01-25  2:39 ` [PATCH v6 2/3] libceph: rename read_sparse_msg_XX to read_partial_sparse_msg_XX xiubli
@ 2024-01-25  2:39 ` xiubli
  2024-02-27 17:22   ` Luis Henriques
  2 siblings, 1 reply; 7+ messages in thread
From: xiubli @ 2024-01-25  2:39 UTC (permalink / raw)
  To: ceph-devel; +Cc: idryomov, jlayton, vshankar, mchangir, Xiubo Li

From: Xiubo Li <xiubli@redhat.com>

A short read may occur while reading the message footer from the
socket.  Later, when the socket is ready for another read, the
messenger shoudl invoke all read_partial* handlers, except the
read_partial_sparse_msg_data().  The contract between the messenger
and these handlers is that the handlers should bail if the area
of the message is responsible for is already processed.  So,
in this case, it's expected that read_sparse_msg_data() would bail,
allowing the messenger to invoke read_partial() for the footer and
pick up where it left off.

However read_partial_sparse_msg_data() violates that contract and
ends up calling into the state machine in the OSD client. The
sparse-read state machine just assumes that it's a new op and
interprets some piece of the footer as the sparse-read extents/data
and then returns bogus extents/data length, etc.

This will just reuse the 'total_resid' to determine whether should
the read_partial_sparse_msg_data() bail out or not. Because once
it reaches to zero that means all the extents and data have been
successfully received in last read, else it could break out when
partially reading any of the extents and data. And then the
osd_sparse_read() could continue where it left off.

URL: https://tracker.ceph.com/issues/63586
Signed-off-by: Xiubo Li <xiubli@redhat.com>
Reviewed-by: Jeff Layton <jlayton@kernel.org>
---
 include/linux/ceph/messenger.h |  2 +-
 net/ceph/messenger_v1.c        | 25 +++++++++++++------------
 net/ceph/messenger_v2.c        |  4 ++--
 net/ceph/osd_client.c          |  9 +++------
 4 files changed, 19 insertions(+), 21 deletions(-)

diff --git a/include/linux/ceph/messenger.h b/include/linux/ceph/messenger.h
index 2eaaabbe98cb..1717cc57cdac 100644
--- a/include/linux/ceph/messenger.h
+++ b/include/linux/ceph/messenger.h
@@ -283,7 +283,7 @@ struct ceph_msg {
 	struct kref kref;
 	bool more_to_follow;
 	bool needs_out_seq;
-	bool sparse_read;
+	u64 sparse_read_total;
 	int front_alloc_len;
 
 	struct ceph_msgpool *pool;
diff --git a/net/ceph/messenger_v1.c b/net/ceph/messenger_v1.c
index 4cb60bacf5f5..126b2e712247 100644
--- a/net/ceph/messenger_v1.c
+++ b/net/ceph/messenger_v1.c
@@ -160,8 +160,9 @@ static size_t sizeof_footer(struct ceph_connection *con)
 static void prepare_message_data(struct ceph_msg *msg, u32 data_len)
 {
 	/* Initialize data cursor if it's not a sparse read */
-	if (!msg->sparse_read)
-		ceph_msg_data_cursor_init(&msg->cursor, msg, data_len);
+	u64 len = msg->sparse_read_total ? : data_len;
+
+	ceph_msg_data_cursor_init(&msg->cursor, msg, len);
 }
 
 /*
@@ -1036,7 +1037,7 @@ static int read_partial_sparse_msg_data(struct ceph_connection *con)
 	if (do_datacrc)
 		crc = con->in_data_crc;
 
-	do {
+	while (cursor->total_resid) {
 		if (con->v1.in_sr_kvec.iov_base)
 			ret = read_partial_message_chunk(con,
 							 &con->v1.in_sr_kvec,
@@ -1044,23 +1045,23 @@ static int read_partial_sparse_msg_data(struct ceph_connection *con)
 							 &crc);
 		else if (cursor->sr_resid > 0)
 			ret = read_partial_sparse_msg_extent(con, &crc);
-
-		if (ret <= 0) {
-			if (do_datacrc)
-				con->in_data_crc = crc;
-			return ret;
-		}
+		if (ret <= 0)
+			break;
 
 		memset(&con->v1.in_sr_kvec, 0, sizeof(con->v1.in_sr_kvec));
 		ret = con->ops->sparse_read(con, cursor,
 				(char **)&con->v1.in_sr_kvec.iov_base);
+		if (ret <= 0) {
+			ret = ret ? ret : 1; /* must return > 0 to indicate success */
+			break;
+		}
 		con->v1.in_sr_len = ret;
-	} while (ret > 0);
+	}
 
 	if (do_datacrc)
 		con->in_data_crc = crc;
 
-	return ret < 0 ? ret : 1;  /* must return > 0 to indicate success */
+	return ret;
 }
 
 static int read_partial_msg_data(struct ceph_connection *con)
@@ -1253,7 +1254,7 @@ static int read_partial_message(struct ceph_connection *con)
 		if (!m->num_data_items)
 			return -EIO;
 
-		if (m->sparse_read)
+		if (m->sparse_read_total)
 			ret = read_partial_sparse_msg_data(con);
 		else if (ceph_test_opt(from_msgr(con->msgr), RXBOUNCE))
 			ret = read_partial_msg_data_bounce(con);
diff --git a/net/ceph/messenger_v2.c b/net/ceph/messenger_v2.c
index f8ec60e1aba3..a0ca5414b333 100644
--- a/net/ceph/messenger_v2.c
+++ b/net/ceph/messenger_v2.c
@@ -1128,7 +1128,7 @@ static int decrypt_tail(struct ceph_connection *con)
 	struct sg_table enc_sgt = {};
 	struct sg_table sgt = {};
 	struct page **pages = NULL;
-	bool sparse = con->in_msg->sparse_read;
+	bool sparse = !!con->in_msg->sparse_read_total;
 	int dpos = 0;
 	int tail_len;
 	int ret;
@@ -2060,7 +2060,7 @@ static int prepare_read_tail_plain(struct ceph_connection *con)
 	}
 
 	if (data_len(msg)) {
-		if (msg->sparse_read)
+		if (msg->sparse_read_total)
 			con->v2.in_state = IN_S_PREPARE_SPARSE_DATA;
 		else
 			con->v2.in_state = IN_S_PREPARE_READ_DATA;
diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
index 837b69541376..ad2ed334cdbb 100644
--- a/net/ceph/osd_client.c
+++ b/net/ceph/osd_client.c
@@ -5510,7 +5510,7 @@ static struct ceph_msg *get_reply(struct ceph_connection *con,
 	}
 
 	m = ceph_msg_get(req->r_reply);
-	m->sparse_read = (bool)srlen;
+	m->sparse_read_total = srlen;
 
 	dout("get_reply tid %lld %p\n", tid, m);
 
@@ -5777,11 +5777,8 @@ static int prep_next_sparse_read(struct ceph_connection *con,
 	}
 
 	if (o->o_sparse_op_idx < 0) {
-		u64 srlen = sparse_data_requested(req);
-
-		dout("%s: [%d] starting new sparse read req. srlen=0x%llx\n",
-		     __func__, o->o_osd, srlen);
-		ceph_msg_data_cursor_init(cursor, con->in_msg, srlen);
+		dout("%s: [%d] starting new sparse read req\n",
+		     __func__, o->o_osd);
 	} else {
 		u64 end;
 
-- 
2.43.0


^ permalink raw reply related	[flat|nested] 7+ messages in thread

* Re: [PATCH v6 3/3] libceph: just wait for more data to be available on the socket
  2024-01-25  2:39 ` [PATCH v6 3/3] libceph: just wait for more data to be available on the socket xiubli
@ 2024-02-27 17:22   ` Luis Henriques
  2024-02-28  0:22     ` Xiubo Li
  2024-02-28  0:45     ` Xiubo Li
  0 siblings, 2 replies; 7+ messages in thread
From: Luis Henriques @ 2024-02-27 17:22 UTC (permalink / raw)
  To: xiubli; +Cc: ceph-devel, idryomov, jlayton, vshankar, mchangir

Hi Xiubo!

xiubli@redhat.com writes:

> From: Xiubo Li <xiubli@redhat.com>
>
> A short read may occur while reading the message footer from the
> socket.  Later, when the socket is ready for another read, the
> messenger shoudl invoke all read_partial* handlers, except the
> read_partial_sparse_msg_data().  The contract between the messenger
> and these handlers is that the handlers should bail if the area
> of the message is responsible for is already processed.  So,
> in this case, it's expected that read_sparse_msg_data() would bail,
> allowing the messenger to invoke read_partial() for the footer and
> pick up where it left off.
>
> However read_partial_sparse_msg_data() violates that contract and
> ends up calling into the state machine in the OSD client. The
> sparse-read state machine just assumes that it's a new op and
> interprets some piece of the footer as the sparse-read extents/data
> and then returns bogus extents/data length, etc.
>
> This will just reuse the 'total_resid' to determine whether should
> the read_partial_sparse_msg_data() bail out or not. Because once
> it reaches to zero that means all the extents and data have been
> successfully received in last read, else it could break out when
> partially reading any of the extents and data. And then the
> osd_sparse_read() could continue where it left off.

I'm seeing an issue with fstest generic/580, which seems to enter an
infinite loop effectively rendering the testing VM unusable.  It's pretty
easy to reproduce, just run the test ensuring to be using msgv2 (I'm
mounting the filesystem with 'ms_mode=crc'), and you should see the
following on the logs:

[...]
  libceph: prepare_sparse_read_cont: ret 0x1000 total_resid 0x0 resid 0x0                                                                                       
  libceph: osd1 (2)192.168.155.1:6810 read processing error                                                                                                     
  libceph: mon0 (2)192.168.155.1:40608 session established                                                                                                      
  libceph: bad late_status 0x1                                                                                                                                  
  libceph: osd1 (2)192.168.155.1:6810 protocol error, bad epilogue                                                                                              
  libceph: mon0 (2)192.168.155.1:40608 session established                                                                                                      
  libceph: prepare_sparse_read_cont: ret 0x1000 total_resid 0x0 resid 0x0                                                                                       
  libceph: osd1 (2)192.168.155.1:6810 read processing error              
  libceph: mon0 (2)192.168.155.1:40608 session established                                                                                                      
  libceph: bad late_status 0x1                                                                                                                                  
[...]

Reverting this patch (commit 8e46a2d068c9 ("libceph: just wait for more
data to be available on the socket")) seems to fix.  I haven't
investigated it further, but since it'll take me some time to refresh my
memory, I thought I should report it immediately.  Maybe someone has any
idea.

Cheers,
-- 
Luís


> URL: https://tracker.ceph.com/issues/63586
> Signed-off-by: Xiubo Li <xiubli@redhat.com>
> Reviewed-by: Jeff Layton <jlayton@kernel.org>
> ---
>  include/linux/ceph/messenger.h |  2 +-
>  net/ceph/messenger_v1.c        | 25 +++++++++++++------------
>  net/ceph/messenger_v2.c        |  4 ++--
>  net/ceph/osd_client.c          |  9 +++------
>  4 files changed, 19 insertions(+), 21 deletions(-)
>
> diff --git a/include/linux/ceph/messenger.h b/include/linux/ceph/messenger.h
> index 2eaaabbe98cb..1717cc57cdac 100644
> --- a/include/linux/ceph/messenger.h
> +++ b/include/linux/ceph/messenger.h
> @@ -283,7 +283,7 @@ struct ceph_msg {
>  	struct kref kref;
>  	bool more_to_follow;
>  	bool needs_out_seq;
> -	bool sparse_read;
> +	u64 sparse_read_total;
>  	int front_alloc_len;
>  
>  	struct ceph_msgpool *pool;
> diff --git a/net/ceph/messenger_v1.c b/net/ceph/messenger_v1.c
> index 4cb60bacf5f5..126b2e712247 100644
> --- a/net/ceph/messenger_v1.c
> +++ b/net/ceph/messenger_v1.c
> @@ -160,8 +160,9 @@ static size_t sizeof_footer(struct ceph_connection *con)
>  static void prepare_message_data(struct ceph_msg *msg, u32 data_len)
>  {
>  	/* Initialize data cursor if it's not a sparse read */
> -	if (!msg->sparse_read)
> -		ceph_msg_data_cursor_init(&msg->cursor, msg, data_len);
> +	u64 len = msg->sparse_read_total ? : data_len;
> +
> +	ceph_msg_data_cursor_init(&msg->cursor, msg, len);
>  }
>  
>  /*
> @@ -1036,7 +1037,7 @@ static int read_partial_sparse_msg_data(struct ceph_connection *con)
>  	if (do_datacrc)
>  		crc = con->in_data_crc;
>  
> -	do {
> +	while (cursor->total_resid) {
>  		if (con->v1.in_sr_kvec.iov_base)
>  			ret = read_partial_message_chunk(con,
>  							 &con->v1.in_sr_kvec,
> @@ -1044,23 +1045,23 @@ static int read_partial_sparse_msg_data(struct ceph_connection *con)
>  							 &crc);
>  		else if (cursor->sr_resid > 0)
>  			ret = read_partial_sparse_msg_extent(con, &crc);
> -
> -		if (ret <= 0) {
> -			if (do_datacrc)
> -				con->in_data_crc = crc;
> -			return ret;
> -		}
> +		if (ret <= 0)
> +			break;
>  
>  		memset(&con->v1.in_sr_kvec, 0, sizeof(con->v1.in_sr_kvec));
>  		ret = con->ops->sparse_read(con, cursor,
>  				(char **)&con->v1.in_sr_kvec.iov_base);
> +		if (ret <= 0) {
> +			ret = ret ? ret : 1; /* must return > 0 to indicate success */
> +			break;
> +		}
>  		con->v1.in_sr_len = ret;
> -	} while (ret > 0);
> +	}
>  
>  	if (do_datacrc)
>  		con->in_data_crc = crc;
>  
> -	return ret < 0 ? ret : 1;  /* must return > 0 to indicate success */
> +	return ret;
>  }
>  
>  static int read_partial_msg_data(struct ceph_connection *con)
> @@ -1253,7 +1254,7 @@ static int read_partial_message(struct ceph_connection *con)
>  		if (!m->num_data_items)
>  			return -EIO;
>  
> -		if (m->sparse_read)
> +		if (m->sparse_read_total)
>  			ret = read_partial_sparse_msg_data(con);
>  		else if (ceph_test_opt(from_msgr(con->msgr), RXBOUNCE))
>  			ret = read_partial_msg_data_bounce(con);
> diff --git a/net/ceph/messenger_v2.c b/net/ceph/messenger_v2.c
> index f8ec60e1aba3..a0ca5414b333 100644
> --- a/net/ceph/messenger_v2.c
> +++ b/net/ceph/messenger_v2.c
> @@ -1128,7 +1128,7 @@ static int decrypt_tail(struct ceph_connection *con)
>  	struct sg_table enc_sgt = {};
>  	struct sg_table sgt = {};
>  	struct page **pages = NULL;
> -	bool sparse = con->in_msg->sparse_read;
> +	bool sparse = !!con->in_msg->sparse_read_total;
>  	int dpos = 0;
>  	int tail_len;
>  	int ret;
> @@ -2060,7 +2060,7 @@ static int prepare_read_tail_plain(struct ceph_connection *con)
>  	}
>  
>  	if (data_len(msg)) {
> -		if (msg->sparse_read)
> +		if (msg->sparse_read_total)
>  			con->v2.in_state = IN_S_PREPARE_SPARSE_DATA;
>  		else
>  			con->v2.in_state = IN_S_PREPARE_READ_DATA;
> diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
> index 837b69541376..ad2ed334cdbb 100644
> --- a/net/ceph/osd_client.c
> +++ b/net/ceph/osd_client.c
> @@ -5510,7 +5510,7 @@ static struct ceph_msg *get_reply(struct ceph_connection *con,
>  	}
>  
>  	m = ceph_msg_get(req->r_reply);
> -	m->sparse_read = (bool)srlen;
> +	m->sparse_read_total = srlen;
>  
>  	dout("get_reply tid %lld %p\n", tid, m);
>  
> @@ -5777,11 +5777,8 @@ static int prep_next_sparse_read(struct ceph_connection *con,
>  	}
>  
>  	if (o->o_sparse_op_idx < 0) {
> -		u64 srlen = sparse_data_requested(req);
> -
> -		dout("%s: [%d] starting new sparse read req. srlen=0x%llx\n",
> -		     __func__, o->o_osd, srlen);
> -		ceph_msg_data_cursor_init(cursor, con->in_msg, srlen);
> +		dout("%s: [%d] starting new sparse read req\n",
> +		     __func__, o->o_osd);
>  	} else {
>  		u64 end;
>  
> -- 
>
> 2.43.0
>


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [PATCH v6 3/3] libceph: just wait for more data to be available on the socket
  2024-02-27 17:22   ` Luis Henriques
@ 2024-02-28  0:22     ` Xiubo Li
  2024-02-28  0:45     ` Xiubo Li
  1 sibling, 0 replies; 7+ messages in thread
From: Xiubo Li @ 2024-02-28  0:22 UTC (permalink / raw)
  To: Luis Henriques; +Cc: ceph-devel, idryomov, jlayton, vshankar, mchangir


On 2/28/24 01:22, Luis Henriques wrote:
> Hi Xiubo!
>
> xiubli@redhat.com writes:
>
>> From: Xiubo Li <xiubli@redhat.com>
>>
>> A short read may occur while reading the message footer from the
>> socket.  Later, when the socket is ready for another read, the
>> messenger shoudl invoke all read_partial* handlers, except the
>> read_partial_sparse_msg_data().  The contract between the messenger
>> and these handlers is that the handlers should bail if the area
>> of the message is responsible for is already processed.  So,
>> in this case, it's expected that read_sparse_msg_data() would bail,
>> allowing the messenger to invoke read_partial() for the footer and
>> pick up where it left off.
>>
>> However read_partial_sparse_msg_data() violates that contract and
>> ends up calling into the state machine in the OSD client. The
>> sparse-read state machine just assumes that it's a new op and
>> interprets some piece of the footer as the sparse-read extents/data
>> and then returns bogus extents/data length, etc.
>>
>> This will just reuse the 'total_resid' to determine whether should
>> the read_partial_sparse_msg_data() bail out or not. Because once
>> it reaches to zero that means all the extents and data have been
>> successfully received in last read, else it could break out when
>> partially reading any of the extents and data. And then the
>> osd_sparse_read() could continue where it left off.
> I'm seeing an issue with fstest generic/580, which seems to enter an
> infinite loop effectively rendering the testing VM unusable.  It's pretty
> easy to reproduce, just run the test ensuring to be using msgv2 (I'm
> mounting the filesystem with 'ms_mode=crc'), and you should see the
> following on the logs:
>
> [...]
>    libceph: prepare_sparse_read_cont: ret 0x1000 total_resid 0x0 resid 0x0
>    libceph: osd1 (2)192.168.155.1:6810 read processing error
>    libceph: mon0 (2)192.168.155.1:40608 session established
>    libceph: bad late_status 0x1
>    libceph: osd1 (2)192.168.155.1:6810 protocol error, bad epilogue
>    libceph: mon0 (2)192.168.155.1:40608 session established
>    libceph: prepare_sparse_read_cont: ret 0x1000 total_resid 0x0 resid 0x0
>    libceph: osd1 (2)192.168.155.1:6810 read processing error
>    libceph: mon0 (2)192.168.155.1:40608 session established
>    libceph: bad late_status 0x1
> [...]
>
> Reverting this patch (commit 8e46a2d068c9 ("libceph: just wait for more
> data to be available on the socket")) seems to fix.  I haven't
> investigated it further, but since it'll take me some time to refresh my
> memory, I thought I should report it immediately.  Maybe someone has any
> idea.

Thanks Luis to reporting this.

Let me try to have a look and fix it.

- Xiubo


> Cheers,


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: [PATCH v6 3/3] libceph: just wait for more data to be available on the socket
  2024-02-27 17:22   ` Luis Henriques
  2024-02-28  0:22     ` Xiubo Li
@ 2024-02-28  0:45     ` Xiubo Li
  1 sibling, 0 replies; 7+ messages in thread
From: Xiubo Li @ 2024-02-28  0:45 UTC (permalink / raw)
  To: Luis Henriques; +Cc: ceph-devel, idryomov, jlayton, vshankar, mchangir


On 2/28/24 01:22, Luis Henriques wrote:
> Hi Xiubo!
>
> xiubli@redhat.com writes:
>
>> From: Xiubo Li <xiubli@redhat.com>
>>
>> A short read may occur while reading the message footer from the
>> socket.  Later, when the socket is ready for another read, the
>> messenger shoudl invoke all read_partial* handlers, except the
>> read_partial_sparse_msg_data().  The contract between the messenger
>> and these handlers is that the handlers should bail if the area
>> of the message is responsible for is already processed.  So,
>> in this case, it's expected that read_sparse_msg_data() would bail,
>> allowing the messenger to invoke read_partial() for the footer and
>> pick up where it left off.
>>
>> However read_partial_sparse_msg_data() violates that contract and
>> ends up calling into the state machine in the OSD client. The
>> sparse-read state machine just assumes that it's a new op and
>> interprets some piece of the footer as the sparse-read extents/data
>> and then returns bogus extents/data length, etc.
>>
>> This will just reuse the 'total_resid' to determine whether should
>> the read_partial_sparse_msg_data() bail out or not. Because once
>> it reaches to zero that means all the extents and data have been
>> successfully received in last read, else it could break out when
>> partially reading any of the extents and data. And then the
>> osd_sparse_read() could continue where it left off.
> I'm seeing an issue with fstest generic/580, which seems to enter an
> infinite loop effectively rendering the testing VM unusable.  It's pretty
> easy to reproduce, just run the test ensuring to be using msgv2 (I'm
> mounting the filesystem with 'ms_mode=crc'), and you should see the
> following on the logs:
>
> [...]
>    libceph: prepare_sparse_read_cont: ret 0x1000 total_resid 0x0 resid 0x0
>    libceph: osd1 (2)192.168.155.1:6810 read processing error
>    libceph: mon0 (2)192.168.155.1:40608 session established
>    libceph: bad late_status 0x1
>    libceph: osd1 (2)192.168.155.1:6810 protocol error, bad epilogue
>    libceph: mon0 (2)192.168.155.1:40608 session established
>    libceph: prepare_sparse_read_cont: ret 0x1000 total_resid 0x0 resid 0x0
>    libceph: osd1 (2)192.168.155.1:6810 read processing error
>    libceph: mon0 (2)192.168.155.1:40608 session established
>    libceph: bad late_status 0x1
> [...]
>
> Reverting this patch (commit 8e46a2d068c9 ("libceph: just wait for more
> data to be available on the socket")) seems to fix.  I haven't
> investigated it further, but since it'll take me some time to refresh my
> memory, I thought I should report it immediately.  Maybe someone has any
> idea.

The following patch should fix it. I haven't test it yet. Will do it 
later today:


diff --git a/net/ceph/messenger_v2.c b/net/ceph/messenger_v2.c
index a0ca5414b333..2c32ad4d9774 100644
--- a/net/ceph/messenger_v2.c
+++ b/net/ceph/messenger_v2.c
@@ -1860,10 +1860,10 @@ static int prepare_read_control_remainder(struct 
ceph_connection *con)
  static int prepare_read_data(struct ceph_connection *con)
  {
         struct bio_vec bv;
+       u64 len = con->in_msg->sparse_read_total ? : data_len(con->in_msg);

         con->in_data_crc = -1;
-       ceph_msg_data_cursor_init(&con->v2.in_cursor, con->in_msg,
-                                 data_len(con->in_msg));
+       ceph_msg_data_cursor_init(&con->v2.in_cursor, con->in_msg, len);

         get_bvec_at(&con->v2.in_cursor, &bv);
         if (ceph_test_opt(from_msgr(con->msgr), RXBOUNCE)) {


> Cheers,


^ permalink raw reply related	[flat|nested] 7+ messages in thread

end of thread, other threads:[~2024-02-28  0:45 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-01-25  2:39 [PATCH v6 0/3] libceph: fix sparse-read failure bug xiubli
2024-01-25  2:39 ` [PATCH v6 1/3] libceph: fail the sparse-read if the data length doesn't match xiubli
2024-01-25  2:39 ` [PATCH v6 2/3] libceph: rename read_sparse_msg_XX to read_partial_sparse_msg_XX xiubli
2024-01-25  2:39 ` [PATCH v6 3/3] libceph: just wait for more data to be available on the socket xiubli
2024-02-27 17:22   ` Luis Henriques
2024-02-28  0:22     ` Xiubo Li
2024-02-28  0:45     ` Xiubo Li

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).