Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Progress bar when orbot is starting gets stuck sometimes #621

Closed
syphyr opened this issue Feb 22, 2022 · 14 comments
Closed

Progress bar when orbot is starting gets stuck sometimes #621

syphyr opened this issue Feb 22, 2022 · 14 comments
Assignees

Comments

@syphyr
Copy link
Contributor

syphyr commented Feb 22, 2022

The progress bar when Orbot starts up often gets stuck with a message saying "starting orbot". This happens very often if Orbot is chosen start up at boot. But, this also occurs often when just starting and stopping Orbot.

In OrbotService.java, it looks like the status bar is waiting for a LOG_NOTICE_BOOTSTRAPPED, but the issue is that often Orbot's log does not contain this message after Orbot starts up. For example, when starting and stopping Orbot, the log message often gets truncated for some reason.

@syphyr
Copy link
Contributor Author

syphyr commented Feb 22, 2022

The exact message when it gets stuck is:
Orbot is starting... Connected to tor control port

Notice how when this occurs, bootsrapping is stuck on 5% in the log but tor appears to be connected.

Screenshot_20220222-235722

@syphyr
Copy link
Contributor Author

syphyr commented Feb 22, 2022

Also, I see this in the logcat if I let Orbot sit a few mins when the notification is stuck:

02-22 23:57:34.279 28216 30865 F libc    : Fatal signal 6 (SIGABRT), code -6 in tid 30865 (tor)
02-22 23:57:34.397 30866 30866 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
02-22 23:57:34.397 30866 30866 F DEBUG   : LineageOS Version: '14.1-20220221-NIGHTLY-gts210vewifi'
02-22 23:57:34.397 30866 30866 F DEBUG   : Build fingerprint: 'samsung/gts210vewifixx/gts210vewifi:7.0/NRD90M/T813XXU2BQD3:user/release-keys'
02-22 23:57:34.397 30866 30866 F DEBUG   : Revision: '4'
02-22 23:57:34.397 30866 30866 F DEBUG   : ABI: 'arm64'
02-22 23:57:34.397 30866 30866 F DEBUG   : pid: 28216, tid: 30865, name: tor  >>> org.torproject.android <<<
02-22 23:57:34.397 30866 30866 F DEBUG   : signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
02-22 23:57:34.397 30866 30866 F DEBUG   :     x0   0000000000000000  x1   0000000000007891  x2   0000000000000006  x3   0000000000000008
02-22 23:57:34.397 30866 30866 F DEBUG   :     x4   00000000000000c5  x5   0000007f3b8fdfd0  x6   6f69747265737341  x7   30203d3d2072206e
02-22 23:57:34.397 30866 30866 F DEBUG   :     x8   0000000000000083  x9   ffffffffffffffdf  x10  0000000000000000  x11  0000000000000001
02-22 23:57:34.398 30866 30866 F DEBUG   :     x12  ffffffffffffffff  x13  632e6e69616d2f6e  x14  000000000000000c  x15  2e8ba2e8ba2e8ba3
02-22 23:57:34.398 30866 30866 F DEBUG   :     x16  0000007f87b80ec8  x17  0000007f87b2a828  x18  0000007f858b08e0  x19  0000007f3b8ff4f8
02-22 23:57:34.398 30866 30866 F DEBUG   :     x20  0000000000000006  x21  0000007f3b8ff450  x22  0000000000000016  x23  0000007f649045f5
02-22 23:57:34.398 30866 30866 F DEBUG   :     x24  0000007f3b8ff4e8  x25  f4b187470769864c  x26  0000007f39b0f898  x27  f4b187470769864c
02-22 23:57:34.398 30866 30866 F DEBUG   :     x28  0000000000000001  x29  0000007f3b8fe120  x30  0000007f87b27cd0
02-22 23:57:34.398 30866 30866 F DEBUG   :     sp   0000007f3b8fe100  pc   0000007f87b2a830  pstate 0000000060000000
02-22 23:57:34.405 30866 30866 F DEBUG   : 
02-22 23:57:34.405 30866 30866 F DEBUG   : backtrace:
02-22 23:57:34.405 30866 30866 F DEBUG   :     #00 pc 000000000006c830  /system/lib64/libc.so (tgkill+8)
02-22 23:57:34.405 30866 30866 F DEBUG   :     #01 pc 0000000000069ccc  /system/lib64/libc.so (pthread_kill+64)
02-22 23:57:34.405 30866 30866 F DEBUG   :     #02 pc 0000000000023ea0  /system/lib64/libc.so (raise+24)
02-22 23:57:34.405 30866 30866 F DEBUG   :     #03 pc 000000000001c924  /system/lib64/libc.so (abort+52)
02-22 23:57:34.405 30866 30866 F DEBUG   :     #04 pc 00000000001729d4  /data/app/org.torproject.android-2/lib/arm64/libtor.so (tor_raw_abort_+12)
02-22 23:57:34.405 30866 30866 F DEBUG   :     #05 pc 000000000017bf58  /data/app/org.torproject.android-2/lib/arm64/libtor.so (tor_abort_+12)
02-22 23:57:34.406 30866 30866 F DEBUG   :     #06 pc 0000000000108448  /data/app/org.torproject.android-2/lib/arm64/libtor.so (pubsub_install+156)
02-22 23:57:34.406 30866 30866 F DEBUG   :     #07 pc 0000000000108558  /data/app/org.torproject.android-2/lib/arm64/libtor.so (tor_run_main+152)
02-22 23:57:34.406 30866 30866 F DEBUG   :     #08 pc 0000000000106a40  /data/app/org.torproject.android-2/lib/arm64/libtor.so (Java_org_torproject_jni_TorService_runMain+36)
02-22 23:57:34.406 30866 30866 F DEBUG   :     #09 pc 0000000000bb5590  /data/app/org.torproject.android-2/oat/arm64/base.odex (offset 0xad8000)

@bitmold
Copy link
Collaborator

bitmold commented Feb 23, 2022

I actually spent a good deal of time looking into this today, here's what I know so far:

Tor doesn't just appear to be connected, but it actually is - going to check.torproject.org works and all that.

The specific message you quoted: "Connected to tor control port" happens in the method initControlConnection() in OrbotService

private void initControlConnection() {
        if (conn != null) {
            logNotice(getString(R.string.log_notice_connected_to_tor_control_port));
            try {
                String confSocks = conn.getInfo("net/listeners/socks");
                StringTokenizer st = new StringTokenizer(confSocks, " ");

                confSocks = st.nextToken().split(":")[1];
                confSocks = confSocks.substring(0, confSocks.length() - 1);
                mPortSOCKS = Integer.parseInt(confSocks);

                String confHttp = conn.getInfo("net/listeners/httptunnel");
                st = new StringTokenizer(confHttp, " ");

                confHttp = st.nextToken().split(":")[1];
                confHttp = confHttp.substring(0, confHttp.length() - 1);
                mPortHTTP = Integer.parseInt(confHttp);

                String confDns = conn.getInfo("net/listeners/dns");
                st = new StringTokenizer(confDns, " ");
                if (st.hasMoreTokens()) {
                    confDns = st.nextToken().split(":")[1];
                    confDns = confDns.substring(0, confDns.length() - 1);
                    mPortDns = Integer.parseInt(confDns);
                    Prefs.getSharedPrefs(getApplicationContext()).edit().putInt(PREFS_DNS_PORT, mPortDns).apply();
                }

                String confTrans = conn.getInfo("net/listeners/trans");
                st = new StringTokenizer(confTrans, " ");
                if (st.hasMoreTokens()) {
                    confTrans = st.nextToken().split(":")[1];
                    confTrans = confTrans.substring(0, confTrans.length() - 1);
                    mPortTrans = Integer.parseInt(confTrans);
                }

                sendCallbackPorts(mPortSOCKS, mPortHTTP, mPortDns, mPortTrans);

            } catch (IOException e) {
                e.printStackTrace();
                stopTorOnError(e.getLocalizedMessage());
                conn = null;
            }
        }
}

Earlier I spent a lot of time sprinkling a lot of Log statements into OrbotService and rebooting my device in order to try and get this error. I've noticed that when this error occurs sendCallBackPorts is called, IE the IOException is not thrown

@bitmold
Copy link
Collaborator

bitmold commented Feb 23, 2022

We listen to the tor controller's "BW" event by way of subscribing to the TorControlCommands.EVENT_BANDWIDTH_USED with our TorContorlConnection. The same object used in the code snippet above.

This event acts as a heartbeat. Every second or so in fires off the bandwidth, and when Orbot works as it should, it replaces the progress bar with the bandwidth stats and a text string that says Tor is Connected. Notably when this error occurs, this event is not firing

@bitmold
Copy link
Collaborator

bitmold commented Feb 23, 2022

Under some (race) condition(s) the tor control connection is lost, basically 🤷‍♀️ I'll post more here when I find out more ...

@syphyr if you come up with any way to reliably reproduce this bug that'd be a huge lifesaver.

@bitmold
Copy link
Collaborator

bitmold commented Feb 23, 2022

@n8fr8

My theory right now is that Orbot's UI gets connected to tor because this RawEventListener in tor-android's TorService is firing off:

 /**
     * Announce Tor is available for connections once the first circuit is complete
     */
    private final RawEventListener startedEventListener = new RawEventListener() {
        @Override
        public void onEvent(String keyword, String data) {
            if (TorService.STATUS_STARTING.equals(TorService.currentStatus)
                    && TorControlCommands.EVENT_CIRCUIT_STATUS.equals(keyword)
                    && data != null && data.length() > 0) {
                String[] tokenArray = data.split(" ");
                if (tokenArray.length > 1 && TorControlCommands.CIRC_EVENT_BUILT.equals(tokenArray[1])) {
                    TorService.broadcastStatus(TorService.this, TorService.STATUS_ON);
                }
            }
        }
    };

However, for some reason, the one in OrbotService is not...

@syphyr
Copy link
Contributor Author

syphyr commented Feb 23, 2022

Under some (race) condition(s) the tor control connection is lost, basically woman_shrugging I'll post more here when I find out more ...

@syphyr if you come up with any way to reliably reproduce this bug that'd be a huge lifesaver.

I can usually reproduce this issue by the following steps:

  1. Start Orbot with VPN mode disabled
  2. Start Tor (Select Onion) and wait for connection to finish
  3. Stop Tor (Select Onion)
  4. Settings -> Exit
  5. Repeat steps 1-4 approx. 6-8 times and the error usually occurs.

Using an older/slower android device might make this easier to reproduce since the race condition seems to occur when repeatedly starting and stopping the Orbot application (not just starting and stopping the Tor service within Orbot). Perhaps the application is not starting up fast enough to sync with the Tor service.

This race condition between Orbot and Tor is a very old issue because I can also reproduce it with Orbot 16.0.1.

I did notice that when the notification bar is stuck on "Starting Orbot...", Orbot's UI says the Tor is connected. Why does Orbot's UI message not get stuck at "Starting Orbot" like the notification bar does?

@Michas0206
Copy link

Michas0206 commented Mar 6, 2022

Ah, have not read this before, seems I have the same issue on 2 phones here with 16.6.0 rc3.
On both phones, Orbot's notification got stuck after a reboot almost exactly as described here. Unfortunately I have nothing helpful to solve this atm

Edit:
Seems my Samsung has more problems/is not so stable - on my LG I can solve this issue by pressing the Onion and pressing VPN-Mode inside the app to disconnect and press VPN-mode again to reconnect. The data activity appeared.
Not on my Samsung, it seems it does not connect anymore, the Onion just says "Orbot startet...". It needed a 'hard restart' through long pressing the app and force end, after this it connected fine, also shows activity indicators now.

@bitmold
Copy link
Collaborator

bitmold commented Mar 7, 2022

@eighthave
When I'm able to reproduce this bug It seems I'm stuck in this loop in OrbotService's ServiceConnection implementation for TorService.

 while ((conn = torService.getTorControlConnection()) == null) {
                    try {
                        Thread.sleep(500);
                    } catch (InterruptedException e) {
                        Log.e("bim", e.getLocalizedMessage());
                    }
                }

I haven't gotten into debugging it yet, but it seems like somehow TorService's startTorServiceThread is either crashing or hanging

@bitmold
Copy link
Collaborator

bitmold commented Mar 7, 2022

@eighthave, specifically TorService is stuck here:

if (runLock.isLocked()) {
                        Log.i(TAG, "Waiting for lock");
                    }
                    runLock.lock();

I'm usually able to reproduce this by starting Orbot and then immediately closing and returning to the home screen.

@eighthave
Copy link
Member

eighthave commented Mar 8, 2022 via email

@akwizgran
Copy link

Yes, this one. In the comments I've suggested some possible causes and fixes.

@bitmold
Copy link
Collaborator

bitmold commented Mar 11, 2022

It is, I didn't initially realize that this Orbot UI issue was related on tor-android

@Michas0206
Copy link

Still struggling on this and loosing connections with 16.6.1RC1...sorry but in current state Orbot is almost unusable / a security threat - it is able to "fix" its issues temporarily by disabling/reenabling Vpn-connection - but I assume apps try to connect while disabling this in Orbot, so its not the safest way to handle.

Whatever is causing these problems, please invest ALL your efforts in fixing these stability-problems....users need a stable and safe app, especially when its security relevant.

bitmold added a commit that referenced this issue Apr 20, 2022
…occur, basically Orbot set tor events and then TorService set its own CIRC event which caused the Orbot UI to not update
@bitmold bitmold closed this as completed Jul 26, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants