request error = HttpMethodError logs

[rictic]

I'm finding the following in my server logs with some frequency:

ERROR:hyper::server: request error = HttpMethodError

After spending some time on this, I've found a simple reproduction that seems to hinge on requests with a chunked transfer encoding, though I couldn't tell if it was the hyper client or the server that was incorrect. Wireshark hinted that it may be the client, but I believe that I've encountered this log message in the wild and not just when testing the hyper server with the hyper client.

The log message is produced when the server is trying to read the http method of a request but encounters unexpected characters. In the case of the error reproduction below, the server appears to be trying to read for a second request on the connection, and it encounters \r\n instead of the expected http method.

extern crate test;
extern crate hyper;

use std::io;
use std::rand;
use hyper::method::Method;
use hyper::client::Request;
use hyper::server;
use hyper::status::StatusCode;

#[test]
fn http_method_error_is_logged() {
    let ts = TestServer::new();
    Request::new(Method::Post, ts.get_url())
        .unwrap().start().unwrap().send().unwrap();
    io::stdio::stderr().write_line(
        "^^^^^^^     That ERROR log message there     ^^^^^^^").unwrap();

    // I couldn't work out how to capture the error logs, stdio::set_stderr()
    // only catches messages sent with panic! I think. As a result this "test" 
    // doesn't assert, you just have to look at the printed output.

    // Things which cause this error to not reproduce:
    //   * changing the request to one with no body, like a GET
    //   * providing a Content-Length on the request
}

fn hello(_: server::Request, mut res: server::Response) {
    *res.status_mut() = StatusCode::Ok;
    let mut res = res.start().unwrap();
    res.write(b"Hello World!").unwrap();
    res.end().unwrap();
}


struct TestServer {
    listen_serv : hyper::server::Listening,
    port : u16,
}

impl TestServer {
    fn new() -> TestServer {
        let host = from_str("127.0.0.1").unwrap();
        // Try to guess a free port that we can bind to:
        for _ in range(0, 100u) {
            let port = rand::random();
            let server = hyper::server::Server::http(host, port);

            match server.listen(hello) {
                Ok(listening) => {
                    return TestServer {
                        listen_serv: listening,
                        port: port
                    }
                },
                Err(_) => (),
            };
        }

        panic!("Could not find a port to bind the test server to!");
    }

    fn get_url(&self) -> hyper::Url {
        let mut url = "http://127.0.0.1:".to_string();
        url.push_str(self.port.to_string().as_slice());
        url.push_str("/");
        hyper::Url::parse(url.as_slice()).unwrap()
    }
}

impl Drop for TestServer {
    fn drop(&mut self) {
        self.listen_serv.close().unwrap();
    }
}

[seanmonstar]

It seems the error is 2-fold:

1. Most all clients don't send a chunked message when there really isn't a body. The client interface was trying to guess if it was chunked. The newer Client struct should properly set Content-Length: 0 when there is no body.
2. Even so, if the server handler does not read the whole request body (if a client did POST data), and ignores it, then the data will still be in the pipe. The keep alive loop will read on the socket again to see if the connection has continue, and will find the rest of the POST body. This part means that the server perhaps needs to be adjusted somehow to make sure the full request is read, even if the Handler doesn't do it.

[reem]

We could call the appropriate reading/writing functions in Drop, thereby ensuring we always read or write even if the Handler does nothing.