add more logs when the body is incomplete

[yanns]

For example, simply getting a javascript with a Play application logs the following error:

DEBUG:alacrity::http::parser: Body contains 0 bytes and we need 93868 bytes
TRACE:alacrity::http::parser: response till now: Some(Response { head: ResponseHead { version: Http11, status: 200, reason: "OK", headers: [Header { name: "ETag", value: "\"efab29516dc38c40118a01a7888ffd6b30e8b971\"" }, Header { name: "Cache-Control", value: "no-cache" }, Header { name: "Last-Modified", value: "Tue, 08 Mar 2016 10:25:02 GMT" }, Header { name: "Content-Length", value: "93868" }, Header { name: "Content-Type", value: "application/javascript; charset=utf-8" }, Header { name: "Date", value: "Wed, 23 Nov 2016 17:34:00 GMT" }] }, body: [] })
thread 'main' panicked at 'Not enough bytes to parse response', src/backend.rs:31

It is not a chunked response. I guess the body is send later in the pipeline.

[hjr3]

I really want to fix the root cause, but blocked until tokio-proto changes land. I heard sometime this week, though I am now skeptical

[yanns]

If you have time, I'd be interested in understanding what the root cause is.

[hjr3]

I am actually wrong! According to https://github.com/hjr3/alacrity/blob/c53eb164d72b8a9c5ac785d2d9513eef5f9a75d5/src/framed.rs#L40 we can return Async::NotReady. I copied the src/framed.rs code from tokio-proto and overlooked that. It does not help that the new tokio-proto uses a Result<Option<T>> to indicate errors and readiness.

Ohhh, now I am excited to make more progress.

[yanns]

If I understand correctly, when the parser returns an Ok(None), we just have to return Async::NotReady?

Does it mean that we have to buffer the whole body before sending the response to the client? This approach will show severe limitations with important bodies, like downloads.

[hjr3]

For now we buffer it. Next steps are to make HttpParser contain instances of both RequestParser and ResponseParser. We then track the parsing state. That way if we parse the head of a request, we can start sending that upstream to the backend. If we are in a chunked transfer, we can start sending the chunks as they come in too.

For a normal content length body, we can optimize it to send it in some sort of chunked form. Especially if the body is large (as is with the case of downloads). I meany really, when it comes to the body, we can literally copy from one socket into the other.

[hjr3]

I am almost done with a POC that should:

• combine request and response parsing logic
• track internal progress (i.e. we parsed the status line but are waiting on headers before we create a Frame)
• allow a Frame to be returned with a minimal amount of data (i.e. parsed head with {no body, partial body, full body})

[yanns]

I quickly tried with Async::NotReady. No panic anymore, but the browser waits for the body...

TRACE:alacrity::backend: in parse
TRACE:alacrity::backend: Attempting to parse bytes into HTTP Request
DEBUG:alacrity::http::parser: Body contains 0 bytes and we need 93868 bytes
TRACE:alacrity::http::parser: response till now: Some(Response { head: ResponseHead { version: Http11, status: 200, reason: "OK", headers: [Header { name: "ETag", value: "\"efab29516dc38c40118a01a7888ffd6b30e8b971\"" }, Header { name: "Cache-Control", value: "no-cache" }, Header { name: "Last-Modified", value: "Tue, 08 Mar 2016 10:25:02 GMT" }, Header { name: "Content-Length", value: "93868" }, Header { name: "Content-Type", value: "application/javascript; charset=utf-8" }, Header { name: "Date", value: "Thu, 24 Nov 2016 17:27:07 GMT" }] }, body: [] })
DEBUG:alacrity::backend: Not enough bytes to parse response
TRACE:tokio_proto::pipeline::pipeline: write_in_frames
TRACE:alacrity::framed: framed transport flushed
DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 9440110 }
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 169369 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 4338895682449 }
TRACE:tokio_core::reactor: event Ready {Readable} Token(6)
DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 34892 }

https://github.com/yanns/alacrity/commit/12efe796d1f175ff0bbdfd6361f5e07d959a3925