Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Local to remote tproxy+tcp failed to do websocket handshake with the server #327

Closed
CorrM opened this issue Jul 31, 2024 · 5 comments
Closed
Labels

Comments

@CorrM
Copy link
Contributor

CorrM commented Jul 31, 2024

Describe the bug

Maybe the problem its trying to resolve remote "192.168.12.1:8888" which is a local network address

To Reproduce

  • Run wstunnel client (info blow this section)
  • Create a hotspot wifi point (im using this https://github.com/lakinduakash/linux-wifi-hotspot)
  • iptables -t nat -A PREROUTING -i ap0 -p tcp --dport 80 -j REDIRECT --to-ports 8888
  • iptables -t nat -A PREROUTING -i ap0 -p tcp --dport 443 -j REDIRECT --to-ports 8888
  • Connect any device (for me its an android device)
  • Try use the internet browser

Expected behavior

Working tunnel without errors

Your wstunnel setup

  • client
    • client -L tproxy+tcp://0.0.0.0:8888 --connection-min-idle 5 wss://<VPS_IP>:443
  • server
    • wstunnel server wss://[::]:8080 -p http://<PROXY_IP>:<PROXY_PORT>

Desktop (please complete the following information):

  • OS: Linux
  • Version: 6.10

Additional context

My network interfaces: (ap0 is hotspot interface)

$ ifconfig
ap0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 192.168.12.1  netmask 255.255.255.0  broadcast 192.168.12.255
        inet6 fe80::52eb:71ff:fe77:8487  prefixlen 64  scopeid 0x20<link>
        ether 50:eb:71:77:84:87  txqueuelen 1000  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 41  bytes 6038 (5.8 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

enp4s0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        ether a8:5e:45:15:39:0e  txqueuelen 1000  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

enp5s0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 192.168.1.2  netmask 255.255.255.0  broadcast 192.168.1.255
        inet6 fe80::9d54:3a89:b8b1:d930  prefixlen 64  scopeid 0x20<link>
        ether a8:5e:45:15:39:0d  txqueuelen 1000  (Ethernet)
        RX packets 457194  bytes 554077699 (528.4 MiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 265614  bytes 32603668 (31.0 MiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
        device memory 0xfc700000-fc71ffff

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet 127.0.0.1  netmask 255.0.0.0
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 95887  bytes 79924942 (76.2 MiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 95887  bytes 79924942 (76.2 MiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

wstunnel log:

2024-07-31T17:40:09.887896Z ERROR tunnel{id="019109e0-98ad-7573-9659-0c60403a1425" remote="192.168.12.1:8888"}: wstunnel::tunnel::client::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400

Stack backtrace:
   0: <E as anyhow::context::ext::StdError>::ext_context
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.86/src/backtrace.rs:27:14
   1: anyhow::context::<impl anyhow::Context<T,E> for core::result::Result<T,E>>::with_context
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.86/src/context.rs:65:31
   2: wstunnel::tunnel::transport::websocket::connect::{{closure}}
             at ./src/tunnel/transport/websocket.rs:192:30
   3: wstunnel::tunnel::client::client::WsClient::connect_to_server::{{closure}}
             at ./src/tunnel/client/client.rs:72:22
   4: wstunnel::tunnel::client::client::WsClient::run_tunnel::{{closure}}::{{closure}}
             at ./src/tunnel/client/client.rs:121:22
   5: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321:9
   6: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/future/future.rs:123:9
   7: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:328:17
   8: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/loom/std/unsafe_cell.rs:16:9
   9: tokio::runtime::task::core::Core<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:317:13
  10: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:485:19
  11: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  12: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  13: __rust_try
  14: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  15: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  16: tokio::runtime::task::harness::poll_future
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:473:18
  17: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:208:27
  18: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:153:15
  19: tokio::runtime::task::raw::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:271:5
  20: tokio::runtime::task::raw::RawTask::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:201:18
  21: tokio::runtime::task::LocalNotified<S>::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/mod.rs:427:9
  22: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:657:17
  23: tokio::runtime::coop::with_budget
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/coop.rs:107:5
  24: tokio::runtime::coop::budget
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/coop.rs:73:5
  25: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:593:9
  26: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:544:24
  27: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:509:21
  28: tokio::runtime::context::scoped::Scoped<T>::set
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context/scoped.rs:40:9
  29: tokio::runtime::context::set_scheduler::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context.rs:180:26
  30: std::thread::local::LocalKey<T>::try_with
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/local.rs:283:12
  31: std::thread::local::LocalKey<T>::with
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/local.rs:260:9
  32: tokio::runtime::context::set_scheduler
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context.rs:180:9
  33: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:504:9
  34: tokio::runtime::context::runtime::enter_runtime
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context/runtime.rs:65:16
  35: tokio::runtime::scheduler::multi_thread::worker::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:496:5
  36: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:462:45
  37: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/task.rs:42:21
  38: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:328:17
  39: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/loom/std/unsafe_cell.rs:16:9
  40: tokio::runtime::task::core::Core<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:317:13
  41: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:485:19
  42: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  43: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  44: __rust_try
  45: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  46: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  47: tokio::runtime::task::harness::poll_future
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:473:18
  48: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:208:27
  49: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:153:15
  50: tokio::runtime::task::raw::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:271:5
  51: tokio::runtime::task::raw::RawTask::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:201:18
  52: tokio::runtime::task::UnownedTask<S>::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/mod.rs:464:9
  53: tokio::runtime::blocking::pool::Task::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:160:9
  54: tokio::runtime::blocking::pool::Inner::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:518:17
  55: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:476:13
  56: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/sys_common/backtrace.rs:155:18
  57: std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/mod.rs:542:17
  58: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  59: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  60: __rust_try
  61: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  62: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  63: std::thread::Builder::spawn_unchecked_::{{closure}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/mod.rs:541:30
  64: core::ops::function::FnOnce::call_once{{vtable.shim}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/ops/function.rs:250:5
  65: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/alloc/src/boxed.rs:2063:9
  66: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/alloc/src/boxed.rs:2063:9
  67: std::sys::pal::unix::thread::Thread::new::thread_start
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/sys/pal/unix/thread.rs:108:17
  68: <unknown>
  69: <unknown>
2024-07-31T17:40:09.888413Z DEBUG rustls::common_state: Sending warning alert CloseNotify    
2024-07-31T17:40:09.911746Z DEBUG tunnel{id="019109e0-c037-7b40-86c0-f2bbe4a9f7ac" remote="192.168.12.1:8888"}: wstunnel::tunnel::transport::websocket: with HTTP upgrade request Request { method: GET, uri: /v1/events, version: HTTP/1.1, headers: {"host": "<VPS_IP>", "upgrade": "websocket", "connection": "upgrade", "sec-websocket-key": "X+X70cPWBitn0QFKgE9f6A==", "sec-websocket-version": "13", "sec-websocket-protocol": "v1, authorization.bearer.eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpZCI6IjAxOTEwOWUwLWMwMzctN2I0MC04NmMwLWYyYmJlNGE5ZjdhYyIsInAiOnsiVGNwIjp7InByb3h5X3Byb3RvY29sIjpmYWxzZX19LCJyIjoiMTkyLjE2OC4xMi4xIiwicnAiOjg4ODh9.oPzsaHDqDEDgUTCJqg7F5oYW1iCt3Yp6PUie8dJYDVE"}, body: Empty }    
2024-07-31T17:40:09.911934Z  INFO wstunnel::protocols::tcp::server: Opening TCP connection to <VPS_IP>:443    
2024-07-31T17:40:09.912027Z DEBUG wstunnel::protocols::tcp::server: Connecting to <VPS_IP>:443
2024-07-31T17:40:09.996168Z DEBUG wstunnel::protocols::tcp::server: Connected to tcp endpoint <VPS_IP>:443, aborted all other connection attempts
2024-07-31T17:40:09.996199Z  INFO wstunnel::protocols::tls::server: Doing TLS handshake using SNI IpAddress(V4(Ipv4Addr([95, 179, 239, 127]))) with the server <VPS_IP>:443
2024-07-31T17:40:09.996513Z DEBUG rustls::client::hs: Resuming session    
2024-07-31T17:40:10.017244Z ERROR tunnel{id="019109e0-9924-7db0-b34b-9c78d61544cf" remote="192.168.12.1:8888"}: wstunnel::tunnel::client::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400

Stack backtrace:
   0: <E as anyhow::context::ext::StdError>::ext_context
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.86/src/backtrace.rs:27:14
   1: anyhow::context::<impl anyhow::Context<T,E> for core::result::Result<T,E>>::with_context
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.86/src/context.rs:65:31
   2: wstunnel::tunnel::transport::websocket::connect::{{closure}}
             at ./src/tunnel/transport/websocket.rs:192:30
   3: wstunnel::tunnel::client::client::WsClient::connect_to_server::{{closure}}
             at ./src/tunnel/client/client.rs:72:22
   4: wstunnel::tunnel::client::client::WsClient::run_tunnel::{{closure}}::{{closure}}
             at ./src/tunnel/client/client.rs:121:22
   5: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321:9
   6: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/future/future.rs:123:9
   7: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:328:17
   8: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/loom/std/unsafe_cell.rs:16:9
   9: tokio::runtime::task::core::Core<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:317:13
  10: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:485:19
  11: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  12: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  13: __rust_try
  14: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  15: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  16: tokio::runtime::task::harness::poll_future
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:473:18
  17: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:208:27
  18: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:153:15
  19: tokio::runtime::task::raw::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:271:5
  20: tokio::runtime::task::raw::RawTask::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:201:18
  21: tokio::runtime::task::LocalNotified<S>::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/mod.rs:427:9
  22: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:657:17
  23: tokio::runtime::coop::with_budget
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/coop.rs:107:5
  24: tokio::runtime::coop::budget
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/coop.rs:73:5
  25: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:593:9
  26: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:544:24
  27: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:509:21
  28: tokio::runtime::context::scoped::Scoped<T>::set
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context/scoped.rs:40:9
  29: tokio::runtime::context::set_scheduler::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context.rs:180:26
  30: std::thread::local::LocalKey<T>::try_with
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/local.rs:283:12
  31: std::thread::local::LocalKey<T>::with
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/local.rs:260:9
  32: tokio::runtime::context::set_scheduler
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context.rs:180:9
  33: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:504:9
  34: tokio::runtime::context::runtime::enter_runtime
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context/runtime.rs:65:16
  35: tokio::runtime::scheduler::multi_thread::worker::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:496:5
  36: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:462:45
  37: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/task.rs:42:21
  38: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:328:17
  39: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/loom/std/unsafe_cell.rs:16:9
  40: tokio::runtime::task::core::Core<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:317:13
  41: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:485:19
  42: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  43: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  44: __rust_try
  45: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  46: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  47: tokio::runtime::task::harness::poll_future
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:473:18
  48: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:208:27
  49: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:153:15
  50: tokio::runtime::task::raw::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:271:5
  51: tokio::runtime::task::raw::RawTask::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:201:18
  52: tokio::runtime::task::UnownedTask<S>::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/mod.rs:464:9
  53: tokio::runtime::blocking::pool::Task::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:160:9
  54: tokio::runtime::blocking::pool::Inner::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:518:17
  55: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:476:13
  56: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/sys_common/backtrace.rs:155:18
  57: std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/mod.rs:542:17
  58: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  59: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  60: __rust_try
  61: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  62: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  63: std::thread::Builder::spawn_unchecked_::{{closure}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/mod.rs:541:30
  64: core::ops::function::FnOnce::call_once{{vtable.shim}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/ops/function.rs:250:5
  65: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/alloc/src/boxed.rs:2063:9
  66: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/alloc/src/boxed.rs:2063:9
  67: std::sys::pal::unix::thread::Thread::new::thread_start
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/sys/pal/unix/thread.rs:108:17
  68: <unknown>
  69: <unknown>
2024-07-31T17:40:10.017727Z DEBUG rustls::common_state: Sending warning alert CloseNotify    
2024-07-31T17:40:10.080967Z DEBUG rustls::client::hs: Using ciphersuite TLS13_AES_256_GCM_SHA384    
2024-07-31T17:40:10.081014Z DEBUG rustls::client::tls13: Resuming using PSK    
2024-07-31T17:40:10.081438Z DEBUG rustls::client::tls13: TLS1.3 encrypted extensions: [Protocols([ProtocolName(687474702f312e31)])]    
2024-07-31T17:40:10.081469Z DEBUG rustls::client::hs: ALPN protocol is Some(b"http/1.1")    
2024-07-31T17:40:10.274054Z ERROR tunnel{id="019109e0-9a23-7131-acc3-5d635f3213e2" remote="192.168.12.1:8888"}: wstunnel::tunnel::client::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400

Stack backtrace:
   0: <E as anyhow::context::ext::StdError>::ext_context
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.86/src/backtrace.rs:27:14
   1: anyhow::context::<impl anyhow::Context<T,E> for core::result::Result<T,E>>::with_context
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.86/src/context.rs:65:31
   2: wstunnel::tunnel::transport::websocket::connect::{{closure}}
             at ./src/tunnel/transport/websocket.rs:192:30
   3: wstunnel::tunnel::client::client::WsClient::connect_to_server::{{closure}}
             at ./src/tunnel/client/client.rs:72:22
   4: wstunnel::tunnel::client::client::WsClient::run_tunnel::{{closure}}::{{closure}}
             at ./src/tunnel/client/client.rs:121:22
   5: <tracing::instrument::Instrumented<T> as core::future::future::Future>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tracing-0.1.40/src/instrument.rs:321:9
   6: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/future/future.rs:123:9
   7: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:328:17
   8: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/loom/std/unsafe_cell.rs:16:9
   9: tokio::runtime::task::core::Core<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:317:13
  10: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:485:19
  11: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  12: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  13: __rust_try
  14: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  15: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  16: tokio::runtime::task::harness::poll_future
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:473:18
  17: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:208:27
  18: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:153:15
  19: tokio::runtime::task::raw::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:271:5
  20: tokio::runtime::task::raw::RawTask::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:201:18
  21: tokio::runtime::task::LocalNotified<S>::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/mod.rs:427:9
  22: tokio::runtime::scheduler::multi_thread::worker::Context::run_task::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:657:17
  23: tokio::runtime::coop::with_budget
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/coop.rs:107:5
  24: tokio::runtime::coop::budget
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/coop.rs:73:5
  25: tokio::runtime::scheduler::multi_thread::worker::Context::run_task
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:593:9
  26: tokio::runtime::scheduler::multi_thread::worker::Context::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:544:24
  27: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:509:21
  28: tokio::runtime::context::scoped::Scoped<T>::set
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context/scoped.rs:40:9
  29: tokio::runtime::context::set_scheduler::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context.rs:180:26
  30: std::thread::local::LocalKey<T>::try_with
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/local.rs:283:12
  31: std::thread::local::LocalKey<T>::with
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/local.rs:260:9
  32: tokio::runtime::context::set_scheduler
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context.rs:180:9
  33: tokio::runtime::scheduler::multi_thread::worker::run::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:504:9
  34: tokio::runtime::context::runtime::enter_runtime
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/context/runtime.rs:65:16
  35: tokio::runtime::scheduler::multi_thread::worker::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:496:5
  36: tokio::runtime::scheduler::multi_thread::worker::Launch::launch::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/scheduler/multi_thread/worker.rs:462:45
  37: <tokio::runtime::blocking::task::BlockingTask<T> as core::future::future::Future>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/task.rs:42:21
  38: tokio::runtime::task::core::Core<T,S>::poll::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:328:17
  39: tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/loom/std/unsafe_cell.rs:16:9
  40: tokio::runtime::task::core::Core<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/core.rs:317:13
  41: tokio::runtime::task::harness::poll_future::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:485:19
  42: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  43: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  44: __rust_try
  45: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  46: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  47: tokio::runtime::task::harness::poll_future
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:473:18
  48: tokio::runtime::task::harness::Harness<T,S>::poll_inner
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:208:27
  49: tokio::runtime::task::harness::Harness<T,S>::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/harness.rs:153:15
  50: tokio::runtime::task::raw::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:271:5
  51: tokio::runtime::task::raw::RawTask::poll
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/raw.rs:201:18
  52: tokio::runtime::task::UnownedTask<S>::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/task/mod.rs:464:9
  53: tokio::runtime::blocking::pool::Task::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:160:9
  54: tokio::runtime::blocking::pool::Inner::run
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:518:17
  55: tokio::runtime::blocking::pool::Spawner::spawn_thread::{{closure}}
             at /home/corrm/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.39.2/src/runtime/blocking/pool.rs:476:13
  56: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/sys_common/backtrace.rs:155:18
  57: std::thread::Builder::spawn_unchecked_::{{closure}}::{{closure}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/mod.rs:542:17
  58: <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/panic/unwind_safe.rs:272:9
  59: std::panicking::try::do_call
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:559:40
  60: __rust_try
  61: std::panicking::try
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panicking.rs:523:19
  62: std::panic::catch_unwind
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/panic.rs:149:14
  63: std::thread::Builder::spawn_unchecked_::{{closure}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/thread/mod.rs:541:30
  64: core::ops::function::FnOnce::call_once{{vtable.shim}}
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/core/src/ops/function.rs:250:5
  65: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/alloc/src/boxed.rs:2063:9
  66: <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/alloc/src/boxed.rs:2063:9
  67: std::sys::pal::unix::thread::Thread::new::thread_start
             at /rustc/051478957371ee0084a7c0913941d2a8c4757bb9/library/std/src/sys/pal/unix/thread.rs:108:17
  68: <unknown>
  69: <unknown>
2024-07-31T17:40:10.274585Z DEBUG rustls::common_state: Sending warning alert CloseNotify    
2024-07-31T17:40:10.319734Z DEBUG tunnel{id="019109e0-c1cf-7a30-933a-9826a0708c1c" remote="192.168.12.1:8888"}: wstunnel::tunnel::transport::websocket: with HTTP upgrade request Request { method: GET, uri: /v1/events, version: HTTP/1.1, headers: {"host": "<VPS_IP>", "upgrade": "websocket", "connection": "upgrade", "sec-websocket-key": "1FhDacOG73Hc6tKhLzzFng==", "sec-websocket-version": "13", "sec-websocket-protocol": "v1, authorization.bearer.eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpZCI6IjAxOTEwOWUwLWMxY2YtN2EzMC05MzNhLTk4MjZhMDcwOGMxYyIsInAiOnsiVGNwIjp7InByb3h5X3Byb3RvY29sIjpmYWxzZX19LCJyIjoiMTkyLjE2OC4xMi4xIiwicnAiOjg4ODh9.TkYJM2kl6I43bQxoFMlMRwbApf7L7_BMkq9YIHPpY70"}, body: Empty }    
2024-07-31T17:40:10.319875Z  INFO wstunnel::protocols::tcp::server: Opening TCP connection to <VPS_IP>:443    
2024-07-31T17:40:10.319946Z DEBUG wstunnel::protocols::tcp::server: Connecting to <VPS_IP>:443
2024-07-31T17:40:10.403732Z DEBUG wstunnel::protocols::tcp::server: Connected to tcp endpoint <VPS_IP>:443, aborted all other connection attempts
2024-07-31T17:40:10.403759Z  INFO wstunnel::protocols::tls::server: Doing TLS handshake using SNI IpAddress(V4(Ipv4Addr([95, 179, 239, 127]))) with the server <VPS_IP>:443
2024-07-31T17:40:10.404042Z DEBUG rustls::client::hs: Resuming session    
2024-07-31T17:40:10.488425Z DEBUG rustls::client::hs: Using ciphersuite TLS13_AES_256_GCM_SHA384    
2024-07-31T17:40:10.488461Z DEBUG rustls::client::tls13: Resuming using PSK    
2024-07-31T17:40:10.488823Z DEBUG rustls::client::tls13: TLS1.3 encrypted extensions: [Protocols([ProtocolName(687474702f312e31)])]    
2024-07-31T17:40:10.488846Z DEBUG rustls::client::hs: ALPN protocol is Some(b"http/1.1")
@CorrM CorrM added the bug label Jul 31, 2024
@erebe
Copy link
Owner

erebe commented Jul 31, 2024

Would you mind trying with an official release ? If you are using the head, I am not sure I haven't broken anything yet.

Also check the log of the server, it is the handshake with the server that is failling. It returns a HTTP 400 bad request. The start of the tproxy server is going fine

@CorrM
Copy link
Contributor Author

CorrM commented Jul 31, 2024

Server log: (remote="192.168.12.1:8888" !)

wstunnel --version
wstunnel 9.6.1
2024-07-31T19:29:59.685105Z  INFO tunnel{peer="[::ffff:156.221.44.121]:5206" id="01910a45-4d45-7a55-bdc1-d382c1cf9354" remote="192.168.12.1:8888"}:http_proxy: wstunnel::protocols::tcp::server: Connecting to http proxy <PROXY_IP>:47598
2024-07-31T19:29:59.685112Z  INFO tunnel{peer="[::ffff:156.221.44.121]:5206" id="01910a45-4d45-7a55-bdc1-d382c1cf9354" remote="192.168.12.1:8888"}:http_proxy: wstunnel::protocols::tcp::server: Opening TCP connection to <PROXY_IP>:47598
2024-07-31T19:29:59.765952Z  INFO wstunnel::tunnel::server: Accepting connection
2024-07-31T19:29:59.766008Z  INFO tunnel{peer="[::ffff:156.221.44.121]:16832"}: wstunnel::tunnel::server: Doing TLS handshake
2024-07-31T19:30:00.715559Z ERROR tunnel{peer="[::ffff:156.221.44.121]:5210"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Shutdown, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
2024-07-31T19:30:00.715735Z ERROR tunnel{peer="[::ffff:156.221.44.121]:16822" id="01910a45-379c-74e0-9ddf-13c68963acec" remote="192.168.12.1:8888"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Io, Custom { kind: UnexpectedEof, error: "peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof" })
2024-07-31T19:30:00.715781Z ERROR tunnel{peer="[::ffff:156.221.44.121]:5208"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Shutdown, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
2024-07-31T19:30:00.716103Z ERROR tunnel{peer="[::ffff:156.221.44.121]:16824" id="01910a45-39ee-7438-8326-176c18493d7b" remote="192.168.12.1:8888"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Io, Custom { kind: UnexpectedEof, error: "peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof" })
2024-07-31T19:30:00.716569Z ERROR tunnel{peer="[::ffff:156.221.44.121]:5206" id="01910a45-4d45-7a55-bdc1-d382c1cf9354" remote="192.168.12.1:8888"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Io, Custom { kind: UnexpectedEof, error: "peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof" })
2024-07-31T19:30:00.716897Z ERROR tunnel{peer="[::ffff:156.221.44.121]:16832"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Shutdown, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
2024-07-31T19:30:00.717130Z ERROR tunnel{peer="[::ffff:156.221.44.121]:16830"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Shutdown, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
2024-07-31T19:30:00.717282Z ERROR tunnel{peer="[::ffff:156.221.44.121]:5202" id="01910a45-3d80-7263-84e9-c5f318bbe7a3" remote="192.168.12.1:8888"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Io, Custom { kind: UnexpectedEof, error: "peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof" })
2024-07-31T19:30:00.717766Z ERROR tunnel{peer="[::ffff:156.221.44.121]:16826" id="01910a45-497f-75ac-bf27-03b1c10ccd6d" remote="192.168.12.1:8888"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Io, Custom { kind: UnexpectedEof, error: "peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof" })
2024-07-31T19:30:00.717927Z ERROR tunnel{peer="[::ffff:156.221.44.121]:16828"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Shutdown, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
2024-07-31T19:30:00.718197Z ERROR tunnel{peer="[::ffff:156.221.44.121]:5204" id="01910a45-3a4c-7015-a9f6-aa94ee650d89" remote="192.168.12.1:8888"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Io, Custom { kind: UnexpectedEof, error: "peer closed connection without sending TLS close_notify: https://docs.rs/rustls/latest/rustls/manual/_03_howto/index.html#unexpected-eof" })
2024-07-31T19:30:00.718788Z ERROR tunnel{peer="[::ffff:156.221.44.121]:5212"}: wstunnel::tunnel::server: Error while upgrading cnx: hyper::Error(Shutdown, Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })

Client logs:

wstunnel --version
wstunnel 9.6.1
2024-07-31T19:29:54.916002Z ERROR tunnel{id="01910a45-1371-74f8-8834-b5b392ec49c4" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:55.487627Z ERROR tunnel{id="01910a45-15a4-7e38-b793-182a0a8d2bf5" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:55.568764Z ERROR tunnel{id="01910a45-15ff-7ccd-bed1-3bc5ac9d51cd" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:55.584584Z  INFO wstunnel::tcp: Opening TCP connection to <VPS_IP>:443
2024-07-31T19:29:55.667643Z  INFO wstunnel::tls: Doing TLS handshake using SNI IpAddress(V4(Ipv4Addr([95, 179, 239, 127]))) with the server <VPS_IP>:443
2024-07-31T19:29:55.688959Z ERROR tunnel{id="01910a45-166c-7066-832d-afcc6bfd4e22" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.210037Z ERROR tunnel{id="01910a45-1876-7fbc-8b28-f1754cb58fc8" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.213534Z ERROR tunnel{id="01910a45-1881-70a3-900b-d0486ebc6d9f" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.226954Z ERROR tunnel{id="01910a45-1890-7d16-854f-5ad376bbe751" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.236963Z ERROR tunnel{id="01910a45-1895-7315-acf3-d911423ea988" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.241477Z ERROR tunnel{id="01910a45-1897-718f-859f-4cb44990dad6" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.246188Z ERROR tunnel{id="01910a45-18a4-72a9-bf95-74073d5ff08f" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.516829Z ERROR tunnel{id="01910a45-19b6-7a14-8413-8431c63f73a1" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:56.799520Z ERROR tunnel{id="01910a45-1ac1-7d48-a21d-a248f7e06df2" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.039271Z ERROR tunnel{id="01910a45-1fa4-7296-9ba6-b072ba682829" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.065510Z ERROR tunnel{id="01910a45-1fc0-7094-9f55-b391fbcd3ce9" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.231769Z ERROR tunnel{id="01910a45-2064-7f1f-bd2c-a0344eccbf25" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.234439Z ERROR tunnel{id="01910a45-2066-77a2-8bc9-d8d5b7bdda66" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.235716Z ERROR tunnel{id="01910a45-2064-77fc-b276-1d32758186ba" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.553052Z ERROR tunnel{id="01910a45-21a8-7576-b907-b845d7c5677e" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.557182Z ERROR tunnel{id="01910a45-21aa-748a-8441-8e1a36e331e9" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.561742Z ERROR tunnel{id="01910a45-21ad-72f6-b2b8-02d41adba928" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.562697Z ERROR tunnel{id="01910a45-21af-7da2-a553-27f141418055" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.564179Z ERROR tunnel{id="01910a45-21b1-7129-a1c7-4bc6a4e5d237" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.585436Z ERROR tunnel{id="01910a45-21c7-7d6b-85d5-60aa5256aa5f" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.655904Z  INFO wstunnel::tcp: Opening TCP connection to <VPS_IP>:443
2024-07-31T19:29:58.725210Z ERROR tunnel{id="01910a45-2206-746f-a3a9-698d62eb30f5" remote="192.168.12.1:8888"}: wstunnel::tunnel::client: failed to do websocket handshake with the server wss://<VPS_IP>:443

Caused by:
    Invalid status code: 400
2024-07-31T19:29:58.740607Z  INFO wstunnel::tls: Doing TLS handshake using SNI IpAddress(V4(Ipv4Addr([95, 179, 239, 127]))) with the server <VPS_IP>:443
2024-07-31T19:29:59.622055Z  INFO wstunnel::tcp: Opening TCP connection to <VPS_IP>:443
2024-07-31T19:29:59.704394Z  INFO wstunnel::tls: Doing TLS handshake using SNI IpAddress(V4(Ipv4Addr([95, 179, 239, 127]))) with the server <VPS_IP>:443

@erebe
Copy link
Owner

erebe commented Aug 1, 2024

Strange it seems the connection breaks server side before it has any chance to do the websocket upgrade. Meaning, something cut the connection before the server received the data.
Would you mind sharing the log of the server with --log-lvl=trace ?

Also if your server is not behind a reverse proxy, try to use http2 directly. On client side replace wss://<VPS_IP>:443 by https://<VPS_IP>:443

@CorrM
Copy link
Contributor Author

CorrM commented Aug 1, 2024

Server:
wstunnel --log-lvl=trace server https://[::]:443 -p "http://$PROXY_USER:$PROXY_PASS@$PROXY_IP:$PROXY_PORT"
wstunnel_log.txt

Client:
sudo wstunnel client -L tproxy+tcp://0.0.0.0:8888 --connection-min-idle 6 https://<VPS_IP>:443
wstunnel_client_log.txt

@erebe
Copy link
Owner

erebe commented Aug 2, 2024

You are not doing any connection/tunnel on client side now 🙈 You need to initiate a connection on the tproxy server. As you set --connection-min-idle 6 the client is only doing tcp + tls connection to the server and is waiting for an incoming tunnel to go further. (Everything seem ok at this lvl from the logs)

Remove --connection-min-idle 6 on the client to debug and start a connection on your tproxy server

@erebe erebe closed this as completed Aug 15, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants