search

hjr3 / weldr

A HTTP 1.1 proxy written in Rust using tokio.
Apache License 2.0
217 stars 20 forks source link

Refactor to use revamped tokio-proto #38

Closed hjr3 closed 7 years ago

hjr3 commented 7 years ago

Updated to use the new tokio-proto with Sink/Stream as the old crate had some unhandled corner cases.

Fixes #35

hjr3 commented 7 years ago

@yanns can you try the streaming response body on this one? it is working for me. i may spend another day cleaning up some code bits before merging.

yanns commented 7 years ago

This branch leads to a panic for me:

RUST_LOG=alacrity,tokio_core,tokio_proto cargo run --bin alacrity 127.0.0.1:9001 127.0.0.1:9000 127.0.0.1:9002
    Finished debug [unoptimized + debuginfo] target(s) in 0.0 secs
     Running `target/debug/alacrity 127.0.0.1:9001 127.0.0.1:9000 127.0.0.1:9002`
DEBUG:tokio_core::reactor: adding a new I/O source
INFO:alacrity::proxy: Listening on: 127.0.0.1:9001
DEBUG:tokio_core::reactor: consuming notification queue
DEBUG:tokio_core::reactor: scheduling direction for: 0
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 2, nanos: 191432796 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 109610977194939 }
TRACE:tokio_core::reactor: event Ready {Readable} Token(2)
DEBUG:tokio_core::reactor: notifying a task handle
DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 113249 }
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 121116 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 109610977433637 }
TRACE:tokio_core::reactor: event Ready {Readable} Token(1)
DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 16956 }
DEBUG:tokio_core::reactor: consuming notification queue
DEBUG:tokio_core::reactor: adding a new I/O source
DEBUG:alacrity::proxy: Incoming connection on 127.0.0.1:51146
DEBUG:alacrity::pool::inner: Pool is cloaning (hehe) out 127.0.0.1:9000
DEBUG:alacrity::proxy: Preparing backend request to V4(127.0.0.1:9000)
DEBUG:tokio_core::reactor: adding a new I/O source
DEBUG:tokio_core::reactor: consuming notification queue
DEBUG:tokio_core::reactor: scheduling direction for: 0
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 172660 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 109610978050274 }
TRACE:tokio_core::reactor: event Ready {Readable | Writable} Token(4)
TRACE:tokio_core::reactor: event Ready {Writable} Token(6)
TRACE:tokio_core::reactor: event Ready {Readable} Token(5)
TRACE:tokio_core::reactor: event Ready {Readable} Token(3)
DEBUG:tokio_core::reactor: loop process - 4 events, Duration { secs: 0, nanos: 167349 }
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 135547 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 109610978359068 }
TRACE:tokio_core::reactor: event Ready {Readable} Token(9)
TRACE:tokio_proto::streaming::pipeline::advanced: Pipeline::tick
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: framed transport flushed
DEBUG:tokio_core::reactor: consuming notification queue
DEBUG:tokio_core::reactor: scheduling direction for: 1
TRACE:alacrity::framed: attempting to decode a frame
TRACE:alacrity::frontend: decode
DEBUG:alacrity::frontend: Raw request [71, 69, 84, 32, 47, 97, 115, 115, 101, 116, 115, 47, 106, 97, 118, 97, 115, 99, 114, 105, 112, 116, 115, 47, 106, 113, 117, 101, 114, 121, 45, 49, 46, 55, 46, 49, 46, 109, 105, 110, 46, 106, 115, 32, 72, 84, 84, 80, 47, 49, 46, 49, 13, 10, 85, 115, 101, 114, 45, 65, 103, 101, 110, 116, 58, 32, 87, 103, 101, 116, 47, 49, 46, 49, 56, 32, 40, 100, 97, 114, 119, 105, 110, 49, 53, 46, 53, 46, 48, 41, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 42, 47, 42, 13, 10, 65, 99, 99, 101, 112, 116, 45, 69, 110, 99, 111, 100, 105, 110, 103, 58, 32, 105, 100, 101, 110, 116, 105, 116, 121, 13, 10, 72, 111, 115, 116, 58, 32, 108, 111, 99, 97, 108, 104, 111, 115, 116, 58, 57, 48, 48, 49, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 75, 101, 101, 112, 45, 65, 108, 105, 118, 101, 13, 10, 13, 10]
TRACE:alacrity::framed: frame decoded from buffer
TRACE:tokio_proto::streaming::pipeline::advanced: process_out_frame
TRACE:tokio_proto::streaming::pipeline::advanced: read out message
TRACE:alacrity::proxy: frontend service
TRACE:alacrity::framed: attempting to decode a frame
TRACE:alacrity::frontend: decode
DEBUG:alacrity::frontend: Raw request []
DEBUG:alacrity::frontend: Partial request
DEBUG:tokio_core::reactor: consuming notification queue
DEBUG:tokio_core::reactor: scheduling direction for: 1
TRACE:tokio_proto::streaming::pipeline::advanced: write_in_frames
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: framed transport flushed
TRACE:tokio_proto::streaming::pipeline::advanced: write_in_body
DEBUG:tokio_proto::streaming::pipeline::advanced: write in body done
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: framed transport flushed
TRACE:tokio_core::reactor: event Ready {Readable} Token(7)
TRACE:tokio_proto::streaming::pipeline::advanced: Pipeline::tick
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: framed transport flushed
DEBUG:tokio_core::reactor: consuming notification queue
DEBUG:tokio_core::reactor: scheduling direction for: 2
TRACE:tokio_proto::streaming::pipeline::advanced: write_in_frames
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: framed transport flushed
TRACE:tokio_proto::streaming::pipeline::advanced: write_in_body
DEBUG:tokio_proto::streaming::pipeline::advanced: write in body done
TRACE:tokio_proto::streaming::pipeline::client: Dispatch::poll
TRACE:tokio_proto::streaming::pipeline::client:    --> received request
TRACE:tokio_proto::streaming::pipeline::advanced:    --> got message
TRACE:tokio_proto::streaming::pipeline::advanced: write_in_message
TRACE:tokio_proto::streaming::pipeline::advanced: got in_flight value without body
TRACE:alacrity::backend: encode
DEBUG:alacrity::backend: Request Message { message: <HTTP Request GET /assets/javascripts/jquery-1.7.1.min.js>, body: false }
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: writing; remaining=180
TRACE:alacrity::framed: framed transport flushed
TRACE:tokio_proto::streaming::pipeline::advanced: write_in_body
DEBUG:tokio_proto::streaming::pipeline::advanced: write in body done
TRACE:tokio_proto::streaming::pipeline::client: Dispatch::poll
TRACE:tokio_proto::streaming::pipeline::client:    --> not ready
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: framed transport flushed
DEBUG:tokio_core::reactor: loop process - 2 events, Duration { secs: 0, nanos: 546017 }
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 133035 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 109610979044577 }
TRACE:tokio_core::reactor: event Ready {Writable} Token(6)
DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 22942 }
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 5177849 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 109610984248774 }
TRACE:tokio_core::reactor: event Ready {Readable} Token(6)
DEBUG:tokio_core::reactor: notifying a task handle
DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 56318 }
DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 142170 }
DEBUG:tokio_core::reactor: loop time - Instant { t: 109610984451165 }
TRACE:tokio_core::reactor: event Ready {Readable} Token(7)
TRACE:tokio_proto::streaming::pipeline::advanced: Pipeline::tick
TRACE:alacrity::framed: flushing framed transport
TRACE:alacrity::framed: framed transport flushed
DEBUG:tokio_core::reactor: consuming notification queue
DEBUG:tokio_core::reactor: scheduling direction for: 2
TRACE:alacrity::framed: attempting to decode a frame
TRACE:alacrity::backend: decode
DEBUG:alacrity::response: Found content length of 93868
thread 'main' panicked at 'assertion failed: end <= self.buf.len()', /Users/yannsimon/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-core-0.1.1/src/io/frame.rs:67
note: Run with `RUST_BACKTRACE=1` for a backtrace.
hjr3 commented 7 years ago

What did you proxy? I will try and recreate.

On Wed, Dec 7, 2016 at 23:58 Yann Simon notifications@github.com wrote:

This branch leads to a panic for me:

RUST_LOG=alacrity,tokio_core,tokio_proto cargo run --bin alacrity 127.0.0.1:9001 127.0.0.1:9000 127.0.0.1:9002

Finished debug [unoptimized + debuginfo] target(s) in 0.0 secs

 Running `target/debug/alacrity 127.0.0.1:9001 127.0.0.1:9000 127.0.0.1:9002`

DEBUG:tokio_core::reactor: adding a new I/O source

INFO:alacrity::proxy: Listening on: 127.0.0.1:9001

DEBUG:tokio_core::reactor: consuming notification queue

DEBUG:tokio_core::reactor: scheduling direction for: 0

DEBUG:tokio_core::reactor: loop poll - Duration { secs: 2, nanos: 191432796 }

DEBUG:tokio_core::reactor: loop time - Instant { t: 109610977194939 }

TRACE:tokio_core::reactor: event Ready {Readable} Token(2)

DEBUG:tokio_core::reactor: notifying a task handle

DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 113249 }

DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 121116 }

DEBUG:tokio_core::reactor: loop time - Instant { t: 109610977433637 }

TRACE:tokio_core::reactor: event Ready {Readable} Token(1)

DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 16956 }

DEBUG:tokio_core::reactor: consuming notification queue

DEBUG:tokio_core::reactor: adding a new I/O source

DEBUG:alacrity::proxy: Incoming connection on 127.0.0.1:51146

DEBUG:alacrity::pool::inner: Pool is cloaning (hehe) out 127.0.0.1:9000

DEBUG:alacrity::proxy: Preparing backend request to V4(127.0.0.1:9000)

DEBUG:tokio_core::reactor: adding a new I/O source

DEBUG:tokio_core::reactor: consuming notification queue

DEBUG:tokio_core::reactor: scheduling direction for: 0

DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 172660 }

DEBUG:tokio_core::reactor: loop time - Instant { t: 109610978050274 }

TRACE:tokio_core::reactor: event Ready {Readable | Writable} Token(4)

TRACE:tokio_core::reactor: event Ready {Writable} Token(6)

TRACE:tokio_core::reactor: event Ready {Readable} Token(5)

TRACE:tokio_core::reactor: event Ready {Readable} Token(3)

DEBUG:tokio_core::reactor: loop process - 4 events, Duration { secs: 0, nanos: 167349 }

DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 135547 }

DEBUG:tokio_core::reactor: loop time - Instant { t: 109610978359068 }

TRACE:tokio_core::reactor: event Ready {Readable} Token(9)

TRACE:tokio_proto::streaming::pipeline::advanced: Pipeline::tick

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: framed transport flushed

DEBUG:tokio_core::reactor: consuming notification queue

DEBUG:tokio_core::reactor: scheduling direction for: 1

TRACE:alacrity::framed: attempting to decode a frame

TRACE:alacrity::frontend: decode

DEBUG:alacrity::frontend: Raw request [71, 69, 84, 32, 47, 97, 115, 115, 101, 116, 115, 47, 106, 97, 118, 97, 115, 99, 114, 105, 112, 116, 115, 47, 106, 113, 117, 101, 114, 121, 45, 49, 46, 55, 46, 49, 46, 109, 105, 110, 46, 106, 115, 32, 72, 84, 84, 80, 47, 49, 46, 49, 13, 10, 85, 115, 101, 114, 45, 65, 103, 101, 110, 116, 58, 32, 87, 103, 101, 116, 47, 49, 46, 49, 56, 32, 40, 100, 97, 114, 119, 105, 110, 49, 53, 46, 53, 46, 48, 41, 13, 10, 65, 99, 99, 101, 112, 116, 58, 32, 42, 47, 42, 13, 10, 65, 99, 99, 101, 112, 116, 45, 69, 110, 99, 111, 100, 105, 110, 103, 58, 32, 105, 100, 101, 110, 116, 105, 116, 121, 13, 10, 72, 111, 115, 116, 58, 32, 108, 111, 99, 97, 108, 104, 111, 115, 116, 58, 57, 48, 48, 49, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 75, 101, 101, 112, 45, 65, 108, 105, 118, 101, 13, 10, 13, 10]

TRACE:alacrity::framed: frame decoded from buffer

TRACE:tokio_proto::streaming::pipeline::advanced: process_out_frame

TRACE:tokio_proto::streaming::pipeline::advanced: read out message

TRACE:alacrity::proxy: frontend service

TRACE:alacrity::framed: attempting to decode a frame

TRACE:alacrity::frontend: decode

DEBUG:alacrity::frontend: Raw request []

DEBUG:alacrity::frontend: Partial request

DEBUG:tokio_core::reactor: consuming notification queue

DEBUG:tokio_core::reactor: scheduling direction for: 1

TRACE:tokio_proto::streaming::pipeline::advanced: write_in_frames

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: framed transport flushed

TRACE:tokio_proto::streaming::pipeline::advanced: write_in_body

DEBUG:tokio_proto::streaming::pipeline::advanced: write in body done

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: framed transport flushed

TRACE:tokio_core::reactor: event Ready {Readable} Token(7)

TRACE:tokio_proto::streaming::pipeline::advanced: Pipeline::tick

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: framed transport flushed

DEBUG:tokio_core::reactor: consuming notification queue

DEBUG:tokio_core::reactor: scheduling direction for: 2

TRACE:tokio_proto::streaming::pipeline::advanced: write_in_frames

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: framed transport flushed

TRACE:tokio_proto::streaming::pipeline::advanced: write_in_body

DEBUG:tokio_proto::streaming::pipeline::advanced: write in body done

TRACE:tokio_proto::streaming::pipeline::client: Dispatch::poll

TRACE:tokio_proto::streaming::pipeline::client: --> received request

TRACE:tokio_proto::streaming::pipeline::advanced: --> got message

TRACE:tokio_proto::streaming::pipeline::advanced: write_in_message

TRACE:tokio_proto::streaming::pipeline::advanced: got in_flight value without body

TRACE:alacrity::backend: encode

DEBUG:alacrity::backend: Request Message { message: <HTTP Request GET /assets/javascripts/jquery-1.7.1.min.js>, body: false }

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: writing; remaining=180

TRACE:alacrity::framed: framed transport flushed

TRACE:tokio_proto::streaming::pipeline::advanced: write_in_body

DEBUG:tokio_proto::streaming::pipeline::advanced: write in body done

TRACE:tokio_proto::streaming::pipeline::client: Dispatch::poll

TRACE:tokio_proto::streaming::pipeline::client: --> not ready

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: framed transport flushed

DEBUG:tokio_core::reactor: loop process - 2 events, Duration { secs: 0, nanos: 546017 }

DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 133035 }

DEBUG:tokio_core::reactor: loop time - Instant { t: 109610979044577 }

TRACE:tokio_core::reactor: event Ready {Writable} Token(6)

DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 22942 }

DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 5177849 }

DEBUG:tokio_core::reactor: loop time - Instant { t: 109610984248774 }

TRACE:tokio_core::reactor: event Ready {Readable} Token(6)

DEBUG:tokio_core::reactor: notifying a task handle

DEBUG:tokio_core::reactor: loop process - 1 events, Duration { secs: 0, nanos: 56318 }

DEBUG:tokio_core::reactor: loop poll - Duration { secs: 0, nanos: 142170 }

DEBUG:tokio_core::reactor: loop time - Instant { t: 109610984451165 }

TRACE:tokio_core::reactor: event Ready {Readable} Token(7)

TRACE:tokio_proto::streaming::pipeline::advanced: Pipeline::tick

TRACE:alacrity::framed: flushing framed transport

TRACE:alacrity::framed: framed transport flushed

DEBUG:tokio_core::reactor: consuming notification queue

DEBUG:tokio_core::reactor: scheduling direction for: 2

TRACE:alacrity::framed: attempting to decode a frame

TRACE:alacrity::backend: decode

DEBUG:alacrity::response: Found content length of 93868

thread 'main' panicked at 'assertion failed: end <= self.buf.len()', /Users/yannsimon/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-core-0.1.1/src/io/frame.rs:67

note: Run with RUST_BACKTRACE=1 for a backtrace.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/hjr3/alacrity/pull/38#issuecomment-265676665, or mute the thread https://github.com/notifications/unsubscribe-auth/AACCJiCu3aP0XOySI6ZttD_yal35dm5_ks5rF7iogaJpZM4LHYpC .

yanns commented 7 years ago

This is a Scala application: https://github.com/yanns/play2-wiki-growth-sse.

I wanted to use it to test server send events, but for the moment, I'm just using for a very simple test:

wget http://localhost:9000/assets/javascripts/jquery-1.7.1.min.js
wget http://localhost:9001/assets/javascripts/jquery-1.7.1.min.js
hjr3 commented 7 years ago

Great, I can recreate. I will fix in a bit!

hjr3 commented 7 years ago

@yanns this update works with your play app

yanns commented 7 years ago

😍 😍 Great work!

hjr3 commented 7 years ago

I am working on making the body handling more robust. I will restore request body support during that time.