microg / GmsCore

Free implementation of Play Services
https://microg.org
Apache License 2.0
8.19k stars 1.69k forks source link

Wishlist: reconect GCM on connectivity change #29

Closed bonanza123 closed 8 years ago

bonanza123 commented 9 years ago

When I've seen that correctly, an automatic reconnect doesn't take place when the connectivity, e.g. from mobile to WIFI changes, right? Is it possible to add this?

Tentos commented 9 years ago

Interestingly, I have not noticed any problems when it comes to this. The app Autostarts lists uG services as one of the apps that is notified when the connectivity changes, and as far as I can tell, the uG services always reconnected when I switched from mobile to WiFi and vice versa. (OS Monitor showed that the connection was re-established.) Did you have any problems, @bonanza123 ? (An honest question, I do not doubt that you have a serious reason to post your question here. :-) )

bonanza123 commented 9 years ago

I don't have any real problems. But in my build I extended the heartbeat interval to 10 minutes to reduce the wakeups ( if I remember correctly, googles default is something around 15 - 20 minutes). And additionally, I have often switches from mobile to Wifi and back.

In the case the app would automatically reconnect on a connectivity change and would not be waiting for the next interval, the "dead period" would be reduced. (note that I'm not sure whether the app doesn't reconnect on connectivity change, meaning I haven't had a deep look into the code, I just didn't notice it yet)

Tentos commented 9 years ago

An option to increase the heartbeat interval was in fact a suggestion I wanted to post. :+1: My guess (based on my observations) is that a connectivity change lets uG reconnect immediately: I did not notice any delay. Even if the reconnect on connectivity change works, I am not sure whether the automatic and immediate reconnect is triggered when the uG services were terminated (and restarted) by Android because of the lack of system resources (or because someone has restarted the service with OS Monitor). In this case, uG may indeed wait for the next interval.

bonanza123 commented 9 years ago

I just had a look at the 'catlog' and the heartbeat messages that are logged there. Based on them, I was not able to notice immediate reconnects after the connectivity change.

From my very limited android knowledge, I guess the 'connectivity change' is a broadcast to which apps can listen. So I guess that would also enable µg to restart and reconnect (but I'm not sure).

pejakm commented 8 years ago

Oh, so this is the issue I'm experiencing! I've described it in #23. Tested with Push Notifications tester. Sometimes it wont receive push messages, so I restart my phone and the messages arrive immediately. Now I know why. I've set wifi sleep policy to off, so when my phone is in deep sleep, wifi is off. This obviously affects microG.

pejakm commented 8 years ago

Some logs. Procedure:

u0_a52@p880:/ $ su
root@p880:/ # logcat | grep Gms
D/GmsWearSvc(  884): onBind: Intent { act=com.google.android.gms.wearable.BIND pkg=com.google.android.gms }
D/GmsServiceBroker(  884): onTransact [unknown]: 26, android.os.Parcel@1a4d4740, 16
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=9}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=9}
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=10}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=10}
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=11}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=11}
D/GmsGcmRegisterSvc(  884): onHandleIntent: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms (has extras) }
D/GmsGcmRegisterSvc(  884): register[req]: Bundle[{sender=197533215920, app=PendingIntent{1e074e9a: android.os.BinderProxy@282b93cb}, google.messenger=android.os.Messenger@3b97f7a8}]
D/GmsHttpFormClient(  884): -- Request --
D/GmsHttpFormClient(  884): X-GOOG.USER_AID=4563711268479711284&device=4563711268479711284&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&sender=197533215920
D/GmsHttpFormClient(  884): -- Response --
D/GmsHttpFormClient(  884): token=APA91bE_RRUddutPhB8fp8hUnxaETLiFFsAI7H_kHzlORSKy-4V_MYv7oA-UJISiWTZx8aPJS4jrtQMRdyEcJ1LlFVOuFrJLeD-03HFZSV8fgfytKifJpNr6hy-6-L_0L87Zmytnpb3kto9X5DHSLASCvWy04p-R_w
D/GmsGcmRegisterSvc(  884): received response: RegisterResponse{token='APA91bE_RRUddutPhB8fp8hUnxaETLiFFsAI7H_kHzlORSKy-4V_MYv7oA-UJISiWTZx8aPJS4jrtQMRdyEcJ1LlFVOuFrJLeD-03HFZSV8fgfytKifJpNr6hy-6-L_0L87Zmytnpb3kto9X5DHSLASCvWy04p-R_w', retryAfter='null', deleted='null'}
D/GmsGcmRegisterSvc(  884): register[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) } extras=Bundle[{registration_id=APA91bE_RRUddutPhB8fp8hUnxaETLiFFsAI7H_kHzlORSKy-4V_MYv7oA-UJISiWTZx8aPJS4jrtQMRdyEcJ1LlFVOuFrJLeD-03HFZSV8fgfytKifJpNr6hy-6-L_0L87Zmytnpb3kto9X5DHSLASCvWy04p-R_w}]
D/GmsGcmMcsSvc(  884): Incoming message: DataMessageStanza{id=462BC431, from=197533215920, category=com.firstrowria.pushnotificationtester, token=do_not_collapse, app_data=[AppData{key=serverTime, value=1444297978421}, AppData{key=title, value=Test notification}], from_trusted_server=false, persistent_id=0:1444297978446601%c5da679ff9fd7ecd, sent=1444297978427}
D/GmsGcmRegisterSvc(  884): onHandleIntent: Intent { act=com.google.android.c2dm.intent.UNREGISTER pkg=com.google.android.gms (has extras) }
D/GmsHttpFormClient(  884): -- Request --
D/GmsHttpFormClient(  884): X-GOOG.USER_AID=4563711268479711284&device=4563711268479711284&app=com.firstrowria.pushnotificationtester&cert=1acbe3831cb1827bee6a78879501d7c3bc074987&app_ver=7&delete=1
D/GmsHttpFormClient(  884): -- Response --
D/GmsHttpFormClient(  884): deleted=com.firstrowria.pushnotificationtester
D/GmsGcmRegisterSvc(  884): received response: RegisterResponse{token='null', retryAfter='null', deleted='com.firstrowria.pushnotificationtester'}
D/GmsGcmRegisterSvc(  884): unregister[res]: Intent { act=com.google.android.c2dm.intent.REGISTRATION pkg=com.firstrowria.pushnotificationtester (has extras) } extras=Bundle[{unregistered=com.firstrowria.pushnotificationtester}]
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=13}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=12}
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=14}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=13}
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=15}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=14}
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=16}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=15}
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=17}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=16}
D/GmsGcmMcsSvc(  884): 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/GmsGcmMcsSvc(  884): Outgoing message: HeartbeatPing{last_stream_id_received=18}
D/GmsGcmMcsSvc(  884): Incoming message: HeartbeatAck{last_stream_id_received=17}
D/GmsGcmMcsSvc(  884): I/O error: javax.net.ssl.SSLException: Read error: ssl=0xaf837200: I/O error during system call, Connection timed out
D/GmsGcmMcsSvc(  884): Teardown initiated, reason: javax.net.ssl.SSLException: Read error: ssl=0xaf837200: I/O error during system call, Connection timed out
D/GmsGcmTrigger(  884): Ignoring Intent { act=org.microg.gms.gcm.RECONNECT flg=0x10 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver }: network is offline, scheduling new attempt.
D/GmsGcmTrigger(  884): 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/GmsGcmTrigger(  884): 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/GmsGcmTrigger(  884): Ignoring Intent { act=org.microg.gms.gcm.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmTrigger(  884): Ignoring Intent { act=org.microg.gms.gcm.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: network is offline, scheduling new attempt.
D/GmsGcmMcsSvc(  884): Connect initiated, reason: Intent { act=org.microg.gms.gcm.mcs.CONNECT cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
D/GmsGcmMcsSvc(  884): Starting MCS connection...
D/GmsCheckinClient(  884): -- Request --
D/GmsCheckinClient(  884): CheckinRequest{androidId=4563711268479711284, 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=1443207885, device=p880, sdkVersion=22, model=Optimus 4X HD, manufacturer=LGE, product=x3, otaInstalled=false}, lastCheckinMs=1444253743482, event=[Event{tag=system_update, value=1536,0,-1,NULL, timeMs=1444298346854}], stat=[], requestedGroup=[], cellOperator=26207, simOperator=26207, roaming=mobile-notroaming, userNumber=0}, locale=sr_RS, loggingId=-5682764228824660435, macAddress=[b407f9c6ecd5], meid=355031042155735, accountCookie=[], timeZone=Europe/Sarajevo, securityToken=4523325655660476993, version=3, otaCert=[71Q6Rn2DDZl1zPDVaaeEHItd], serial=0087413A92ED8713, 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_EX
D/GmsGcmMcsSvc(  884): Connected to mtalk.google.com:5228
D/GmsGcmMcsSvc(  884): Activated SSL with mtalk.google.com:5228
W/GmsGcmMcsSvc(  884): Exception while connecting!
W/GmsGcmMcsSvc(  884): javax.net.ssl.SSLHandshakeException: SSL handshake aborted: ssl=0xb4488200: I/O error during system call, Connection refused
W/GmsGcmMcsSvc(  884):  at com.android.org.conscrypt.NativeCrypto.SSL_do_handshake(Native Method)
W/GmsGcmMcsSvc(  884):  at com.android.org.conscrypt.OpenSSLSocketImpl.startHandshake(OpenSSLSocketImpl.java:318)
W/GmsGcmMcsSvc(  884):  at com.android.org.conscrypt.OpenSSLSocketImpl.waitForHandshake(OpenSSLSocketImpl.java:623)
W/GmsGcmMcsSvc(  884):  at com.android.org.conscrypt.OpenSSLSocketImpl.getInputStream(OpenSSLSocketImpl.java:585)
W/GmsGcmMcsSvc(  884):  at org.microg.gms.gcm.McsService.connect(McsService.java:177)
W/GmsGcmMcsSvc(  884):  at org.microg.gms.gcm.McsService.handleMessage(McsService.java:316)
W/GmsGcmMcsSvc(  884):  at android.os.Handler.dispatchMessage(Handler.java:98)
W/GmsGcmMcsSvc(  884):  at org.microg.gms.gcm.McsService.onHandleIntent(McsService.java:157)
W/GmsGcmMcsSvc(  884):  at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:65)
W/GmsGcmMcsSvc(  884):  at android.os.Handler.dispatchMessage(Handler.java:102)
W/GmsGcmMcsSvc(  884):  at android.os.Looper.loop(Looper.java:135)
W/GmsGcmMcsSvc(  884):  at android.os.HandlerThread.run(HandlerThread.java:61)
D/GmsGcmMcsSvc(  884): Teardown initiated, reason: javax.net.ssl.SSLHandshakeException: SSL handshake aborted: ssl=0xb4488200: I/O error during system call, Connection refused
D/GmsCheckinSvc(  884): Checked in as 3f558f38172e3834
^C
130|root@p880:/ #
mar-v-in commented 8 years ago

listening on connectivity changes and using it to restart the GCM service was always implemented. I guess the problem here is something else. 766a6a1 hopefully fixes these problems, else please report over in #31 or create a corresponding bug report (with logs).