Fix race condition in OCSPRequestSession.

Fix race condition in OCSPRequestSession.

BUG=23437
TEST=none

Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=32580

[wtc, 2009-11-19 19:57:00]

LGTM.  Thanks!

[willchan no longer on Chromium, 2009-11-19 19:59:02]

On 2009/11/19 19:57:00, wtc wrote:
> LGTM.  Thanks!

FWIW, I've patched this into my client and run it all morning and it hasn't
crashed yet.

[willchan no longer on Chromium, 2009-11-19 20:07:33]

Spoke too soon!  New crash:

[20576:2104:1127202221447:FATAL:net/ocsp/nss_ocsp.cc(251)] Check failed:
!request_.

Program received signal SIGTRAP, Trace/breakpoint trap.
[Switching to Thread 0x42024950 (LWP 2104)]
DebugUtil::BreakDebugger () at base/debug_util_posix.cc:184
184     }
(gdb) ba
#0  DebugUtil::BreakDebugger () at base/debug_util_posix.cc:184
#1  0x0000000000b0cff5 in ~LogMessage (this=0x42022830, __in_chrg=<value
optimized out>) at base/logging.cc:539
#2  0x0000000000d755d9 in ~OCSPRequestSession (this=0x7fffed09b8c0,
__in_chrg=<value optimized out>) at net/ocsp/nss_ocsp.cc:251
#3  0x0000000000d72e77 in DeleteInternal (x=0x7fffed09b8c0) at
./base/ref_counted.h:146
#4  0x0000000000d72e8f in Destruct (x=0x7fffed09b8c0) at
./base/ref_counted.h:112
#5  0x0000000000d73fec in Release (this=0x7fffed09b8c8) at
./base/ref_counted.h:140
#6  0x0000000000d7437b in OCSPFree (request=0x7fffed09b8c0) at
net/ocsp/nss_ocsp.cc:529
#7  0x00007ffff53ec70c in pkix_pl_OcspResponse_Destroy (object=0x7fffed9e75c8,
plContext=0x7fffed935620) at pkix_pl_ocspresponse.c:180
#8  0x00007ffff53f645a in PKIX_PL_Object_DecRef (object=0x7fffed9e75c8,
plContext=0x7fffed935620) at pkix_pl_object.c:924
#9  0x00007ffff5399d74 in pkix_OcspChecker_CheckExternal (cert=0x7fffec35a268,
issuer=<value optimized out>, date=<value optimized out>, 
    checkerObject=<value optimized out>, procParams=0x7fffed9e7148,
methodFlags=5, pRevStatus=0x4202306c, pReasonCode=0x7fffed847b58,
pNBIOContext=0x42023050, 
    plContext=0x7fffed935620) at pkix_ocspchecker.c:363
#10 0x00007ffff539ab99 in PKIX_RevocationChecker_Check (cert=0x7fffec35a268,
issuer=0x7fffec35a148, revChecker=<value optimized out>,
procParams=0x7fffed9e7148, 
    chainVerificationState=1, testingLeafCert=<value optimized out>,
pRevStatus=0x42023238, pReasonCode=0x7fffed847b58, pNbioContext=0x42023230, 
    plContext=0x7fffed935620) at pkix_revocationchecker.c:417
#11 0x00007ffff53b4304 in pkix_CheckChain (certs=0x7fffed618118, numCerts=2,
anchor=<value optimized out>, checkers=0x7fffe8f7ba28,
revChecker=0x7fffe8ee0728, 
    removeCheckedExtOIDs=0x7fffec959028, procParams=0x7fffed9e7148,
pCertCheckedIndex=0x7fffed847b44, pCheckerIndex=0x7fffed847b48,
pRevChecking=0x7fffed847b68, 
    pReasonCode=0x7fffed847b58, pNBIOContext=0x42023318,
pFinalSubjPubKey=0x42023330, pPolicyTree=0x42023328, pVerifyTree=0x0,
plContext=0x7fffed935620)
    at pkix_validate.c:791
#12 0x00007ffff53b87d2 in pkix_Build_ValidateEntireChain (state=0x7fffed847b28,
anchor=0x7fffed5963e8, pNBIOContext=0x42023648, pValResult=0x42023680, 
    verifyNode=0x7fffed596848, plContext=0x7fffed935620) at pkix_build.c:1326
#13 0x00007ffff53b99e0 in pkix_BuildForwardDepthFirstSearch
(pNBIOContext=0x42023918, state=0x7fffed847b28, pValResult=0x42023908,
plContext=0x7fffed935620)
    at pkix_build.c:2517
#14 0x00007ffff53bea7d in pkix_Build_InitiateBuildChain
(procParams=0x7fffed8475a8, pNBIOContext=0x42023ab8, pState=0x42023ac8,
pBuildResult=0x42023ac0, 
    pVerifyNode=0x42023b50, plContext=0x7fffed935620) at pkix_build.c:3531
#15 0x00007ffff53c0d6a in PKIX_BuildChain (procParams=0x42022150,
pNBIOContext=0x42023b68, pState=0x42023b60, pBuildResult=0x42023b70,
pVerifyNode=0x42023b50, 
    plContext=0x7fffed935620) at pkix_build.c:3711
#16 0x00007ffff5340f0d in CERT_PKIXVerifyCert (cert=0x7fffed15a220,
usages=<value optimized out>, paramsIn=0x42023c40, paramsOut=0x42023f00,
wincx=<value optimized out>)
    at certvfypkix.c:2159
#17 0x0000000000ebbcf4 in PKIXVerifyCert (cert_handle=0x7fffed15a220,
check_revocation=true, policy_oids=0x0, num_policy_oids=0, cvout=0x42023f00)
    at net/base/x509_certificate_nss.cc:427
#18 0x0000000000ebc93a in net::X509Certificate::Verify (this=0x7fffece503c0,
hostname="www.google.com", flags=1, verify_result=0x7fffef8cd06c)
    at net/base/x509_certificate_nss.cc:538
#19 0x0000000000e7e4fd in net::CertVerifier::Request::DoVerify
(this=0x7fffef8cd000) at net/base/cert_verifier.cc:40
#20 0x0000000000e7df37 in DispatchToMethod<net::CertVerifier::Request, void
(net::CertVerifier::Request::*)()> (obj=0x7fffef8cd000, 
    method=0xe7e4b6 <net::CertVerifier::Request::DoVerify()>, arg=...) at
./base/tuple.h:412
#21 0x0000000000e7df74 in RunnableMethod<net::CertVerifier::Request, void
(net::CertVerifier::Request::*)(), Tuple0>::Run (this=0x7fffed820c00) at
./base/task.h:284
#22 0x0000000001e316e3 in ThreadMain (this=0x7fffed867ce0) at
base/worker_pool_linux.cc:78
#23 0x0000000000b25010 in ThreadFunc (closure=0x7fffed867ce0) at
base/platform_thread_posix.cc:26
#24 0x00007ffff44473f7 in start_thread () from /lib/libpthread.so.0
#25 0x00007ffff2c1bb4d in clone () from /lib/libc.so.6
#26 0x0000000000000000 in ?? ()


On 2009/11/19 19:59:02, willchan wrote:
> On 2009/11/19 19:57:00, wtc wrote:
> > LGTM.  Thanks!
> 
> FWIW, I've patched this into my client and run it all morning and it hasn't
> crashed yet.

[eroman, 2009-11-19 20:19:29]

Please backport these fixes to 4.0 branch when it is all sorted out. Thanks

[wtc, 2009-11-19 20:43:23]

On 2009/11/19 20:07:33, willchan wrote:
> Spoke too soon!  New crash:
> 
> [20576:2104:1127202221447:FATAL:net/ocsp/nss_ocsp.cc(251)] Check failed:
> !request_.
> 
> Program received signal SIGTRAP, Trace/breakpoint trap.
> [Switching to Thread 0x42024950 (LWP 2104)]
> DebugUtil::BreakDebugger () at base/debug_util_posix.cc:184
> 184     }
> (gdb) ba
> #0  DebugUtil::BreakDebugger () at base/debug_util_posix.cc:184
> #1  0x0000000000b0cff5 in ~LogMessage (this=0x42022830, __in_chrg=<value
> optimized out>) at base/logging.cc:539
> #2  0x0000000000d755d9 in ~OCSPRequestSession (this=0x7fffed09b8c0,
> __in_chrg=<value optimized out>) at net/ocsp/nss_ocsp.cc:251
> #3  0x0000000000d72e77 in DeleteInternal (x=0x7fffed09b8c0) at
> ./base/ref_counted.h:146
> #4  0x0000000000d72e8f in Destruct (x=0x7fffed09b8c0) at
> ./base/ref_counted.h:112
> #5  0x0000000000d73fec in Release (this=0x7fffed09b8c8) at
> ./base/ref_counted.h:140
> #6  0x0000000000d7437b in OCSPFree (request=0x7fffed09b8c0) at
> net/ocsp/nss_ocsp.cc:529
> #7  0x00007ffff53ec70c in pkix_pl_OcspResponse_Destroy (object=0x7fffed9e75c8,
> plContext=0x7fffed935620) at pkix_pl_ocspresponse.c:180
> #8  0x00007ffff53f645a in PKIX_PL_Object_DecRef (object=0x7fffed9e75c8,
> plContext=0x7fffed935620) at pkix_pl_object.c:924

I believe this is a reference-count bug.  When a worker thread
posts a task to the IO thread, the task should acquire a reference
to OCSPRequestSession.  I thought NewRunnableMethod should take
care of this for us...

[wtc, 2009-11-19 20:59:16]

The RunnableMethod class should take care of acquiring and
releasing the reference to the object:

template <class T, class Method, class Params>
class RunnableMethod : public CancelableTask {
 public:
  RunnableMethod(T* obj, Method meth, const Params& params)
      : obj_(obj), meth_(meth), params_(params) {
    traits_.RetainCallee(obj_);
  }

  ~RunnableMethod() {
    ReleaseCallee();
  }

So I don't know why the reference count seems to be wrong.