microg / microg/GmsCore

GmsGcmMcsSvc: Unknown messages getting logged (push)

Open
#1,590 2 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

☁️ Cloud / Push Messaging bug
Dominant language
Java
Stars
14.6k
Forks
3.2k
Avg merge
12d 11h
Merged PRs (30d)
4

Description

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]}}

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start at GmsGcmMcsSvc and the GmsGcmMcsInput entries for incoming IqStanza messages, comparing the logged extension IDs 12 and 13 with the surrounding login and acknowledgement flow. Determine whether these messages are expected and what handling or logging outcome is required; done means the unknown-message reports are correctly resolved and push acknowledgements still work.

Written by the indexing model from the issue text.

Assessment

Tech stack
android, firebase, java
Domain
mobile
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.