Ceph » Linux kernel client

This may be a duplicate of http://tracker.newdream.net/issues/2937
and even if not, it's probably related.

After poking around with kdb this afternoon I have narrowed it down to
bio_split() being called with something other than exactly one page in
it. In this case, there are 0x17 = 23 pages in the bio to be split.

I'm now going to try to work backward from there to determine how
it could happen.

Just adding a little debug notes for my own reference.

Here is a dump of the bio involved in a crash using the base code:
0xffff880213477740 00000000000abd00 0000000000000000 ................
0xffff880213477750 ffff88020d0a2c00 4000000000000009 .,.............@
0xffff880213477760 0000000000000001 0000001700000080 ................
0xffff880213477770 0000300000080000 0000008000009000 .....0..........
0xffff880213477780 0000000000000001 ffff88020d4a0000 ..........J.....
0xffff880213477790 ffffffffa0068c30 ffff88020cbf1420 0....... .......
0xffff8802134777a0 0000000000000000 ffffffff811b2d50 ........P-......
0xffff8802134777b0 ffffea00085c11c0 0000000000001000 ..\.............

And here's one with my code with modified rbd_merge_bvec() function:
[1]kdb> md8c32 ffff88020bb2db00
0xffff88020bb2db00 00000000000abd00 0000000000000000 ................
0xffff88020bb2db10 ffff88020d0f8b00 4000000000000009 ...............@
0xffff88020bb2db20 0000000000000001 0000003c00000080 ............<...
0xffff88020bb2db30 0000200000080000 0000008000002000 ..... ... ......
0xffff88020bb2db40 0000000000000001 ffff8802205c8000 ..........\ ....
0xffff88020bb2db50 ffffffffa0068c30 ffff88020bdcfba0 0...............
0xffff88020bb2db60 0000000000000000 ffffffff811b2d50 ........P-......
0xffff88020bb2db70 ffffffff81c2a260 ffffffff81c2a2c0 `...............
0xffff88020bb2db80 ffff88020ca0de00 ffff8802245852c0 .........RX$....
0xffff88020bb2db90 ffffffff81080350 0000000000000000 P...............
0xffff88020bb2dba0 0000000000000000 0000000000000000 ................
0xffff88020bb2dbb0 0000000000000000 0000000000000000 ................
0xffff88020bb2dbc0 ffff88020bb2d8c0 0000000000000000 ................
0xffff88020bb2dbd0 ffff88020d0f8b00 f000000000000009 ................
0xffff88020bb2dbe0 0000000000000000 0000000100000001 ................
0xffff88020bb2dbf0 0000100000000000 0000000400001000 ................

Note that the problem occurs at the same sector offset,
0x000abd00 = 703744, and involves a bio with 0x80 = 128
full pages (4096 bytes apiece) in it.

I'm think I might know what's happening here.

Although rbd_merge_bvec() is a little odd in how it works, I
believe it is producing a result that will work the way its
callers expect. (I have a patch to clean this up though.)

The problem is in bio_chain_clone(), which is called only
by bio_rq_fn() in order to divide a single I/O request's
chain of bio's into a set of cloned chains of bio's. Each
"segment" (osd object) of the range of bytes in an rbd image
covered by the request will get its own cloned bio chain.

When bio_rq_fn() has a request to process, it allocates a
collection structure (rbd_req_coll) to hold the response
codes for each cloned chain submitted until they are all
complete. It then determines the end of the rbd segment
that contains the first byte in the request. It clones the
beginning of the bio chain up to the end of that segment,
using bio_chain_clone(), and passes the result (ultimately)
to rbd_do_request(), which submits it to the OSD containing
the target object. This continues until the full request
has been processed.

When each of these sub-requests completes, it calls its
callback function rbd_req_cb(), which handles zeroing
target pages for read operations as appropriate, recording
completion status, dropping references to the collection,
bio, and request, and freeing other data associated with
this cloned operation.

So bio_chain_clone() is responsible for splitting off a
cloned chain of bio's, up to a fixed offset. For the
most part this process is a simple matter of building a
new chain by cloning each bio in the original chain.
The only interesting case occurs at the boundary of
an rbd image segment, where a single bio might need
to be divided into two cloned bio's, one covering the
end of one segment and one covering the beginning of
the next.

In that case, bio_chain_clone() calls bio_split(), which
is a generic routine meant to handle exactly this sort
of division of a bio into two cloned pieces.

Now one of the requirements of using bio_split is that
the only splittable bio is one containing only a single
I/O vector--therefore affecting only one page. And the
BUG call that's being tripped here is occurring because
bio_split() is being passed a bio structure that describes
I/O to more than one page.

(OK, I'm going to save this and continue in another post.)

The way things are supposed to work for bio_split() is that
any bio that will be subject to a split will have already
been guaranteed to involve only a single page. This is
supposed to happen through the use of a callback function
tied to the block queue--set via blk_queue_merge_bvec().

Whenever an I/O vector (a bio_vec) is added to an existing
bio in a block queue, the generic code calls this callback
to see if there's any reason it cannot add it. This is
intended for stacking/layered drivers, which might have
certain boundaries or other characteristics (such as
different-sized blocks over different ranges of a logical
device) that might result in a bio that can't be processed
correctly once the request gets issued. If it's OK, the
bio_iov gets added to the existing bio; if it's not, the
existing bio gets closed out, more or less, and a new one
is allocated and used to contain the bio_iov in question.

An rbd image is exactly that type of device--its backing
storage is divided at fixed boundaries (based on its object
order, 4MB by default), and if a new bio_vec would cross
such a boundary the callback (rbd_merge_bvec()) should
indicate that the bio_vec should not be added.

So that's the way it all works... What's happening here?

Now that I've described all this I'm having doubts about
my suspicion, so I'll describe it in yet another post after
I think through it again.

I can easily reproduce this problem by doing this in my UML
environment:

1. note that count=8 below will not crash
   dd if=/dev/zero of=/b/foo bs=1024k count=9
   sync # push stuff to disk

Whoops, should have previewed that. Here's the same thing,
formatted as I intended.

I can easily reproduce this problem by doing this in my UML
environment:

    rbd create image1 --size=1024
    rbd map image1     # let's assume we get /dev/rbd1
    sleep 1            # for udev
    mkfs.btrfs /dev/rbd1
    mkdir -p /b
    mount /dev/rbd1 /b
    # note that count=8 below will not crash
    dd if=/dev/zero of=/b/foo bs=1024k count=9
    sync               # push stuff to disk

I added a printk() inside our merge function, rbd_merge_bvec().
It never gets called when I reproduce the problem as described
above.  The failure occurs when attempting to split a bio that
has these attributes:
    bi_sector:  703744
    bi_rw:      1 (write)
    bi_vcnt:    128
    bi_idx:     0
    bi_size:    524288

If I attempt to do a similar I/O touching the same offsets
directly to the rbd device using dd, I *do* see the printk()
lines, meaning we are calling the function.

    dd if=/dev/zero of=/dev/rbd1 bs=512 count=5 seek=703740 oflag=direct

Currently trying to track down why I'm seeing this.

After a long collaborative session on the btrfs IRC channel I think we may
have figured out the cause of this problem.

The return value from bio_add_page() will be less then the number of bytes
requested if the underlying block device finds the proposed addition not
acceptable.  In that case, the caller should not add to the bio and should
start a new one instead.

Although btrfs consistently uses the bio_add_page() interface, it does so
with the bi_sector field encoded using "logical" rather than "physical" 
sector offsets.  In this context, the logical offset has to do with an
internal btrfs extent map (I think), while the physical offset is the
sector offsets as understood by the underlying block device.  Only later,
just before submitting I/O to the backing store, will these logical
offsets be translated into physical ones.

As a result, the information used by the merge function is not correct,
so the "answer" to the "is adding this data to this bio OK?" question
therefore won't be correct.

The fix therefore needs to be in btrfs.  It somehow needs to
translate the bio so its bi_sector field is a physical sector
offset before any call to bio_add_page().  When that is done,
the rbd (and every other) merge function can provide the correct
return value, and we should not end up with a multi-page bio
when we need to split a bio in bio_chain_clone().