Log spam with backtraces, when a federation transaction returns a response without body

[deepbluev7]

Description

Some homeservers don't always return a response on PUT /_matrix/federation/v1/send/{txnId}, if the transaction included no PDUs. While that is probably a spec violation, I think synapse should handle that more gracefully and not try to parse an empty response as JSON.

@400000005ffaf4b51ecf4add 2021-01-10 12:35:28,516 - synapse.http.matrixfederationclient - 187 - WARNING - federation_transaction_transmission_loop-21412 - {PUT-O-14279} [test.zemos.net] Error reading response PUT matrix://test.zemo
s.net/_matrix/federation/v1/send/1610274786587: Expecting value: line 1 column 1 (char 0)
@400000005ffaf4b51ed3c572 2021-01-10 12:35:28,516 - synapse.federation.sender.per_destination_queue - 427 - ERROR - federation_transaction_transmission_loop-21412 - TX [test.zemos.net] Failed to send transaction
@400000005ffaf4b51ed3c9e8 Traceback (most recent call last):
@400000005ffaf4b51ed3cbf1   File "/usr/lib/python3.8/site-packages/synapse/federation/sender/per_destination_queue.py", line 331, in _transaction_transmission_loop
@400000005ffaf4b51ed3cde6     success = await self._transaction_manager.send_new_transaction(
@400000005ffaf4b51ed3cfa9   File "/usr/lib/python3.8/site-packages/synapse/util/metrics.py", line 92, in measured_func
@400000005ffaf4b51ed3d126     r = await func(self, *args, **kwargs)
@400000005ffaf4b51ed3d2b7   File "/usr/lib/python3.8/site-packages/synapse/federation/sender/transaction_manager.py", line 149, in send_new_transaction
@400000005ffaf4b51ed3d433     response = await self._transport_layer.send_transaction(
@400000005ffaf4b51ed3d57e   File "/usr/lib/python3.8/site-packages/synapse/federation/transport/client.py", line 154, in send_transaction
@400000005ffaf4b51ed3d6fb     response = await self.client.put_json(
@400000005ffaf4b51ed3d877   File "/usr/lib/python3.8/site-packages/synapse/http/matrixfederationclient.py", line 717, in put_json
@400000005ffaf4b51ed3d9cc     body = await _handle_json_response(
@400000005ffaf4b51ed3db3f   File "/usr/lib/python3.8/site-packages/synapse/http/matrixfederationclient.py", line 176, in _handle_json_response
@400000005ffaf4b51ed3dc93     body = await make_deferred_yieldable(d)
@400000005ffaf4b51ed3ddf2   File "/usr/lib/python3.8/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
@400000005ffaf4b51ed3df47     current.result = callback(current.result, *args, **kw)
@400000005ffaf4b51ed3e091   File "/usr/lib/python3.8/json/decoder.py", line 337, in decode
@400000005ffaf4b51ed3e1fa     obj, end = self.raw_decode(s, idx=_w(s, 0).end())
@400000005ffaf4b51ed3e359   File "/usr/lib/python3.8/json/decoder.py", line 355, in raw_decode
@400000005ffaf4b51ed3e499     raise JSONDecodeError("Expecting value", s, err.value) from None
@400000005ffaf4b51ed3e5f8 json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

Steps to reproduce

• send some EDUs to a construct server

Version information

• Homeserver: neko.dev and a few others

• Version: Synapse 1.25rc1

• Install method: various

• Platform: various

[clokep]

We should probably be catching the JSON error and doing something reasonable with it. It does seem like this should return some sort of body though: https://matrix.org/docs/spec/server_server/latest#put-matrix-federation-v1-send-txnid

[deepbluev7]

I totally agree, that some body should be returned, but the spec only really makes this explicit, when PDUs are in the transaction. I had a discussion with the construct author and he said, since the json would be empty, the body is unnecessary. He'll fix it in any case though. I only documented this here, because I think this could be handled more nicely in the logs. It's really minor. It just is a bit confusing, that the transaction seems to be successful, but still throws an error and causes sentry notifications. Probably a good issue for someone new to synapse to look into or so.

[clokep]

I'm going to fix this since it is spamming our sentry too.