High CPU bug correlation with failed cloud messaging event #24

prurigro · 2015-08-01T03:46:47Z

You mentioned this bug to me on IRC a month or so ago before I switched back from unifiednlp to gmscore, so when it first happened I just figured I'd disable the checkin feature as I needed battery life to be reliable at the time. I recently re-enabled it along with cloud messaging after seeing a commit that stated checkin had been fixed, but I hadn't been able to tell if it was working or not as I only have one app that utilizes it (Slack, which I also get email notifications for.)

I'm out right now so I unfortunately wasn't able to collect a logcat, but I can say that I had no occurrences of the high CPU bug for a day or so until a few minutes ago when I received the first email notification I've gotten from Slack since re-enabling checkin/cloud messaging (via IMAP IDLE, so I get it right away), which failed to notify me through the app via cloud messaging. At this point my CPU immediately spiked, and it remained high until I rebooted (after checking top to see that the culprit was indeed gmscore)

I'll try enabling checkin and cloud messaging again when I have a reliable power source nearby next week, but I hope this helps narrow the potential causes of the bug down for now.

Cheers!

bonanza123 · 2015-08-02T17:07:01Z

I also noticed a battery drain in the case a GCM connection cannot be established (which in may case was due problems of signature faking). Which way to fake the google gms service signature are you using? Are you using the xposed module? Can you post the Xposed log then?

MCS rework related to #23 and #24

prurigro · 2015-08-04T15:59:10Z

Hmm, I just returned from a trip where I had relatively poor reception throughout, and despite having check-in and GCM disabled after posting that issue on Friday, I ended up running into the high CPU bug about 6 times. I also had wifi disabled, which I only mention because it might be relevant?

@bonanza123: I hadn't realized the xposed module might be an issue or I would have saved the logs, but I'll definitely save them next time before restarting my phone.

I'm installing the latest build and will see if I run into the issue again- cheers!

prurigro · 2015-08-04T16:33:06Z

I tested using http://apps.evozi.com/apk-downloader/?id=com.firstrowria.pushnotificationtester and got the following logcat:

D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR
D/GmsGcmRegisterSvc( 3309): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) }
D/GmsGcmRegisterSvc( 3309): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 3309): register[req]: Bundle[{sender=197533215920, app=PendingIntent{ba8a71d: android.os.BinderProxy@438a706}, google.messenger=android.os.Messenger@3a721c7}]
D/GmsHttpFormClient( 3309): -- Request --
D/GmsHttpFormClient( 3309): X-GOOG.USER_AID=0&device=0&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR
D/GmsGcmRegisterSvc( 3309): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) }
D/GmsGcmRegisterSvc( 3309): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 3309): register[req]: Bundle[{sender=197533215920, app=PendingIntent{37282d92: android.os.BinderProxy@438a706}, google.messenger=android.os.Messenger@3a721c7}]
D/GmsHttpFormClient( 3309): -- Request --
D/GmsHttpFormClient( 3309): X-GOOG.USER_AID=0&device=0&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR
D/GmsGcmRegisterSvc( 3309): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) }
D/GmsGcmRegisterSvc( 3309): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 3309): register[req]: Bundle[{sender=197533215920, app=PendingIntent{aea1363: android.os.BinderProxy@438a706}, google.messenger=android.os.Messenger@3a721c7}]
D/GmsHttpFormClient( 3309): -- Request --
D/GmsHttpFormClient( 3309): X-GOOG.USER_AID=0&device=0&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR
D/GmsGcmRegisterSvc( 3309): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) }
D/GmsGcmRegisterSvc( 3309): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 3309): register[req]: Bundle[{sender=197533215920, app=PendingIntent{19249b60: android.os.BinderProxy@438a706}, google.messenger=android.os.Messenger@3a721c7}]
D/GmsHttpFormClient( 3309): -- Request --
D/GmsHttpFormClient( 3309): X-GOOG.USER_AID=0&device=0&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR
D/GmsGcmRegisterSvc( 3309): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) }
D/GmsGcmRegisterSvc( 3309): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 3309): register[req]: Bundle[{sender=197533215920, app=PendingIntent{282d9819: android.os.BinderProxy@438a706}, google.messenger=android.os.Messenger@3a721c7}]
D/GmsHttpFormClient( 3309): -- Request --
D/GmsHttpFormClient( 3309): X-GOOG.USER_AID=0&device=0&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR
D/GmsGcmRegisterSvc( 3309): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) }
D/GmsGcmRegisterSvc( 3309): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 3309): register[req]: Bundle[{sender=197533215920, app=PendingIntent{3c1790de: android.os.BinderProxy@438a706}, google.messenger=android.os.Messenger@3a721c7}]
D/GmsHttpFormClient( 3309): -- Request --
D/GmsHttpFormClient( 3309): X-GOOG.USER_AID=0&device=0&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR
D/GmsGcmRegisterSvc( 3309): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) }
D/GmsGcmRegisterSvc( 3309): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 3309): register[req]: Bundle[{sender=197533215920, app=PendingIntent{2de082bf: android.os.BinderProxy@438a706}, google.messenger=android.os.Messenger@3a721c7}]
D/GmsHttpFormClient( 3309): -- Request --
D/GmsHttpFormClient( 3309): X-GOOG.USER_AID=0&device=0&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 3309): -- Response --
D/GmsHttpFormClient( 3309): Error=PHONE_REGISTRATION_ERROR

(it continues like this for a while, and its beginning correlated with the CPU spike)

The xposed log just shows a bunch of faked signature messages

mar-v-in · 2015-08-04T16:38:53Z

According to the log, your phone is not registered on google servers. Please enforce a first time checkin by dialing *#*#CHECKIN#*#* and check the logcat output.

I tried the mentioned application and it does work for me, although unregistering fails...

mar-v-in · 2015-08-05T09:17:41Z

The CPU bug happened again and I was able to trace it this time, I'll provide a fix soon.

Tentos · 2015-08-07T16:48:38Z

Excellent, @mar-v-in . As a workaround, the OS Monitor app (also available on F-Droid) offers the possibility to easily reset and restart a process. The restarted GMS core then behaves as expected (it automatically re-connects to GCM and has a non-existent CPU footprint).

n76 · 2015-08-14T01:06:49Z

I noticed high battery usage this morning and checked to see what the settings->battery had to indicate. It showed "unknown". Rebooted the phone and then it showed uG services as a big power user. You had a commit a few days ago that referenced this bug, so I downloaded the 4Aug build from http://files.brnmod.rocks/apps/GmsCore/Latest/

I had check-in disabled and I have now changed to check-in enabled. But see no difference, uG services still shows as a power hog.

For what it is worth I am running a AOSP based 5.1.1 ROM with Xposed to get uG services to work. Have I missed an update or is this bug still an issue?

n76 · 2015-08-14T01:10:49Z

@Tentos - I've just installed OS Monitor and attempted to "kill/restart process" on uG services and I see no effect, still about 50% CPU. Any suggestions?

Tentos · 2015-08-14T14:50:35Z

Hello @n76 - yes, the version of August 4 2015 is still affected by the high CPU usage. As for the OS Monitor "workaround": unfortunately, I can only state that it works for me. Have you tried to re-start uG again? Or did you install uG as a system app? If you have installed it as a system app, you probably have to launch OS Monitor with root privileges, too (which can be done in the OS Monitor settings) to properly re-start the uG services.

EDIT: I am sorry that I cannot provide more help, I am a noob when it comes to the internals of Android. :-/

n76 · 2015-08-14T14:57:40Z

Thank you @Tentos - I had installed uG as a system app. Not sure why I thought I needed that, maybe left over from experiments before I got Xposed installed. Temporarily I have removed uG services and reinstalled UnifiedNLP. I will try again with uG services installed as a user app and watch for a newer version with the high CPU usage fixed.

bonanza123 · 2015-08-16T20:05:35Z

For me, the high Cpu bug is still present and comes with thousands of these messages:

08-16 22:03:40.631 W/GmsGcmMcsSvc(812): Unknown message: null
08-16 22:03:40.632 D/GmsGcmMcsSvc(812): Incoming message: null

bonanza123 · 2015-08-17T04:23:40Z

Thanks for the update. Now I have a lot of these messages:
08-17 06:20:31.055 D/GmsGcmMcsSvc(18426): Incoming message: null
08-17 06:20:31.055 D/GmsGcmMcsSvc(18426): Teardown initiated, reason: null message
08-17 06:20:31.048 I/ReceiverStop(14674): handle not: com.google.android.gms - org.microg.gms.gcm.RECONNECT

wake up device when reconnecting, fix teardown incomplete on null message (#24)

mar-v-in added a commit that referenced this issue Aug 4, 2015

Update maps, rework MCS

331813c

MCS rework related to #23 and #24

mar-v-in closed this as completed in bd69c16 Aug 14, 2015

mar-v-in added a commit that referenced this issue Aug 16, 2015

Update build tools and upstream, fix issue described in #24

c826702

mar-v-in added a commit that referenced this issue Aug 17, 2015

Improve mcs connection

1a83f82

wake up device when reconnecting, fix teardown incomplete on null message (#24)

acsway878787 mentioned this issue Jan 13, 2017

Crashed when clicking Self-check,Google Cloud Messaging,and all the colmn(with logcat) #267

Closed

whyteks mentioned this issue Mar 27, 2017

java.lang.UnsupportedOperationException: Can't convert to color: type=0x2 #354

Closed

sonickles9 mentioned this issue Oct 11, 2018

UI crash on Zenfone phones (5.x) #463

Closed

werdahias mentioned this issue Dec 12, 2020

SafetyNet not working #1308

Closed

phibbs7 mentioned this issue Apr 15, 2022

[de.mardukcorp.kawaiinihongo] Hangs on loading flash cards. #1704

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

High CPU bug correlation with failed cloud messaging event #24

High CPU bug correlation with failed cloud messaging event #24

prurigro commented Aug 1, 2015

bonanza123 commented Aug 2, 2015

prurigro commented Aug 4, 2015

prurigro commented Aug 4, 2015

mar-v-in commented Aug 4, 2015

mar-v-in commented Aug 5, 2015

Tentos commented Aug 7, 2015

n76 commented Aug 14, 2015

n76 commented Aug 14, 2015

Tentos commented Aug 14, 2015

n76 commented Aug 14, 2015

bonanza123 commented Aug 16, 2015

bonanza123 commented Aug 17, 2015

High CPU bug correlation with failed cloud messaging event #24

High CPU bug correlation with failed cloud messaging event #24

Comments

prurigro commented Aug 1, 2015

bonanza123 commented Aug 2, 2015

prurigro commented Aug 4, 2015

prurigro commented Aug 4, 2015

mar-v-in commented Aug 4, 2015

mar-v-in commented Aug 5, 2015

Tentos commented Aug 7, 2015

n76 commented Aug 14, 2015

n76 commented Aug 14, 2015

Tentos commented Aug 14, 2015

n76 commented Aug 14, 2015

bonanza123 commented Aug 16, 2015

bonanza123 commented Aug 17, 2015