On Aug 2, 2019, at 4:31 PM, Waqar Khan wrote:

Hi, I have a twisted server. And I have been seeing this annoying issue. Normally. when i develop and test it out. everything is fine.. But then I try to loadtest is via https://locust.io/ https://locust.io/

Again, everything is fine.. until I "stop" the test. Then, I see this 'Traceback (most recent call last):\n File "/usr/local/Cellar/python/3.7.1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/events.py", line 88, in _run\n self._context.run(self._callback, *self._args)\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 827, in adapt\n adapt.actual.callback(extracted)\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 460, in callback\n self._startRunCallbacks(result)\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks\n self._runCallbacks()\n--- <exception caught here> ---\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks\n current.result = callback(current.result, *args, **kw)\n File .... File "/usr/local/lib/python3.7/site-packages/twisted/web/server.py", line 238, in write\n http.Request.write(self, data)\n File "/usr/local/lib/python3.7/site-packages/twisted/web/http.py", line 1118, in write\n self.channel.writeHeaders(version, code, reason, headers)\nbuiltins.AttributeError: \'NoneType\' object has no attribute \'writeHeaders\'\n'

I found this similar bug report: https://github.com/buildbot/buildbot/issues/4045 https://github.com/buildbot/buildbot/issues/4045 But I am using 19.2.1 twisted version..

There is a prerelease version, with this bug fixed, that is awaiting final release upload right now; can you try with Twisted==19.7.0rc1 ? That should fix this issue. If not, then we have some investigating to do :-). -g -g

On Aug 4, 2019, at 5:57 PM, Waqar Khan wrote:

Hi Glyph, Thanks for the suggestion. I tried the suggestion.. While it fixes the self.channel NoneType issue.. It creates another issue.

Traceback (most recent call last): File "/usr/local/Cellar/python/3.7.1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 827, in adapt adapt.actual.callback(extracted) File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 460, in callback self._startRunCallbacks(result) File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks self._runCallbacks() --- <exception caught here> --- File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks current.result = callback(current.result, *args, **kw) ...... request.finish() File "/usr/local/lib/python3.7/site-packages/twisted/web/server.py", line 268, in finish return http.Request.finish(self) File "/usr/local/lib/python3.7/site-packages/twisted/web/http.py", line 1071, in finish "Request.finish called on a request after its connection was lost; " builtins.RuntimeError: Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this.

Oh, hrm. The idea here is that any code that returns NOT_DONE_YET (i.e. does asynchronous work to generate a response) should also be tracking whether it needs to call `.finish()` by watching a `.notifyFinish()` Deferred. I bet that there are plenty of resources in Twisted which don't follow this rule, and we should fix those; but possibly we should also make this error message less stern. Do you have a minimal example?

I have got some handle on the issue. I was wondering if you have any advise on how to debug the issue. Somewhere in the codebase are async/await code (from asyncio world). Hence, when the connection is closed down by client, seems like those pending coroutines are lingering on.

This, I have no idea about. What tasks are you starting, when are you expecting them to get cleaned up, what are they blocking on, how do these interact with Twisted? There are a couple dozen questions I'd have to know the answer to in order to even begin debugging this. If you cancel all the outstanding tasks and look at their tracebacks when exiting it might give you more of a sense of where they're stuck... -g

Just for sake of completeness: def print_json_response(resp, request): request.write(json.dumps(resp)) request.close() It is this close function which is causing the issue I suspect that somehow the fact that the client has closed the connection, is not being handled. On Sun, Aug 4, 2019 at 11:26 PM Waqar Khan wrote:

Hi Glyph, Here is the minimal version

class FooResource(resource.Resource): def render_GET(request): future = asyncio.ensure_future(self.fetch_response(request)) // some async await functions d = Deferred.fromFuture(future) d.addCallback(print_json_response, request) // this is actually where the error is triggered. d.addErrback(lambda failure: failure.trap(defer.CancelledError)) finished_errback = request.notifyFinish() finished_errback.addErrback(self.handle_cancel, d) // simple logs and cancels d by d.cancel() return NOT_DONE_YET

The traceback is like 'Traceback (most recent call last):\n File "/usr/local/Cellar/python/3.7.1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/events.py", line 88, in _run\n self._context.run(self._callback, *self._args)\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 827, in adapt\n adapt.actual.callback(extracted)\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 460, in callback\n self._startRunCallbacks(result)\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks\n self._runCallbacks()\n--- <exception caught here> ---\n File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks\n current.result = callback(current.result, *args, **kw)\n File "/Users/wqKhan/twisted_eg/parse_response.py", line 3, in print_json_response\n *print_json_response*(response, request)\n File "/Users/wqKhan/twisted_eg/parse_response.py", line 21, in *print_json_response*\n request.finish()\n File "/usr/local/lib/python3.7/site-packages/twisted/web/server.py", line 268, in finish\n return http.Request.finish(self)\n File "/usr/local/lib/python3.7/site-packages/twisted/web/http.py", line 1071, in finish\n "Request.finish called on a request after its connection was lost; "\nbuiltins.RuntimeError: Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this.\n'

On Sun, Aug 4, 2019 at 10:36 PM Glyph wrote:

...

...

On Aug 4, 2019, at 5:57 PM, Waqar Khan wrote:

Hi Glyph, Thanks for the suggestion. I tried the suggestion.. While it fixes the self.channel NoneType issue.. It creates another issue.

Traceback (most recent call last): File "/usr/local/Cellar/python/3.7.1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 827, in adapt adapt.actual.callback(extracted) File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 460, in callback self._startRunCallbacks(result) File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks self._runCallbacks() --- <exception caught here> --- File "/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks current.result = callback(current.result, *args, **kw) ...... request.finish() File "/usr/local/lib/python3.7/site-packages/twisted/web/server.py", line 268, in finish return http.Request.finish(self) File "/usr/local/lib/python3.7/site-packages/twisted/web/http.py", line 1071, in finish "Request.finish called on a request after its connection was lost; " builtins.RuntimeError: Request.finish called on a request after its connection was lost; use Request.notifyFinish to keep track of this.

Oh, hrm. The idea here is that any code that returns NOT_DONE_YET (i.e. does asynchronous work to generate a response) should also be tracking whether it needs to call `.finish()` by watching a `.notifyFinish()` Deferred. I bet that there are plenty of resources in Twisted which don't follow this rule, and we should fix those; but possibly we should also make this error message less stern. Do you have a minimal example?

...

I have got some handle on the issue. I was wondering if you have any advise on how to debug the issue. Somewhere in the codebase are async/await code (from asyncio world). Hence, when the connection is closed down by client, seems like those pending coroutines are lingering on.

This, I have no idea about. What tasks are you starting, when are you expecting them to get cleaned up, what are they blocking on, how do these interact with Twisted? There are a couple dozen questions I'd have to know the answer to in order to even begin debugging this. If you cancel all the outstanding tasks and look at their tracebacks when exiting it might give you more of a sense of where they're stuck...

-g

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

Ah yes.. That is true.. If I comment out request.finish() (Here is the doc which I tried to followed: https://twistedmatrix.com/documents/13.0.0/web/howto/web-in-60/interrupted.h... ) Then actually.. when I try to test out the code... (via curl or like doing requests.get .. to the URI).. it is just stuck.. In [491]: requests.get("http://0.0.0.0:9999/test ....with params " ) It just stays stuck :( I do want to convey my thanks for the help. Really appreciate it. On Sun, Aug 4, 2019 at 11:55 PM Glyph wrote:

...

On Aug 4, 2019, at 8:43 PM, Waqar Khan wrote:

Just for sake of completeness: def print_json_response(resp, request): request.write(json.dumps(resp)) request.close()

Presumably this line actually says "request.finish()"?

This is indeed the problem; just don't call "request.finish()" if notifyFinish() has already been callback'd.

-g

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

Hi Glyph, I am not sure I understand. Is there a method/variable in request which keeps a track whether notifyFinish has been fired.. So, I can do something like. if not request.hasFiredNotifyFinish: request.finish() ?? I have sort of able to get around this issue.. though I can't put a finger on what actually worked. Here is what I did.. First change to 19.7rc01 version.. and just fix the channel issue. Next self.fetch_response(request).. This is an async def.. So what I did was.. async def fetch_response(request): future = {} try: future = await some other async def.. which returns future except asyncio.CancelledError as e: print("Error..", e) return future I basically ended up doing this everywhere where there is async/await. Next, I added this: d.addErrback(lambda failure: failure.trap(asyncio.CancelledError)) So.. now.. I don't see the notifyFinish error anymore. And I am bit terrified not to touch anything.. :-D But, I want to try out your suggestion as that seems like a more solid way to handle the issue. But I am not sure I quite understand, how do I figure out whether notifyFinish has been called before calling finish? On Mon, Aug 5, 2019 at 1:56 AM Glyph wrote:

On Aug 4, 2019, at 9:04 PM, Waqar Khan wrote:

Ah yes.. That is true..

If I comment out request.finish() (Here is the doc which I tried to followed: https://twistedmatrix.com/documents/13.0.0/web/howto/web-in-60/interrupted.h... ) Then actually.. when I try to test out the code... (via curl or like doing requests.get .. to the URI).. it is just stuck..

Yep! This makes sense; if you don't call `.finish()` *at all* then your code will never tell the client that it's done.

But if you call `.finish()` *after notifyFinish() has fired* then you get that error.

If you change your code to only call `.finish()` if the deferred returned by notifyFinish() has not fired or failed yet, do you get the error? It's possible that you still do, in which case, there's a bug in Twisted that needs to be fixed.

I do want to convey my thanks for the help. Really appreciate it.

Thanks for using Twisted :) -g

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

On Mon, Aug 5, 2019 at 2:15 PM Waqar Khan wrote:

False alarm. Seems like there are some sneaky conditions when I get the error message. Like before, I use to get notifyFinish error everytime. Now, it seems that 6/10 times things are "clean" but then 4/10 times there are notifyFinish errors. Wondering on your suggestion. How do I ensure whether the notifyFinish error deferred has been fired or not. Could I have like a vanilla "HelloWorld" example? Thanks

You can find an example of this here - https://twistedmatrix.com/documents/current/web/howto/web-in-60/interrupted.... Jean-Paul

On Mon, Aug 5, 2019 at 2:24 AM Waqar Khan wrote:

...

Hi Glyph, I am not sure I understand.

Is there a method/variable in request which keeps a track whether notifyFinish has been fired.. So, I can do something like.

if not request.hasFiredNotifyFinish: request.finish() ??

I have sort of able to get around this issue.. though I can't put a finger on what actually worked. Here is what I did.. First change to 19.7rc01 version.. and just fix the channel issue.

Next self.fetch_response(request).. This is an async def.. So what I did was..

async def fetch_response(request): future = {} try: future = await some other async def.. which returns future except asyncio.CancelledError as e: print("Error..", e) return future

I basically ended up doing this everywhere where there is async/await. Next, I added this: d.addErrback(lambda failure: failure.trap(asyncio.CancelledError))

So.. now.. I don't see the notifyFinish error anymore. And I am bit terrified not to touch anything.. :-D

But, I want to try out your suggestion as that seems like a more solid way to handle the issue. But I am not sure I quite understand, how do I figure out whether notifyFinish has been called before calling finish?

On Mon, Aug 5, 2019 at 1:56 AM Glyph wrote:

...

On Aug 4, 2019, at 9:04 PM, Waqar Khan wrote:

Ah yes.. That is true..

If I comment out request.finish() (Here is the doc which I tried to followed: https://twistedmatrix.com/documents/13.0.0/web/howto/web-in-60/interrupted.h... ) Then actually.. when I try to test out the code... (via curl or like doing requests.get .. to the URI).. it is just stuck..

Yep! This makes sense; if you don't call `.finish()` *at all* then your code will never tell the client that it's done.

But if you call `.finish()` *after notifyFinish() has fired* then you get that error.

If you change your code to only call `.finish()` if the deferred returned by notifyFinish() has not fired or failed yet, do you get the error? It's possible that you still do, in which case, there's a bug in Twisted that needs to be fixed.

I do want to convey my thanks for the help. Really appreciate it.

Thanks for using Twisted :) -g

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

To add on this.. Glpyh's suggestion was to not call `request.close()` if notifyFinish() deferred has been fired. But I am not sure how do I check if that deffered is available or not. On Mon, Aug 5, 2019 at 2:26 PM Waqar Khan wrote:

Hi Jean, Yeah, actually that is the example that I looked into and implemented my code.

The issue I have is.. still some instances of interrupted responses are not trapped. Copying pasting my minimal implementation for your convinence

def print_json_response(resp, request): request.write(json.dumps(resp)) request.close() class FooResource(resource.Resource): def render_GET(request): future = asyncio.ensure_future(self.fetch_response(request)) // some async await functions d = Deferred.fromFuture(future) d.addCallback(print_json_response, request) // this is actually where the error is triggered. d.addErrback(lambda failure: failure.trap(defer.CancelledError)) finished_errback = request.notifyFinish() finished_errback.addErrback(self.handle_cancel, d) // simple logs and cancels d by d.cancel() return NOT_DONE_YET

async def fetch_response(self, request): future = {} try: future = await some other async def.. which returns future except asyncio.CancelledError as e: print("Error..", e) return future def handle_cancel(failure, d): d.cancel() print(failure.getTraceback())

On Mon, Aug 5, 2019 at 2:21 PM Jean-Paul Calderone < exarkun@twistedmatrix.com> wrote:

...

On Mon, Aug 5, 2019 at 2:15 PM Waqar Khan wrote:

...

False alarm. Seems like there are some sneaky conditions when I get the error message. Like before, I use to get notifyFinish error everytime. Now, it seems that 6/10 times things are "clean" but then 4/10 times there are notifyFinish errors. Wondering on your suggestion. How do I ensure whether the notifyFinish error deferred has been fired or not. Could I have like a vanilla "HelloWorld" example? Thanks

You can find an example of this here - https://twistedmatrix.com/documents/current/web/howto/web-in-60/interrupted....

Jean-Paul

...

On Mon, Aug 5, 2019 at 2:24 AM Waqar Khan wrote:

...

Hi Glyph, I am not sure I understand.

Is there a method/variable in request which keeps a track whether notifyFinish has been fired.. So, I can do something like.

if not request.hasFiredNotifyFinish: request.finish() ??

I have sort of able to get around this issue.. though I can't put a finger on what actually worked. Here is what I did.. First change to 19.7rc01 version.. and just fix the channel issue.

Next self.fetch_response(request).. This is an async def.. So what I did was..

async def fetch_response(request): future = {} try: future = await some other async def.. which returns future except asyncio.CancelledError as e: print("Error..", e) return future

I basically ended up doing this everywhere where there is async/await. Next, I added this: d.addErrback(lambda failure: failure.trap(asyncio.CancelledError))

So.. now.. I don't see the notifyFinish error anymore. And I am bit terrified not to touch anything.. :-D

But, I want to try out your suggestion as that seems like a more solid way to handle the issue. But I am not sure I quite understand, how do I figure out whether notifyFinish has been called before calling finish?

On Mon, Aug 5, 2019 at 1:56 AM Glyph wrote:

...

On Aug 4, 2019, at 9:04 PM, Waqar Khan wrote:

Ah yes.. That is true..

If I comment out request.finish() (Here is the doc which I tried to followed: https://twistedmatrix.com/documents/13.0.0/web/howto/web-in-60/interrupted.h... ) Then actually.. when I try to test out the code... (via curl or like doing requests.get .. to the URI).. it is just stuck..

Yep! This makes sense; if you don't call `.finish()` *at all* then your code will never tell the client that it's done.

But if you call `.finish()` *after notifyFinish() has fired* then you get that error.

If you change your code to only call `.finish()` if the deferred returned by notifyFinish() has not fired or failed yet, do you get the error? It's possible that you still do, in which case, there's a bug in Twisted that needs to be fixed.

I do want to convey my thanks for the help. Really appreciate it.

Thanks for using Twisted :) -g

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python

_______________________________________________ Twisted-Python mailing list Twisted-Python@twistedmatrix.com https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python