Sentry noise created by BrokenPipeError when logging (legacy?) metrics

[DMRobertson]

E.g https://sentry.tools.element.io/organizations/element/issues/90/events/4eed7e6e30e541cda425e3395680f230/?project=2&query=is%3Aunresolved+----------------------------------------&sort=freq&statsPeriod=14d

Looking up the logs from matrix.org:

2022-09-28 09:35:15,429 - synapse.util.caches.lrucache - 212 - INFO - LruCache._expire_old_entries-22758 - Dropped 2223 items from caches
2022-09-28 09:35:15,436 - synapse.metrics._gc - 120 - INFO - sentinel - Collecting gc 2
2022-09-28 09:35:33,456 - twisted - 274 - ERROR - sentinel - ----------------------------------------
2022-09-28 09:35:33,462 - twisted - 274 - ERROR - sentinel - Exception happened during processing of request from ('94.237.56.139', 33022)
2022-09-28 09:35:33,476 - twisted - 274 - ERROR - sentinel - Traceback (most recent call last):
2022-09-28 09:35:33,482 - twisted - 274 - ERROR - sentinel -   File "/home/synapse/pyston_2.3.3/lib/python3.8-pyston2.3/socketserver.py", line 683, in process_request_thread
2022-09-28 09:35:33,483 - twisted - 274 - ERROR - sentinel -     self.finish_request(request, client_address)
2022-09-28 09:35:33,486 - twisted - 274 - ERROR - sentinel -   File "/home/synapse/pyston_2.3.3/lib/python3.8-pyston2.3/socketserver.py", line 360, in finish_request
2022-09-28 09:35:33,487 - twisted - 274 - ERROR - sentinel -     self.RequestHandlerClass(request, client_address, self)
2022-09-28 09:35:33,488 - twisted - 274 - ERROR - sentinel -   File "/home/synapse/pyston_2.3.3/lib/python3.8-pyston2.3/socketserver.py", line 747, in __init__
2022-09-28 09:35:33,489 - twisted - 274 - ERROR - sentinel -     self.handle()
2022-09-28 09:35:33,491 - twisted - 274 - ERROR - sentinel -   File "/home/synapse/pyston_2.3.3/lib/python3.8-pyston2.3/http/server.py", line 427, in handle
2022-09-28 09:35:33,491 - twisted - 274 - ERROR - sentinel -     self.handle_one_request()
2022-09-28 09:35:33,492 - twisted - 274 - ERROR - sentinel -   File "/home/synapse/pyston_2.3.3/lib/python3.8-pyston2.3/http/server.py", line 415, in handle_one_request
2022-09-28 09:35:33,494 - twisted - 274 - ERROR - sentinel -     method()
2022-09-28 09:35:33,495 - twisted - 274 - ERROR - sentinel -   File "/home/synapse/src/synapse/metrics/_legacy_exposition.py", line 226, in do_GET
2022-09-28 09:35:33,496 - twisted - 274 - ERROR - sentinel -     self.wfile.write(output)
2022-09-28 09:35:33,497 - twisted - 274 - ERROR - sentinel -   File "/home/synapse/pyston_2.3.3/lib/python3.8-pyston2.3/socketserver.py", line 826, in write
2022-09-28 09:35:33,498 - twisted - 274 - ERROR - sentinel -     self._sock.sendall(b)
2022-09-28 09:35:33,499 - twisted - 274 - ERROR - sentinel - BrokenPipeError: [Errno 32] Broken pipe
2022-09-28 09:35:33,500 - twisted - 274 - ERROR - sentinel - ----------------------------------------

which comes from

synapse/synapse/metrics/_legacy_exposition.py

Lines 208 to 226 in cf11919

	def do_GET(self) -> None:
	registry = self.registry
	params = parse_qs(urlparse(self.path).query)
	if "help" in params:
	emit_help = True
	else:
	emit_help = False
	try:
	output = generate_latest(registry, emit_help=emit_help)
	except Exception:
	self.send_error(500, "error generating metric output")
	raise
	self.send_response(200)
	self.send_header("Content-Type", CONTENT_TYPE_LATEST)
	self.send_header("Content-Length", str(len(output)))
	self.end_headers()
	self.wfile.write(output)

Note that this isn't using our regular Servlet machinery but a stdlib socketserver to serve HTTP.

I'm not familiar with BrokenPipeError, but apparently it is

raised when trying to write on a pipe while the other end has been closed, or trying to write on a socket which has been shutdown for writing.

[DMRobertson]

Suggestions, in order of decreasing pragmatism:

• Catch BrokenPipeError while writing and log a warning if it occurs. (Assuming we didn't "shutdown the socket for writing", probably not an error: we didn't do anything wrong, the far end went away.)
• Catch any Exception from within do_GET?
• Write our own subclass of BaseHTTPRequestHandler which catches and logs exceptions

[richvdh]

another possibility:

• assuming these exception are getting to stderr via the uncaught exception hook: add a hook which sends them via the logger instead. (I actually thought Sentry installed an excepthook: are these hitting sentry twice?)