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

2 minutes delay of System Out Intent #128

Closed
daimoniuma opened this Issue Nov 12, 2016 · 15 comments

Comments

3 participants
@daimoniuma

daimoniuma commented Nov 12, 2016

Seems like I got serious memory leaks on Xposed Bridge. I disabled all modules while captured this issues. Also Xposed freezes my package manager: intent "package installed/updated" comes within a big delay (1-2 minutes). Impossible to install next apk while this delay from previous installation.

tmp_9327-Memory Leaks from Xposed-946719000.zip

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 12, 2016

Periodically my system becomes very busy, it can drops down SystemUI (visually navbar & statusbar go away), then it will be reloaded within 1-5 minutes of lagging.

@rovo89

This comment has been minimized.

Owner

rovo89 commented Nov 12, 2016

Ehrm.. are you referring to these?

android.app.ServiceConnectionLeaked: Service com.uei.control.Service has leaked ServiceConnection com.uei.control.j@165ca41 that was originally bound here
android.app.ServiceConnectionLeaked: Service com.google.android.finsky.billing.iab.InAppBillingService has leaked ServiceConnection com.google.android.finsky.billing.iab.InAppEmulation$1@1405cddb that was originally bound here

Why do you think these are related to XposedBridge? The messages clearly say which services are the culprit.

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 12, 2016

Yes. The last line: «at Xposed Bridge». I'm on stock firmware, where is nothing corrupt... was.

As I said, Bridge already take affection on my Package Installer (lock after installing within some minutes). If I disable Bridge (without modules), I get back quick updating through Google Play without delay.

What is com.uei.control? I captured it after updating through Google Play, when my system was overloaded. Seems like system process. It never was broken before Xposed.

I think all this problems are linked between themself & Xposed Bridge.

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 12, 2016

com.uei.lg.quicksetsdk.lite

It is a IR controller (SDK, for UI there is other app) for LG devices (system app).

@rovo89

This comment has been minimized.

Owner

rovo89 commented Nov 12, 2016

Yes. The last line: «at Xposed Bridge».

That line is there in every single stack trace when Xposed is installed. It isn't related to the leaked services or any other crashes at all.

lock after installing within some minutes

Can you please point me to the relevant lines in the log where the new APK is installed and where the intent for that is fired?

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 12, 2016

But I can't believe that most stable apps like Google Services & IR SDK appears in logs with the same issue just because themselves.

I updated app, then waited about 2 minutes for unlocking (intent + next package update). Then I waited some time until my system stabilizes. Isn't captured because too much time left. I'll try to catch this when next update will arrive.

Intent isn't fired. It is freezed for some time.

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 12, 2016

Here it is. Just updated com.grarak.kerneladiutor.

tmp_24023-2016-11-12-17-10-16-install-251374505.zip

@rovo89

This comment has been minimized.

Owner

rovo89 commented Nov 12, 2016

11-12 17:01:03.413 I/Finsky  (14812): [1] com.google.android.finsky.installer.as.d(46374): Begin install of com.grarak.kerneladiutor
11-12 17:01:05.632 I/PackageManager(1175): Running dexopt on: /data/app/com.grarak.kerneladiutor-1/base.apk pkg=com.grarak.kerneladiutor isa=arm vmSafeMode=false
11-12 17:01:14.143 I/dex2oat (15165): dex2oat took 8.393s (threads: 4)
11-12 17:01:17.290 I/PRESAGE (7073): InstallReceiver Receive Intent: Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:com.grarak.kerneladiutor flg=0x4000010 (has extras) } 
11-12 17:01:17.290 I/PRESAGE (7073): InstallReceiver Receive Intent: Intent { act=android.intent.action.PACKAGE_REMOVED dat=package:com.grarak.kerneladiutor flg=0x4000010 (has extras) } 
11-12 17:01:18.328 I/PRESAGE (7073): InstallReceiver Receive Intent: Intent { act=android.intent.action.PACKAGE_REPLACED dat=package:com.grarak.kerneladiutor flg=0x4000010 (has extras) } 
11-12 17:01:18.651 I/Finsky  (14812): [1] com.google.android.finsky.installer.au.a(2394): Successful install of com.grarak.kerneladiutor

Looks ok to me, the intents are sent shortly after the installation is done - where is the issue?

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 12, 2016

Maybe...

11-12 17:03:00.051 I/System.out(17524): intent pkg com.grarak.kerneladiutor

Seems like that. For example, Link2SD automatically process linked apps. Without Xposed Link2SD started to do it's things within few seconds after update. With Xposed it starts up to few minutes (it shows notification, so I clearly see the delay). As I said, in this interval impossible to install further updates from GP.

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 13, 2016

I found that I didn't activate events recording in logcat. There is new log (main + events). Find com.xda.labs. Don't worry about dex warning (can't remove because it is linked through Link2SD). What is strange it is a spam from keychain.

11-13 20:54:13.823 I/ifw_intent_matched(1265): [1,NULL,1000,35,com.android.keychain,com.lge.springcleaning,com.lge.eula,com.lge.lginstallservies,com.lge.keepscreenon,com.qualcomm.atfwd,com.lge.lgfota.permission,android.intent.action.PACKAGE_REPLACED,NULL,package:com.xda.labs,67108880]

Link2SD started to move it on external SD after System Out Intent, as I guess before. 2 minutes delay.

tmp_30503-2016-11-13-20-56-08-keychain-63406487.zip

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 19, 2016

Finally I got the definition. I want to bring my apologizes for wasting your time.

  1. Service leak in Google Billing seems to be caused by Lucky Patcher (Google Billing emulation). I disabled this emulation and never saw the issue anymore.
  2. I tried to replace IR SDK Lite with extended (from LG too) which provides bigger base of supported devices far time ago. But it wasn't suitable, and I returned back stock. But this SDK unpacks libraries to /data/data/. Never saw leaks after wiping data of this SDK. Only noticed other issue ones.
11-19 00:02:16.990 W/System.err(2763): android.os.DeadObjectException
11-19 00:02:16.996 W/System.err(2763):  at android.os.BinderProxy.transactNative(Native Method)
11-19 00:02:16.996 W/System.err(2763):  at android.os.BinderProxy.transact(Binder.java:496)
11-19 00:02:16.996 W/System.err(2763):  at com.uei.control.IControl.unregisterCallback(IControl.java:502)
11-19 00:02:16.996 W/System.err(2763):  at com.lge.qremote.remote.system.RemoteControlManager$1.onServiceDisconnected(RemoteControlManager.java:199)
11-19 00:02:16.996 W/System.err(2763):  at android.app.LoadedApk$ServiceDispatcher.doDeath(LoadedApk.java:1342)
11-19 00:02:16.996 W/System.err(2763):  at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1356)
11-19 00:02:16.996 W/System.err(2763):  at android.os.Handler.handleCallback(Handler.java:739)
11-19 00:02:16.996 W/System.err(2763):  at android.os.Handler.dispatchMessage(Handler.java:95)
11-19 00:02:16.997 W/System.err(2763):  at android.os.Looper.loop(Looper.java:135)
11-19 00:02:16.997 W/System.err(2763):  at android.app.ActivityThread.main(ActivityThread.java:5356)
11-19 00:02:16.997 W/System.err(2763):  at java.lang.reflect.Method.invoke(Native Method)
11-19 00:02:16.997 W/System.err(2763):  at java.lang.reflect.Method.invoke(Method.java:372)
11-19 00:02:16.997 W/System.err(2763):  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:908)
11-19 00:02:16.997 W/System.err(2763):  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:703)
11-19 00:02:16.997 W/System.err(2763):  at de.robv.android.xposed.XposedBridge.main(XposedBridge.java:102)
11-19 00:02:16.997 E/UEI.SmartControl(2763): IControl.unregisterCallback error: android.os.DeadObjectException
11-19 00:02:17.001 W/System.err(2763): android.os.DeadObjectException
11-19 00:02:17.001 W/System.err(2763):  at android.os.BinderProxy.transactNative(Native Method)
11-19 00:02:17.001 W/System.err(2763):  at android.os.BinderProxy.transact(Binder.java:496)
11-19 00:02:17.001 W/System.err(2763):  at com.uei.control.IControl.unregisterSetupReadyCallback(IControl.java:818)
11-19 00:02:17.001 W/System.err(2763):  at com.lge.qremote.remote.system.RemoteControlManager$1.onServiceDisconnected(RemoteControlManager.java:200)
11-19 00:02:17.001 W/System.err(2763):  at android.app.LoadedApk$ServiceDispatcher.doDeath(LoadedApk.java:1342)
11-19 00:02:17.001 W/System.err(2763):  at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1356)
11-19 00:02:17.001 W/System.err(2763):  at android.os.Handler.handleCallback(Handler.java:739)
11-19 00:02:17.001 W/System.err(2763):  at android.os.Handler.dispatchMessage(Handler.java:95)
11-19 00:02:17.099 I/am_proc_died(1277): [0,5583,com.uei.lg.quicksetsdk.lite]
11-19 00:02:17.099 I/am_schedule_service_restart(1277): [0,com.uei.lg.quicksetsdk.lite/com.uei.control.Service,1000]
11-19 00:02:17.001 W/System.err(2763):  at android.os.Looper.loop(Looper.java:135)
11-19 00:02:17.001 W/System.err(2763):  at android.app.ActivityThread.main(ActivityThread.java:5356)
11-19 00:02:17.001 W/System.err(2763):  at java.lang.reflect.Method.invoke(Native Method)
11-19 00:02:17.001 W/System.err(2763):  at java.lang.reflect.Method.invoke(Method.java:372)
11-19 00:02:17.002 W/System.err(2763):  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:908)
11-19 00:02:17.002 W/System.err(2763):  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:703)
11-19 00:02:17.002 W/System.err(2763):  at de.robv.android.xposed.XposedBridge.main(XposedBridge.java:102)
11-19 00:02:17.002 E/UEI.SmartControl(2763): IControl.unregisterSetupReadyCallback error: android.os.DeadObjectException
11-19 00:02:17.002 I/QRemote (2763): [RemoteControlManager.java:203:onServiceDisconnected()] oooooo Control unbind before rebinding.

Not sure, if is it your. Logs are attached.

tmp_29553-2016-11-19-00-02-45-lg-ir-sdk1700989755.zip

Issue with packages installation is still here. So we can continue the discussion. ☺

@daimoniuma daimoniuma changed the title from Service has leaked ServiceConnection to 2 minutes delay of System Out Intent Nov 19, 2016

@daimoniuma

This comment has been minimized.

daimoniuma commented Nov 20, 2016

Nope, few minutes ago I saw it again.

11-20 21:48:49.088 E/ActivityThread(16081): Service com.uei.control.Service has leaked ServiceConnection com.uei.control.j@26ed4140 that was originally bound here

I might assume that it is hid incompatibility with LG software. Previously you had issues with Smart Cover from LG...

@daimoniuma

This comment has been minimized.

daimoniuma commented Dec 2, 2016

@rovo89, it's the first time when I got something about package installer into Xposed's log. Could it explain something? Also I noticed that all this issues are referenced with Java Binder.

12-03 00:42:00.107 E/Xposed  (27508): java.lang.RuntimeException: Package manager has died
12-03 00:42:00.107 E/Xposed  (27508): 	at android.app.ApplicationPackageManager.queryIntentActivitiesAsUser(ApplicationPackageManager.java:571)
12-03 00:42:00.107 E/Xposed  (27508): 	at android.app.ApplicationPackageManager.queryIntentActivities(ApplicationPackageManager.java:557)
12-03 00:42:00.107 E/Xposed  (27508): 	at de.robv.android.xposed.XposedBridge.invokeOriginalMethodNative(Native Method)
12-03 00:42:00.107 E/Xposed  (27508): 	at de.robv.android.xposed.XposedBridge.handleHookedMethod(XposedBridge.java:334)
12-03 00:42:00.107 E/Xposed  (27508): 	at android.app.ApplicationPackageManager.queryIntentActivities(<Xposed>)
12-03 00:42:00.107 E/Xposed  (27508): 	at ru.freeman42.app4pda.e.bz.a(SourceFile:180)
12-03 00:42:00.107 E/Xposed  (27508): 	at ru.freeman42.app4pda.e.bz.a(SourceFile:172)
12-03 00:42:00.107 E/Xposed  (27508): 	at ru.freeman42.app4pda.services.ac.run(SourceFile:666)
12-03 00:42:00.107 E/Xposed  (27508): 	at java.lang.Thread.run(Thread.java:818)
12-03 00:42:00.107 E/Xposed  (27508): Caused by: android.os.TransactionTooLargeException
12-03 00:42:00.107 E/Xposed  (27508): 	at android.os.BinderProxy.transactNative(Native Method)
12-03 00:42:00.107 E/Xposed  (27508): 	at android.os.BinderProxy.transact(Binder.java:496)
12-03 00:42:00.107 E/Xposed  (27508): 	at android.content.pm.IPackageManager$Stub$Proxy.queryIntentActivities(IPackageManager.java:2481)
12-03 00:42:00.107 E/Xposed  (27508): 	at android.app.ApplicationPackageManager.queryIntentActivitiesAsUser(ApplicationPackageManager.java:565)
12-03 00:42:00.107 E/Xposed  (27508): 	... 8 more
@daimoniuma

This comment has been minimized.

daimoniuma commented Mar 17, 2017

Issue with system overloading is called by Kernel Adiutor. Shame. 😥 Sorry. It's hard to detect because it's kernel level fail (no notices in logcat). I'm not sure at that moment if extremely long delay after apps updates comes from Xposed and tired from tests. Anyway it isn't a big problem. You have more priority tasks. Sorry again.

@daimoniuma daimoniuma closed this Mar 17, 2017

@MPeti1

This comment has been minimized.

MPeti1 commented Feb 2, 2018

I have also noticed that intents are veeeery sloooowly going through the system, but it's really caused by kernel adiutor? but why only when xposed is enabled? sorry for reopening the thread, but i think i have the best chance for getting response if i ask it here

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment