Project

General

Profile

Bug #36345

librados C API aio read empty buffer

Added by Anonymous about 4 years ago. Updated about 4 years ago.

Status:
Resolved
Priority:
Normal
Category:
Dev Interfaces
Target version:
% Done:

0%

Source:
Community (user)
Tags:
Backport:
Regression:
No
Severity:
2 - major
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
librados
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

When using the AIO functions, the readbuffer remains empty. when using the normal rados_read, the buffer is filled with contents

same code works without problems in 12.2.3

sample program attached, limited the print of the object to 60 chars.

test_ceph.c View (2.53 KB) Anonymous, 10/08/2018 02:56 PM

test_ceph.cc View (1.96 KB) Anonymous, 10/08/2018 04:11 PM


Related issues

Related to Ceph - Bug #23964: Buffer overflow if operation returns more data than length provided to aio_execute. Resolved 05/02/2018

History

#1 Updated by Anonymous about 4 years ago

the 'same' in c++ seems to work, so i guess it's limited to the c api

#2 Updated by Greg Farnum about 4 years ago

  • Project changed from Ceph to RADOS
  • Subject changed from librados aio read empty buffer to librados C API aio read empty buffer
  • Category changed from librados to Dev Interfaces
  • Component(RADOS) librados added

#3 Updated by Wido den Hollander about 4 years ago

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.

#4 Updated by Greg Farnum about 4 years ago

  • Assignee set to Wido den Hollander

Yeah can you make a PR, Wido? Somebody will need to know or run through how the IoCtx works with these data members and that's more likely with a PR.

#5 Updated by Kefu Chai about 4 years ago

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?

#6 Updated by Kefu Chai about 4 years ago

  • Status changed from New to Fix Under Review

#7 Updated by Kefu Chai about 4 years ago

  • Related to Bug #23964: Buffer overflow if operation returns more data than length provided to aio_execute. added

#8 Updated by Wido den Hollander about 4 years ago

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?

#9 Updated by Kefu Chai about 4 years ago

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.

#10 Updated by Kefu Chai about 4 years ago

  • Status changed from Fix Under Review to Can't reproduce

Wido, i am closing this issue as "can't reproduce". if you managed to reproduce it, please feel free to reopen it. thanks!

#11 Updated by imirc tw about 4 years ago

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.

#12 Updated by Wido den Hollander about 4 years ago

  • Status changed from Can't reproduce to 12

Updating this ticket as the issue seems to be related to two things:

- When using osd_op_timeout
- When using a user (not client.admin) which is limited to a particular pool when doing IO (allow rw pool=X)

That's what we found out when testing this.

#13 Updated by imirc tw about 4 years ago

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.

#14 Updated by Kefu Chai about 4 years ago

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.

#15 Updated by imirc tw about 4 years ago

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.

#16 Updated by Kefu Chai about 4 years ago

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

#17 Updated by imirc tw about 4 years ago

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

#18 Updated by imirc tw about 4 years ago

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] --

#19 Updated by imirc tw about 4 years ago

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

#20 Updated by imirc tw about 4 years ago

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

#21 Updated by imirc tw about 4 years ago

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

#22 Updated by Kefu Chai about 4 years ago

  • Status changed from 12 to Fix Under Review

imirc tw, thank you for your analysis. i am approving https://github.com/ceph/ceph/pull/24534. so "unshared buffer" originates from a fix of #9582 , and it's expected.

#23 Updated by Sage Weil about 4 years ago

  • Status changed from Fix Under Review to Resolved

Also available in: Atom PDF