More Torbutton hangs on New Identity control port access

added MikePerry201408R TorBrowserTeam201408 component::applications/tor browser owner::gk priority::high resolution::fixed status::closed tbb-newnym tbb-torbutton tbb-usability type::defect labels

Trac:
Description: skruffy is reporting hangs on Torbutton's New Identity. Oddly, the hangs seem to be more common if you are loading a bunch of websites at the time of hitting New Identity, but that is not a full repro case.

The hang actually appears to be happening while attempting to open a control port connection. Perhaps another race introduced by our SOCKS optimistic data hack in nsITransport? Or perhaps our hack for #8462 (moved) is insufficient in some cases, and/or during heavy network activity.

to

skruffy is reporting hangs on Torbutton's New Identity. Oddly, the hangs seem to be more common if you are loading a bunch of websites at the time of hitting New Identity, but that is not a full repro case.

The hang actually appears to be happening while attempting to open a control port connection. Perhaps another race introduced by our SOCKS optimistic data hack in nsITransport? Or perhaps our hack for #8642 (closed) is insufficient in some cases, and/or during heavy network activity.

Hang happens exactly after call of "outputStream.writeBytes(auth_cmd, auth_cmd.length)". Tcpdump shows no one packet, no syn, no connection established.

Modified torbutton_do_new_identity() so it calls only torbutton_send_ctrl_cmd() and nothing else. Hangs still happens in the same place.

Socket is never alive during repro case that leads to hangs. Tested with modified torbutton_send_ctrl_cmd() so it waited alive socket after opening stream, like so:

    var input = socket.openInputStream(3, 1, 1); // 3 == OPEN_BLOCKING|OPEN_UNBUFFERED
    var output = socket.openOutputStream(3, 1, 1); // 3 == OPEN_BLOCKING|OPEN_UNBUFFERED

    while (!socket.isAlive()) {}
    torbutton_log(4, "Alive!");

If hangs happens then it never reaches "Alive!" and browser ask about unresponsive script later.

I got reproducable hang using modified torbutton_send_ctrl_cmd(), on startup without any pages loaded.

    var socketTransportService = Components.classes["@mozilla.org/network/socket-transport-service;1"]
        .getService(Components.interfaces.nsISocketTransportService);
    var sockets = new Array();
    var max=540; // 550 hangs, 545 bypasses
    for(var i = 0; i < max; i++) {
      var s = socketTransportService.createTransport(null, 0, m_tb_control_host, m_tb_control_port, null);


      var input = s.openInputStream(3, 1, 1); // 3 == OPEN_BLOCKING|OPEN_UNBUFFERED
      var output = s.openOutputStream(3, 1, 1); // 3 == OPEN_BLOCKING|OPEN_UNBUFFERED
      sockets.push(s);
    }
    for(var i = 0; i < max-1; i++) {
      sockets[i].close;
    }
    var socket =  sockets[max-2];
    torbutton_log(4, "Browser will hang now!");

Those number for tested box, it's depends platform in some way. I was unable to find any correlation with local limits like max descriptors or something. Probably missed something.

var socket = sockets[max-2]; Should be var socket = sockets[max-1];

Well code is buggy. Ignore it.

It hangs if socket never closed, as broken code do not close any.

Trac:
Cc: N/A to g.koppen@jondos.de

This code helps to avoid conditions that leads to hang if no connection able to create.

--- torbutton.js.original
+++ torbutton.js
@@ -1385,6 +1385,20 @@
   }
 }
 
+function torbutton_process_even_queue() {
+    // Get the current thread.
+    var thread = Components.classes["@mozilla.org/thread-manager;1"].
+                 getService(Components.interfaces.nsIThreadManager).currentThread;
+/*
+Warning: Calling nsIThread.processNextEvent allows network
+and UI events to run which can modify data structures that
+your code isn't expecting to be modified during a synchronous
+method call. This can cause random crashes and other bugs that
+may be hard to find and fix. Consider use asynchronous callbacks instead.
+*/
+    while (thread.processNextEvent(false)) {}
+}
+
 /* The "New Identity" implementation does the following:
  *   1. Disables Javascript and plugins on all tabs
  *   2. Clears state:
@@ -1580,7 +1594,8 @@
   var prefService = Components.classes["@mozilla.org/preferences-service;1"]
       .getService(Components.interfaces.nsIPrefService);
   prefService.savePrefFile(null);
-  
+
+  torbutton_process_even_queue();
   torbutton_log(3, "New Identity: Sending NEWNYM");
 
   // We only support TBB for newnym.

Trac:
Status: new to needs_review

it was event queue in my brain. typo, but this code works.

Why do you think that warning can be ignored in the current case?

Replying to gk:

Why do you think that warning can be ignored in the current case?

Do you think that warning can't be ignored?

No any modified data should prevent: access control port, open new window, close current window. Before "Sending NEWNYM" it actually assumed everything finished: tabs closed, conns destroyed, prefs synced, etc. With processing all events in queue you can guarantee that.

The only thing is UI. User can open new tab, or press "NEWNYM" yet while it process queue? or something evil yet. Ok lets fix browser code instead, it's bug anyway. Or migrate away.

Trac:
Status: needs_review to new

https://bugzilla.mozilla.org/show_bug.cgi?id=698882 Is it reason of hangs?

Here comes some gdb output as a starting point:

#4  0xb628579a in mozilla::ReentrantMonitor::Wait (this=0x9b2814e0, 
    interval=4294967295)
    at /home/ubuntu/build/tor-browser/obj-i686-pc-linux-gnu/xpcom/build/BlockingResourceBase.cpp:313
#5  0xb4a8f352 in mozilla::ReentrantMonitorAutoEnter::Wait (this=0xbfffb7ac, 
    interval=4294967295) at ../../dist/include/mozilla/ReentrantMonitor.h:192
#6  0xb62caa37 in nsPipeOutputStream::Wait (this=0x9b2814bc)
    at /home/ubuntu/build/tor-browser/xpcom/io/nsPipe3.cpp:980
#7  0xb62cae45 in nsPipeOutputStream::WriteSegments (this=0x9b2814bc, 
    reader=0xb62cafea <nsReadFromRawBuffer(nsIOutputStream*, void*, char*, uint32_t, uint32_t, uint32_t*)>, closure=0x9b5e0be0, count=46, 
    writeCount=0xbfffb898)
    at /home/ubuntu/build/tor-browser/xpcom/io/nsPipe3.cpp:1090
#8  0xb62cb077 in nsPipeOutputStream::Write (this=0x9b2814bc, 
    fromBuf=0x9b5e0be0 "AUTHENTICATE 422f587d45483e5b737b2f7863234042\r\n", 
    bufLen=47, writeCount=0xbfffb898)
    at /home/ubuntu/build/tor-browser/xpcom/io/nsPipe3.cpp:1150
#9  0xb62bc86d in nsBinaryOutputStream::Write (this=0x9b6d1980, 
    aBuf=0x9b5e0be0 "AUTHENTICATE 422f587d45483e5b737b2f7863234042\r\n", 
    aCount=47, aActualBytes=0xbfffb898)
    at /home/ubuntu/build/tor-browser/xpcom/io/nsBinaryStream.cpp:51
#10 0xb62bd0e7 in nsBinaryOutputStream::WriteBytes (this=0x9b6d1980, 
    aString=0x9b5e0be0 "AUTHENTICATE 422f587d45483e5b737b2f7863234042\r\n", 
    aLength=47)
    at /home/ubuntu/build/tor-browser/xpcom/io/nsBinaryStream.cpp:216

It is pretty reliably reproducible in my debug build if I open a bunch of bookmarks (say 5) simultaneously and choose the "New Identity" option immediately afterwards.

Trac:
Keywords: N/A deleted, tbb-newnym added

Trac:
Cc: g.koppen@jondos.de to gk, mcs, brade

More Torbutton hangs on New Identity control port access

Child items 0

Activity