FubarDevelopment / FtpServer

Portable FTP server written in .NET
http://fubardevelopment.github.io/FtpServer/
MIT License
473 stars 161 forks source link

Uploading file to ftp working on remote ubuntu machine #77

Closed Maciejszuchta closed 5 years ago

Maciejszuchta commented 5 years ago

Hello, Im experiencing weird issue. I have got and netcoreapp2.2 hosted on ubuntu 16.04 server. Application is behind Nginx proxy. Now when I try to upload the file on that machine via my netcore app and Fubar FtpServer i get such Log


Aug 28 08:52:18 ip-172-31-43-174 dotnet[26985]:       Connected from 127.0.0.1:41800
Aug 28 08:52:18 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "FTP Server Ready".
Aug 28 08:52:18 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "User {0} logged in, needs password".
Aug 28 08:52:18 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "Password ok, FTP server ready".
Aug 28 08:52:18 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "Extensions supported:".
Aug 28 08:52:18 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "END".
Aug 28 08:52:19 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "Command okay.".
Aug 28 08:52:19 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "{0} Type: {1}".
Aug 28 08:52:19 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "File not found ({0}).".
Aug 28 08:52:19 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "Binary transfer mode active.".
Aug 28 08:52:19 ip-172-31-43-174 dotnet[26985]: NGettext: Translation not found for message id "Entering Extended Passive Mode (|||{0}|).".

It's weird because the file exists on my machine from which I upload the file. I also tried for testing purposes to create an empty directory via ftp and it worked OK.

fubar-coder commented 5 years ago

You can safely ignore this messages from NGettext. It just means that there are no translations and that it'll use the original text instead. I'll try to take a look how I can suppress these messages.

Maciejszuchta commented 5 years ago

But this is not the case. When I try to upload the file it doesn't appear on remote ubuntu server.

fubar-coder commented 5 years ago

Ok, it was a misunderstanding on my side. I guess that you were confused by the File not found message. This was probably caused by an FTP command to test if the file already exists on the server to determine if the client should show a message like "File already exists. Overwrite?" for the user.

My assumption is, that the port for the passive connection isn't reachable for your client. This might be caused by:

How to fix this problem:

If this doesn't work: Please enable logging of the FTP server and use the following log levels:

{
  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "System": "Information",
      "Microsoft": "Information",
      "FubarDev.FtpServer.CommandHandlers.ListCommandHandler": "Trace",
      "FubarDev.FtpServer.CommandHandlers.MlstCommandHandler": "Trace"
    }
  }
}

The configuration above is what you'd need in the QuickStart.AspNetCoreHost project.

The following is the code if you don't have an appsettings.json:

services
   .AddLogging(lb => lb.AddConsole()
       .SetMinimumLevel(LogLevel.Trace)
       .AddFilter("System", LogLevel.Information)
       .AddFilter("Microsoft", LogLevel.Information)
       .AddFilter("FubarDev.FtpServer.CommandHandlers.ListCommandHandler", LogLevel.Trace)
       .AddFilter("FubarDev.FtpServer.CommandHandlers.MlstCommandHandler", LogLevel.Trace))

You'll need the Microsoft.Extensions.Logging.Console NuGet package.

Maciejszuchta commented 5 years ago

This is what I get when logging is enabled and I try to upload the file:

Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "FTP Server Ready".
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (220)"
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       220 FTP Server Ready
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       USER admin
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "User {0} logged in, needs password".
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (331)"
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       331 User admin logged in, needs password
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:47 ip-***-**-**-** dotnet[5842]:       PASS **************** (password omitted)
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FileSystem.DotNet.DotNetFileSystemProvider[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       The root directory for admin is /home/ubuntu/Projects
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "Password ok, FTP server ready".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (230)"
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       230 Password ok, FTP server ready
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       FEAT
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "Extensions supported:".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "END".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (211)"
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       211-Extensions supported:
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        EPRT
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        EPSV
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        HOST
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        LANG en*
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        MDTM
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        MFCT
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        MFF modify;create;
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        MFMT
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        MLST type*;size*;perm*;modify*;create*;
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        REST STREAM
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        SITE BLST
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        SIZE
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:        UTF8
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       211 END
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       OPTS UTF8 ON
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "Command okay.".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (200)"
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       200 Command okay.
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "{0} Type: {1}".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       SYST
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (215)"
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       215 UNIX Type: A
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       CWD ExampleGame
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "Successful ({0})".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (250)"
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       250 Successful (/ExampleGame/)
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       TYPE I
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "Binary transfer mode active.".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (200)"
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       200 Binary transfer mode active.
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       EPSV
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "Entering Extended Passive Mode (|||{0}|).".
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (229)"
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       229 Entering Extended Passive Mode (|||34336|).
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:46:48 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       QUIT
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: NGettext: Translation not found for message id "Service closing control connection.".
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       Executing server command "SEND RESPONSE (221)"
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       221 Service closing control connection.
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       Wait to read server commands
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       Executing server command "CLOSE CONNECTION"
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       StopAsync called
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       StopAsync called
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       Stopped reading commands
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       Stopped sending responses
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]: info: FubarDev.FtpServer.FtpConnection[0]
Aug 28 12:47:04 ip-***-**-**-** dotnet[5842]:       Connection closed
fubar-coder commented 5 years ago

It seems that the client doesn't execute a STOR command, which means that it doesn't even try to upload it.

Which client do you use?

Maciejszuchta commented 5 years ago

I am using FluentFtp https://github.com/robinrodricks/FluentFTP

fubar-coder commented 5 years ago

Congratulation! You've found a bug in the server. According to the RFC 959, the server has to start listen on the passive port before the data transfer command gets sent do the server:

      The passive data transfer process (this may be a user-DTP or a
      second server-DTP) shall "listen" on the data port prior to
      sending a transfer request command.  The FTP request command
      determines the direction of the data transfer.

But this server starts listening on the passive port after it received the STOR command and responded with a 150 response code.

Maciejszuchta commented 5 years ago

But how is it possible that I was able to upload the file when I setup both applications locally?

fubar-coder commented 5 years ago

TBH: I don't know. Maybe you used a different FTP client? However, I'm currently working on a fix and version 3.0.2 should be published in the next couple of hours.

fubar-coder commented 5 years ago

OK, I'm totally lost.

I created a unit test and everything is fine. The server behaves exactly like described in the spec and opens the data port during the PASV/EPSV command execution. In other words: The client can indeed connect to the server before issuing a STOR command.

Just a wild guess. The log is different from the output above, because it doesn't show the message NGettext: Translation not found for message id "File not found ({0}).". This means that the client is doing something different than before.

This might be a dumb question: How did you configure the directory where the data should be stored? Maybe the data stored in an unexpected directory?

Maciejszuchta commented 5 years ago

I think that my issue is connected with fact that I am using nginx to redirect connections to my aws server to application that is running on localhost:5000 and this application is serving fubar ftp server on port localhost:5002. I can connect to this port via ftp client and e.g list directory but I suppose nginx can have some problems while transfering the file to this port...

fubar-coder commented 5 years ago

Can you provide some information about using Nginx as a proxy for an FTP server? AFAIK Nginx doesn't support FTP proxying natively and it seems that something like a the TCP proxy module needs to be used? What is your configuration?

Have you tried configuring a port range and a 1:1 pass-through of the ports for the passive data connection?

Maciejszuchta commented 5 years ago

Im my nginx.conf I got this configuration

user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
    worker_connections 768;
    # multi_accept on;
}
stream{
    upstream stream_orientdb{
        server 127.0.0.1:2424;
    }

    upstream stream_mongodb{
        server 127.0.0.1:27017;
    }
    upstream ftp{ 
        server 127.0.0.1:5002;<------- this is where my fubar ftp server is listening
    }

    server{
        listen 27021;<------- I use this port to access the server
        proxy_connect_timeout 120s;
        proxy_timeout 120s;
        proxy_pass ftp;
    }
    server{
        listen 27020; 
                proxy_connect_timeout 5s;
                proxy_timeout 20s;
                proxy_pass stream_mongodb;
    }

    server{
        listen 8080;
        proxy_connect_timeout 5s;
        proxy_timeout 20s;
        proxy_pass stream_orientdb;
    }
}
fubar-coder commented 5 years ago

Ok, I see where the problem is.

The FTP server has two TCP connections:

  1. The control connection mapped from 27021 (external) to 5002 (internal)
  2. The data connection

The data connection will be created dynamically. There are two modes:

  1. Active data connection (FTP server creates a connection to the client)
  2. Passive data connection (FTP server opens a port and listens for a connection from the client)

The client usually uses passive data connections.

To make passive data connections work, the following steps need to be done:

  1. The server must open a port
  2. The server sends the port number to the client
  3. The client opens a connection to the port the client got in step 2

The step 3 is what fails in your configuration.

This is how to solve the problem:

  1. Create a server entry for the data connection (e.g. from 50000 external to 50000internal). The numbers must be the same!
  2. Set the PasvMinPort and PasvMaxPort configuration values to the same value (50000)

Now, everything should start working. There is still a limitation: You can only transfer one file (or directory listing) at once. To allow more transfers, you have to allow more ports, but it seems that you need a server (and upstream) entry per port, so Nginx probably isn't very well-suited for this scenario.

I'd suggest to create server (and upstream) entries for at least 2 passive data ports per allowed client.

So, for 2 clients, you should create server (external, and upstream, internal) entries for ports 50000-50003 (external) and map them to the same internal port.

Maciejszuchta commented 5 years ago

So if I understood correctly in netcoreapp startup:

    services.Configure<SimplePasvOptions>(opt =>
            {
                opt.PasvMinPort = 27022;
                opt.PasvMaxPort = 27022;
            }); 

Nginx configuration

stream{

        upstream ftp{
                server 127.0.0.1:5002;
        }
        upstream file{
                server 127.0.0.1:5002;
        }

        server{
                listen 27022;
                proxy_connect_timeout 120s;
                proxy_timeout 120s;
                proxy_pass file;
        }

        server{
                listen 27021;
                proxy_connect_timeout 120s;
                proxy_timeout 120s;
                proxy_pass ftp;
        }
Maciejszuchta commented 5 years ago

If I do it like this I get

Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: NGettext: Translation not found for message id "Binary transfer mode active.".
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       Executing server command "SEND RESPONSE (200)"
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       200 Binary transfer mode active.
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       Wait to read server commands
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       EPSV
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: warn: FubarDev.FtpServer.PasvListenerFactory[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       No free ports available for data connection
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: fail: FubarDev.FtpServer.Commands.DefaultFtpCommandDispatcher[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       Failed to process message (EPSV )
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: System.Net.Sockets.SocketException (98): Address already in use
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.PasvListenerFactory.CreateListenerInRange(IFtpConnection connection, PasvListenerOptions pasvOptions)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.PasvListenerFactory.CreateTcpListenerAsync(IFtpConnection connection, Nullable`1 addressFamily, Int32 port, CancellationToken cancellationToken)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.DataConnection.PassiveDataConnectionFeatureFactory.CreateFeatureAsync(FtpCommand ftpCommand, Nullable`1 addressFamily, CancellationToken cancellationToken)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.CommandHandlers.PasvCommandHandler.Process(FtpCommand command, CancellationToken cancellationToken)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.Commands.DefaultFtpCommandDispatcher.ExecuteCommandAsync(FtpExecutionContext context)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: NGettext: Translation not found for message id "Syntax error in parameters or arguments.".
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       Executing server command "SEND RESPONSE (501)"
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: dbug: FubarDev.FtpServer.ServerCommandHandlers.SendResponseServerCommandHandler[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       501 Syntax error in parameters or arguments.
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: trce: FubarDev.FtpServer.FtpConnection[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       Wait to read server commands
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: dbug: FubarDev.FtpServer.FtpConnection[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       PASV
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: warn: FubarDev.FtpServer.PasvListenerFactory[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       No free ports available for data connection
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: fail: FubarDev.FtpServer.Commands.DefaultFtpCommandDispatcher[0]
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:       Failed to process message (PASV )
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: System.Net.Sockets.SocketException (98): Address already in use
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.PasvListenerFactory.CreateListenerInRange(IFtpConnection connection, PasvListenerOptions pasvOptions)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.PasvListenerFactory.CreateTcpListenerAsync(IFtpConnection connection, Nullable`1 addressFamily, Int32 port, CancellationToken cancellationToken)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.DataConnection.PassiveDataConnectionFeatureFactory.CreateFeatureAsync(FtpCommand ftpCommand, Nullable`1 addressFamily, CancellationToken cancellationToken)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.CommandHandlers.PasvCommandHandler.Process(FtpCommand command, CancellationToken cancellationToken)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]:    at FubarDev.FtpServer.Commands.DefaultFtpCommandDispatcher.ExecuteCommandAsync(FtpExecutionContext context)
Aug 29 07:28:28 ip-***-**-**-** dotnet[12150]: NGettext: Translation not found for message id "Syntax error in parameters or arguments.".
fubar-coder commented 5 years ago

Ok, it seems that listen 27022 binds to all network interfaces - including localhost. This causes the problem here.

In other words: The proxy server uses localhost:27022 (due to listen 27022), which means that the FTP server is unable to use this port as data connection. You have to change the listen option to include the IP address of the network interface that gets its TCP packages from the outside. Now, the FTP server should be able to use localhost:27022.

You must also change upstream file to:

        upstream file{
                server 127.0.0.1:27022;
        }

Note: You must not use the same port for a control and a passive data connection.

EDIT: I guess that this difficult configuration is the reason why this StackOverflow answer says that FTP isn't supported.

fubar-coder commented 5 years ago

Closing this issue as it's a configuration problem in a third-party product.