search

tokuhirom / p6-HTTP-Server-Tiny

Web application server for Perl6
Artistic License 2.0
18 stars 10 forks source link

Error in t/09-chunked-request.t #64

Open GeJ opened 6 years ago

GeJ commented 6 years ago

I've had this error for quite a while but since nobody had reported it, I thought that the error came from my setup.

However, today while trying to build HTTP-Server-Tiny and bumping into the same error again, I had a look at #63 and it was pretty similar (except that I'm not using Docker, but running FreeBSD).

I'm new at Perl6 so any hint or pointer to debug this issue are more than welcome.

That said, I activated HST_DEBUG and here is the result : 

# env HST_DEBUG="1" perl6 -Ilib t/09-chunked-request.t
1..1
http server is ready: http://127.0.0.1:15555/ (pid:88859, keepalive: 1)
[DEBUG] [88859] [5] new request
# wrote requests
[DEBUG] [88859] [5] new request
[DEBUG] [88859] [5] DONE
[DEBUG] [88859] [5] got chunk
[DEBUG] [88859] [5] parsing http request
[DEBUG] [88859] [5] http parsing status: -2
[DEBUG] [88859] [5] sending response 400
[DEBUG] [88859] [5] sent header
[DEBUG] [88859] [5] sent body
[DEBUG] [88859] [5] sent response
[DEBUG] [88859] [5] closing connection
[DEBUG] [88859] [5] closed connection
[DEBUG] [88859] [5] got chunk
[DEBUG] [88859] [5] parsing http request
Use of Nil in numeric context
  in block <unit> at t/09-chunked-request.t line 76
not ok 1 - 
# Failed test at t/09-chunked-request.t line 76
# Looks like you failed 1 test of 1

The server's response being : HTTP/1.0 400 Bad Request\r\nserver: HTTP::Server::Tiny\r\ndate: Wed, 04-Oct-2017 12:05:59 GMT\r\n\r\nBad request

But, if I group the request headers up to (and including) the standalone CRLF in one string like this : 

my $req_headers = (
    "POST /resource/test HTTP/1.1\r\n",
    "User-Agent: curl/7.28.0\r\n",
    "Host: localhost:8888\r\n",
    "Content-type: text/plain\r\n",
    "Transfer-Encoding: chunked\r\n",
    "Connection: Keep-Alive\r\n",
    "Expect: 100-continue\r\n",
    "\r\n"
).join("");
for (
    $req_headers,
    "13\r\n",
    "hogehoge1\n",
    ...

Then the test runs successfully with the following debugging information : 

# env HST_DEBUG="1" perl6 -Ilib t/09-chunked-request.t
1..1
http server is ready: http://127.0.0.1:15555/ (pid:88914, keepalive: 1)
[DEBUG] [88914] [5] new request
# wrote requests
[DEBUG] [88914] [5] new request
[DEBUG] [88914] [5] DONE
[DEBUG] [88914] [5] got chunk
[DEBUG] [88914] [5] parsing http request
[DEBUG] [88914] [5] http parsing status: 179
[DEBUG] [88914] [5] content-length: Any
[DEBUG] [88914] [5] tempfile
[DEBUG] [88914] [5] filename: /tmp/p6-httpd.88914.gjA5FjZjbH: True
[DEBUG] [88914] [5] got chunk
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 235
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 212
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 189
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 166
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 143
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 120
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 97
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 74
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 19 51
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 4 + 21 28
[DEBUG] [88914] [5] writing temp file
[DEBUG] [88914] [5] write to /tmp/p6-httpd.88914.gjA5FjZjbH
[DEBUG] [88914] [5] found chunk marker
[DEBUG] [88914] [5] got chunk 3 + 0 3
[DEBUG] [88914] [5] end chunk
[DEBUG] [88914] [5] wrote 192 bytes by chunked
[DEBUG] [88914] [5] ran app: 200
[DEBUG] [88914] [5] sending response 200
[DEBUG] [88914] [5] sent header
[DEBUG] [88914] [5] send end mark
[DEBUG] [88914] [5] sent body
[DEBUG] [88914] [5] sent response
[DEBUG] [88914] [5] closing connection
[DEBUG] [88914] [5] closed connection
[DEBUG] [88914] [8] DONE
ok 1 -

Now I'm not sure if the problem comes from HTTP::Server::Tiny or HTTP::Parser. Any idea?

GeJ commented 6 years ago

I tried to dig further. Looking at HTTP::Parser, one can read at line 97 : 

# >0: header size
# -1: failed
# -2: request is partial
sub parse-http-request(Blob $req is copy) is export {

But the comments in HTTP::Server::Tiny (at line 186) say : 

        } elsif $header_len == -1 { # incomplete header
            debug 'incomplete header' unless DEBUGGING;
        } elsif $header_len == -2 { # invalid request
            self!send-response(400, [], ['Bad request']);

Isn't there a discrepancy here?

GeJ commented 6 years ago

No taker? I guess I'm the only one who is experiencing this issue after all.

FYI, after some further debugging, if I invert the logic with the elsif $header_len == -1 and -2, the test passes successfully.