Ceph » rbd

Is there any chance this problem started with the addition
of that last commit:
06fb6a9f ceph: fix buffer pointer advance in ceph_sync_write

Do we have any evidence this problem also occurs without that
commit in place?

I don't expect that's a cause of trouble (because that seems
to correct a real problem), I'm just looking to eliminate
variables.

I took the liberty of connecting to the console of plana66, which
appears to have been left in this state for that purpose...

The actual current instruction pointer is:
ffffffffa0328156 = 0xffffffffa0328156 ([libceph]ceph_msg_data_set_pages+0x36)

And that corresponds to this line of code:
BUG_ON(msg->p.type != CEPH_MSG_DATA_NONE);

That indicates that the data for the given message
was set more than once, which is assumed to never
happen. That assumption could have been wrong, I'll
have to look at the context again.

The message data type that had been set before was
CEPH_MSG_DATA_PAGES, which seems better than any
other value but it still violates the assumption.

It is the data out field in the request message that's
being set more than once. (What I expected, but I've
verified this.)

I should probably talk with someone about what's going on
in ceph_osdc_start_request(). It has some logic that's
a bit convoluted and I may have missed something in my
recent changes.

Here is the reasoning for how it works now:
- req is a local variable initialized to NULL
- deep in the function, of we haven't locked any
pages yet, we allocated a new osd request with
req = ceph_osdc_new_request(...)
- ceph_osdc_new_request() creates a new osd request.
This includes allocating new request and reply messages
that are tied to the osd request. The types for both
the in and out data fields are set to NONE at that time.
- req is never reassigned until later in the function,
right after a call to initiate the osd request:
rc = ceph_osdc_start_request(...);
BUG_ON(rc);
req = NULL;

And now, I think I may have found the problem...

I think the problem is that the message data fields
need to be initialized. That happens if the message
is allocated via ceph_msg_new(), but not if the mempool
is used for allocating the message.

A long time ago I found a similar issue, where mempool
allocated objects were not getting zeroed when they
were taken from a mempool rather than via kmalloc.

So rather than simply add the initialization here I'd
like to restructure it a bit so that after allocation
(either via mempool or kmalloc) a separate initialization
routine is called for both cases. This is a pattern that
should probably be repeated elsewhere that a mempool is
used.

I have dropped my connection to the plana66 console. I
think I'm done with it and will pursue a fix for this.

I'm going to leave it up to someone else (named "Sage")
to free up those resources if that's appropriate.

OK I have a fix, and it doesn't do what I said it should...

Basically it just re-initializes the message when the last
reference to it is dropped. To really test this we'd need
to reproduce the problem, but I am pretty comfortable that
the explanation I made earlier is the root cause.

I'm going to post the patch for review without testing it
(other than a compile).

This commit has been pushed to the ceph-client "testing" branch.
d51342b libceph: initialize data fields on last msg put

I am not marking this resolves just yet. I had no good
way of verifying the fix. We'll let it run with nightly
testing for a few days and if the problem doesn't happen
again we'll assume this fix worked and will close it at
that time.