newrelic-python-agent icon indicating copy to clipboard operation
newrelic-python-agent copied to clipboard

Premature response iterator close in `_WSGIApplicationIterable.__iter__` breaks WebSocket handling in Odoo 16 + Werkzeug 1.0.1

Open emilkholod opened this issue 8 months ago • 4 comments

Description

In _WSGIApplicationIterable.__iter__:

def __iter__(self):
	self.start_trace()

	try:
		for item in self.generator:
			try:
				self.transaction._calls_yield += 1
				self.transaction._bytes_sent += len(item)
			except Exception:
				pass

			yield item

	except GeneratorExit:
		raise

	except:  # Catch all
		notice_error()
		raise

	finally:
		self.close()

🔴 Issue: self.close() is called immediately after iteration ends, even before response headers may have been sent in some frameworks.

Troubleshooting or NR Diag results

I added logging inside the execute() method in Werkzeug’s WSGIRequestHandler:

def execute(app):
	self.log_message("We have request on '%s' endpoint", environ.get("PATH_INFO"))
	application_iter = app(environ, start_response)
	try:
		for data in application_iter:
			write(data)
		if not headers_sent:
			self.log_message("On '%s' endpoint we need to write empty bytes", environ.get("PATH_INFO"))
			write(b"")
			self.log_message("On '%s' endpoint empty bytes were written", environ.get("PATH_INFO"))
	except Exception as exc:
		import traceback
		self.log_error("On '%s' endpoint something went wrong: %s", environ.get("PATH_INFO"), traceback.format_exc())
	finally:
		if hasattr(application_iter, "close"):
			application_iter.close()

Resulting log:

We have request on '/websocket' endpoint - - -
On '/websocket' endpoint we need to write empty bytes 5 0.004 10.003
On '/websocket' endpoint something went wrong: Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/werkzeug/serving.py", line 319, in execute
    write(b"")
  File "/usr/lib/python3/dist-packages/werkzeug/serving.py", line 273, in write
    self.send_response(code, msg)
  File "/usr/lib/python3/dist-packages/werkzeug/serving.py", line 394, in send_response
    self.wfile.write(hdr.encode("ascii"))
  File "/usr/lib/python3.9/socketserver.py", line 799, in write
    self._sock.sendall(b)
BrokenPipeError: [Errno 32] Broken pipe - - -

This happens because the iterator is already closed by New Relic before write(b"") is called.

So the question are:

  • Is it a bug that self.close() is called in the finally block of __iter__()?
  • Or should websocket transactions never be wrapped in _WSGIApplicationIterable at all?
  • And why ignore_transaction doesn't work?

Expected Behavior

According to PEP-3333:

try:
	for data in result:
		if data:  # don't send headers until body appears
			write(data)
	if not headers_sent:
		write(b'')  # send headers now if body was empty
finally:
	if hasattr(result, 'close'):
		result.close()

➡️ close() should only be called after any final attempt to flush headers using write().

Werkzeug implements this correctly (source):

try:
	for data in application_iter:
		write(data)
	if not headers_sent:
		write(b"")
finally:
	if hasattr(application_iter, "close"):
		application_iter.close()

➡️ In this scenario, when the WebSocket route returns an empty iterator, write(b"") triggers header flush after iteration.
This gets broken when self.close() is called early by New Relic's wrapper.

So WebSocket connections fail after New Relic instrumentation is enabled.

Two possible fixes:

  • The agent should not call close() before WSGI server has sent headers.
  • Or it should not wrap WebSocket endpoints at all in _WSGIApplicationIterable.

Maybe also ignore_transaction should be rechecked?

Your Environment

Additional context

If I remove the following lines from __iter__() in _WSGIApplicationIterable:

finally:
	self.close()

…then WebSocket works correctly again.

emilkholod avatar Jun 07 '25 08:06 emilkholod