sygnal
sygnal copied to clipboard
Don't log stack trace when handling `TemporaryNotificationDispatchException` exception
Describe the bug Not sure but saw something in the debug logs
2021-06-09 14:12:27,111 [1] INFO sygnal.access Handled request: "127.0.0.1" - - [09/Jun/2021:12:12:27 +0000] "POST /_matrix/push/v1/notify HTTP/1.0" 200 16 "-" "Synapse/1.27.0"
2021-06-09 14:14:51,633 [1] DEBUG sygnal.http [132ef873-b946-4892-8c14-3260ae636326] Sending push to pushkin com.aarenet.anConnect.ios.app.ios.prod for app ID com.aarenet.anConnect.ios.app.ios.prod
2021-06-09 14:14:51,634 [1] INFO sygnal.apnspushkin [132ef873-b946-4892-8c14-3260ae636326] Sending as APNs-ID 202656f0-f97e-4782-8911-9c26dfce882b
2021-06-09 14:14:51,634 [1] DEBUG aioapns Notification 202656f0-f97e-4782-8911-9c26dfce882b: waiting for connection
2021-06-09 14:14:51,636 [1] DEBUG sygnal.http [3a3949ad-d628-44c8-abff-c812aa08b910] Sending push to pushkin com.aarenet.anconnect.android for app ID com.aarenet.anconnect.android
2021-06-09 14:14:51,638 [1] INFO sygnal.gcmpushkin [3a3949ad-d628-44c8-abff-c812aa08b910] Sending (attempt 0) => ['fG3HsmCoQGCt4nV37ce68K:APA91bF5ST_wz9tBHmgC8VNmjLz52rkOSe-3JdkNoeFiaj_ge7hD0Fr6Imcl-mRHihviqohmhg9q4IoO_WSy0wplMxCYRAVbFD7Wi2UVvOu8YFGmYwruN-TAldH9Qx0f2EN5WgBcpacA']
2021-06-09 14:14:51,638 [1] DEBUG sygnal.helper.proxy.proxyagent_twisted Requesting b'https://fcm.googleapis.com/fcm/send' via <HostnameEndpoint fcm.googleapis.com:443>
2021-06-09 14:14:51,644 [1] WARNING sygnal.gcmpushkin [3a3949ad-d628-44c8-abff-c812aa08b910] Temporary failure, will retry in 10 seconds
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/sygnal/gcmpushkin.py", line 193, in _perform_http_request
bodyProducer=body_producer,
twisted.web._newclient.ResponseNeverReceived: [<twisted.python.failure.Failure twisted.internet.error.ConnectionLost: Connection to the other side was lost in a non-clean fashion: Connection lost.>]
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/sygnal/gcmpushkin.py", line 384, in _dispatch_notification_unlimited
n, log, body, headers, mapped_pushkeys, span
File "/usr/local/lib/python3.7/site-packages/sygnal/gcmpushkin.py", line 209, in _request_dispatch
response, response_text = await self._perform_http_request(body, headers)
File "/usr/local/lib/python3.7/site-packages/sygnal/gcmpushkin.py", line 199, in _perform_http_request
) from exception
sygnal.exceptions.TemporaryNotificationDispatchException: GCM request failure
2021-06-09 14:14:51,745 [1] INFO twisted Stopping factory _HTTP11ClientFactory(<function HTTPConnectionPool._newConnection.<locals>.quiescentCallback at 0x7f99c4350f80>, <twisted.internet.endpoints._WrapperEndpoint object at 0x7f99c42b36d0>)
That looks to be because the request timed out. Maybe the internet or Google had a blip or something :shrug:
I'm not sure why we log the stack trace though, we should just log the exception message and not the stack trace.
I think this is just a case of removing exc_info=True
here:
https://github.com/matrix-org/sygnal/blob/214497a1584c37e57f01499628d123ed984bd271/sygnal/gcmpushkin.py#L398-L402
And also adding exc
to the log line.