Ceph » CephFS

Them doing a sync write is probably correct as their concurrency is being managed by the MDS now, and they aren't going to be allowed to buffer anything.
Although the actual trace is quite different, this is setting off comparisons to #4679 in my brain; did you check if it's a cap revoke issue of some kind?

It is a new issue in the sync write path, nothing to do with cap revoke. Alex has made quite a lot of changes in that area. The Oops can be reproduced in seconds with current test branch.

    ret = ceph_osdc_start_request(&fsc->client->osdc, req, false);
    if (!ret) {
        if (req->r_safe_callback) {
            /*
             * Add to inode unsafe list only after we
             * start_request so that a tid has been assigned.
             */
            spin_lock(&ci->i_unsafe_lock);
            list_add_tail(&req->r_unsafe_item,
                      &ci->i_unsafe_writes);
            spin_unlock(&ci->i_unsafe_lock);
            ceph_get_cap_refs(ci, CEPH_CAP_FILE_WR);
        }

        ret = ceph_osdc_wait_request(&fsc->client->osdc, req);
        if (ret < 0 && req->r_safe_callback) {
            spin_lock(&ci->i_unsafe_lock);
            list_del_init(&req->r_unsafe_item);
            spin_unlock(&ci->i_unsafe_lock);
            ceph_put_cap_refs(ci, CEPH_CAP_FILE_WR);
        }
    }

Found a potential cause. the request may complete before adding it to the unsafe list.

the request may complete before adding it to the unsafe list.

That looks like a reasonable explanation to me. And if so it's
an old bug but maybe my recent changes made it trigger.

If I could reproduce it I could narrow down exactly where it's
happening using the debugger to verify your suspicion.

I'll see what I can do.

Your description of how to reproduce it is fine (two clients
writing concurrently to the same file) but can you offer some
more specifics?

Well that's interesting.

I haven't been working with the ceph file system much so
I'm not sure what to expect. But I have both my clients
hung. (I have seen something similar with the ceph "next"
branch recently so I guess I better go back to "bobtail".)

Can you confirm what version of ceph you're working with?
I have been assuming the "testing" branch referred to the
ceph-client code.

In any case, I'll document what I did here.

I created a file in a file system mounted by 2 ceph fs
clients. I wrote to it from one host and was able to read
the result back.

I then wrote to it from the second host, and that
was successful. Reading it back from that same (second)
host confirmed it. However now the "cat" process that
was reading it is hung, stuck here:
[<ffffffffa046801d>] ceph_mdsc_do_request+0x12d/0x2a0 [ceph]
[<ffffffffa044f591>] ceph_do_getattr+0xf1/0x1c0 [ceph]
[<ffffffffa0452b43>] ceph_aio_read+0x413/0x890 [ceph]
[<ffffffff81183923>] do_sync_read+0xa3/0xe0
[<ffffffff81184070>] vfs_read+0xb0/0x180
[<ffffffff81184192>] sys_read+0x52/0xa0
[<ffffffff81666e59>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff

Meanwhile, back on the first host, I attempted to read
the shared file with a cat command, and it to is hung,
stuck with exactly the same stack trace.

No obvious indication of a problem on the mds or
osd machines.

Well, I unfortunately got the same problem using
the "bobtail" branch.

Specifically what I'm doing:

machine 1
---------
hostname > /mnt/ceph/foo
cat /mnt/ceph/foo
(shows hostname)
                         machine 2
                         ---------
                         cat /mnt/ceph/foo
                         (shows machine 1 hostname)
                         hostname > /mnt/ceph/foo
                         cat /mnt/ceph/foo
                         (shows machine 2 hostname,
                          then hangs)
cat /mnt/ceph/foo
(no output, hangs)

I'll try once more, creating foo in a subdirectory
rather than in the root of the mounted file system,
in case it makes any difference at all...

OK, well I believe I have reproduced the problem.
I did this on two nodes simultaneously:

dd if=/dev/zero of=/mnt/ceph/shared_file bs=4096

Nothing seemed to happen at first, so I interrupted one
of them. The other one I couldn't interrupt, and it
was at that point I noticed one of the machines had
crashed. And it involved sync_write_commit(), _raw_spin_lock(),
and lock_acquire() at approximate the same offsets.

I'm going to try to narrow down precisely where it is in
the code to see if your theory is correct.

This crash looks a little bit familiar to me, and I think
I created a bug for it, but at the moment I can't find it.
I had seen this or something like it with rbd.

It may not be the same as what you are seeing Zheng, because
what I'm talking about has to do with interrupting while
waiting for an osd request to complete. I did that; I'm
not aware that you did.

The problem--from memory--is that if an interrupt occurs
during the wait_for_completion_interruptible() call
in ceph_osdc_wait_request(), a block of code is entered
that drops a reference before being done with a data
structure. (I'll look a little more closely to get more
concrete with this, but I wanted to just document what
I think I see right at the moment.)

The function is small, so I'm just going to reproduce
it here for reference.

int ceph_osdc_wait_request(struct ceph_osd_client *osdc,
                           struct ceph_osd_request *req)
{
        int rc;

        rc = wait_for_completion_interruptible(&req->r_completion);
        if (rc < 0) {
                mutex_lock(&osdc->request_mutex);
                __cancel_request(req);
                __unregister_request(osdc, req);
                mutex_unlock(&osdc->request_mutex);
                complete_request(req);
                dout("wait_request tid %llu canceled/timed out\n", req->r_tid);
                return rc;
        }

        dout("wait_request tid %llu result %d\n", req->r_tid, req->r_result);
        return req->r_result;
}

Zheng I think I have a fix. I'm going to test it first,
but then I'd like to supply it to you to see if it resolves
the problem you're seeing. Is that OK?

I also proposed a fix: [PATCH 1/4] ceph: add osd request to inode unsafe list in advance

FYI I just reproduced the problem without interrupt
and it matches what I saw before. (So I don't believe
the interrupt was a factor when I reproduced it before.)

Zheng Yan wrote:

The Oops is caused by uninitialized req->r_inode

Already tracked down the Oops. time to sleep, bye.