search

onionshare / onionshare-android

Android version of OnionShare
https://onionshare.org/
GNU General Public License v3.0
168 stars 18 forks source link

Tor sometimes hangs when bootstrapping at 30% #26

Closed grote closed 1 year ago

grote commented 2 years ago

This is not easy to reproduce, but happens sometimes when testing. After many tries I managed to reproduce and capture logs:

2022-02-01 17:16:14.931 I/o.o.a.t.TorManager: Starting...
2022-02-01 17:16:15.552 D/o.o.a.t.TorManager: TorService: Starting...
2022-02-01 17:16:15.553 I/o.o.a.t.ShareService: OnionService connected
2022-02-01 17:16:18.157 D/o.o.a.t.TorManager: TorService: Started
2022-02-01 17:16:18.168 E/o.o.a.t.TorManager: Starting hidden service...
2022-02-01 17:16:18.170 D/o.o.a.t.TorManager: INFO: hs_service_add_ephemeral: Added ephemeral v3 onion service: [scrubbed]
2022-02-01 17:16:18.412 D/o.o.a.t.TorManager: INFO: connection_edge_process_relay_cell_not_open: 'connected' received for circid 2162404534 streamid 32304 after 0 seconds.
2022-02-01 17:16:18.413 D/o.o.a.t.TorManager: INFO: internal circ (length 1): $D30734EC319A37E15155F6B710E9CC8F987FC772(open)
2022-02-01 17:16:18.413 D/o.o.a.t.TorManager: NOTICE: Bootstrapped 30% (loading_status): Loading networkstatus consensus
2022-02-01 17:16:18.413 D/o.o.a.t.TorManager: STATUS_CLIENT: NOTICE BOOTSTRAP PROGRESS=30 TAG=loading_status SUMMARY="Loading networkstatus consensus"
grote commented 2 years ago

I was asked to create an upstream ticket for this: https://gitlab.torproject.org/tpo/core/tor/-/issues/40558

akwizgran commented 2 years ago

I've been seeing hangs during bootstrapping and also later, when the HS descriptor UPLOAD events have been emitted but the UPLOADED events never seem to arrive. There are lots of CIRC EXTENDED events before Tor stops responding.

Something that might be relevant to OnionShare here but maybe not to upstream Tor is that OnionShare doesn't log any BOOTSTRAP events in this case. The progress bar eventually jumps to 90% due to the UPLOAD events, but it seems like we're missing all the BOOTSTRAP events. Perhaps the events are happening before we register to receive them, in which case we might want to start Tor with DisableNetwork set, and then enable the network when we're ready for it to start bootstrapping?

grote commented 2 years ago

I already noticed the missing BOOTSTRAP events, but assumed that was only because it had already bootstrapped last time and this is still good for this time.

we might want to start Tor with DisableNetwork set

If this helps, sure. Just need to figure out how to do that with tor-android. Custom .torrc maybe.

grote commented 2 years ago

If I add DisableNetwork 1 into TorService.getDefaultsTorrc(), I get:

2022-02-04 11:58:45.064 19304-19324/org.onionshare.android E/AndroidRuntime: FATAL EXCEPTION: ControlSocket
    Process: org.onionshare.android:tor, PID: 19304
    java.lang.StringIndexOutOfBoundsException: String index out of range: -1
        at java.lang.String.substring(String.java:2064)
        at org.torproject.jni.TorService.getPortFromGetInfo(TorService.java:291)
        at org.torproject.jni.TorService.access$600(TorService.java:43)
        at org.torproject.jni.TorService$2.run(TorService.java:276)

Looks like that TorService might always expect network to be enabled and "net/listeners/socks" to be there?

grote commented 2 years ago

Seems to happen almost always when not using the app for some time. When coming back to it, the first sharing hangs at 30%, but subsequent ones always pass.

h2dden commented 2 years ago

I am running GrapheneOS SQ1D.220205.004.2022021721 and I have never mamaged to get past 50%... ![Uploading Screenshot_20220220-185551.png…]()

grote commented 2 years ago

@h2dden could it be that the OnionShare app is routed over Tor e.g. with Orbot in VPN mode? If so, could you please open a new ticket for that?

h2dden commented 2 years ago

no orbot here. onionshare has direct access to the network. is it required to install orbot?

grote commented 2 years ago

No, Orbot is not required. Are you otherwise limiting internet access to Onionshare? Could you share logcat of the Onionshare app after pressing the start button until it gets stuck?

h2dden commented 2 years ago

I will try this afternoon

h2dden commented 2 years ago

I might have rushed declaring that it always fails... I am not using orbot, but I am using bitmask. I am careful to avoid tor over vpn so I make use of the nice features bitmask has and set some app to be excluded from the vpn. when I set the browser to be excluded from vpn I can see my real ip. I have set onionshare to be excluded from the vpn: when I do that, onionshare fails to start sharing. The below log corresponds to this scenario. If I turn off bitmask, onionshare starts sharing correctly Hopefully the below log will show something interesting:

02-22 16:48:33.547 1496 1593 V StorageManagerService: Package org.onionshare.android.nightly does not have legacy storage 02-22 19:53:26.718 955 1712 E cutils : Failed to open(/data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof): No such file or directory 02-22 19:53:26.718 955 1712 E installd: Failed to prepare /data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof: No such file or directory 02-22 19:53:26.718 1496 1582 E ArtManagerService: Failed to prepare profile for org.onionshare.android.nightly:/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/base.apk 02-22 19:53:26.742 1496 1593 V StorageManagerService: Package org.onionshare.android.nightly does not have legacy storage 02-22 19:53:33.449 955 1516 E cutils : Failed to open(/data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof): No such file or directory 02-22 19:53:33.449 955 1516 E installd: Failed to prepare /data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof: No such file or directory 02-22 19:53:33.449 1496 1581 E ArtManagerService: Failed to prepare profile for org.onionshare.android.nightly:/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/base.apk 02-22 19:55:10.690 1496 9260 I ActivityTaskManager: START u10 {act=android.settings.APPLICATION_DETAILS_SETTINGS dat=package:org.onionshare.android.nightly flg=0x10008000 cmp=com.android.settings/.applications.InstalledAppDetails bnds=[472,1227][1039,1374] (has extras)} from uid 1010101 02-22 19:55:11.173 13649 13924 I Role : org.onionshare.android.nightly not qualified for android.app.role.HOME due to missing RequiredComponent{mIntentFilterData=IntentFilterData{mAction='android.intent.action.MAIN', mCategories='[android.intent.category.HOME]', mDataScheme='null', mDataType='null'}, mPermission='null'} 02-22 19:55:11.174 13649 13924 I Role : org.onionshare.android.nightly not qualified for android.app.role.DIALER due to missing RequiredComponent{mIntentFilterData=IntentFilterData{mAction='android.intent.action.DIAL', mCategories='[]', mDataScheme='null', mDataType='null'}, mPermission='null'} 02-22 19:55:11.175 13649 13924 I Role : org.onionshare.android.nightly not qualified for android.app.role.SMS due to missing RequiredComponent{mIntentFilterData=IntentFilterData{mAction='android.provider.Telephony.SMS_DELIVER', mCategories='[]', mDataScheme='null', mDataType='null'}, mPermission='android.permission.BROADCAST_SMS'} 02-22 19:58:27.945 955 1516 E cutils : Failed to open(/data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof): No such file or directory 02-22 19:58:27.945 955 1516 E installd: Failed to prepare /data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof: No such file or directory 02-22 19:58:27.945 1496 1582 E ArtManagerService: Failed to prepare profile for org.onionshare.android.nightly:/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/base.apk 02-22 19:58:27.984 1496 1593 V StorageManagerService: Package org.onionshare.android.nightly does not have legacy storage 02-22 19:58:33.870 955 1516 E cutils : Failed to open(/data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof): No such file or directory 02-22 19:58:33.870 955 1516 E installd: Failed to prepare /data/misc/profiles/cur/10/org.onionshare.android.nightly/primary.prof: No such file or directory 02-22 19:58:33.870 1496 1581 E ArtManagerService: Failed to prepare profile for org.onionshare.android.nightly:/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/base.apk 02-22 19:59:17.270 1496 9935 I ActivityTaskManager: START u10 {act=android.settings.APPLICATION_DETAILS_SETTINGS dat=package:org.onionshare.android.nightly flg=0x10008000 cmp=com.android.settings/.applications.InstalledAppDetails bnds=[472,1227][1039,1374] (has extras)} from uid 1010101 02-22 19:59:17.662 16194 16235 I Role : org.onionshare.android.nightly not qualified for android.app.role.HOME due to missing RequiredComponent{mIntentFilterData=IntentFilterData{mAction='android.intent.action.MAIN', mCategories='[android.intent.category.HOME]', mDataScheme='null', mDataType='null'}, mPermission='null'} 02-22 19:59:17.663 16194 16235 I Role : org.onionshare.android.nightly not qualified for android.app.role.DIALER due to missing RequiredComponent{mIntentFilterData=IntentFilterData{mAction='android.intent.action.DIAL', mCategories='[]', mDataScheme='null', mDataType='null'}, mPermission='null'} 02-22 19:59:17.664 16194 16235 I Role : org.onionshare.android.nightly not qualified for android.app.role.SMS due to missing RequiredComponent{mIntentFilterData=IntentFilterData{mAction='android.provider.Telephony.SMS_DELIVER', mCategories='[]', mDataScheme='null', mDataType='null'}, mPermission='android.permission.BROADCAST_SMS'} 02-22 19:59:42.116 1496 5516 I ActivityTaskManager: START u10 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity bnds=[439,1343][641,1681]} from uid 1010101 02-22 19:59:42.167 1496 1594 I ActivityManager: Start proc 18299:org.onionshare.android.nightly/u10a152 for pre-top-activity {org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity} 02-22 19:59:42.168 18299 18299 W Zygote : Can't access app profile directory: /data_mirror/cur_profiles/10/org.onionshare.android.nightly 02-22 19:59:42.370 18299 18299 V GraphicsEnvironment: ANGLE Developer option for 'org.onionshare.android.nightly' set to: 'default' 02-22 19:59:42.370 18299 18299 V GraphicsEnvironment: ANGLE GameManagerService for org.onionshare.android.nightly: false 02-22 19:59:42.392 18299 18319 D vulkan : searching for layers in '/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/lib/arm64' 02-22 19:59:42.392 18299 18319 D vulkan : searching for layers in '/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/base.apk!/lib/arm64-v8a' 02-22 19:59:42.407 18299 18319 D mali_cmarp_predictor: checking cmar_predictor for org.onionshare.android.nightly 02-22 19:59:42.645 1496 1581 I ActivityTaskManager: Displayed org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity: +518ms 02-22 19:59:43.016 1496 5516 W InputManager-JNI: Input channel object 'a0ede1c Splash Screen org.onionshare.android.nightly (client)' was disposed without first being removed with the input manager! 02-22 19:59:48.051 18299 18299 D o.o.a.t.ShareService: onStartCommand Intent { cmp=org.onionshare.android.nightly/org.onionshare.android.tor.ShareService } 02-22 19:59:48.089 1496 1594 I ActivityManager: Start proc 18413:org.onionshare.android.nightly:tor/u10a152 for service {org.onionshare.android.nightly/org.onionshare.android.tor.OnionService} 02-22 19:59:48.092 18413 18413 W Zygote : Can't access app profile directory: /data_mirror/cur_profiles/10/org.onionshare.android.nightly 02-22 19:59:48.177 18413 18413 V GraphicsEnvironment: ANGLE Developer option for 'org.onionshare.android.nightly' set to: 'default' 02-22 19:59:48.178 18413 18413 V GraphicsEnvironment: ANGLE GameManagerService for org.onionshare.android.nightly: false 02-22 19:59:48.182 18413 18413 W oid.nightly:tor: type=1400 audit(0.0:65510): avc: granted { execute } for path="/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/lib/arm64/libtor.so" dev="dm-20" ino=115102 scontext=u:r:untrusted_app:s0:c152,c256,c522,c768 tcontext=u:object_r:apk_data_file:s0 tclass=file 02-22 19:59:48.194 18413 18413 E linker : "/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/lib/arm64/libtor.so": ignoring DT_PREINIT_ARRAY in shared library! 02-22 19:59:58.090 1872 1872 D InterruptionStateProvider: No bubble up: not allowed to bubble: 10|org.onionshare.android.nightly|1|null|1010152 02-22 19:59:58.091 1872 1872 D InterruptionStateProvider: No heads up: unimportant notification: 10|org.onionshare.android.nightly|1|null|1010152 02-22 19:59:58.092 1872 1972 D PeopleSpaceWidgetMgr: Sbn doesn't contain valid PeopleTileKey: null/10/org.onionshare.android.nightly 02-22 20:00:15.856 1872 1872 D SystemUIToast: user hasn't been fully initialized, not showing an app icon for packageName=org.onionshare.android.nightly 02-22 20:00:18.498 1496 2414 W NotificationService: Toast already killed. pkg=org.onionshare.android.nightly token=android.os.BinderProxy@c83d874 02-22 20:01:27.334 1872 1972 D PeopleSpaceWidgetMgr: Sbn doesn't contain valid PeopleTileKey: null/10/org.onionshare.android.nightly 02-22 20:01:27.991 1496 9935 I ActivityManager: Process org.onionshare.android.nightly:tor (pid 18413) has died: fg SVC 02-22 20:01:37.882 1496 9935 I InputDispatcher: Monitor swipe-up (server) is stealing touch from [74d1076 org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity (server), ] 02-22 20:01:39.197 1496 1584 I ActivityManager: Killing 18299:org.onionshare.android.nightly/u10a152 (adj 905): remove task 02-22 20:01:39.306 1496 6895 I WindowManager: WIN DEATH: Window{74d1076 u10 org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity} 02-22 20:01:39.306 1496 6895 W InputManager-JNI: Input channel object '74d1076 org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity (client)' was disposed without first being removed with the input manager! 02-22 20:01:39.318 1496 1592 W UsageStatsService: Unexpected activity event reported! (org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity event : 23 instanceId : 213759550) 02-22 20:01:49.190 16566 16566 D openvpn : adding to allowed appsorg.onionshare.android.nightly 02-22 20:01:50.112 16566 16566 D openvpn : adding to allowed appsorg.onionshare.android.nightly 02-22 20:01:51.550 16566 16566 D openvpn : removing from allowed appsorg.onionshare.android.nightly 02-22 20:01:52.332 16566 16566 D openvpn : adding to allowed appsorg.onionshare.android.nightly 02-22 20:02:14.532 1496 8449 I ActivityTaskManager: START u10 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity bnds=[439,1343][641,1681]} from uid 1010101 02-22 20:02:14.572 1496 1594 I ActivityManager: Start proc 18543:org.onionshare.android.nightly/u10a152 for pre-top-activity {org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity} 02-22 20:02:14.575 18543 18543 W Zygote : Can't access app profile directory: /data_mirror/cur_profiles/10/org.onionshare.android.nightly 02-22 20:02:14.622 18543 18543 V GraphicsEnvironment: ANGLE Developer option for 'org.onionshare.android.nightly' set to: 'default' 02-22 20:02:14.622 18543 18543 V GraphicsEnvironment: ANGLE GameManagerService for org.onionshare.android.nightly: false 02-22 20:02:14.635 18543 18562 D vulkan : searching for layers in '/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/lib/arm64' 02-22 20:02:14.635 18543 18562 D vulkan : searching for layers in '/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/base.apk!/lib/arm64-v8a' 02-22 20:02:14.639 18543 18562 D mali_cmarp_predictor: checking cmar_predictor for org.onionshare.android.nightly 02-22 20:02:14.809 1496 1581 I ActivityTaskManager: Displayed org.onionshare.android.nightly/org.onionshare.android.ui.MainActivity: +268ms 02-22 20:02:15.173 1496 9935 W InputManager-JNI: Input channel object '7b22785 Splash Screen org.onionshare.android.nightly (client)' was disposed without first being removed with the input manager! 02-22 20:02:19.735 18543 18543 D o.o.a.t.ShareService: onStartCommand Intent { cmp=org.onionshare.android.nightly/org.onionshare.android.tor.ShareService } 02-22 20:02:19.757 1496 1594 I ActivityManager: Start proc 18605:org.onionshare.android.nightly:tor/u10a152 for service {org.onionshare.android.nightly/org.onionshare.android.tor.OnionService} 02-22 20:02:19.762 18605 18605 W Zygote : Can't access app profile directory: /data_mirror/cur_profiles/10/org.onionshare.android.nightly 02-22 20:02:19.833 18605 18605 V GraphicsEnvironment: ANGLE Developer option for 'org.onionshare.android.nightly' set to: 'default' 02-22 20:02:19.833 18605 18605 V GraphicsEnvironment: ANGLE GameManagerService for org.onionshare.android.nightly: false 02-22 20:02:19.841 18605 18605 E linker : "/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/lib/arm64/libtor.so": ignoring DT_PREINIT_ARRAY in shared library! 02-22 20:02:19.834 18605 18605 W oid.nightly:tor: type=1400 audit(0.0:65670): avc: granted { execute } for path="/data/app/~~AUy8LcOEGwBobQqFSExLAg==/org.onionshare.android.nightly-OO7TNlszhfW5uKZHXkgtPQ==/lib/arm64/libtor.so" dev="dm-20" ino=115102 scontext=u:r:untrusted_app:s0:c152,c256,c522,c768 tcontext=u:object_r:apk_data_file:s0 tclass=file 02-22 20:02:29.807 1872 1872 D InterruptionStateProvider: No bubble up: not allowed to bubble: 10|org.onionshare.android.nightly|1|null|1010152 02-22 20:02:29.810 1872 1872 D InterruptionStateProvider: No heads up: unimportant notification: 10|org.onionshare.android.nightly|1|null|1010152 02-22 20:02:29.812 1872 1972 D PeopleSpaceWidgetMgr: Sbn doesn't contain valid PeopleTileKey: null/10/org.onionshare.android.nightly 02-22 20:03:18.542 1872 1972 D PeopleSpaceWidgetMgr: Sbn doesn't contain valid PeopleTileKey: null/10/org.onionshare.android.nightly 02-22 20:03:19.193 1496 9935 I ActivityManager: Process org.onionshare.android.nightly:tor (pid 18605) has died: fg SVC

grote commented 2 years ago

User beta feedback from Google Play:

Feedback1:

First time i tested, it would infinitely try to share with no progress.
restarted and tried again, finally provided a link but then the browser was infinitely loading the link (again with no progress)

Feedback2:

Tried to send a 1 mb jpeg file but it paused on starting for 5 minutes on my android 11. No receive option.

grote commented 2 years ago

After switching our tor control approach, I haven't seen this again.