Kumassy/ownserver

handle connection reset by peer from local server

Closed this issue · 2 comments

Kumassy commented

this error occurs:

WARN  magic_tunnel_client::local        > closing stream
thread 'tokio-runtime-worker' panicked at 'failed to read data from socket: Os { code: 54, kind: ConnectionReset, message: "Connection reset by peer" }', /Users/Kyosuke/GitHub/magic-tunnel/proxy_client/src/local.rs:47:45
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

at
https://github.com/Kumassy/magic-tunnel/blob/b9a103f30c2fe00e2b21eff247de70ad0026ab96/proxy_client/src/local.rs#L47

how to reproduce

  • launch proxy server
  • launch proxy client
  • nc -kl 3000
  • nc localhost <remote process port>
  • kill nc client
  • nc localhost <remote process port>
  • send message multiple times from nc client
  • -> proxy client panic

nc client must re-connect within 5 secs as defined at https://github.com/Kumassy/magic-tunnel/blob/3003b4006445e55cea77ceabb96f2838b0f0a7c7/proxy_client/src/proxy_client.rs#L190

再現条件がまだよくわかっていない

DEBUG tungstenite::handshake::client > Client handshake done.
 INFO  magic_tunnel_client::proxy_client > WebSocket handshake has been successfully completed
 INFO  magic_tunnel_client::proxy_client > Server accepted our connection. I am client_oVTfcME8PKuIOQj_uw9c2cUwWY73xn3MGXS32wDC5qI
 INFO  magic_tunnel_client::proxy_client > got client_info from server: ClientInfo { client_id: ClientId("oVTfcME8PKuIOQj_uw9c2cUwWY73xn3MGXS32wDC5qI"), assigned_port: 3765 }
 INFO  proxy_client                      > client is running under configuration: ClientInfo { client_id: ClientId("oVTfcME8PKuIOQj_uw9c2cUwWY73xn3MGXS32wDC5qI"), assigned_port: 3765 }
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> init
 INFO  magic_tunnel_client::local        > setting up local stream: stream_QpXlDB_mDCU
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Init(StreamId([66, 149, 229, 12, 31, 230, 12, 37]))
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 8
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [97, 115, 100, 102, 115, 100, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 8
 INFO  magic_tunnel_client::proxy_client > stream["stream_QpXlDB_mDCU"] -> new data: 11
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_QpXlDB_mDCU)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([66, 149, 229, 12, 31, 230, 12, 37]), [115, 97, 100, 102, 115, 100, 102, 100, 115, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 11
 INFO  magic_tunnel_client::proxy_client > got end stream ["stream_QpXlDB_mDCU"]
 DEBUG magic_tunnel_client::proxy_client > Processed packet: End(StreamId([66, 149, 229, 12, 31, 230, 12, 37]))
 INFO  magic_tunnel_client::proxy_client > stream["stream_velo3JSpak0"] -> init
 INFO  magic_tunnel_client::local        > setting up local stream: stream_velo3JSpak0
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Init(StreamId([189, 233, 104, 220, 148, 169, 106, 77]))
 INFO  magic_tunnel_client::proxy_client > stream["stream_velo3JSpak0"] -> new data: 5
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_velo3JSpak0)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([189, 233, 104, 220, 148, 169, 106, 77]), [97, 115, 100, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 5
 INFO  magic_tunnel_client::proxy_client > stream["stream_velo3JSpak0"] -> new data: 5
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_velo3JSpak0)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([189, 233, 104, 220, 148, 169, 106, 77]), [97, 115, 100, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 5
 INFO  magic_tunnel_client::proxy_client > stream["stream_velo3JSpak0"] -> new data: 4
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_velo3JSpak0)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([189, 233, 104, 220, 148, 169, 106, 77]), [115, 100, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 4
 INFO  magic_tunnel_client::proxy_client > stream["stream_velo3JSpak0"] -> new data: 9
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_velo3JSpak0)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([189, 233, 104, 220, 148, 169, 106, 77]), [115, 100, 102, 115, 100, 102, 115, 100, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 9
 INFO  magic_tunnel_client::proxy_client > got end stream ["stream_velo3JSpak0"]
 DEBUG magic_tunnel_client::proxy_client > Processed packet: End(StreamId([189, 233, 104, 220, 148, 169, 106, 77]))
 INFO  magic_tunnel_client::proxy_client > stream["stream_Abw_HI_ph8w"] -> init
 INFO  magic_tunnel_client::local        > setting up local stream: stream_Abw_HI_ph8w
 WARN  magic_tunnel_client::local        > closing stream
thread 'tokio-runtime-worker' panicked at 'failed to read data from socket: Os { code: 54, kind: ConnectionReset, message: "Connection reset by peer" }', /Users/Kyosuke/GitHub/magic-tunnel/proxy_client/src/local.rs:47:45
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
 INFO  magic_tunnel_client::local        > done reading from client stream
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Init(StreamId([1, 188, 63, 28, 143, 233, 135, 204]))
 INFO  magic_tunnel_client::proxy_client > stream["stream_Abw_HI_ph8w"] -> new data: 9
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_Abw_HI_ph8w)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([1, 188, 63, 28, 143, 233, 135, 204]), [97, 115, 100, 102, 115, 100, 97, 102, 10])
 INFO  magic_tunnel_client::proxy_client > stream["stream_Abw_HI_ph8w"] -> new data: 5
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_Abw_HI_ph8w)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([1, 188, 63, 28, 143, 233, 135, 204]), [115, 97, 100, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 9
 DEBUG magic_tunnel_client::local        > wrote to local service: 5
 WARN  magic_tunnel_client::local        > closing stream
 ERROR magic_tunnel_client::local        > failed to shutdown: Os { code: 57, kind: NotConnected, message: "Socket is not connected" }
Kumassy commented

mitigate this issue by 8e7e524

 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> init
 INFO  magic_tunnel_client::local        > setting up local stream: stream_pBS3TQufhlY
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Init(StreamId([164, 20, 183, 77, 11, 159, 134, 86]))
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 9
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [97, 115, 100, 102, 115, 97, 100, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 9
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 13
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [97, 115, 100, 102, 115, 97, 100, 102, 115, 100, 97, 102, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 13
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 16
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [115, 97, 100, 102, 115, 97, 100, 102, 115, 100, 97, 102, 115, 100, 97, 10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 16
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 1
 INFO  magic_tunnel_client::proxy_client > forwarded to local tcp (stream_pBS3TQufhlY)
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [10])
 DEBUG magic_tunnel_client::local        > wrote to local service: 1
 WARN  magic_tunnel_client::local        > closing stream
 ERROR magic_tunnel_client::local        > failed to read data from socket: Os { code: 54, kind: ConnectionReset, message: "Connection reset by peer" }
 INFO  magic_tunnel_client::local        > done reading from client stream
 WARN  magic_tunnel_client::local        > closing stream
 ERROR magic_tunnel_client::local        > failed to shutdown: Os { code: 57, kind: NotConnected, message: "Socket is not connected" }
 INFO  magic_tunnel_client::proxy_client > stream["stream_pBS3TQufhlY"] -> new data: 21
 ERROR magic_tunnel_client::proxy_client > got data but no stream to send it to.
 DEBUG magic_tunnel_client::proxy_client > Processed packet: Data(StreamId([164, 20, 183, 77, 11, 159, 134, 86]), [97, 115, 100, 102, 115, 100, 97, 102, 97, 115, 100, 102, 115, 100, 97, 102, 115, 97, 100, 102, 10])
 INFO  magic_tunnel_client::proxy_client > got end stream ["stream_pBS3TQufhlY"]
 DEBUG magic_tunnel_client::proxy_client > Processed packet: End(StreamId([164, 20, 183, 77, 11, 159, 134, 86]))

 nc localhost 3940
asdfsadf


asdfsadfsdaf


sadfsadfsdafsda


asdfsdafasdfsdafsadf
HTTP/1.1 500
Content-Length: 32

Tunnel says: connection refused.
Kumassy commented

The problems happens when client re-open connection immediately after client closes.
Use after released local port?