Gadgetbridge gets silently killed and restarted #134

Closed
opened 6 years ago by ashimokawa · 25 comments
Owner

Sometimes Android kills the Gadgerprocess, probably when a generic notification arrives.
There is no dialog that indicates that it was killed.
The service gets restarted but the device does not get reconnected.
This behavior was described in #89

I will provide more details later

Sometimes Android kills the Gadgerprocess, probably when a generic notification arrives. There is no dialog that indicates that it was killed. The service gets restarted but the device does not get reconnected. This behavior was described in #89 I will provide more details later
glitchphan commented 6 years ago (Migrated from github.com)
Poster
Owner

Where do log files get written to when you check the log option? Seems the latest version is disconnecting more than ever, and I enabled logging for a bit to capture a disconnect or two.

Where do log files get written to when you check the log option? Seems the latest version is disconnecting more than ever, and I enabled logging for a bit to capture a disconnect or two.
Owner

@glitchphan See the new entry in https://github.com/Freeyourgadget/Gadgetbridge/wiki/User-Documentation

And yes, we should make that file or its location more accesible in Gadgetbridge itself.

@glitchphan See the new entry in https://github.com/Freeyourgadget/Gadgetbridge/wiki/User-Documentation And yes, we should make that file or its location more accesible in Gadgetbridge itself.
glitchphan commented 6 years ago (Migrated from github.com)
Poster
Owner

I had looked there, but apparently "needs restart" meant the device, not just the app. :) Try #2..

I had looked there, but apparently "needs restart" meant the device, not just the app. :) Try #2..
Poster
Owner

no, just the app needs restart.

no, just the app needs restart.
glitchphan commented 6 years ago (Migrated from github.com)
Poster
Owner

For whatever reason, the log file didn't show up until I restarted the phone. Now I've been waiting for a disconnect to happen again.. I didn't want to jinx it by posting, but it hasn't happened yet. Maybe the trick is just to keep logging enabled :D.

For whatever reason, the log file didn't show up until I restarted the phone. Now I've been waiting for a disconnect to happen again.. I didn't want to jinx it by posting, but it hasn't happened yet. Maybe the trick is just to keep logging enabled :D.
Poster
Owner

@glitchphan
I do not think the logs will contain anything useful. :(
I saw that the OS killed Gadgetbridge on purpose that won't be visible in the logs...

@glitchphan I do not think the logs will contain anything useful. :( I saw that the OS killed Gadgetbridge on purpose that won't be visible in the logs...
Owner

I'll have a look at fixing this.

I'll have a look at fixing this.
glitchphan commented 6 years ago (Migrated from github.com)
Poster
Owner

Is it odd that it hasn't happened since logging was turned on?

Is it odd that it hasn't happened since logging was turned on?
Poster
Owner

@glitchphan
Ok I will turn logging off, and see if is starts to happen again.

@glitchphan Ok I will turn logging off, and see if is starts to happen again.
Owner

It's strange that the force-close dialog is not shown. I've never seen that. Maybe out-of-memory situation?

It's strange that the force-close dialog is not shown. I've never seen that. Maybe out-of-memory situation?
Owner

FWIW, see this javadoc of the Application class:

/**
 * This method is for use in emulated process environments.  It will
 * never be called on a production Android device, where processes are
 * removed by simply killing them; no user code (including this callback)
 * is executed when doing so.
 */
@CallSuper
public void onTerminate() {
}
FWIW, see this javadoc of the Application class: ``` /** * This method is for use in emulated process environments. It will * never be called on a production Android device, where processes are * removed by simply killing them; no user code (including this callback) * is executed when doing so. */ @CallSuper public void onTerminate() { } ```
Poster
Owner

@cpfeiffer
I do not think it was a OOM situation.
Since we are a foreground service we should be killed last.
We were killed on purpose though (I think it was a policy violation in the NotificationListener Service).

@cpfeiffer I do not think it was a OOM situation. Since we are a foreground service we should be killed last. We were killed on purpose though (I think it was a policy violation in the NotificationListener Service).
Owner

Well in that case, the javadoc of Application.terminate() is probably the answer.

We could only

  • fix the listener
  • make sure to reconnect after restart
Well in that case, the javadoc of Application.terminate() is probably the answer. We could only - fix the listener - make sure to reconnect after restart
Poster
Owner
D/BackupManagerService(  592): Received broadcast Intent { act=android.intent.action.PACKAGE_CHANGED dat=package:nodomain.freeyourgadget.gadgetbridge flg=0x4000010 (has extras) }M
V/NotificationListeners(  592): disabling notification listener for user 0: ComponentInfo{org.cyanogenmod.theme.chooser/org.cyanogenmod.theme.chooser.NotificationHijackingService}M
V/NotificationListeners(  592): disabling notification listener for user 0: ComponentInfo{nodomain.freeyourgadget.gadgetbridge/nodomain.freeyourgadget.gadgetbridge.externalevents.NotificationListener}M
I/ActivityManager(  592): Killing 1581:nodomain.freeyourgadget.gadgetbridge/u0a91 (adj 0): remove taskM
W/bt-l2cap( 4155): L2CA_SetDesireRole() new:x0, disallow_switch:0M
W/bt-rfcomm( 4155): rfc_port_closedM
W/bt-btif ( 4155): bta_jv_rfc_port_to_cb(port_handle:0x8):jv handle:0x0 not FOUNDM
E/bt-btif ( 4155): bta_jv_port_mgmt_cl_cback, p_cb:0x0, p_cb->p_cback:0x0, p_pcbM
W/bt-l2cap( 4155): L2CA_DisconnectReq()  CID: 0x0041M
W/bt-l2cap( 4155): L2CAP - st: W4_L2CAP_DISC_RSP evt: 18M
W/Searchables(  592): No global search activity foundM
W/ActivityManager(  592): Exception when unbinding service nodomain.freeyourgadget.gadgetbridge/.externalevents.NotificationListenerM
W/ActivityManager(  592): android.os.DeadObjectExceptionM
W/ActivityManager(  592):       at android.os.BinderProxy.transactNative(Native Method)M
W/ActivityManager(  592):       at android.os.BinderProxy.transact(Binder.java:496)M
W/ActivityManager(  592):       at android.app.ApplicationThreadProxy.scheduleUnbindService(ApplicationThreadNative.java:921)M
W/ActivityManager(  592):       at com.android.server.am.ActiveServices.removeConnectionLocked(ActiveServices.java:1796)M
W/ActivityManager(  592):       at com.android.server.am.ActiveServices.unbindServiceLocked(ActiveServices.java:916)M
W/ActivityManager(  592):       at com.android.server.am.ActivityManagerService.unbindService(ActivityManagerService.java:15629)M
W/ActivityManager(  592):       at android.app.ContextImpl.unbindService(ContextImpl.java:1842)M
W/ActivityManager(  592):       at com.android.server.notification.ManagedServices.unregisterService(ManagedServices.java:448)M
W/ActivityManager(  592):       at com.android.server.notification.ManagedServices.rebindServices(ManagedServices.java:324)M
W/ActivityManager(  592):       at com.android.server.notification.ManagedServices.onPackagesChanged(ManagedServices.java:162)M
W/ActivityManager(  592):       at com.android.server.notification.NotificationManagerService$2.onReceive(NotificationManagerService.java:817)M
W/ActivityManager(  592):       at android.app.LoadedApk$ReceiverDispatcher$Args.run(LoadedApk.java:867)M
W/ActivityManager(  592):       at android.os.Handler.handleCallback(Handler.java:739)M
W/ActivityManager(  592):       at android.os.Handler.dispatchMessage(Handler.java:95)M
W/ActivityManager(  592):       at android.os.Looper.loop(Looper.java:135)M
W/ActivityManager(  592):       at com.android.server.SystemServer.run(SystemServer.java:298)M
W/ActivityManager(  592):       at com.android.server.SystemServer.main(SystemServer.java:186)M
W/ActivityManager(  592):       at java.lang.reflect.Method.invoke(Native Method)M
W/ActivityManager(  592):       at java.lang.reflect.Method.invoke(Method.java:372)M
W/ActivityManager(  592):       at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:904)M
W/ActivityManager(  592):       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:699)M
<pre> D/BackupManagerService( 592): Received broadcast Intent { act=android.intent.action.PACKAGE_CHANGED dat=package:nodomain.freeyourgadget.gadgetbridge flg=0x4000010 (has extras) }M V/NotificationListeners( 592): disabling notification listener for user 0: ComponentInfo{org.cyanogenmod.theme.chooser/org.cyanogenmod.theme.chooser.NotificationHijackingService}M V/NotificationListeners( 592): disabling notification listener for user 0: ComponentInfo{nodomain.freeyourgadget.gadgetbridge/nodomain.freeyourgadget.gadgetbridge.externalevents.NotificationListener}M I/ActivityManager( 592): Killing 1581:nodomain.freeyourgadget.gadgetbridge/u0a91 (adj 0): remove taskM W/bt-l2cap( 4155): L2CA_SetDesireRole() new:x0, disallow_switch:0M W/bt-rfcomm( 4155): rfc_port_closedM W/bt-btif ( 4155): bta_jv_rfc_port_to_cb(port_handle:0x8):jv handle:0x0 not FOUNDM E/bt-btif ( 4155): bta_jv_port_mgmt_cl_cback, p_cb:0x0, p_cb->p_cback:0x0, p_pcbM W/bt-l2cap( 4155): L2CA_DisconnectReq() CID: 0x0041M W/bt-l2cap( 4155): L2CAP - st: W4_L2CAP_DISC_RSP evt: 18M W/Searchables( 592): No global search activity foundM W/ActivityManager( 592): Exception when unbinding service nodomain.freeyourgadget.gadgetbridge/.externalevents.NotificationListenerM W/ActivityManager( 592): android.os.DeadObjectExceptionM W/ActivityManager( 592): at android.os.BinderProxy.transactNative(Native Method)M W/ActivityManager( 592): at android.os.BinderProxy.transact(Binder.java:496)M W/ActivityManager( 592): at android.app.ApplicationThreadProxy.scheduleUnbindService(ApplicationThreadNative.java:921)M W/ActivityManager( 592): at com.android.server.am.ActiveServices.removeConnectionLocked(ActiveServices.java:1796)M W/ActivityManager( 592): at com.android.server.am.ActiveServices.unbindServiceLocked(ActiveServices.java:916)M W/ActivityManager( 592): at com.android.server.am.ActivityManagerService.unbindService(ActivityManagerService.java:15629)M W/ActivityManager( 592): at android.app.ContextImpl.unbindService(ContextImpl.java:1842)M W/ActivityManager( 592): at com.android.server.notification.ManagedServices.unregisterService(ManagedServices.java:448)M W/ActivityManager( 592): at com.android.server.notification.ManagedServices.rebindServices(ManagedServices.java:324)M W/ActivityManager( 592): at com.android.server.notification.ManagedServices.onPackagesChanged(ManagedServices.java:162)M W/ActivityManager( 592): at com.android.server.notification.NotificationManagerService$2.onReceive(NotificationManagerService.java:817)M W/ActivityManager( 592): at android.app.LoadedApk$ReceiverDispatcher$Args.run(LoadedApk.java:867)M W/ActivityManager( 592): at android.os.Handler.handleCallback(Handler.java:739)M W/ActivityManager( 592): at android.os.Handler.dispatchMessage(Handler.java:95)M W/ActivityManager( 592): at android.os.Looper.loop(Looper.java:135)M W/ActivityManager( 592): at com.android.server.SystemServer.run(SystemServer.java:298)M W/ActivityManager( 592): at com.android.server.SystemServer.main(SystemServer.java:186)M W/ActivityManager( 592): at java.lang.reflect.Method.invoke(Native Method)M W/ActivityManager( 592): at java.lang.reflect.Method.invoke(Method.java:372)M W/ActivityManager( 592): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:904)M W/ActivityManager( 592): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:699)M </pre>
Poster
Owner

Maybe it is our fault because we use the package manager to turn receivers on and off, and that triggers the BackupManager thinking the apk has changed?

Maybe it is our fault because we use the package manager to turn receivers on and off, and that triggers the BackupManager thinking the apk has changed?
Owner

Did you notice that it is exactly the NotificationListener causing the problem, which is the only receiver that we do not dynamically enable and disable?

Did you notice that it is exactly the _NotificationListener_ causing the problem, which is the only receiver that we **do not** dynamically enable and disable?
Owner

I don't think disabling the BackupManager is the right way to do it.

  1. allowing backups should be a good thing (unless your activity backups are synced to some proprietary cloud service)
  2. there may be (now or in the future) other listeners that will exhibit the same problem
I don't think disabling the BackupManager is the right way to do it. 1. allowing backups should be a good thing (unless your activity backups are synced to some proprietary cloud service) 2. there may be (now or in the future) other listeners that will exhibit the same problem
Poster
Owner

@cpfeiffer
I agree regarding 1. but I don't really think it is the listeners fault, we are being killed on purpose for whatever reason.

@cpfeiffer I agree regarding 1. but I don't really think it is the listeners fault, we are being killed on purpose for whatever reason.
Poster
Owner

FYI, I just tagged 0.6.3 with allowBackup="false".
Feedback is appreciated, build should show up in f-droid soon.

FYI, I just tagged 0.6.3 with allowBackup="false". Feedback is appreciated, build should show up in f-droid soon.
Poster
Owner

The bug was still there in 0.6.3, hopefully the current git is better.

The bug was still there in 0.6.3, hopefully the current git is better.
glitchphan commented 6 years ago (Migrated from github.com)
Poster
Owner

Yeah, the first couple of days of 0.6.3 were the worst, but it seems to be back to the normal only disconnecting a few times a day :). One time, on the first day, I tapped to connect (and it did because I checked my watch), went to home screen, pulled down the notification drawer, and watched the Gadgetbridge notification change from connected to not connected.

Yeah, the first couple of days of 0.6.3 were the worst, but it seems to be back to the normal only disconnecting a few times a day :). One time, on the first day, I tapped to connect (and it did because I checked my watch), went to home screen, pulled down the notification drawer, and watched the Gadgetbridge notification change from connected to not connected.
Poster
Owner

@glitchphan
That's bad. And something completely different then. :/

If it changes from "connected" to "not connected" it means that the connection was closed but Gadgetbridge was not killed (else it would display "Gadgerbridge is running")

This bug is about Gadgetbridge getting killed by the OS and restarted.

Do you have any logs for your bug?

@glitchphan That's bad. And something completely different then. :/ If it changes from "connected" to "not connected" it means that the connection was closed but Gadgetbridge was not killed (else it would display "Gadgerbridge is running") This bug is about Gadgetbridge getting killed by the OS and restarted. Do you have any logs for your bug?
Owner

This issue should be fixed -- @glitchphan, please create a new issue for your disconnection problem.

This issue should be fixed -- @glitchphan, please create a new issue for your disconnection problem.
glitchphan commented 6 years ago (Migrated from github.com)
Poster
Owner

I guess I have seen both, then. Unfortunately I had just turned off logging again before installing newer version. I will test the next one with and without, and report back.

I guess I have seen both, then. Unfortunately I had just turned off logging again before installing newer version. I will test the next one with and without, and report back.
Poster
Owner

@glitchphan
0.6.4 has been tagged, hope this issue is really fixed.

@glitchphan 0.6.4 has been tagged, hope this issue is really fixed.
Sign in to join this conversation.
No Milestone
No Assignees
2 Participants
Notifications
Due Date

No due date set.

Dependencies

This issue currently doesn't have any dependencies.

Loading…
There is no content yet.