-
Notifications
You must be signed in to change notification settings - Fork 127
Description
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 thefinally
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
- Docker image of Odoo 16
- Uses Werkzeug 1.0.1
- NewRelic Instrumentation Module
- Tested with New Relic 9.13.0
- Also reproduced with New Relic 9.1.0 as specified by the addon
Additional context
If I remove the following lines from __iter__()
in _WSGIApplicationIterable
:
finally:
self.close()
…then WebSocket works correctly again.