bolcom / libunftp

Extensible, async, cloud orientated FTP(S) server library and the core of unFTP: https://github.com/bolcom/unFTP. Follow up and talk to us on https://t.me/unftp
Apache License 2.0
186 stars 34 forks source link

Connection reset by peer `unwrap` #375

Open ralpha opened 3 years ago

ralpha commented 3 years ago

I tried out unFTP, but found some problems.

When using FileZilla (v3.28.0) to connect to the FTP I get the following error when trying to login.

thread 'tokio-runtime-worker' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" }', /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/libunftp-0.18.0/src/server/datachan.rs:234:51

I think this is a TLS issue.

FileZilla log:

Status: Disconnected from server
Status: Connecting to 127.0.0.1:2121...
Status: Connection established, waiting for welcome message...
Status: Initializing TLS...
Status: Verifying certificate...
Status: TLS connection established.
Status: Logged in
Status: Retrieving directory listing...
Command:    PWD
Response:   257 "/"
Command:    TYPE I
Response:   200 Always in binary mode
Command:    PASV
Response:   227 Entering Passive Mode (127,0,0,1,195,133)
Command:    LIST
Response:   150 Sending directory list
Error:  GnuTLS error -15: An unexpected TLS packet was received.
Error:  Transfer connection interrupted: ECONNABORTED - Connection aborted
Error:  Connection timed out after 20 seconds of inactivity
Error:  Failed to retrieve directory listing

But when trying to connect using another client (programmed commands) it works correctly and I can connect (some login info).

Reproduce:

Versions used:

Start server:

CURRENT_PATH=$(pwd)
./unftp_x86_64-unknown-linux-gnu \
  --bind-address=127.0.0.1:2121 \
  --bind-address-http=127.0.0.1:8085 \
  --passive-ports=50000-51000 \
  --root-dir=$CURRENT_PATH/root \
  --ftps-certs-file=$CURRENT_PATH/unftp.crt \
  --ftps-key-file=$CURRENT_PATH/unftp.key \
  --auth-type=json \
  --auth-json-path=credentials.json \
  -vv

Note: --ftps-required-on-control-channel=all is NOT set in this case. So TLS is not enforced.

Startup output (cleaned up a bit):

module: main
INFO Starting unFTP server., sbe-type: filesystem, auth-type: json, home: /ftp/root, http-address: 127.0.0.1:8085, ftp-address: 127.0.0.1:2121, libunftp-version: 0.18.0, version: v0.12.11
INFO Using passive port range 50000..51000
INFO Using passive host option 'FromConnection'
INFO Idle session timeout is set to 600 seconds
INFO Starting HTTP service., address: 127.0.0.1:8085
INFO Exposing unFTP service home., path: /
INFO Exposing Prometheus unFTP exporter endpoint., path: /metrics
INFO Exposing readiness endpoint., path: /ready
INFO Exposing liveness endpoint., path: /health
INFO FTPS enabled
INFO FTPS requirement for clients on control channel: FTPS not enforced, mode: None
INFO FTPS requirement for clients on data channel: FTPS not enforced, mode: None

FileZilla Settings:

Host: 127.0.0.1
Port: 2121
Protocol: FTP
Encryption: Use explici FTP over TLS if available
Logon Type: Normal
User: my_username
Password: my_password
Transfer mode: Default
Charset: Force UTF-8 (Autodetect gives same result)

When connecting I get the error, filezilla log see above. unFTP log:

 trace-id: 0x9e947be676dad5c
  source: 127.0.0.1:44050
   Jul 23 17:19:26.397 INFO Starting control loop
   Jul 23 17:19:26.397 INFO Control channel event Command(Auth { protocol: Tls }), seq: 1
   Jul 23 17:19:26.397 INFO Control channel reply CodeAndMsg { code: AuthOkayNoDataNeeded, msg: "Upgrading to TLS" }, seq: 1
   Jul 23 17:19:26.397 INFO Upgrading control channel to TLS
   Jul 23 17:19:26.407 INFO Control channel event InternalMsg(SecureControlChannel), seq: 2
   Jul 23 17:19:26.407 INFO Control channel reply None, seq: 2
   Jul 23 17:19:26.409 INFO Control channel event Command(User { username: b"my_username" }), seq: 3
   Jul 23 17:19:26.409 INFO Control channel reply CodeAndMsg { code: NeedPassword, msg: "Password Required" }, seq: 3
   Jul 23 17:19:26.409 INFO Control channel event Command(Pass { password: Password { bytes: ******* } }), seq: 4
   Jul 23 17:19:26.409 INFO Control channel reply None, seq: 4
   Jul 23 17:19:26.410 INFO User User(username: "my_username", name: None, surname: None) logged in
   Jul 23 17:19:26.410 INFO Control channel event InternalMsg(AuthSuccess), seq: 5
   Jul 23 17:19:26.410 INFO Control channel reply CodeAndMsg { code: UserLoggedIn, msg: "User logged in, proceed" }, seq: 5
   Jul 23 17:19:26.410 INFO Control channel event Command(Opts { option: Utf8 { on: true } }), seq: 6
   Jul 23 17:19:26.410 INFO Control channel reply CodeAndMsg { code: CommandOkay, msg: "Always in UTF-8 mode." }, seq: 6
   Jul 23 17:19:26.410 INFO Control channel event Command(Pbsz), seq: 7
   Jul 23 17:19:26.410 INFO Control channel reply CodeAndMsg { code: CommandOkay, msg: "OK" }, seq: 7
   Jul 23 17:19:26.410 INFO Control channel event Command(Prot { param: Private }), seq: 8
   Jul 23 17:19:26.410 INFO Control channel reply CodeAndMsg { code: CommandOkay, msg: "PROT OK. Securing data channel" }, seq: 8
   Jul 23 17:19:26.411 INFO Control channel event Command(Pwd), seq: 9
   Jul 23 17:19:26.411 INFO Control channel reply CodeAndMsg { code: DirCreated, msg: "\"/\"" }, seq: 9
   Jul 23 17:19:26.411 INFO Control channel event Command(Type), seq: 10
   Jul 23 17:19:26.411 INFO Control channel reply CodeAndMsg { code: CommandOkay, msg: "Always in binary mode" }, seq: 10
   Jul 23 17:19:26.411 INFO Control channel event Command(Pasv), seq: 11
   Jul 23 17:19:26.411 INFO Control channel reply CodeAndMsg { code: EnteringPassiveMode, msg: "Entering Passive Mode (127,0,0,1,197,184)" }, seq: 11
   Jul 23 17:19:26.411 INFO Control channel event Command(List { options: None, path: None }), seq: 12
   Jul 23 17:19:26.411 INFO Control channel reply CodeAndMsg { code: FileStatusOkay, msg: "Sending directory list" }, seq: 12
   username: my_username
    Jul 23 17:19:26.412 INFO Data channel command received: List { options: None, path: None }
thread 'tokio-runtime-worker' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" }', /usr/local/cargo/registry/src/github.com-1ecc6299db9ec823/libunftp-0.18.0/src/server/datachan.rs:234:51
stack backtrace:
   0: rust_begin_unwind
             at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/std/src/panicking.rs:493:5
   1: core::panicking::panic_fmt
             at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/core/src/panicking.rs:92:14
   2: core::result::unwrap_failed
             at /rustc/53cb7b09b00cbea8754ffb78e7e3cb521cb8af4b/library/core/src/result.rs:1355:5
   3: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
   4: libunftp::server::datachan::DataCommandExecutor<Storage,User>::execute_command::{{closure}}::{{closure}}
   5: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
   6: tokio::runtime::task::harness::poll_future
   7: tokio::runtime::task::raw::poll
   8: tokio::runtime::thread_pool::worker::Context::run_task
   9: tokio::runtime::task::raw::poll
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

I guess and hope this is enough info to reproduce and fix it. For me this issue is not a big deal, but just want to make sure it is patched. Looks like a nice project, if you have to use ftp that is ;)

robklg commented 3 years ago

Hi. First of all, sorry for the late reply. We must have missed this around the holidays.

I'll see if we can look at this soonish, whether we can reproduce this at least.

Looks like a nice project, if you have to use ftp that is ;)

You are getting it! 😄

ralpha commented 3 years ago

No problem, take your time. I worked around it and was able to test what I need to test. So this is not holding me back. But would be nice to see it fixed for future use.

hannesdejager commented 2 years ago

Tested this now with unFTP 0.13.2 on Linux

Got a slightly different error the first time:

image

But I could browse directories, all fine.

Then after that I couldn't reproduce it again.

@ralpha do you still have the issue in your latest version? And is it only on connection?

hannesdejager commented 2 months ago

@ralpha is this still an issue for you?

ralpha commented 1 day ago

I'm no longer working for the company that I had this problem in. So I don't have access to the codebase anymore. Meaning that I can not really test it anymore.

So if you think this issue is not longer relevant, feel free to close it. If others have this issue they can always reopen it or create a new issues.