william-os4y/fapws3 — Issue #32: WSGI POST reading
Author: skinkie
Created: 2012-01-24 02:26:29+00:00
State: open

I am currently trying to benchmark wsgi apps with posting. What puzzles me is that it seems that every framework I try POSTing creates a delay of one second on top of the processing time.

If I compare fapws3 with uwsgi, the POST performance is similar, where uwsgi outperforms fapws3 if a client posts to the server, while the server is not touching the wsgi.input object. When enabling post buffering in uwsgi, a similar latency of fapws3 is observed.

Reproducability:
import fapws._evwsgi as evwsgi
from fapws import base

def KV55(environ, start_response):
#response = environ['wsgi.input'].read(int(environ['CONTENT_LENGTH']))
response = ''
start_response('200 OK', [('Content-Type', 'text/xml'), ('Content-length', str(len(response)))])
yield response

def start():
evwsgi.start("0.0.0.0", "8181")
evwsgi.set_base_module(base)

evwsgi.wsgi_cb(("/", KV55))

evwsgi.set_debug(0)
evwsgi.run()

start()

time curl -X POST -T kv55.xml http://127.0.0.1:8181

real 0m1.014s
user 0m0.008s
sys 0m0.004s

(document is about 3k)

Because I started with uwsgi, I figured out that the delay seems to be on an epoll_wait.

{{EPOLLIN, {u32=3, u64=4294967299}}}, 64, 59743) = 1
clock_gettime(CLOCK_MONOTONIC, {19638, 918400814}) = 0
accept(3, {sa_family=AF_INET, sin_port=htons(48250), sin_addr=inet_addr("127.0.0.1")}, [16]) = 6
fcntl(6, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
epoll_ctl(4, EPOLL_CTL_ADD, 6, {EPOLLIN, {u32=6, u64=12884901894}}) = 0
clock_gettime(CLOCK_MONOTONIC, {19638, 918913760}) = 0
epoll_wait(4, {{EPOLLIN, {u32=6, u64=12884901894}}}, 64, 59743) = 1
clock_gettime(CLOCK_MONOTONIC, {19638, 919034276}) = 0
read(6, "POST /kv55.xml HTTP/1.1\r\nUser-Ag"..., 32768) = 196
clock_gettime(CLOCK_MONOTONIC, {19638, 919240711}) = 0

epoll_wait(4, {{EPOLLIN, {u32=6, u64=12884901894}}}, 64, 59743) = 1

clock_gettime(CLOCK_MONOTONIC, {19639, 919742520}) = 0
read(6, "\n\n"..., 32768) = 3935
epoll_ctl(4, EPOLL_CTL_MOD, 6, {EPOLLOUT, {u32=6, u64=17179869190}}) = 0
clock_gettime(CLOCK_MONOTONIC, {19639, 920070711}) = 0
epoll_wait(4, {{EPOLLOUT, {u32=6, u64=17179869190}}}, 64, 59743) = 1
clock_gettime(CLOCK_MONOTONIC, {19639, 920205867}) = 0
write(6, "HTTP/1.0 200 OK\r\nDate: Tue, 24 J"..., 119) = 119
clock_gettime(CLOCK_MONOTONIC, {19639, 920982086}) = 0
epoll_wait(4, {{EPOLLOUT, {u32=6, u64=17179869190}}}, 64, 59743) = 1
clock_gettime(CLOCK_MONOTONIC, {19639, 921086163}) = 0
close(6) = 0
clock_gettime(CLOCK_MONOTONIC, {19639, 921306357}) = 0