Well, there's an Op::out_bl, Op::outbl, and ObjectOperation::out_bl
and I'm having some trouble keeping them straight as I skim through
the code.
But I do see a lot of stuff like
o->out_bl.swap(op.out_bl);
m->claim_data(*op->outbl);
vector<bufferlist*>::iterator pb = op->out_bl.begin();
I'm still not clear on why having the previous result's data in there
doesn't work, but a new bit of "random" data does. But given that this
is just a client messing itself up I think we should just create a
ticket so we can track it, add a doc string somewhere saying
explicitly that output buffer lists need to be new/clean, and get on
with our lives. Unless somebody wants to walk through what's going on
in librados, which might be a good exercise?
-Greg
On Sun, Dec 23, 2018 at 4:14 PM Noah Watkins <nwatkins@xxxxxxxxxx> wrote:
>
> I was going to write this e-mail asking about any [unwritten] rules
> for sharing bufferlist instances across librados API invocations after
> seeing some non-intuitive behavior, but some simple changes to the
> test make it seem more and more like a bug. I've replicated this on
> the latest master, and a commit back closer to when mimic branched
> (circa May).
>
> The test below calls the `hello.say_hello` objclass method. For the
> invocations here this is effectively an echo test: it directly writes
> the input back into the output. It's called twice, and the `outbl`
> that receives the response from `ioctx::operate` is shared across the
> calls.
>
> ceph::bufferlist outbl;
>
> {
> char bytes[24];
> ceph::bufferlist bl;
> bl.append(bytes, sizeof(bytes));
> librados::ObjectReadOperation op;
> op.exec("hello", "say_hello", bl);
> ret = ioctx.operate("obj", &op, &outbl);
> ASSERT_EQ(ret, 0);
> }
>
> ASSERT_TRUE(outbl.length() > 0);
>
> {
> char bytes[36];
> ceph::bufferlist bl;
> bl.append(bytes, sizeof(bytes));
> librados::ObjectReadOperation op;
> op.exec("hello", "say_hello", bl);
> ret = ioctx.operate("obj", &op, &outbl);
> ASSERT_EQ(ret, 0);
> }
>
> The behavior I see when running this test is that on the second
> invocation of the objclass method the client never returns, and the
> OSD and client retry the operation an unbounded number of times. Here
> it is with RETRY=189
>
> 2018-12-23 17:52:23.646 7fa673edd700 15 osd.0 pg_epoch: 7 pg[1.1( v
> 7'1 (0'0,7'1] local-lis/les=6/7 n=1 ec=6/6 lis/c 6/6 les/c/f 7/7/0
> 6/6/6) [0] r=0 lpr=6 crt=7'1 lcod 0'0 mlcod 0'0 active+clean]
> log_op_stats osd_op(client.4125.0:4 1.1 1:847a3d55:::obj:head [call
> hello.say_hello] snapc 0=[] RETRY=189
> ondisk+retry+read+known_if_redirected e7) v8 inb 0 outb 44 lat
> 0.000871
>
> And the full log is here:
> https://paste.fedoraproject.org/paste/zYkKNU1iAB7Mt3thpjKM7w
>
> If one clears outbl before the second invocation, that is:
>
> ASSERT_TRUE(outbl.length() > 0);
> outbl.clear();
>
> Then the entire test succeeds. That seemed like non-intuitive
> behavior, but maybe its just not documented that `ioctx::operate`
> assumes an empty bufferlist. However, the following change _does not_
> trigger the error:
>
> ASSERT_TRUE(outbl.length() > 0);
> outbl.clear();
> outbl.append("foo", 3);
>
> Suggesting that a non-empty bufferlist is OK (at least it doesn't
> cause the infinite RETRY loop), and there is some lingering state some
> where.
>
> - Noah
