[tor-bugs] #9531 [TorBrowserButton]: More Torbutton hangs on New Identity control port access
Tor Bug Tracker & Wiki
blackhole at torproject.org
Tue Apr 1 08:56:44 UTC 2014
#9531: More Torbutton hangs on New Identity control port access
----------------------------------+---------------------------------------
Reporter: mikeperry | Owner: mikeperry
Type: defect | Status: new
Priority: major | Milestone:
Component: TorBrowserButton | Version:
Resolution: | Keywords: tbb-usability, tbb-newnym
Actual Points: | Parent ID:
Points: |
----------------------------------+---------------------------------------
Comment (by gk):
TL;DR: We can't use blocking sockets the way we are doing that right now.
They are responsible for the hangs.
If we only have non-TLS connections everything is fine. The picture
changes as soon as TLS connections are processed while we click on New
Identity or start the browser. Then the following may happen (this is the
case when we start-up; hitting New Identity gives a slightly different
stacktrace which boils down to the same problem, though):
{{{
#1 0xb772cc5b in pthread_cond_wait@@GLIBC_2.3.2 ()
at
../nptl/sysdeps/unix/sysv/linux/i386/i686/../i486/pthread_cond_wait.S:187
#2 0xb71ec899 in PR_WaitCondVar (cvar=0xa1a07d00, timeout=4294967295)
at /home/ubuntu/build/tor-
browser/nsprpub/pr/src/pthreads/ptsynch.c:385
#3 0xb5e53402 in Wait (this=<optimized out>, interval=<optimized out>)
at ../../../../dist/include/mozilla/CondVar.h:71
#4 Wait (interval=<optimized out>, this=<optimized out>)
at ../../../../dist/include/mozilla/Monitor.h:47
#5 Wait (interval=<optimized out>, this=<optimized out>)
at ../../../../dist/include/mozilla/Monitor.h:102
#6 mozilla::psm::SyncRunnableBase::DispatchToMainThreadAndWait (
this=0xa1a2f6e0)
at /home/ubuntu/build/tor-
browser/security/manager/ssl/src/PSMRunnable.cpp:25
#7 0xb5e45b6d in nsNSSSocketInfo::GetPreviousCert (this=0xab3c8580,
_result=0xb28feef4)
at /home/ubuntu/build/tor-
browser/security/manager/ssl/src/nsNSSIOLayer.cpp:427
#8 0xb5e31670 in HandshakeCallback (fd=0xab318280,
client_data=0xab3c8580)
at /home/ubuntu/build/tor-
browser/security/manager/ssl/src/nsNSSCallbacks.cpp:901
#9 0xb709f871 in ssl_FinishHandshake (ss=0xfffffe00) at sslsecur.c:141
#10 0xb708cd65 in ssl3_FinishHandshake (ss=0xaa08a000) at ssl3con.c:10637
#11 0xb708e609 in ssl3_AuthCertificateComplete (ss=0xaa08a000, error=0)
at ssl3con.c:10040
#12 0xb709faec in SSL_AuthCertificateComplete (fd=0xaa0760e0, error=0)
at sslsecur.c:1566
#13 0xb5e486ea in nsNSSSocketInfo::SetCertVerificationResult
(this=0xab3c8580,
errorCode=0, errorMessageType=mozilla::psm::PlainErrorMessage)
at /home/ubuntu/build/tor-
browser/security/manager/ssl/src/nsNSSIOLayer.cpp:456
#14 0xb5e53ecf in mozilla::psm::(anonymous
namespace)::SSLServerCertVerificationResult::Run (this=0xa1a2f6a0)
at /home/ubuntu/build/tor-
browser/security/manager/ssl/src/SSLServerCertVerification.cpp:1357
#15 0xb6366498 in nsThread::ProcessNextEvent (this=0xb2907a60,
mayWait=true,
result=0xb28ff1ef)
at /home/ubuntu/build/tor-browser/xpcom/threads/nsThread.cpp:626
#16 0xb63307a7 in NS_ProcessNextEvent (thread=0xfffffe00, mayWait=true)
at /home/ubuntu/build/tor-browser/obj-i686-pc-linux-
gnu/xpcom/build/nsThreadUtils.cpp:238
#17 0xb543f43e in nsSocketTransportService::Run (this=0xb29079a0)
at /home/ubuntu/build/tor-
browser/netwerk/base/src/nsSocketTransportService2.cpp:648
}}}
A SSLServerCertVerificationResult is dispatched to the socket transport
thread (see: https://mxr.mozilla.org/mozilla-
esr24/source/security/manager/ssl/src/SSLServerCertVerification.cpp#88 for
a reason why this has to happen). Processing this event leads to
dispatching PreviousCertRunnable to the main thread. Now, if that is
processed on the main thread *before* our
{{{
outputStream.writeBytes(command, command.length);
}}}
everything is fine. If not we see something like the following in the log:
{{{
-1344275648[b722a540]: nsSocketOutputStream::Write [this=9d128794 count=0]
-1344275648[b722a540]: calling PR_Write [count=0]
-1399850176[acb3b680]: STS dispatch [ab6821f0]
-1220368640[b722a300]: STS dispatch [a9dca700]
-1220368640[b722a300]: STS dispatch [aa76cce0]
-1220368640[b722a300]: STS dispatch [aa76cd00]
-1220368640[b722a300]: creating nsSocketTransport @9d128e00
-1220368640[b722a300]: nsSocketTransport::Init [this=9d128e00
host=127.0.0.1:9151 proxy=:0]
-1220368640[b722a300]: nsSocketTransport::PostEvent [this=9d128e00 type=3
status=0 param=0]
-1220368640[b722a300]: STS dispatch [aa76cde0]
-1220368640[b722a300]: nsSocketTransport::OpenInputStream [this=9d128e00
flags=3]
-1220368640[b722a300]: STS dispatch [aa46c2e8]
-1220368640[b722a300]: nsSocketTransport::PostEvent [this=9d128e00 type=0
status=0 param=0]
-1220368640[b722a300]: STS dispatch [aa76ce00]
-1220368640[b722a300]: nsSocketTransport::OpenOutputStream [this=9d128e00
flags=3]
-1220368640[b722a300]: STS dispatch [aa46c338]
-1220368640[b722a300]: nsSocketTransport::PostEvent [this=9d128e00 type=0
status=0 param=0]
-1220368640[b722a300]: STS dispatch [aa76ce40]
-1220368640[b722a300]: OOO WriteSegments [this=a18ed2ac count=47]
-1220368640[b722a300]: OOO appended new segment
-1220368640[b722a300]: OOO rolling back write cursor 0 bytes
-1220368640[b722a300]: OOO SegmentLen is 1
-1220368640[b722a300]: OOO ReadCount is 1
-1220368640[b722a300]: OOO SegmentLen is now 0 and originalLen is 1
-1220368640[b722a300]: OOO advancing write cursor by 1
-1220368640[b722a300]: OOO pipe output: waiting for space
-1690313920[aa456940]: STS dispatch [aa49a3a0]
-1673528512[aa456640]: STS dispatch [aa48fac0]
-1681921216[aa4567c0]: STS dispatch [aa496ec0]
}}}
Calling PR_Write actually leads to dispatching the TLS stuff to the socket
thread as explained above (note though that this log documents a hang on
"New Identity"). While the TLS code is running on that thread Torbutton
creates a new socket transport and is opening an input and an output
stream which leads to dispatching things to the socket thread, too. But
this one is till blocked by the TLS code, thus, the stream setup is not
properly done yet. Nevertheless, execution of Torbutton code is proceeding
with
{{{
outputStream.writeBytes(command, command.length);
}}}
which results in a blocking main thread with a still blocked socket
thread: we have a deadlock.
--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/9531#comment:23>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online
More information about the tor-bugs
mailing list