Re: self.channel.writeHeaders(version, code, reason, headers)\nbuiltins.AttributeError: \'NoneType\' object has no attribute \'writeHeaders\'\

Waqar Khan <[email protected]> Sun, 4 Aug 2019 23:43:08 -0400
Newsgroups gmane.comp.python.twisted
Message-ID <CAJuJkHPGzmzCaK2sGVdrw7FHtkQFn8jz03mKR7Pk6hbdMc4CxQ@mail.gmail.com>
--===============2289639243849240412==
Content-Type: multipart/alternative; boundary="00000000000049e075058f5682bd"

--00000000000049e075058f5682bd
Content-Type: text/plain; charset="UTF-8"

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 <[email protected]> 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 <[email protected]> wrote:
>
>>
>>
>> > On Aug 4, 2019, at 5:57 PM, Waqar Khan <[email protected]> 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
>> [email protected]
>> https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python
>>
>

--00000000000049e075058f5682bd
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">Just for sake of completeness:<div>def=C2=A0print_json_res=
ponse(resp, request):</div><div>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0request.w=
rite(json.dumps(resp))</div><div>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0request.=
close()</div><div><br></div><div>It is this close function which is causing=
 the issue</div><div>I suspect that somehow the fact that the client has cl=
osed the connection, is not being handled.=C2=A0</div><div><br></div></div>=
<br><div class=3D"gmail_quote"><div dir=3D"ltr" class=3D"gmail_attr">On Sun=
, Aug 4, 2019 at 11:26 PM Waqar Khan &lt;<a href=3D"mailto:[email protected]=
m">[email protected]</a>&gt; wrote:<br></div><blockquote class=3D"gmail_quo=
te" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204=
);padding-left:1ex"><div dir=3D"ltr">Hi Glyph,<div>=C2=A0 =C2=A0Here is the=
 minimal version</div><div><br></div><div><br></div><div>class FooResource(=
resource.Resource):</div><div>=C2=A0 =C2=A0 =C2=A0 =C2=A0def render_GET(req=
uest):</div><div>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 future =
=3D asyncio.ensure_future(self.fetch_response(request)) // some async await=
 functions</div><div>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 d =3D=
=C2=A0Deferred.fromFuture(future)</div><div>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=
=A0 =C2=A0 =C2=A0=C2=A0d.addCallback(print_json_response, request) // this =
is actually where the error is triggered.</div><div>=C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0=C2=A0d.addErrback(lambda failure: failure.trap(=
defer.CancelledError))</div><div>=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0=C2=A0finished_errback =3D request.notifyFinish()</div><div>=C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 finished_errback.addErrback(self.=
handle_cancel, d) // simple logs and cancels d by d.cancel()</div><div>=C2=
=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 return NOT_DONE_YET</div><div=
><br></div><div>The traceback is like</div><div>&#39;Traceback (most recent=
 call last):\n =C2=A0File &quot;/usr/local/Cellar/python/3.7.1/Frameworks/P=
ython.framework/Versions/3.7/lib/python3.7/asyncio/events.py&quot;, line 88=
, in _run\n =C2=A0 =C2=A0self._context.run(self._callback, *self._args)\n =
=C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/internet/de=
fer.py&quot;, line 827, in adapt\n =C2=A0 =C2=A0adapt.actual.callback(extra=
cted)\n =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/int=
ernet/defer.py&quot;, line 460, in callback\n =C2=A0 =C2=A0self._startRunCa=
llbacks(result)\n =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/t=
wisted/internet/defer.py&quot;, line 568, in _startRunCallbacks\n =C2=A0 =
=C2=A0self._runCallbacks()\n--- &lt;exception caught here&gt; ---\n =C2=A0F=
ile &quot;/usr/local/lib/python3.7/site-packages/twisted/internet/defer.py&=
quot;, line 654, in _runCallbacks\n =C2=A0 =C2=A0current.result =3D callbac=
k(current.result, *args, **kw)\n =C2=A0File &quot;/Users/wqKhan/twisted_eg/=
parse_response.py&quot;, line 3, in print_json_response\n=C2=A0 =C2=A0 <b>p=
rint_json_response</b>(response, request)\n =C2=A0File &quot;/Users/wqKhan/=
twisted_eg/parse_response.py&quot;, line 21, in <b>print_json_response</b>\=
n =C2=A0 =C2=A0request.finish()\n =C2=A0File &quot;/usr/local/lib/python3.7=
/site-packages/twisted/web/server.py&quot;, line 268, in finish\n =C2=A0 =
=C2=A0return http.Request.finish(self)\n =C2=A0File &quot;/usr/local/lib/py=
thon3.7/site-packages/twisted/web/http.py&quot;, line 1071, in finish\n =C2=
=A0 =C2=A0&quot;Request.finish called on a request after its connection was=
 lost; &quot;\nbuiltins.RuntimeError: Request.finish called on a request af=
ter its connection was lost; use Request.notifyFinish to keep track of this=
.\n&#39;</div><div><br></div><div><br></div></div><br><div class=3D"gmail_q=
uote"><div dir=3D"ltr" class=3D"gmail_attr">On Sun, Aug 4, 2019 at 10:36 PM=
 Glyph &lt;<a href=3D"mailto:[email protected]" target=3D"_blank">gly=
[email protected]</a>&gt; wrote:<br></div><blockquote class=3D"gmail_quo=
te" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204=
);padding-left:1ex"><br>
<br>
&gt; On Aug 4, 2019, at 5:57 PM, Waqar Khan &lt;<a href=3D"mailto:wk80333@g=
mail.com" target=3D"_blank">[email protected]</a>&gt; wrote:<br>
&gt; <br>
&gt; Hi Glyph,<br>
&gt;=C2=A0 =C2=A0Thanks for the suggestion.<br>
&gt; I tried the suggestion.. While it fixes the self.channel NoneType issu=
e.. It creates another issue.<br>
&gt; <br>
&gt; Traceback (most recent call last):<br>
&gt;=C2=A0 =C2=A0File &quot;/usr/local/Cellar/python/3.7.1/Frameworks/Pytho=
n.framework/Versions/3.7/lib/python3.7/asyncio/events.py&quot;, line 88, in=
 _run<br>
&gt;=C2=A0 =C2=A0 =C2=A0self._context.run(self._callback, *self._args)<br>
&gt;=C2=A0 =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/=
internet/defer.py&quot;, line 827, in adapt<br>
&gt;=C2=A0 =C2=A0 =C2=A0adapt.actual.callback(extracted)<br>
&gt;=C2=A0 =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/=
internet/defer.py&quot;, line 460, in callback<br>
&gt;=C2=A0 =C2=A0 =C2=A0self._startRunCallbacks(result)<br>
&gt;=C2=A0 =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/=
internet/defer.py&quot;, line 568, in _startRunCallbacks<br>
&gt;=C2=A0 =C2=A0 =C2=A0self._runCallbacks()<br>
&gt; --- &lt;exception caught here&gt; ---<br>
&gt;=C2=A0 =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/=
internet/defer.py&quot;, line 654, in _runCallbacks<br>
&gt;=C2=A0 =C2=A0 =C2=A0current.result =3D callback(current.result, *args, =
**kw)<br>
&gt; ......<br>
&gt;=C2=A0 =C2=A0 =C2=A0request.finish()<br>
&gt;=C2=A0 =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/=
web/server.py&quot;, line 268, in finish<br>
&gt;=C2=A0 =C2=A0 =C2=A0return http.Request.finish(self)<br>
&gt;=C2=A0 =C2=A0File &quot;/usr/local/lib/python3.7/site-packages/twisted/=
web/http.py&quot;, line 1071, in finish<br>
&gt;=C2=A0 =C2=A0 =C2=A0&quot;Request.finish called on a request after its =
connection was lost; &quot;<br>
&gt; builtins.RuntimeError: Request.finish called on a request after its co=
nnection was lost; use Request.notifyFinish to keep track of this.<br>
<br>
Oh, hrm.=C2=A0 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 w=
hether it needs to call `.finish()` by watching a `.notifyFinish()` Deferre=
d.=C2=A0 I bet that there are plenty of resources in Twisted which don&#39;=
t follow this rule, and we should fix those; but possibly we should also ma=
ke this error message less stern.=C2=A0 Do you have a minimal example?<br>
<br>
&gt;=C2=A0 I have got some handle on the issue. I was wondering if you have=
 any advise on how to debug the issue. <br>
&gt; Somewhere in the codebase are async/await code (from asyncio world). H=
ence, when the connection is closed down by client, seems like those pendin=
g coroutines are lingering on.<br>
<br>
This, I have no idea about.=C2=A0 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?=C2=A0 There are a couple dozen questions I&#39;d hav=
e to know the answer to in order to even begin debugging this.=C2=A0 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&#39;re stuck...<br>
<br>
-g<br>
<br>
_______________________________________________<br>
Twisted-Python mailing list<br>
<a href=3D"mailto:[email protected]" target=3D"_blank">Twist=
[email protected]</a><br>
<a href=3D"https://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-pytho=
n" rel=3D"noreferrer" target=3D"_blank">https://twistedmatrix.com/cgi-bin/m=
ailman/listinfo/twisted-python</a><br>
</blockquote></div>
</blockquote></div>

--00000000000049e075058f5682bd--

--===============2289639243849240412==
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: base64
Content-Disposition: inline

X19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX19fX18KVHdpc3RlZC1Q
eXRob24gbWFpbGluZyBsaXN0ClR3aXN0ZWQtUHl0aG9uQHR3aXN0ZWRtYXRyaXguY29tCmh0dHBz
Oi8vdHdpc3RlZG1hdHJpeC5jb20vY2dpLWJpbi9tYWlsbWFuL2xpc3RpbmZvL3R3aXN0ZWQtcHl0
aG9uCg==

--===============2289639243849240412==--