v0.14.0 FCM error sending notification

[MichalNemec]

Hello, i have exactly the same issue as #365 and dont know why it got closed. If i remove the two properties from config, its working, but its needed.

If i leave those enabled, then its cycling to send and on macos its random if i get notification and even more random when i get it. Could this be looked at or did the settings changed in the config side?

...
2024-03-31 08:46:12,264 [1] INFO  twisted Starting factory _HTTP11ClientFactory(<function HTTPConnectionPool._newConnection.<locals>.quiescentCallback at 0x7f1cd6797880>, <twisted.internet.endpoints._WrapperEndpoint object at 0x7f1cd5e97ca0>)
2024-03-31 08:46:12,265 [1] INFO  twisted Starting factory _HTTP11ClientFactory(<function HTTPConnectionPool._newConnection.<locals>.quiescentCallback at 0x7f1cd684b490>, <twisted.internet.endpoints._WrapperEndpoint object at 0x7f1cd67b1960>)
2024-03-31 08:46:12,267 [1] INFO  twisted Starting factory _HTTP11ClientFactory(<function HTTPConnectionPool._newConnection.<locals>.quiescentCallback at 0x7f1cd5e90c10>, <twisted.internet.endpoints._WrapperEndpoint object at 0x7f1cd5e9c4c0>)
2024-03-31 08:46:12,319 [1] DEBUG sygnal.gcmpushkin [74cc5d5d-71f8-4e09-a55e-530575c035d4] GCM request took 0.327629 seconds
2024-03-31 08:46:12,320 [1] ERROR sygnal.gcmpushkin [74cc5d5d-71f8-4e09-a55e-530575c035d4] 400 from server, we have sent something invalid! Error: '{\n  "error": {\n    "code": 400,\n    "message": "Invalid JSON payload received. Unknown name \\"content_available\\" at \'message\': Cannot find field.\\nInvalid JSON payload received. Unknown name \\"mutable_content\\" at \'message\': Cannot find field.",\n    "status": "INVALID_ARGUMENT",\n    "details": [\n      {\n        "@type": "type.googleapis.com/google.rpc.BadRequest",\n        "fieldViolations": [\n          {\n            "field": "message",\n            "description": "Invalid JSON payload received. Unknown name \\"content_available\\" at \'message\': Cannot find field."\n          },\n          {\n            "field": "message",\n            "description": "Invalid JSON payload received. Unknown name \\"mutable_content\\" at \'message\': Cannot find field."\n          }\n        ]\n      }\n    ]\n  }\n}\n'
2024-03-31 08:46:12,320 [1] WARNING sygnal.http [74cc5d5d-71f8-4e09-a55e-530575c035d4] Failed to dispatch notification.
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/sygnal/http.py", line 275, in _handle_dispatch
    result = await pushkin.dispatch_notification(notif, d, context)
  File "/usr/local/lib/python3.10/site-packages/sygnal/notifications.py", line 217, in dispatch_notification
    return await self._dispatch_notification_unlimited(n, device, context)
  File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 574, in _dispatch_notification_unlimited
    new_failed, new_pushkeys = await self._request_dispatch(
  File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 287, in _request_dispatch
    return self._handle_v1_response(
  File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 431, in _handle_v1_response
    raise NotificationDispatchException("Invalid request")
sygnal.exceptions.NotificationDispatchException: Invalid request
2024-03-31 08:46:12,321 [1] INFO  sygnal.access Handled request: "IP" - - [31/Mar/2024:08:46:12 +0000] "POST /_matrix/push/v1/notify HTTP/1.1" 502 - "-" "Synapse/1.103.0"
2024-03-31 08:46:12,323 [1] DEBUG sygnal.gcmpushkin [70fb8467-9880-49cb-97f5-58d11aa440e6] GCM request took 0.198191 seconds
2024-03-31 08:46:12,323 [1] ERROR sygnal.gcmpushkin [70fb8467-9880-49cb-97f5-58d11aa440e6] 400 from server, we have sent something invalid! Error: '{\n  "error": {\n    "code": 400,\n    "message": "Invalid JSON payload received. Unknown name \\"content_available\\" at \'message\': Cannot find field.\\nInvalid JSON payload received. Unknown name \\"mutable_content\\" at \'message\': Cannot find field.",\n    "status": "INVALID_ARGUMENT",\n    "details": [\n      {\n        "@type": "type.googleapis.com/google.rpc.BadRequest",\n        "fieldViolations": [\n          {\n            "field": "message",\n            "description": "Invalid JSON payload received. Unknown name \\"content_available\\" at \'message\': Cannot find field."\n          },\n          {\n            "field": "message",\n            "description": "Invalid JSON payload received. Unknown name \\"mutable_content\\" at \'message\': Cannot find field."\n          }\n        ]\n      }\n    ]\n  }\n}\n'
2024-03-31 08:46:12,323 [1] WARNING sygnal.http [70fb8467-9880-49cb-97f5-58d11aa440e6] Failed to dispatch notification.
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/sygnal/http.py", line 275, in _handle_dispatch
    result = await pushkin.dispatch_notification(notif, d, context)
  File "/usr/local/lib/python3.10/site-packages/sygnal/notifications.py", line 217, in dispatch_notification
    return await self._dispatch_notification_unlimited(n, device, context)
  File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 574, in _dispatch_notification_unlimited
    new_failed, new_pushkeys = await self._request_dispatch(
  File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 287, in _request_dispatch
    return self._handle_v1_response(
  File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 431, in _handle_v1_response
    raise NotificationDispatchException("Invalid request")
sygnal.exceptions.NotificationDispatchException: Invalid request
2024-03-31 08:46:12,324 [1] INFO  sygnal.access Handled request: "IP" - - [31/Mar/2024:08:46:12 +0000] "POST /_matrix/push/v1/notify HTTP/1.1" 502 - "-" "Synapse/1.103.0"
2024-03-31 08:46:12,326 [1] DEBUG sygnal.gcmpushkin [57fed7a7-9154-407c-a41d-4690e9550af1] GCM request took 0.510864 seconds
...

[msl2000]

Closed the previous issue for a different question, but the issue is still prevalent.

Have you found a workaround?

[MichalNemec]

no, unfortunately i didnt.

[devonh]

Can you try out the config changes mentioned in https://github.com/matrix-org/sygnal/issues/365#issuecomment-2043678719?

[devonh]

Would you be able to try out the proposed config changes with the 0.14.1 release? That should fix the AttributeError: 'NoneType' object has no attribute 'items' error.

[MichalNemec]

Still having issues. everything from my setup looks correct, because sometimes i get notification on android.

sygnal    | 2024-04-15 18:19:58,215 [1] DEBUG sygnal.http [302f0a3a-1da9-407d-9bdf-ae62f641e6d3] Sending push to pushkin com.example.app for app ID com.example.app
sygnal    | 2024-04-15 18:19:58,284 [1] DEBUG google.auth.transport.requests Making request: POST https://oauth2.googleapis.com/token
sygnal    | 2024-04-15 18:19:58,285 [1] DEBUG urllib3.connectionpool Starting new HTTPS connection (1): oauth2.googleapis.com:443
sygnal    | 2024-04-15 18:19:58,451 [1] DEBUG urllib3.connectionpool https://oauth2.googleapis.com:443 "POST /token HTTP/1.1" 200 None
sygnal    | 2024-04-15 18:19:58,454 [1] INFO  sygnal.gcmpushkin [302f0a3a-1da9-407d-9bdf-ae62f641e6d3] Sending (attempt 0) => ['cU9fTBWBFE8ztT23lW5-Bg:APA91bFide3AP9DEy8xDdITPSr-kZiSPeTff0k0cWES1okCySZcfBpyfDovX2Sr7liHi_B5SPDh9PofRJ8_ycmkFoVyElt2Krf6lI4cKJZTRsrmYHyHmC9wRAGs0a4_EYLy-F0di4tB4'] room:!QsaIaKQfKAECmVSknN:matrix.domain.com, event:$GKUlIPZjr4IefY7NbaHqtP8FHFdJqsH6DxWlTrrakZw
sygnal    | 2024-04-15 18:19:58,454 [1] DEBUG sygnal.helper.proxy.proxyagent_twisted Requesting b'https://fcm.googleapis.com/v1/projects/notif-e9cf5/messages:send' via <HostnameEndpoint fcm.googleapis.com:443>
sygnal    | 2024-04-15 18:19:58,514 [1] DEBUG sygnal.gcmpushkin [302f0a3a-1da9-407d-9bdf-ae62f641e6d3] GCM request took 0.059976 seconds
sygnal    | 2024-04-15 18:19:58,514 [1] ERROR sygnal.gcmpushkin [302f0a3a-1da9-407d-9bdf-ae62f641e6d3] 400 from server, we have sent something invalid! Error: '{\n  "error": {\n    "code": 400,\n    "message": "Request contains an invalid argument.",\n    "status": "INVALID_ARGUMENT",\n    "details": [\n      {\n        "@type": "type.googleapis.com/google.firebase.fcm.v1.FcmError",\n        "errorCode": "INVALID_ARGUMENT"\n      },\n      {\n        "@type": "type.googleapis.com/google.rpc.BadRequest",\n        "fieldViolations": [\n          {\n            "field": "message.token",\n            "description": "Invalid registration token"\n          }\n        ]\n      }\n    ]\n  }\n}\n'
sygnal    | 2024-04-15 18:19:58,514 [1] WARNING sygnal.http [302f0a3a-1da9-407d-9bdf-ae62f641e6d3] Failed to dispatch notification.
sygnal    | Traceback (most recent call last):
sygnal    |   File "/usr/local/lib/python3.10/site-packages/sygnal/http.py", line 275, in _handle_dispatch
sygnal    |     result = await pushkin.dispatch_notification(notif, d, context)
sygnal    |   File "/usr/local/lib/python3.10/site-packages/sygnal/notifications.py", line 217, in dispatch_notification
sygnal    |     return await self._dispatch_notification_unlimited(n, device, context)
sygnal    |   File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 574, in _dispatch_notification_unlimited
sygnal    |     new_failed, new_pushkeys = await self._request_dispatch(
sygnal    |   File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 287, in _request_dispatch
sygnal    |     return self._handle_v1_response(
sygnal    |   File "/usr/local/lib/python3.10/site-packages/sygnal/gcmpushkin.py", line 431, in _handle_v1_response
sygnal    |     raise NotificationDispatchException("Invalid request")
sygnal    | sygnal.exceptions.NotificationDispatchException: Invalid request
sygnal    | 2024-04-15 18:19:58,515 [1] INFO  sygnal.access Handled request: "IP" - - [15/Apr/2024:18:19:58 +0000] "POST /_matrix/push/v1/notify HTTP/1.1" 502 - "-" "Synapse/1.104.0"

[devonh]

Interesting. The important parts of that output are: INVALID_ARGUMENT &

{
  "fieldViolations": [ 
    { 
      "field": "message.token", 
      "description": "Invalid registration token" 
    } 
  ] 
}

Because the notifications are sometimes getting through on android, I assume this is a problem with sending to iOS. If the token being used is the APNs token instead of the FCM token, that would present itself in this way.

What iOS client is being used in this case?

[MichalNemec]

custom, but its a fork of fluffychat

[devonh]

Are you still seeing these issues with the latest version of Sygnal (0.14.3)?