search

microg / GmsCore

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

GmsGcmMcsSvc: Unknown messages getting logged (push) #1590

Open grote opened 3 years ago

grote commented 3 years ago

While investigating push message issues, I noticed some unknown messages getting logged. It is probably nothing and might just get logged in error. Still, I'll paste some below with some context.

10-19 16:04:20.234 10134  8762  8762 D GmsGcmRegister: onBind: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms }
10-19 16:04:20.238 10134  8762  8762 D GmsGcmRegister: handleMessage: package=com.instagram.android what=2 id=2
10-19 16:04:20.238 10134  8762  8762 D GmsGcmRegister: Ack 0:1634639506425378%d88aa106f9fd7ecd for com.instagram.android
10-19 16:04:20.251 10134  8762  8822 D GmsGcmMcsSvc: Ack initiated, reason: Intent { act=org.microg.gms.gcm.mcs.ACK cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
10-19 16:04:20.256 10134  8762 15944 D GmsGcmMcsOutput: Outgoing message: IqStanza{type=SET, id=, extension=Extension{id=13, data=[size=0]}, status=0}
10-19 16:04:21.374 10134  8762  8762 D GmsGcmRegister: onBind: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms }
10-19 16:04:21.377 10134  8762  8762 D GmsGcmRegister: handleMessage: package=com.instagram.android what=2 id=3
10-19 16:04:21.378 10134  8762  8762 D GmsGcmRegister: Ack 0:1634639509884485%d88aa106f9fd7ecd for com.instagram.android
10-19 16:04:21.393 10134  8762  8822 D GmsGcmMcsSvc: Ack initiated, reason: Intent { act=org.microg.gms.gcm.mcs.ACK cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
10-19 16:04:21.397 10134  8762 15944 D GmsGcmMcsOutput: Outgoing message: IqStanza{type=SET, id=, extension=Extension{id=13, data=[size=0]}, status=0}
10-19 16:04:21.643 10134  8762 15943 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=3AC99DBD, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=12}
10-19 16:04:21.643 10134  8762 15943 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=3AC99DBD, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=12}
10-19 16:04:22.455 10134  8762  8762 D GmsGcmTrigger: Ignoring Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }: service is running. heartbeat instead.
10-19 16:04:22.464 10134  8762  8822 D GmsGcmMcsSvc: Heartbeat initiated, reason: Intent { act=org.microg.gms.gcm.mcs.RECONNECT flg=0x14 cmp=com.google.android.gms/org.microg.gms.gcm.TriggerReceiver (has extras) }
10-19 16:04:22.483 10134  8762  8822 D GmsGcmMcsSvc: Scheduling heartbeat in 1731 seconds...
10-19 16:04:22.484 10134  8762 15944 D GmsGcmMcsOutput: Outgoing message: HeartbeatPing{last_stream_id_received=14}
10-19 16:04:22.722 10134  8762 15943 D GmsGcmMcsInput: Incoming message: HeartbeatAck{last_stream_id_received=13}
10-19 16:04:15.170 10134  8762  8762 D GmsGcmTrigger: Not connected to GCM but should be, asking the service to start up. Triggered by: Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4200010 (has extras) }
10-19 16:04:15.188 10134  8762  8822 D GmsGcmMcsSvc: Connect initiated, reason: Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4200010 (has extras) }
10-19 16:04:15.188 10134  8762  8822 D GmsGcmMcsSvc: Connection is not enabled or dead.
10-19 16:04:15.236 10134  8762  8822 D GmsGcmMcsSvc: Starting MCS connection...
10-19 16:04:15.247 10134  8762  8762 D GmsGcmMcsSvc: Connection is not enabled or dead.
10-19 16:04:15.247 10134  8762  8762 D GmsGcmTrigger: Not connected to GCM but should be, asking the service to start up. Triggered by: Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4200010 (has extras) }
10-19 16:04:15.581 10134  8762  8822 D GmsGcmMcsSvc: Connected to mtalk.google.com:5228
10-19 16:04:15.583 10134  8762  8822 D GmsGcmMcsSvc: Activated SSL with mtalk.google.com:5228
10-19 16:04:15.743 10134  8762  8822 D GmsGcmMcsSvc: Scheduling heartbeat in 1731 seconds...
10-19 16:04:15.746 10134  8762  8822 D GmsGcmMcsSvc: Connect initiated, reason: Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4200010 (has extras) }
10-19 16:04:15.754 10134  8762 15944 D GmsGcmMcsSvc: Sending login request...
10-19 16:04:15.757 10134  8762 15944 D GmsGcmMcsOutput: Outgoing message: LoginRequest{id=android-30, domain=mcs.android.com, user=4191077836184055861, resource=4191077836184056861, auth_token=7282849056181573421, device_id=android-3a29b31634c3741d, setting=[Setting{name=new_vc, value=1}], received_persistent_id=[0:1634638625786376%e3016397f9fd7ecd|0:1634638756810353%e3016397f9fd7ecd], adaptive_heartbeat=false, use_rmq2=true, auth_service=ANDROID_ID, network_type=1}
10-19 16:04:15.757 10134  8762 15944 D GmsGcmMcsOutput: Write MCS version code: 41
10-19 16:04:15.971 10134  8762 15943 D GmsGcmMcsInput: Reading from MCS version: 41
10-19 16:04:15.978 10134  8762 15943 D GmsGcmMcsInput: Incoming message: LoginResponse{id=android-30, jid=user@firebase.com/notifications, last_stream_id_received=1, server_timestamp=1634639656537}
10-19 16:04:15.984 10134  8762 15943 D GmsGcmMcsSvc: Logged in
10-19 16:04:15.985 10134  8762 15943 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 16:04:15.985 10134  8762 15943 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 16:04:15.989 10134  8762 15943 D GmsGcmMcsInput: Incoming message: DataMessageStanza{id=3AC8A07A, from=331488535139, to=f9phv6QoQQacGxr3agQ1SK, category=com.fastmail.app, token=notification-A80D0686-redacted, app_data=[AppData{key=google.c.sender.id, value=331484435139}, AppData{key=data, value=redacted}, AppData{key=aps, value=\{"content-available":1\}}, AppData{key=nonce, value=dUm2jev9zPhrBUapZLi1N0HFjZuqYn0j}], persistent_id=0:1634639461798503%9f4755139dd77d6f, ttl=86400, sent=1634639461795}
10-19 16:04:16.002 10134  8762 15943 D GmsGcmMcsSvc: Adding app com.fastmail.app for userId 0 to the temp whitelist
10-19 16:04:16.007 10134  8762 15943 D GmsGcmMcsSvc: Deliver message to all receivers in package com.fastmail.app
10-19 15:47:22.233 10134  8762  9868 D GmsGcmMcsOutput: Write MCS version code: 41
10-19 15:47:22.350 10134  8762  9867 D GmsGcmMcsInput: Reading from MCS version: 41
10-19 15:47:22.458 10134  8762  9867 D GmsGcmMcsInput: Incoming message: LoginResponse{id=android-30, jid=user@firebase.com/notifications, last_stream_id_received=1, server_timestamp=1634638643030}
10-19 15:47:22.466 10134  8762  9867 D GmsGcmMcsSvc: Logged in
10-19 15:47:22.469 10134  8762  9867 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 15:47:22.469 10134  8762  9867 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 15:47:22.233 10134  8762  9868 D GmsGcmMcsOutput: Write MCS version code: 41
10-19 15:47:22.350 10134  8762  9867 D GmsGcmMcsInput: Reading from MCS version: 41
10-19 15:47:22.458 10134  8762  9867 D GmsGcmMcsInput: Incoming message: LoginResponse{id=android-30, jid=user@firebase.com/notifications, last_stream_id_received=1, server_timestamp=1634638643030}
10-19 15:47:22.466 10134  8762  9867 D GmsGcmMcsSvc: Logged in
10-19 15:47:22.469 10134  8762  9867 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 15:47:22.469 10134  8762  9867 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 15:21:53.066 10134  8762  8398 D GmsGcmMcsOutput: Write MCS version code: 41
10-19 15:21:53.357 10134  8762  8397 D GmsGcmMcsInput: Reading from MCS version: 41
10-19 15:21:53.357 10134  8762  8397 D GmsGcmMcsInput: Incoming message: LoginResponse{id=android-30, jid=user@firebase.com/notifications, last_stream_id_received=1, server_timestamp=1634637113900}
10-19 15:21:53.362 10134  8762  8397 D GmsGcmMcsSvc: Logged in
10-19 15:21:53.364 10134  8762  8397 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 15:21:53.364 10134  8762  8397 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 14:51:22.907 10134  8762  5789 D GmsGcmMcsOutput: Write MCS version code: 41
10-19 14:51:23.051 10134  8762  5788 D GmsGcmMcsInput: Reading from MCS version: 41
10-19 14:51:23.156 10134  8762  5788 D GmsGcmMcsInput: Incoming message: LoginResponse{id=android-30, jid=user@firebase.com/notifications, last_stream_id_received=1, server_timestamp=1634635283698}
10-19 14:51:23.166 10134  8762  5788 D GmsGcmMcsSvc: Logged in
10-19 14:51:23.168 10134  8762  5788 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 14:51:23.168 10134  8762  5788 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 11:39:29.579 10134  8762  8822 D GmsGcmMcsSvc: Ack initiated, reason: Intent { act=org.microg.gms.gcm.mcs.ACK cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
10-19 11:39:29.583 10134  8762 22765 D GmsGcmMcsOutput: Outgoing message: IqStanza{type=SET, id=, extension=Extension{id=13, data=[size=0]}, status=0}
10-19 11:39:29.809 10134  8762 22763 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=398A01BC, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=42}
10-19 11:39:29.809 10134  8762 22763 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=398A01BC, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=42}
10-19 11:39:14.025 10134  8762  8822 D GmsGcmMcsSvc: Ack initiated, reason: Intent { act=org.microg.gms.gcm.mcs.ACK cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
10-19 11:39:14.029 10134  8762 22765 D GmsGcmMcsOutput: Outgoing message: IqStanza{type=SET, id=, extension=Extension{id=13, data=[size=0]}, status=0}
10-19 11:39:14.260 10134  8762 22763 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=39879668, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=24}
10-19 11:39:14.260 10134  8762 22763 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=39879668, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=24}

10-19 11:39:10.381 10134  8762  8822 D GmsGcmMcsSvc: Ack initiated, reason: Intent { act=org.microg.gms.gcm.mcs.ACK cmp=com.google.android.gms/org.microg.gms.gcm.McsService (has extras) }
10-19 11:39:10.384 10134  8762 22765 D GmsGcmMcsOutput: Outgoing message: IqStanza{type=SET, id=, extension=Extension{id=13, data=[size=0]}, status=0}
10-19 11:39:10.624 10134  8762 22763 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=39871E9F, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=13}
10-19 11:39:10.624 10134  8762 22763 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=39871E9F, extension=Extension{id=13, data=[size=0]}, last_stream_id_received=13}
10-19 11:39:10.715 10134  8762  8762 D GmsGcmRegister: onBind: Intent { act=com.google.android.c2dm.intent.REGISTER pkg=com.google.android.gms }
10-19 11:39:10.719 10134  8762  8762 D GmsGcmRegister: handleMessage: package=com.fastmail.app what=2 id=13
10-19 11:38:43.930 10134  8762 22765 D GmsGcmMcsOutput: Write MCS version code: 41
10-19 11:38:44.160 10134  8762 22763 D GmsGcmMcsInput: Reading from MCS version: 41
10-19 11:38:44.161 10134  8762 22763 D GmsGcmMcsInput: Incoming message: LoginResponse{id=android-30, jid=user@firebase.com/notifications, last_stream_id_received=1, server_timestamp=1634623724682}
10-19 11:38:44.173 10134  8762 22763 D GmsGcmMcsSvc: Logged in
10-19 11:38:44.177 10134  8762 22763 D GmsGcmMcsInput: Incoming message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
10-19 11:38:44.177 10134  8762 22763 W GmsGcmMcsSvc: Unknown message: IqStanza{type=SET, id=, extension=Extension{id=12, data=[size=0]}}
ale5000-git commented 2 years ago

@grote: Do they still appears with the latest version of microG?

grote commented 2 years ago

I haven't checked. I just noticed when debugging other issues and wanted to document it, in case it interferes with push: Not reacting to certain messages.