http_pipelining_bug.md

Build libuv and Haywire.

git clone https://github.com/kellabyte/Haywire.git
cd haywire
./build.sh

Run Haywire.

out/Default/haywire

Capture HTTP traffic with Wireshark

In a 2nd terminal capture using Wireshark.

sudo tshark -i lo0 -R "http.request || http.response" -d tcp.port==8000,http tcp port 8000

Send pipelined HTTP requests

In a 3rd terminal send pipelined requests from Wrk. We are sending pipelined request in batches of 2.

./wrk -d1 -t1 -c1 --pipeline 2 http://127.0.0.1:8000/

Wireshark output

Capturing on lo0
2177.631709    127.0.0.1 -> 127.0.0.1    HTTP 96 GET / HTTP/1.1 
2177.631715    127.0.0.1 -> 127.0.0.1    HTTP 96 GET / HTTP/1.1 
2177.631796    127.0.0.1 -> 127.0.0.1    HTTP 158 HTTP/1.1 200 OK  (text/plain)
2177.631820    127.0.0.1 -> 127.0.0.1    HTTP 158 HTTP/1.1 200 OK  (text/plain)
* 2177.631835    127.0.0.1 -> 127.0.0.1    HTTP 96 GET / HTTP/1.1 
* 2177.631840    127.0.0.1 -> 127.0.0.1    HTTP 96 GET / HTTP/1.1

Haywire never responded to the last pair of pipelined requests. Why?

Haywire webserver code can be found here

Haywire debug output

The output shows it never got the last pair of requests. Why?

Listening on 0.0.0.0:8000
BEGIN CONNECTION #1
    on_connect() status:0
    uv_accept() returned:0
    uv_read_start() returned:0
    on_read()
    ERROR on_read() nread < 0
    on_close()

First connection always has no bytes to read so gets closed. Bad first connection a wrk bug?

BEGIN CONNECTION #2
    on_connect() status:0
    uv_accept() returned:0
    uv_read_start() returned:0
    on_read()
BEGIN REQUEST #1
    on_message_begin()
    on_headers_complete()
    write_response()
    uv_write() returned:0
    on_message_complete()
END REQUEST #1
BEGIN REQUEST #2
    on_message_begin() (wait what, we get an on_read() first?)
    on_headers_complete()
    write_response()
    uv_write() returned:0
    on_message_complete()
END REQUEST #2

after_write() status:0
after_write() status:0
after_write() status:0
after_write() status:0 ... after_write() loops forever...

after_write() loops on for ever and ever and never stops... Why?