debugs from an interesting CBDATA case study

For background:
 CBDATA uses an external lock counting and pointer management structure
to perform auto_ptr/unique_ptr semantics on objects. If the objects
"this" pointer does not match a magic binary pattern in the CBDATA
object (cookie) for the class it will assert as shown below.

For the code being patched:

* Both Comm::TcpReceiver and ServerStateData inherit from AsynsJob using
the "virtual public" inheritence.

* Both Comm::TcpReceiver and ServerStateData attempt to use
JobCallback() passing their 'this' pointer.

* The instantiated object in all cases described below is an
HttpStateData object which inherits from both of these classes.

* the only change between builds is the class inheritence order.

From the hierarchy definition:
 class HttpStateData : public ServerStateData, public Comm::TcpReceiver

This is replicable with any MISS request.

2014/01/02 02:01:50.351 kid1| src/http.cc(2243) httpStart: httpStart:
"GET http://example.com/"
2014/01/02 02:01:50.352 kid1| src/cbdata.cc(324) cbdataInternalAlloc:
cbdataAlloc: 0x9c8fdf0
2014/01/02 02:01:50.352 kid1| ../src/base/AsyncJob.cc(28) AsyncJob:
AsyncJob constructed, this=0x9c8fe80 type=HttpStateData [job5]
2014/01/02 02:01:50.352 kid1| src/store.cc(545) lock: StoreEntry::lock:
key 'D9237C562111E3C9330563403648CEC3' count=3
2014/01/02 02:01:50.352 kid1| src/http.cc(113) HttpStateData:
HttpStateData 0x9c8fdf0 created
2014/01/02 02:01:50.353 kid1| src/cbdata.cc(419) cbdataInternalLock:
cbdataLock: 0x9c8fdf0=1
2014/01/02 02:01:50.353 kid1| src/cbdata.cc(510) cbdataReferenceValid:
cbdataReferenceValid: 0x9c8fdf0
2014/01/02 02:01:50.353 kid1| src/cbdata.cc(419) cbdataInternalLock:
cbdataLock: 0x9c8fdf0=2
2014/01/02 02:01:50.353 kid1| src/cbdata.cc(510) cbdataReferenceValid:
cbdataReferenceValid: 0x9c8fdf0
2014/01/02 02:01:50.359 kid1| src/cbdata.cc(419) cbdataInternalLock:
cbdataLock: 0x9c8fe24=1
2014/01/02 02:01:50.359 kid1| assertion failed: ../../src/cbdata.cc:132:
"cookie == ((long)this ^ Cookie)"

#3 0x0814a09b in xassert (msg=0x837f7b8 "cookie == ((long)this ^
Cookie)", file=0x837f5ba "../../src/cbdata.cc", line=132) at
../../src/debug.cc:566
        __FUNCTION__ = "xassert"
#4 0x0810ed83 in check (aLine=423, this=0x85b52d4) at
../../src/cbdata.cc:132
        this = 0x85b52d4
#5 cbdataInternalLock (p=p_at_entry=0x85b52e4) at ../../src/cbdata.cc:423
        c = 0x85b52d4
        __FUNCTION__ = "cbdataInternalLock"
#6 0x082e2b11 in CommCommonCbParams::CommCommonCbParams
(this=this_at_entry=0xbffff254, aData=aData_at_entry=0x85b52e4) at
../../src/CommCalls.cc:10
No locals.
#7 0x082e3813 in CommCloseCbParams::CommCloseCbParams (this=0xbffff254,
aData=0x85b52e4) at ../../src/CommCalls.cc:107
No locals.
#8 0x0834f190 in CommCbMemFunT (aMeth=
    (void (Comm::TcpReceiver::*)(Comm::TcpReceiver * const, const
CommCbMemFunT<Comm::TcpReceiver, CommCloseCbParams>::Params &))
0x834e270 <Comm::TcpReceiver::tcpConnectionClosed(CommCloseCbParams
const&)>, aJob=..., this=0xbffff268) at ../../../src/CommCalls.h:180
No locals.
#9 Comm::TcpReceiver::tcpConnectionInit (this=this_at_entry=0x85b52e4) at
../../../src/comm/TcpReceiver.cc:36
No locals.
----- failing:
void
Comm::TcpReceiver::tcpConnectionInit()
{
    /* Ideally this would be setup by the constructor but it involves
     * calls to toCbdata() virtual function implemented by the derived class
     * so must be run explicitly by that class's constructor.
     */

    typedef CommCbMemFunT<Comm::TcpReceiver, CommCloseCbParams> Dialer;
//line 36:
    closed_ = JobCallback(33, 5, Dialer, this,
Comm::TcpReceiver::tcpConnectionClosed);
    comm_add_close_handler(tcp->fd, closed_);
}
-----

#10 0x081a8e20 in HttpStateData::HttpStateData
(this=this_at_entry=0x85b52b0, theFwdState=theFwdState_at_entry=0x85b3380,
__in_chrg=<optimized out>,
    __vtt_parm=<optimized out>) at ../../src/http.cc:140
No locals.
#11 0x081a8f0c in httpStart (fwd=fwd_at_entry=0x85b3380) at
../../src/http.cc:2244
        __FUNCTION__ = "httpStart"

*******************************************************

From the hierarchy definition:
  class HttpStateData : public Comm::TcpReceiver, public ServerStateData

job12 is a POST request. It gets past the httpStart() function which
dies above. There is a series of "waiting for request body to complete"
calls. Then ...

2014/01/05 04:22:43.901| ../src/base/AsyncJob.cc(117) callStart:
HttpStateData status in: [ job12]
2014/01/05 04:22:43.901| src/cbdata.cc(510) cbdataReferenceValid:
cbdataReferenceValid: 0x89ed1f8
2014/01/05 04:22:43.901| src/Server.cc(368) sentRequestBody:
sentRequestBody: FD 22: size 463: errflag 0.
2014/01/05 04:22:43.901| src/Server.cc(369) sentRequestBody:
sentRequestBody called
2014/01/05 04:22:43.901| src/BodyPipe.cc(377) postConsume:
reentrant debuging 2-{src/cbdata.cc(510) cbdataReferenceValid:
cbdataReferenceValid: 0x89ed1f8}-2
consumed 106 bytes [106<=106<=106 0+2047 pipe0x89e9080 cons0x89ed224]
2014/01/05 04:22:43.902| src/Server.cc(425) sendMoreRequestBody: will
write 106 request body bytes
2014/01/05 04:22:43.902| src/cbdata.cc(419) cbdataInternalLock:
cbdataLock: 0x89ed1f8=10
2014/01/05 04:22:43.902| src/cbdata.cc(510) cbdataReferenceValid:
cbdataReferenceValid: 0x89ed1f8
2014/01/05 04:22:43.903| src/cbdata.cc(419) cbdataInternalLock:
cbdataLock: 0x89ed1f8=11
2014/01/05 04:22:43.903| src/cbdata.cc(510) cbdataReferenceValid:
cbdataReferenceValid: 0x89ed1f8
2014/01/05 04:22:43.903| src/cbdata.cc(419) cbdataInternalLock:
cbdataLock: 0x89ed224=1
2014/01/05 04:22:43.903| assertion failed: ../../src/cbdata.cc:132:
"cookie == ((long)this ^ Cookie)"

#3 0x0814a1fb in xassert (msg=0x837f8f8 "cookie == ((long)this ^
Cookie)", file=0x837f6fa "../../src/cbdata.cc", line=132) at
../../src/debug.cc:566
        __FUNCTION__ = "xassert"
#4 0x0810eee3 in check (aLine=423, this=0x89ed214) at
../../src/cbdata.cc:132
        this = 0x89ed214
#5 cbdataInternalLock (p=p_at_entry=0x89ed224) at ../../src/cbdata.cc:423
        c = 0x89ed214
        __FUNCTION__ = "cbdataInternalLock"
#6 0x082e2c91 in CommCommonCbParams::CommCommonCbParams
(this=this_at_entry=0xbffff2ac, aData=aData_at_entry=0x89ed224) at
../../src/CommCalls.cc:10
No locals.
#7 0x082e3524 in CommIoCbParams::CommIoCbParams (this=0xbffff2ac,
aData=0x89ed224) at ../../src/CommCalls.cc:78
No locals.
#8 0x0823de31 in CommCbMemFunT (aMeth=&virtual
ServerStateData::sentRequestBody(CommIoCbParams const&), aJob=...,
this=0xbffff2c8)
    at ../../src/CommCalls.h:180
No locals.
#9 ServerStateData::sendMoreRequestBody (this=this_at_entry=0x89ed224) at
../../src/Server.cc:427
        conn = {p_ = 0x89ed008}
        __FUNCTION__ = "sendMoreRequestBody"
        buf = {buf = 0x89f13d8
"0h0f0D0B0_at_0\t\006\005+\016\003\002\032\005", size = 106, max_capacity =
2097152000, capacity = 2048, stolen = 0,
          static CBDATA_MemBuf = 10}
#10 0x0823ef48 in ServerStateData::sentRequestBody (this=0x89ed224,
io=...) at ../../src/Server.cc:403
        __FUNCTION__ = "sentRequestBody"
#11 0x081aee60 in CommCbMemFunT<HttpStateData, CommIoCbParams>::doDial
(this=0x89f139c) at ../../src/CommCalls.h:197
No locals.
#12 0x081aef75 in JobDialer<HttpStateData>::dial
(this=this_at_entry=0x89f139c, call=...) at ../../src/base/AsyncJobCalls.h:166
        __FUNCTION__ = "dial"
#13 0x081af0d6 in AsyncCallT<CommCbMemFunT<HttpStateData,
CommIoCbParams> >::fire (this=0x89f1380) at ../../src/base/AsyncCall.h:137
No locals.
#14 0x082d0442 in AsyncCall::make (this=0x89f1380) at
../../../src/base/AsyncCall.cc:32
        __FUNCTION__ = "make"
...
Received on Tue Jan 07 2014 - 09:40:33 MST