search

syncthing / syncthing-android

Wrapper of syncthing for Android.
https://syncthing.net/
Mozilla Public License 2.0
3.62k stars 406 forks source link

Crash with "Explicit termination method 'close' not called" #1217

Open ProactiveServices opened 6 years ago

ProactiveServices commented 6 years ago

I switched off power saving mode on my Android and noticed Syncthing's notification icon shuffled, then found this in the log. Syncthing is set to respect battery saving mode.

App Version: 0.10.13 Syncthing Version: v0.14.49-dirty Android Version: Android 5.0.2

--------- beginning of main 08-13 12:12:41.513 W/KeyCharacterMap(16825): Load KCM of non-default device may incur unexpected result. Device ID:9 08-13 12:12:42.314 E/StrictMode(16825): A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks. 08-13 12:12:42.314 E/StrictMode(16825): java.lang.Throwable: Explicit termination method 'close' not called 08-13 12:12:42.314 E/StrictMode(16825): at dalvik.system.CloseGuard.open(CloseGuard.java:184) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.org.conscrypt.OpenSSLSocketImpl.startHandshake(OpenSSLSocketImpl.java:271) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.Connection.upgradeToTls(Connection.java:197) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.Connection.connect(Connection.java:151) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:276) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:211) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.internal.http.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:373) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.internal.http.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:323) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.internal.http.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:491) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.internal.http.DelegatingHttpsURLConnection.getResponseCode(DelegatingHttpsURLConnection.java:105) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.okhttp.internal.http.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:25) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.volley.toolbox.HurlStack.executeRequest(HurlStack.java:99) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.volley.toolbox.BasicNetwork.performRequest(BasicNetwork.java:131) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.volley.NetworkDispatcher.processRequest(NetworkDispatcher.java:120) 08-13 12:12:42.314 E/StrictMode(16825): at com.android.volley.NetworkDispatcher.run(NetworkDispatcher.java:87) 08-13 12:12:42.774 I/Choreographer(16825): Skipped 43 frames! The application may be doing too much work on its main thread. 08-13 12:12:48.430 I/System (16825): exec(/system/bin/logcat -t 300 -v time -s SyncthingNativeCode @ com.nutomic.syncthingandroid.activities.LogActivity$UpdateLogTask.getLog:155) 08-13 12:12:53.075 I/System (16825): exec(/system/bin/logcat -t 300 -v time *:i ps:s art:s @ com.nutomic.syncthingandroid.activities.LogActivity$UpdateLogTask.getLog:155) 08-13 12:12:53.115 W/InputEventReceiver(16825): Attempted to finish an input event but the input event receiver has already been disposed.

Catfriend1 commented 6 years ago

Could you please try to reproduce it with this debug build and tell me what the "status" tab says?

ProactiveServices commented 6 years ago

The conditions/settings listed in the Status tab are the same from when I had the crash: Syncthing is running. Allowed to run on mobile data, but not connected Allowed to run on WiFi and connected Allowed to run on non-metered WiFi. Active WiFi is non-metered. Allowed to run on the current WiFi.

In the options: Run when devices is powered by AC and battery. Respect battery saving setting: Enabled Respect Auto-sync data setting: Disabled

When I switch on power saving Syncthing is still running, the status pane is unchanged. I tried exiting and quitting the app, and starting it in power saving mode and the same happens. I can see in the Android options that power saving is enabled.

Catfriend1 commented 6 years ago

Ok I've to check the run conditions, recalling there was some code that has been for long in the app to detect power save mode but the code only works on android L or higher. This was taken over by my latest PR as is, maybe theres a bug.

ProactiveServices commented 6 years ago

Crashed again and this time the Android log mentions a Syncthing crash, and I received a notification of the crash. The Syncthing logfile only showed the first few lines of a regular start-up and nothing else after folders being ready. I think (but not sure) that I had turned off WiFi at the time. I may have enabled Power Save but not sure. I'm using the debug build you linked earlier.

--------- beginning of main 08-18 00:42:14.005 I/SyncthingNativeCode(14485): [YECXW] INFO: My ID: YECXW42- 08-18 00:42:14.936 E/StrictMode(14485): A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks. 08-18 00:42:14.936 E/StrictMode(14485): java.lang.Throwable: Explicit termination method 'close' not called 08-18 00:42:14.936 E/StrictMode(14485): at dalvik.system.CloseGuard.open(CloseGuard.java:184) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.org.conscrypt.OpenSSLSocketImpl.startHandshake(OpenSSLSocketImpl.java:271) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.Connection.upgradeToTls(Connection.java:197) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.Connection.connect(Connection.java:151) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.internal.http.HttpEngine.connect(HttpEngine.java:276) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.internal.http.HttpEngine.sendRequest(HttpEngine.java:211) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.internal.http.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:373) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.internal.http.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:323) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.internal.http.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:491) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.internal.http.DelegatingHttpsURLConnection.getResponseCode(DelegatingHttpsURLConnection.java:105) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.okhttp.internal.http.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:25) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.volley.toolbox.HurlStack.executeRequest(HurlStack.java:99) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.volley.toolbox.BasicNetwork.performRequest(BasicNetwork.java:131) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.volley.NetworkDispatcher.processRequest(NetworkDispatcher.java:120) 08-18 00:42:14.936 E/StrictMode(14485): at com.android.volley.NetworkDispatcher.run(NetworkDispatcher.java:87) 08-18 00:42:15.006 I/System (14485): exec(sh @ com.nutomic.syncthingandroid.service.SyncthingRunnable.getSyncthingPIDs:229) 08-18 00:42:15.366 I/System (14485): exec(sh @ com.nutomic.syncthingandroid.util.Util.runShellCommand:181) 08-18 00:42:16.397 I/SyncthingNativeCode(14485): [YECXW] INFO: Hashing performance is 14.37 MB/s 08-18 00:42:16.417 I/System (14485): exec(sh @ com.nutomic.syncthingandroid.service.SyncthingRunnable.getSyncthingPIDs:229) 08-18 00:42:19.120 I/SyncthingNativeCode(14485): [YECXW] INFO: Ready to synchronize (sendreceive) 08-18 00:42:19.140 I/SyncthingNativeCode(14485): [YECXW] INFO: Ready to synchronize (sendreceive) 08-18 00:42:19.190 I/SyncthingNativeCode(14485): [YECXW] INFO: Ready to synchronize (sendreceive) 08-18 00:42:19.240 I/SyncthingNativeCode(14485): [YECXW] INFO: Ready to synchronize (sendreceive) 08-18 00:42:19.250 I/SyncthingNativeCode(14485): [YECXW] INFO: Ready to synchronize (sendreceive) 08-18 00:42:19.260 I/SyncthingNativeCode(14485): [YECXW] INFO: Ready to synchronize (sendreceive) 08-18 00:42:19.361 I/SyncthingNativeCode(14485): [YECXW] INFO: Ready to synchronize (sendreceive) 08-18 00:42:19.571 I/System (14485): exec(sh @ com.nutomic.syncthingandroid.util.Util.runShellCommand:181) 08-18 00:42:19.661 I/SyncthingRunnable(14485): Syncthing exited with code 9 08-18 00:42:19.661 W/SyncthingRunnable(14485): Syncthing has crashed (exit code 9) 08-18 01:13:40.572 I/System (14485): exec(/system/bin/logcat -t 300 -v time -s SyncthingNativeCode @ com.nutomic.syncthingandroid.activities.LogActivity$UpdateLogTask.getLog:155) 08-18 01:13:49.821 I/System (14485): exec(/system/bin/logcat -t 300 -v time *:i ps:s art:s @ com.nutomic.syncthingandroid.activities.LogActivity$UpdateLogTask.getLog:155)

Catfriend1 commented 6 years ago

@ProactiveServices : ( When I switch on power saving Syncthing is still running, ) I cannot reproduce this. If I enable power saving mode on my phone, this happens expectedly: image Disabling power save mode runs syncthing again. image Does the problem still persist in the latest rc . I've added the status tab in my fork: https://github.com/Catfriend1/syncthing-android/releases

Catfriend1 commented 6 years ago

I'm currently working on this on my branch.

W/SyncthingRunnable(14485): Syncthing has crashed (exit code 9) The crash handler is little bit outdated, so I'm improving it with the UI telling if syncthing crashed and showing the notification under correct circumstances. When I've tested through enough, I'll make a new RC.

calmh commented 6 years ago

@Catfriend1 That's great, if you intend to contribute this fix back. If this is stuff that you do in your fork and intend to stay in your fork, please do not involve the issue tracker of this project in it.

Catfriend1 commented 6 years ago

@calmh Maybe I'll come back one day when I've more time to do the review stuff with the reviewers. For the moment, I'm pushing development on the app forward as it still has major problems on Android 8 and Android 9 which I will use in the near future on my phone. I'm always glad if I can help. For now, it's up to the maintainers if they like to cherry-pick my fixes in here and up to the users which version they like to use. I've filed "proper" PR's against my fork repo, so it shouldn't be too hard to get this over if desired.

calmh commented 6 years ago

Great, you're welcome to do so and always welcome back. But unless you intend to file fixes here, please keep discussion to your own issue tracker.