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

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

Open
ProactiveServices opened this issue Aug 14, 2018 · 9 comments
Open

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

ProactiveServices opened this issue Aug 14, 2018 · 9 comments

Comments

@ProactiveServices
Copy link
Member

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
Copy link
Contributor

Catfriend1 commented Aug 15, 2018

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

@ProactiveServices
Copy link
Member Author

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
Copy link
Contributor

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
Copy link
Member Author

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
Copy link
Contributor

@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
Copy link
Contributor

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
Copy link
Member

calmh commented Aug 23, 2018

@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
Copy link
Contributor

@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
Copy link
Member

calmh commented Aug 23, 2018

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.

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

Successfully merging a pull request may close this issue.

3 participants