Ceph » RADOS

I was notified about this issue and a simple fix would be:

diff --git a/src/librados/IoCtxImpl.cc b/src/librados/IoCtxImpl.cc
index 3dbc823..6a7b55a 100644
--- a/src/librados/IoCtxImpl.cc
+++ b/src/librados/IoCtxImpl.cc
@@ -2020,6 +2020,10 @@ void librados::IoCtxImpl::C_aio_Complete::finish(int r)
     if (c->out_buf && !c->blp->is_contiguous()) {
       c->rval = -ERANGE;
     } else {
+
+        if (c->out_buf && !c->blp->is_provided_buffer(c->out_buf))
+            c->blp->copy(0, c->blp->length(), c->out_buf);
+
       c->rval = c->blp->length();
     }
   }

However, I'm not sure what the implications might be though.

Wido, i am not able to reproduce this issue on master:

$ ceph osd pool create diablo 2

$ rados -p diablo put xyz /tmp/test_ceph.c

$ ./test_ceph_c
[DEBUG] mtime: 1539238429, psize: 2012
[DEBUG] bytes read: 2012, psize: 2012
[DEBUG] --

#include <rados/librados.hpp>
#include <iostream>
#include
[DEBUG] --
[DEBUG] bytes read: 2012, psize: 2012
[DEBUG] --

#include <rados/librados.hpp>
#include <iostream>
#include
[DEBUG] --

$ ./test_ceph_cxx
[DEBUG] mtime: 1539238429 psize: 2012
[DEBUG] bytes read: 2012, psize: 2012
[DEBUG] --

#include <rados/librados.hpp>
#include <iostream>
#include
[DEBUG] --

on which release did you run into this issue?

I am personally not running into the issue, but the reporter is. The reporter contacted me to forward the fix which solves the problem.

The test program he uses is attached and I think you used it.

This fails with 12.2.8 and 13.2.2, but not with 12.2.3

Does that help?

i tested both v13.2.2 and v12.2.8, with the provided source files. and still no luck: i am not able to reproduce this issue.

Kefu, I'm also experiencing this issue. It seems to be related to `rados osd op timeout`. Once this value is set in the config the aio read won't return any data. This seems related to https://github.com/ceph/ceph/commit/64bca33ae76646879e6801c45e6d91852e488f8b which was the same problem:

--
rados_aio_read(buf) call objecter->read(). Upon receiving reply from osd, message->claim_data() is called which enforces deep copy (both bufferlist and data buffers) because Accelio's registered buffers is NON_SHAREABLE. Received data is on new bufferlist and buffers but not in original buffer provided by rados_aio_read() caller. Another copy to users' buffer is needed
--

The fix provided by Wido is the same as used at that time, so I think fixing issue 23964 has re-introduced this bug by leaving out the code.

Hi Wido,

The 2nd assumption isn't true, that was because the client.admin ceph.conf file used didn't had the osd_op_timeout setting and the client.user did. The issue seems only related to osd_op_timeout.

imirc tw, i don't understand how "rados_osd_op_timeout" is related to this issue. i agree that current librados::IoCtxImpl::C_aio_Complete::finish() fails to work with non_shareable buffer pre-allocated for aio_read, but my concern is more about why you are running into this issue. please see my comment at https://github.com/ceph/ceph/pull/24534#issuecomment-428803421 .

because the raw buffer passed to rados_aio_read() will be used to create a raw_static buffer, see librados::IoCtxImpl::aio_read(), and unlike xio_msg_buffer, raw_static is sharable, i think we are facing a different issue than the one addressed by https://github.com/ceph/ceph/commit/64bca33ae76646879e6801c45e6d91852e488f8b

since xio messenger is not actively maintained, so i don't think we need to take that use case into consideration anymore.

Hi Kefu,

I'm not that deep into the Ceph code, I was making an assumption based on my observations and past tickets about this.

Try running the above tests with rados_osd_op_timeout and you'll see the buffer remains empty. Applying the PR from wido (which was mine) does solve this, I'm not exactly sure why but I figured it was for the same reason in the old commit I mentioned.

imirc tw, on which release did you reproduce this issue? is master affected?

13.2.2 , i will give it a go on master asap.

Kefu Chai, same happens on master:

# ./test_ceph
[DEBUG] mtime: 1540497555, psize: 2637
[DEBUG] bytes read: 2637, psize: 2637
[DEBUG] --

[DEBUG] --
[DEBUG] bytes read: 2637, psize: 2637
[DEBUG] --

#include <stdio.h>
#include <stdlib.h>
#include <rados/libr
[DEBUG] --

when I remove 'rados osd op timeout = 60' from the ceph.conf file, the result is ok:

# ./test_ceph
[DEBUG] mtime: 1540497555, psize: 2637
[DEBUG] bytes read: 2637, psize: 2637
[DEBUG] --

#include <stdio.h>
#include <stdlib.h>
#include <rados/libr
[DEBUG] --
[DEBUG] bytes read: 2637, psize: 2637
[DEBUG] --

#include <stdio.h>
#include <stdlib.h>
#include <rados/libr
[DEBUG] --

Some more info from what I can see while debugging.

Without 'rados osd op timeout', the buffer in librados::IoCtxImpl::C_aio_Complete::finish is of type ceph::buffer::raw_static, which sounds good, and it refers to the malloc'd pointer in test_ceph.c.

Once 'rados osd op timeout' is set, the buffer is a different type, ceph::buffer::raw_posix_aligned and it doens't refer to the malloc'd pointer in test_ceph.c anymore.

I'll try to debug this further

without osd_op_timeout, in Objecter::handle_osd_op_reply, Objecter.cc:3473
op->con px is an AsyncConnection on which revoke_rx_buffer gets called

With osd_op_timeout, op->con px = 0x0

I figured it out. In Objecter.cc:3279

op->ontimeout == 0 && // only post rx_buffer if no timeout; see #9582

The user provided buffer isn't used if osd_op_timeout has been set to prevent certain race conditions

So I guess we do need the following code

--- a/src/librados/IoCtxImpl.cc
+++ b/src/librados/IoCtxImpl.cc
@@ -2020,6 +2020,10 @@ void librados::IoCtxImpl::C_aio_Complete::finish(int r)
     if (c->out_buf && !c->blp->is_contiguous()) {
       c->rval = -ERANGE;
     } else {
+
+        if (c->out_buf && !c->blp->is_provided_buffer(c->out_buf))
+            c->blp->copy(0, c->blp->length(), c->out_buf);
+
       c->rval = c->blp->length();
     }
   }

to copy the buffer to our provided buffer in case the timeout is set, and c->blp isn't our buffer anymore