Comments (22)
bonanza123
commented on August 25, 2024
For your particular period a logcat may be useful. But overall, I also noticed some battery drain: For 21hours (including 8 hours night time with internet off) I have 613 MCS Wakelocks which accounts for 36 minutes in total.
from gmscore.
pejakm
commented on August 25, 2024
Well, I've compiled GmsCore with heartbeat interval of 5 minutes, and it's much better now, almost all night with minimal battery change.
from gmscore.
mar-v-in
commented on August 25, 2024
The red box area definitely is a bug. A logcat would be helpful but I guess it's not easy to reproduce. However there should be a way to fix it by ensuring every wakelock will time out, which is not the case yet. Do you remember how many wakelocks were detected by BBS (not only the time)
Changing the heartbeat interval will decrease battery usage in "normal" runtime (your green area), but will not help in case of a bug like the one described.
Changing some logic in the wakelock for heartbeat might also have more influence to the battery usage than changing the interval. And reducing the heartbeat interval will reduce wakeups which is good for battery, but without a wakeup push messages can not be delivered.
from gmscore.
pejakm
commented on August 25, 2024
Do you remember how many wakelocks were detected by BBS (not only the time)
No, unfortunately, I wanted to capture a screenshot but forgot. I'll keep an eye on my battery usage, if something like this happens again, I'll try to capture as much information as I can.
from gmscore.
pejakm
commented on August 25, 2024
I haven't yet experienced that battery drain, but I captured a half an hour log just in case:
D/GmsWearSvc( 964): onBind: Intent { act=com.google.android.gms.wearable.BIND pkg=com.google.android.gms }
D/GmsServiceBroker( 964): onTransact [unknown]: 26, android.os.Parcel@3c5ba759, 16
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{last_stream_id_received=4}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{}
D/GmsGcmMcsSvc( 964): I/O error: javax.net.ssl.SSLException: Read error: ssl=0xb4486000: I/O error during system call, Connection timed out
D/GmsGcmMcsSvc( 964): Teardown initiated, reason: javax.net.ssl.SSLException: Read error: ssl=0xb4486000: I/O error during system call, Connection timed out
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 10 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 20 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 30 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 40 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 50 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 120 seconds...
D/GmsGcmTrigger( 964): Not connected to GCM but should be, asking the service to start up
D/GmsGcmMcsSvc( 964): Connect initiated, reason: Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }
D/GmsGcmMcsSvc( 964): Starting MCS connection...
W/GmsGcmMcsSvc( 964): Exception while connecting!
D/GmsGcmMcsSvc( 964): Teardown initiated, reason: java.net.UnknownHostException: Unable to resolve host "mtalk.google.com": No address associated with hostname
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsCheckinClient( 964): -- Request --
D/GmsCheckinClient( 964): CheckinRequest{androidId=4457257940567258118, digest=1-929a0dca0eee55513280171a8585da7dcd3700f8, checkin=Checkin{build=Build{fingerprint=lge/x3_open_eu/x3:4.1.2/JZO54K/P88020c.20d4ae5fac:user/release-keys, hardware=x3, brand=LG, radio=LGP880AT-00-V20b-EUR-XXX-JUL-17-2013, bootloader=unknown, clientId=android-google, time=1445041563, device=p880, sdkVersion=22, model=Optimus 4X HD, manufacturer=LGE, product=x3, otaInstalled=false}, lastCheckinMs=1446614670138, event=[Event{tag=system_update, value=1536,0,-1,NULL, timeMs=1446666815705}], stat=[], requestedGroup=[], cellOperator=26207, simOperator=26207, roaming=mobile-notroaming, userNumber=0}, locale=sr_RS, loggingId=6100846230953175972, macAddress=[b407f936f613], meid=355031049511690, accountCookie=[], timeZone=Europe/Sarajevo, securityToken=2998311553695160968, version=3, otaCert=[71Q6Rn2DDZl1zPDVaaeEHItd], serial=008741C3771C6403, deviceConfiguration=DeviceConfig{touchScreen=3, keyboardType=1, navigation=1, screenLayout=2, hasHardKeyboard=false, hasFiveWayNavigation=false, densityDpi=320, glEsVersion=131072, sharedLibrary=[android.test.runner, com.android.future.usb.accessory, com.android.location.provider, com.android.media.remotedisplay, com.android.mediadrm.signer, com.android.nfc_extras, com.google.android.maps, com.google.android.media.effects, com.google.widevine.software.drm, javax.btobex, javax.obex, org.cyanogenmod.hardware, org.cyanogenmod.platform], availableFeature=[android.hardware.audio.low_latency, android.hardware.audio.output, android.hardware.bluetooth, android.hardware.bluetooth_le, android.hardware.camera, android.hardware.camera.any, android.hardware.camera.autofocus, android.hardware.camera.flash, android.hardware.camera.front, android.hardware.faketouch, android.hardware.location, android.hardware.location.gps, android.hardware.location.network, android.hardware.microphone, android.hardware.nfc, android.hardware.screen.landscape, android.hardware.screen.portrait, android.hardware.sensor.accelerometer, android.hardware.sensor.compass, android.hardware.sensor.gyroscope, android.hardware.sensor.light, android.hardware.sensor.proximity, android.hardware.telephony, android.hardware.telephony.gsm, android.hardware.touchscreen, android.hardware.touchscreen.multitouch, android.hardware.touchscreen.multitouch.distinct, android.hardware.touchscreen.multitouch.jazzhand, android.hardware.usb.accessory, android.hardware.usb.host, android.hardware.wifi, android.hardware.wifi.direct, android.software.app_widgets, android.software.backup, android.software.connectionservice, android.software.device_admin, android.software.home_screen, android.software.input_methods, android.software.live_wallpaper, android.software.managed_users, android.software.print, android.software.sip, android.software.sip.voip, android.software.voice_recognizers, android.software.webview, org.cyanogenmod.theme], nativePlatform=[armeabi-v7a, armeabi], widthPixels=720, heightPixels=1280, locale=[, af, af_ZA, am, am_ET, ar, ar_EG, ar_XB, ast_ES, az_AZ, bg, bg_BG, bn_BD, ca, ca_ES, cs, cs_CZ, da, da_DK, de, de_AT, de_CH, de_DE, de_LI, el, el_GR, en, en_AU, en_CA, en_GB, en_IN, en_NZ, en_SG, en_US, en_XA, eo, es, es_ES, es_US, et_EE, eu_ES, fa, fa_IR, fi, fi_FI, fil, fil_PH, fr, fr_BE, fr_CA, fr_CH, fr_FR, gl_ES, gu_IN, hi, hi_IN, hr, hr_HR, hu, hu_HU, hy_AM, in, in_ID, is_IS, it, it_CH, it_IT, iw, iw_IL, ja, ja_JP, ka_GE, kk_KZ, km_KH, kn_IN, ko, ko_KR, ku, ku_IQ, ky_KG, lb, lb_LU, lo_LA, lt, lt_LT, lv, lv_LV, mk_MK, ml_IN, mn_MN, mr_IN, ms_MY, my_MM, nb, nb_NO, ne_NP, nl, nl_BE, nl_NL, pa_IN, pl, pl_PL, pt, pt_BR, pt_PT, rm, rm_CH, ro, ro_RO, ru, ru_RU, si_LK, sk, sk_SK, sl, sl_SI, sq_AL, sr, sr_RS, sv, sv_SE, sw, sw_TZ, ta_IN, te_IN, th, th_TH, tr, tr_TR, uk, uk_UA, ur_PK, uz_UZ, vi, vi_VN, zh_CN, zh_HK, zh_TW, zu, zu_ZA], glExtension=[GL_EXT_Cg_shader, GL_EXT_bgra, GL_EXT_debug_label, GL_EXT_debug_marker, GL_EXT_occlusion_query_boolean, GL_EXT_packed_float, GL_EXT_read_format_bgra, GL_EXT_robustness, GL_EXT_separate_shader_objects, GL_EXT
D/GmsCheckinSvc( 964): Checked in as 3ddb5c7b3bccf406
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 10 seconds...
D/GmsGcmTrigger( 964): Not connected to GCM but should be, asking the service to start up
D/GmsGcmMcsSvc( 964): Connect initiated, reason: Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }
D/GmsGcmMcsSvc( 964): Starting MCS connection...
D/GmsGcmMcsSvc( 964): Connected to mtalk.google.com:5228
D/GmsGcmMcsSvc( 964): Activated SSL with mtalk.google.com:5228
D/GmsGcmMcsSvc( 964): Sending login request...
D/GmsGcmMcsOutput( 964): Outgoing message: LoginRequest{id=android-22, domain=mcs.android.com, user=4457257940567258118, resource=4457257940567258118, auth_token=2998311553695160968, device_id=android-3ddb5c7b3bccf406, setting=[Setting{name=new_vc, value=1}], received_persistent_id=[], adaptive_heartbeat=false, use_rmq2=true, auth_service=ANDROID_ID, network_type=1}
D/GmsGcmMcsOutput( 964): Write MCS version code: 41
D/GmsGcmMcsInput( 964): Reading from MCS version: 41
D/GmsGcmMcsInput( 964): Incoming message: LoginResponse{id=android-22, [email protected]/4457257940567258118, setting=[], last_stream_id_received=1, server_timestamp=1446666827640}
D/GmsGcmMcsSvc( 964): Logged in
D/GmsGcmMcsInput( 964): Incoming message: IqStanza{type=SET, id=CF120530, from=mcs.android.com, [email protected]/4457257940567258118, extension=Extension{id=12, data=ByteString[size=0]}, account_id=-1}
W/GmsGcmMcsSvc( 964): Unknown message: IqStanza{type=SET, id=CF120530, from=mcs.android.com, [email protected]/4457257940567258118, extension=Extension{id=12, data=ByteString[size=0]}, account_id=-1}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{last_stream_id_received=2}
D/GmsGcmMcsInput( 964): Incoming message: HeartbeatAck{last_stream_id_received=2}
D/GmsGcmRegisterSvc( 964): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 964): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) } extras=Bundle[{sender=197533215920, app=PendingIntent{1de87444: android.os.BinderProxy@3ffe692d}, google.messenger=android.os.Messenger@92cae62}]
D/GmsHttpFormClient( 964): -- Request --
D/GmsHttpFormClient( 964): X-GOOG.USER_AID=4457257940567258118&device=4457257940567258118&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient( 964): -- Response --
D/GmsHttpFormClient( 964): token=APA91bGUQbTm5HoO7Qm374ozTVouOW8ZJq_NJ5dFxXUXjlNmvIetgeddb_w6Zr-G1UzfurEjzAuSSCNxvsO7diOmaCp1Fi_YH8Jx5qSlmAKpgheOkSe36w9tC-UfXlXWmo4E7kMMKyVc9GTB7zgNLQ_MgddVSe2lNA
D/GmsGcmRegisterSvc( 964): received response: RegisterResponse{token='APA91bGUQbTm5HoO7Qm374ozTVouOW8ZJq_NJ5dFxXUXjlNmvIetgeddb_w6Zr-G1UzfurEjzAuSSCNxvsO7diOmaCp1Fi_YH8Jx5qSlmAKpgheOkSe36w9tC-UfXlXWmo4E7kMMKyVc9GTB7zgNLQ_MgddVSe2lNA', retryAfter='null', deleted='null'}
D/GmsGcmRegisterSvc( 964): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION (has extras) } extras=Bundle[{registration_id=APA91bGUQbTm5HoO7Qm374ozTVouOW8ZJq_NJ5dFxXUXjlNmvIetgeddb_w6Zr-G1UzfurEjzAuSSCNxvsO7diOmaCp1Fi_YH8Jx5qSlmAKpgheOkSe36w9tC-UfXlXWmo4E7kMMKyVc9GTB7zgNLQ_MgddVSe2lNA}]
D/GmsGcmMcsInput( 964): Incoming message: DataMessageStanza{id=CF1364B8, from=197533215920, category=com.firstrowria.pushnotificationtester, token=do_not_collapse, app_data=[AppData{key=serverTime, value=1446666998663}, AppData{key=title, value=Test notification}], from_trusted_server=false, persistent_id=0:1446666998706965%c5da679ff9fd7ecd, sent=1446666998668}
D/GmsGcmRegisterSvc( 964): onHandleIntent: Intent { act=com.google.android.c2dm.intent.UNREGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc( 964): unregister[res]: Intent { act=com.google.android.c2dm.intent.UNREGISTER pkg=com.google.android.gms (has extras) } extras=Bundle[{app=PendingIntent{f2b4eae: android.os.BinderProxy@3ffe692d}, google.messenger=android.os.Messenger@92cae62}]
D/GmsHttpFormClient( 964): -- Request --
D/GmsHttpFormClient( 964): X-GOOG.USER_AID=4457257940567258118&device=4457257940567258118&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&delete=1
D/GmsHttpFormClient( 964): -- Response --
D/GmsHttpFormClient( 964): deleted=com.firstrowria.pushnotificationtester
D/GmsGcmRegisterSvc( 964): received response: RegisterResponse{token='null', retryAfter='null', deleted='com.firstrowria.pushnotificationtester'}
D/GmsGcmRegisterSvc( 964): unregister[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION (has extras) } extras=Bundle[{unregistered=com.firstrowria.pushnotificationtester}]
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{last_stream_id_received=4}
D/GmsGcmMcsInput( 964): Incoming message: HeartbeatAck{last_stream_id_received=3}
D/GmsWearSvc( 964): onBind: Intent { act=com.google.android.gms.wearable.BIND pkg=com.google.android.gms }
D/GmsServiceBroker( 964): onTransact [unknown]: 26, android.os.Parcel@fd570fa, 16
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{last_stream_id_received=5}
D/GmsGcmMcsInput( 964): Incoming message: HeartbeatAck{last_stream_id_received=4}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{last_stream_id_received=6}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{}
D/GmsGcmMcsSvc( 964): I/O error: javax.net.ssl.SSLException: Read error: ssl=0xb4486000: I/O error during system call, Connection timed out
D/GmsGcmMcsSvc( 964): Teardown initiated, reason: javax.net.ssl.SSLException: Read error: ssl=0xb4486000: I/O error during system call, Connection timed out
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsGcmTrigger( 964): Not connected to GCM but should be, asking the service to start up
D/GmsGcmMcsSvc( 964): Connect initiated, reason: Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }
D/GmsGcmMcsSvc( 964): Starting MCS connection...
D/GmsGcmMcsSvc( 964): Connected to mtalk.google.com:5228
D/GmsGcmMcsSvc( 964): Activated SSL with mtalk.google.com:5228
D/GmsGcmMcsSvc( 964): Sending login request...
D/GmsGcmMcsOutput( 964): Outgoing message: LoginRequest{id=android-22, domain=mcs.android.com, user=4457257940567258118, resource=4457257940567258118, auth_token=2998311553695160968, device_id=android-3ddb5c7b3bccf406, setting=[Setting{name=new_vc, value=1}], received_persistent_id=[0:1446666998706965%c5da679ff9fd7ecd], adaptive_heartbeat=false, use_rmq2=true, auth_service=ANDROID_ID, network_type=1}
D/GmsGcmMcsOutput( 964): Write MCS version code: 41
D/GmsGcmMcsInput( 964): Reading from MCS version: 41
D/GmsGcmMcsInput( 964): Incoming message: LoginResponse{id=android-22, [email protected]/4457257940567258118, setting=[], last_stream_id_received=1, server_timestamp=1446669102445}
D/GmsGcmMcsSvc( 964): Logged in
D/GmsGcmMcsInput( 964): Incoming message: IqStanza{type=SET, id=CF2C11AD, from=mcs.android.com, [email protected]/4457257940567258118, extension=Extension{id=12, data=ByteString[size=0]}, account_id=-1}
W/GmsGcmMcsSvc( 964): Unknown message: IqStanza{type=SET, id=CF2C11AD, from=mcs.android.com, [email protected]/4457257940567258118, extension=Extension{id=12, data=ByteString[size=0]}, account_id=-1}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{last_stream_id_received=2}
D/GmsGcmMcsInput( 964): Incoming message: HeartbeatAck{last_stream_id_received=2}
D/GmsGcmMcsSvc( 964): Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsOutput( 964): Outgoing message: HeartbeatPing{last_stream_id_received=3}
D/GmsGcmMcsSvc( 964): I/O error: javax.net.ssl.SSLException: Read error: ssl=0xb4486000: I/O error during system call, Connection timed out
D/GmsGcmMcsSvc( 964): Teardown initiated, reason: javax.net.ssl.SSLException: Read error: ssl=0xb4486000: I/O error during system call, Connection timed out
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsWearSvc( 964): onBind: Intent { act=com.google.android.gms.wearable.BIND pkg=com.google.android.gms }
D/GmsServiceBroker( 964): onTransact [unknown]: 26, android.os.Parcel@3c5ba759, 16
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 10 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 20 seconds...
D/GmsGcmTrigger( 964): Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 30 seconds...
D/GmsGcmTrigger( 964): Not connected to GCM but should be, asking the service to start up
D/GmsGcmMcsSvc( 964): Connect initiated, reason: Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }
D/GmsGcmMcsSvc( 964): Starting MCS connection...
W/GmsGcmMcsSvc( 964): Exception while connecting!
D/GmsGcmMcsSvc( 964): Teardown initiated, reason: java.net.UnknownHostException: Unable to resolve host "mtalk.google.com": No address associated with hostname
D/GmsGcmMcsSvc( 964): Scheduling reconnect in 5 seconds...
D/GmsGcmTrigger( 964): Not connected to GCM but should be, asking the service to start up
D/GmsGcmMcsSvc( 964): Connect initiated, reason: Intent { act=org.microg.gms.
Note that I'm using 5 minute beat interval. BetterBattery stats report allot of wasted time (1153s, 89,7%) on microG wakelocks (com.google.android.gms.microG services) but counts only 6 of them. (The phone is about two hours on battery, 15 hours of total turned on time.)
from gmscore.
pejakm
commented on August 25, 2024
Also, one thing that I don't understand: Gms should wake my phone and check for new messages, right? When I turned screen on a moment ago, few messages arrived on Viber upon connecting to wifi. Shouldn't Gms wake the phone, turn on wifi, and retrieve those messages? Option _Keep Wi-Fi on during sleep_ is set to Only when plugged in.
from gmscore.
pejakm
commented on August 25, 2024
I think this happened once again, last night. Pictures and log attached, I hope they will be of use.
http://pastebin.com/vPTNdmDh
https://framapic.org/V0l4ssg6Atfv/wW9YNLSL
https://framapic.org/7DgZR4WmsJZV/g6XOOYdY
https://framapic.org/rfwMfmasMTON/pAsNGTUC
https://framapic.org/DC08zhd5MpUA/ygOKEQEQ
from gmscore.
mar-v-in
commented on August 25, 2024
Unfortunately the log does not contain any meaningful entries. I'd like to encourage you to always provide logs with timestamps, as they're crucial to find battery issues (e.g. I can't say if your log is for a timescope of 24h or just 2min). You can easily add timestamps to logcat by using the -v threadtime option (e.g. run adb logcat -v threadtime | grep GmsGcm).
Additionally, looking at the battery usage graph, it seems interesting to me, that last time the high power consumption happened when there was no wifi connection, and this time after the wifi came back... So maybe it's another issue this time?
from gmscore.
michitux
commented on August 25, 2024
I think one problem here is (was) that the wake lock was not released when no ack message was received after a heartbeat ping message. I had the situation that no ack messages were received anymore even though heartbeat pings were sent relatively reliably here because of relatively long intervals between heartbeats (8 minutes and above seems to trigger the problem). The SSL connection reports errors only after several further ping requests as it can also be seen in the log above.
From reading the code I think the wake lock is only released when an ack message is received. Is it really necessary to keep a wake lock for receiving the ack or couldn't the lock be released directly after sending the heart beat ping? Same question for the login request. On the other hand I wonder if microg shouldn't acquire a wake lock as soon as data is received in order to make sure that the device stays awake between the time when the data is received, dispatchMessage() is called and the message has been fully handled as I could imagine that otherwise the device goes back to sleep in between and the app receives the message only after unlocking the device as experienced by @pejakm. An interesting discussion about such issues is this Stackoverflow question.
I'm not sure about the wake locks but I've tried fixing the connectivity issues. I've done this by changing two things:
- Not using inexact alarms. From my logs it seems they are delayed up to 15 minutes if no other events occur even if the interval is set to e.g. 4 minutes. In order to not to drain the battery too much an interval can be used on API level 19 and above. For API Level >= 23 probably even
setExactAndAllowWhileIdle()should be used but I guess there some more testing is necessary which I can't do as don't have a device with Android 6. - Report the connection as broken much earlier when no ack-messages are received anymore. I've currently implemented this by storing the time when ack messages are received and checking if an ack message has been received at most two intervals back. A better way might be to store the stream id on the last heartbeat ping and require it to have changed between to heartbeat but this might also introduce new race conditions.
I'll test this for some more hours especially also when the phone is not connected to WiFi and the charger (where I also had these problems, there they seem to be fixed), if my tests are successful I'll open a pull request.
from gmscore.
pejakm
commented on August 25, 2024
@michitux I'm open to test your changes and report back. I also must point out that I haven't been able to reproduce this issue since long time. The problems I'm mostly facing now are:
- very often I need to open an app (Viber or WhatsApp) to receive a message (although my phone is connected to wifi)
- if my device goes to sleep, after some time wifi shuts down (option
Keep WiFi off during sleepis set toOnly when plugged in), and I no longer receive messages until I pick it up and unlock it (so that it can establish connection to wifi again)
from gmscore.
michitux
commented on August 25, 2024
@pejakm I've just created #74 with my changes. This should make the connection stabler, at least for me the connection works reliably with 5 minutes interval. However I could still reproduce your problem that WhatsApp did not receive a message, see #75.
If your device does not have an internet connection, no messages will be received. Gms won't turn your WiFi on. The idea is that the app keeps an active connection to Google and wakes the phone up when data is received on that connection - which needs a persistent internet connection of course. However when WiFi goes off and you still have an internet connection (e.g. UMTS), the connection should be re-established using that connection. This should be the same behavior with the official Google Play Services.
from gmscore.
forkoz
commented on August 25, 2024
I had few problems with wakelocks at Nov 17, 2015 commits. Could only use gmail 4.2.2 but with amplify I could limit wakelocks to max every 15 minutes. Now just upgrading to latest GMSCore and gmail to 4.9 I have gmail hold much longer locks... ie many minutes at a time. GCM isn't on... just pure sync.
An app automatically kills the connection when the screen is off and is supposed to sync gmail every 45 minutes. Once it does gmail prevents going back to deep sleep and amplify can't help since it holds the lock.
From this thread it sounds like gms isn't properly failing connections. So I'm not getting new mails and the phone can't sleep.
from gmscore.
pejakm
commented on August 25, 2024
@michitux Compiled, installed, set timeout to 300 and looking forward to report back.
from gmscore.
pejakm
commented on August 25, 2024
@michitux With your changes I have a feeling that I have GAPPS installed! Thanks, it really works great now!
from gmscore.
jeekajoo
commented on August 25, 2024
Hi, I experienced a battery drain this week with last version. I fixed it by checking-in. Next time I'll try to get the logcat, for this report to be more helpful.. ;)
Thanks.
J.
from gmscore.
jfrederickson
commented on August 25, 2024
Just saw something that looked weird in my logcat output - I had my interval set to 60 seconds and seemed to be getting heartbeats every 30 seconds instead. Not sure if this is normal. I noticed this due to high battery drain; switched to a 300 second interval and I seem to be getting heartbeats every 5 minutes now as expected.
03-14 14:20:12.033 3222 4845 D GmsGcmMcsSvc: Scheduling heartbeat in 60 seconds...
03-14 14:20:12.034 3222 25904 D GmsGcmMcsOutput: Outgoing message: HeartbeatPing{last_stream_id_received=526}
03-14 14:20:12.773 3222 25903 D GmsGcmMcsInput: Incoming message: HeartbeatAck{last_stream_id_received=526}
03-14 14:20:42.036 3222 4845 D GmsGcmMcsSvc: Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
03-14 14:20:42.036 3222 4845 D GmsGcmMcsSvc: Scheduling heartbeat in 60 seconds...
03-14 14:20:42.038 3222 25904 D GmsGcmMcsOutput: Outgoing message: HeartbeatPing{last_stream_id_received=527}
03-14 14:20:42.752 3222 25903 D GmsGcmMcsInput: Incoming message: HeartbeatAck{last_stream_id_received=527}
03-14 14:21:12.038 3222 4845 D GmsGcmMcsSvc: Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
03-14 14:21:12.038 3222 4845 D GmsGcmMcsSvc: Scheduling heartbeat in 60 seconds...
03-14 14:21:12.040 3222 25904 D GmsGcmMcsOutput: Outgoing message: HeartbeatPing{last_stream_id_received=528}
03-14 14:21:13.401 3222 25903 D GmsGcmMcsInput: Incoming message: HeartbeatAck{last_stream_id_received=528}
03-14 14:21:42.041 3222 4845 D GmsGcmMcsSvc: Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
03-14 14:21:42.041 3222 4845 D GmsGcmMcsSvc: Scheduling heartbeat in 60 seconds...
03-14 14:21:42.043 3222 25904 D GmsGcmMcsOutput: Outgoing message: HeartbeatPing{last_stream_id_received=529}
03-14 14:21:43.272 3222 25903 D GmsGcmMcsInput: Incoming message: HeartbeatAck{last_stream_id_received=529}
03-14 14:22:38.870 3222 4845 D GmsGcmMcsSvc: Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
03-14 14:22:38.870 3222 4845 D GmsGcmMcsSvc: Scheduling heartbeat in 60 seconds...
03-14 14:22:38.872 3222 25904 D GmsGcmMcsOutput: Outgoing message: HeartbeatPing{last_stream_id_received=530}
03-14 14:22:40.223 3222 25903 D GmsGcmMcsInput: Incoming message: HeartbeatAck{last_stream_id_received=530}
03-14 14:23:08.873 3222 4845 D GmsGcmMcsSvc: Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.HEARTBEAT flg=0x4 cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
from gmscore.
mar-v-in
commented on August 25, 2024
@jfrederickson This is intended behaviour. The ping will be sent within the interval [heartbeatMs/2, heartbeatMs] since KitKat. The exact time will be selected based on the device wake state. This will reduce battery consumption when the cpu has less wake-ups (as the system will merge schedules from multiple apps). However when the system is awake (like when you have it connected to your pc) it will always choose heartbeatMs/2 to ensure it's not necassary to wake up later.
We might want to change this behaviour a bit, maybe something like [hearbeatMs*3/4, heartbeatMs*5/4] is a better choice?
As you noticed, you can freely choose heartbeat interval, however values like 300 might be a little high for "push message feeling"
from gmscore.
michitux
commented on August 25, 2024
I'm not using microg anymore, but when I implemented this [heartbeatMs/2, heartbeatMs] interval I tested this mainly with 300s as interval and this worked perfectly fine and I would actually suggest this as default value. Note that the connection is maintained permanently and push messages will also wake up your device when no ping is sent as long as the connection hasn't been dropped in the meantime. You can see connection drops in the log as microg reconnects as soon as it detects that the connection is not alive anymore. Depending on your internet provider and your router when you are using WiFi also longer intervals might work. Every time the connection is lost the stream id is reset, so if you see small values of the stream id in the log and you have had a stable and permanent internet connection (and did not switch between WiFi and mobile data) during the last hours, your interval might be too long.
from gmscore.
pejakm
commented on August 25, 2024
After update to 0.2.2-5-g6bf59b2 the microg would drain entire battery during the night, when wifi is off. Just to note, device checkin is off. I had to revert to stable 0.2.5. No logs for now, as I'm not in position to experiment these days. My best guess is that commit 2a394f9 is the cause of this.
from gmscore.
Catfriend1
commented on August 25, 2024
after update to microg 0.2.3 my battery holds very long. Checkin is on gcm too with 300 secs
from gmscore.
pejakm
commented on August 25, 2024
I can confirm, with 0.2.3 I cannot reproduce this anymore.
from gmscore.
mar-v-in
commented on August 25, 2024
Seems to be no problem anymore, closing.
from gmscore.
Related Issues (20)
- ebay not working/loading HOT 1
- google pay HOT 4
- Crashes when adding a Google Account
- Permission for a forked wiki
- Not receiving OTP HOT 1
- Unable to Sync Messages in Google Chrome After Successful Google Account Login with microG
- [org.paris2024.ticketapp] Can't receive tickets for Paris 2024 Olympics HOT 8
- Crash when using location services with bluetooth turned on HOT 1
- IMPROVEMENT: Add new checks to microG self check
- [com.google.android.apps.maps] <Location not working in Google Maps>
- Bootloop after upgrading from Lineage-microG 20 to 21 (20240706 build)
- Provide stub(s) for use as system package
- Provide distinct apks for different architectures
- Allow translation of microG-UI-tools from Weblate
- Commits can be squashed with Weblate HOT 1
- allow custom ichnaea endpoint paths HOT 2
- [se.slso.app4us] App Alltid Öppet used to work with Companion disabled, now it demands it enabled but this break other apps
- What are the security implications of MicroG? HOT 2
- [com.invoxia.track] Invoxia GPS crashes at start, but only once already logged in
- Adding nightly build artifacts to GitHub Actions
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from gmscore.