[Twisted-web] Response hanging after headers sent
Bruno Harbulot
bruno at distributedmatter.net
Thu Sep 11 08:27:04 MDT 2014
Hello,
I've been trying to implement a simple notification system via long polling
using Twisted 14.0.0. On the client side, a web page makes Ajax calls to an
"update" resource, which will deliver the latest status message known to
the application. On the server side, a thread feeds a queue with status
events and another one polls this queue and sends the latest value to any
pending request, trying to keep the request open for 30 seconds, or until a
new status event arrives, whichever happens sooner (this is the long
polling).
Occasionally, one of responses will just hang. "request.finish()" is called
properly (I've even checked this with "notifyFinish()"), the response
headers are sent, but the response body isn't (according to Wireshark),
thereby leaving the browser hanging (since it thinks a valid response has
started to come through).
I have noticed this behaviour with Twisted 13 and 14, but not with earlier
versions. This is also an intermittent problem. I have been able to
reproduce it a number of times, but not always, and it doesn't necessarily
happen after the same number of requests. It seems to fail more easily on
machines with one CPU core, or when the execution is limited to one core,
with only one request at a time (for some reason, having concurrent
requests from multiple browsers or tabs, or being able to use multiple CPUs
on the server seems to make the problem harder to reproduce).
I'm pasting at the end of this message a simple example where the status
events are coming from a counter running in a separate thread. When
limiting the server process to one CPU, the counter visible on the webpage
rarely seems to go much above 2000. I've only tried under Linux. I've tried
this on an actual PC (limiting to one core using "taskset -c 0 python
test_server.py"), a VM running in VirtualBox (set to 1 CPU) and even a
Raspberry Pi. The Raspberry Pi is where the problem seems to be the easiest
to reproduce, but this also happens with the actual PC and virtual machine.
This was also only tried on a LAN (considering that, for the purpose of
this test case, the notifications are rather frequent). I've tried with the
default chunked encoding, or by setting the content-length explicitly, but
it didn't make a difference.
Is there a way to force to the response to be flushed, after a call to
"request.finish()"? Any other suggestions to fix this would also be
appreciated.
Thank you,
Bruno.
Only 2 files are required for this test case: counter.html, test_server.py.
I've run this in a virtual environment, with Python 2.7 (in which I've
installed Twisted with `pip install twisted==14.0.0`).
On a multicore machine, to limit the execution to one core, call the server
with taskset: "taskset -c 0 python test_server.py".
Once the server is running, point a browser (tried with Chrome and Firefox)
to "http://the.ip.address.example:8880/", you should see a counter
increasing (and eventually stopping, which illustrates the problem). The
issue seems to happen more often when only 1 client (or tab) is connected
to the server.
- counter.html:
<html>
<head>
<script type="application/javascript" src="//
code.jquery.com/jquery-1.11.0.min.js"></script>
</head>
<body>
<div id="counter" style="font-size: 100pt; font-weight: bold;"></div>
<script type="application/javascript">
// <![CDATA[
$(document).ready(function() {
var eTag = null;
var normalRefreshDelay = 50;
var refreshDelay = normalRefreshDelay;
var maxRefreshDelay = 5000;
function refresh() {
var headers = {};
if (eTag) {
headers['If-None-Match'] = eTag;
}
$.ajax({
url: "/update",
headers: headers,
dataType: "json",
cache: false,
success: function(data, status, xhr) {
try {
if (data[1] != null) { $("#counter").text("Counter:
"+data[1]); }
eTag = xhr.getResponseHeader("ETag") || null;
refreshDelay = normalRefreshDelay;
} catch (e) {
refreshDelay = Math.min(refreshDelay * 2,
maxRefreshDelay);
}
},
error: function(xhr, text, error) {
refreshDelay = Math.min(refreshDelay * 2, maxRefreshDelay);
},
complete: function(xhr, textStatus) {
setTimeout(refresh, refreshDelay);
}
});
}
refresh();
});
// ]]>
</script>
</body>
</html>
- test_server.py
# -*- coding: utf-8 -*-
import threading
import time
import Queue
import uuid
import socket
import json
from twisted.web.server import Site
from twisted.web.resource import Resource
from twisted.web.server import NOT_DONE_YET
from twisted.internet import reactor
from twisted.web.static import File
q = Queue.Queue()
def fake_counter():
i = 1
while True:
q.put({ 1: str(i) })
time.sleep(0.15)
i += 1
producer_thread = threading.Thread(target=fake_counter)
producer_thread.daemon = True
producer_thread.start()
class CounterUpdateResource(Resource):
def __init__(self, msg_queue):
Resource.__init__(self)
self.msg_queue = msg_queue
self.msg = {}
self.etag = None
self.pending_requests = []
t = threading.Thread(target=self._poll_messages)
t.daemon = True
t.start()
def _poll_messages(self):
while True:
try:
self.msg = self.msg_queue.get(True, 30)
self.etag = '"%s"' % (uuid.uuid4(),)
print "-> Got new message: %s" % (self.msg,)
except Queue.Empty:
pass
json_str = json.dumps(self.msg)
json_len = len(json_str)
while True:
try:
request = self.pending_requests.pop()
self._actual_render(request, json_str, json_len)
except IndexError:
break
def _actual_render(self, request, json_msg, json_len):
try:
request.setETag(self.etag)
request.setHeader("Content-Type", "application/json")
request.setHeader("Content-Length", json_len)
request.write(json_msg)
request.finish()
except:
pass
def render_GET(self, request):
ifNoneMatchHeader = request.getHeader("If-None-Match")
if ifNoneMatchHeader is None or ifNoneMatchHeader != self.etag:
if self.etag:
request.setETag(self.etag)
request.setHeader("Content-Type", "application/json")
data = json.dumps(self.msg)
request.setHeader("Content-Length", len(data))
return data
else:
self.pending_requests.append(request)
return NOT_DONE_YET
root = Resource()
root.putChild("", File("counter.html"))
root.putChild("update", CounterUpdateResource(q))
factory = Site(root)
reactor.listenTCP(8880, factory)
reactor.run()
- Sample Wireshark output:
Here is a sample output using Wireshark:
GET /update?_=1410440411047 HTTP/1.1
Host: 192.168.0.8:8880
Connection: keep-alive
Cache-Control: max-age=0
Accept: application/json, text/javascript, */*; q=0.01
X-Requested-With: XMLHttpRequest
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML,
like Gecko) Chrome/37.0.2062.103 Safari/537.36
If-None-Match: "84c25895-de1e-4b50-954b-438be9d8d9b7"
Referer: http://192.168.0.8:8880/
Accept-Encoding: gzip,deflate,sdch
Accept-Language: en-GB,en;q=0.8,en-US;q=0.6
HTTP/1.1 200 OK
Date: Thu, 11 Sep 2014 13:06:23 GMT
Content-Length: 12
ETag: "7736231b-ee3a-4a9f-a93e-ced0994df098"
Content-Type: application/json
Server: TwistedWeb/14.0.0
{"1": "371"}
GET /update?_=1410440411048 HTTP/1.1
Host: 192.168.0.8:8880
Connection: keep-alive
Cache-Control: max-age=0
Accept: application/json, text/javascript, */*; q=0.01
X-Requested-With: XMLHttpRequest
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML,
like Gecko) Chrome/37.0.2062.103 Safari/537.36
If-None-Match: "7736231b-ee3a-4a9f-a93e-ced0994df098"
Referer: http://192.168.0.8:8880/
Accept-Encoding: gzip,deflate,sdch
Accept-Language: en-GB,en;q=0.8,en-US;q=0.6
HTTP/1.1 200 OK
Date: Thu, 11 Sep 2014 13:06:23 GMT
Content-Length: 12
ETag: "ddd10400-3530-4cb4-a9cd-0b123032d8af"
Content-Type: application/json
Server: TwistedWeb/14.0.0
(I've inserted a coupe of line returns after "{"1": "371"}" for
readability.)
Here, nothing is sent on the wire after the headers of the last response
(the "\r\n\r\n" are present).
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://twistedmatrix.com/pipermail/twisted-web/attachments/20140911/e7a41a64/attachment.html>
More information about the Twisted-web
mailing list