ftp server disconnects during upload

  • I have enabled the ftp server and till about a week ago everything worked fine.

    Now i have issues with connections being disconnected.


    When restarting my omv server i get 3 email system notifications (in sequence of appearing)


    1.

    Host: \openmediavault.local

    Date: Tue, 26 May 2020 15:09:13

    Service: proftpd

    Event: Does not exist

    Description: process is not running


    This triggered the monitoring system to: restart


    2.

    Host: \openmediavault.local

    Date: Tue, 26 May 2020 15:09:44

    Service: proftpd

    Event: Exists

    Description: process is running with pid 3530


    This triggered the monitoring system to: alert


    3.

    Host: \openmediavault.local

    Date: Tue, 26 May 2020 15:10:44

    Service: proftpd

    Event: Connection failed

    Description: failed protocol test [FTP] at [localhost]:21 [TCP/IP] -- FTP: error receiving data -- Resource temporarily unavailable


    This triggered the monitoring system to: restart



    Then no notifications, the indicators are green but as i said connections are interrupted. In the log files is hardly any information:

    Tue May 26 15:16:53 2020 23 185.94.230.101 645463840 /neostrada/www.leukgevonden.com/www.leukgevonden.com-20200526-131135-4c4ojt.wpress b _ i r ftpuser ftp 1 * i

    Tue May 26 15:17:28 2020 26 185.94.230.101 726804016 /neostrada/www.leukgevonden.com/www.leukgevonden.com-20200526-131135-4c4ojt.wpress b _ i r ftpuser ftp 1 * i

    Tue May 26 15:17:57 2020 25 185.94.230.101 756887848 /neostrada/www.leukgevonden.com/www.leukgevonden.com-20200526-131135-4c4ojt.wpress b _ i r ftpuser ftp 1 * i

    Tue May 26 15:18:29 2020 26 185.94.230.101 740735640 /neostrada/www.leukgevonden.com/www.leukgevonden.com-20200526-131135-4c4ojt.wpress b _ i r ftpuser ftp 1 * i

    OMV 5 on i3-2120 CPU with 8GB

    Portainer with several Dockers

  • Noboby else has this issue? It looks like connetion is disconnect after certain amount of time. Then the client tries again. Smaller files are transferred ok.

    OMV 5 on i3-2120 CPU with 8GB

    Portainer with several Dockers

  • I switched to the pve kernel and the issue has gone. When restarting the omv server i now get only the first 2 email system notifications.

    OMV 5 on i3-2120 CPU with 8GB

    Portainer with several Dockers

  • Unfortunately the error returned. I updated OMV to 5.5.2, but i do not know if that caused it.


    Here is a part of the filezilla log maybe someone can give advice? It is in Dutch but i translated the most important parts


    2020-06-09 09:02:34 6036 4 Antwoord: 227 Entering Passive Mode (192,168,1,4,168,69).

    2020-06-09 09:02:34 6036 4 Opdracht: STOR leukgevonden.com-20200511-140033-h5tg2u.wpress

    2020-06-09 09:02:34 6036 4 Antwoord: 150 Opening BINARY mode data connection for leukgevonden.com-20200511-140033-h5tg2u.wpress

    2020-06-09 09:03:00 6036 3 Status: Connection closed by server

    2020-06-09 09:03:02 6036 4 Fout: Could not write to transfer socket: ECONNRESET - Connection reset by server

    2020-06-09 09:03:02 6036 4 Fout: Connection closed by server

    2020-06-09 09:03:02 6036 4 Fout: File transfer fails after the transfer of 434,7 MB inr 28 seconden

    2020-06-09 09:03:02 6036 4 Status: Connection with server lost

    2020-06-09 09:03:02 6036 4 Status: Verbinden met 192.168.1.4:21...

    2020-06-09 09:03:02 6036 4 Status: Verbinding gemaakt, welkomstbericht afwachten...

    2020-06-09 09:03:02 6036 4 Antwoord: 220 ProFTPD Server ready.

    2020-06-09 09:03:02 6036 4 Opdracht: AUTH TLS

    2020-06-09 09:03:02 6036 4 Antwoord: 500 AUTH not understood

    2020-06-09 09:03:02 6036 4 Opdracht: AUTH SSL

    2020-06-09 09:03:02 6036 4 Antwoord: 500 AUTH not understood

    2020-06-09 09:03:02 6036 4 Status: Onveilige server, die geen FTP over TLS ondersteunt.

    OMV 5 on i3-2120 CPU with 8GB

    Portainer with several Dockers

  • The same problem!


    FTP service is ON, TLS/SSL is ON, TLS/SSL is required, passive mode ON, no masqerade


    Deep investigation results:

    1 - proftpd binded on port 21 or the any other - no effect, error exist

    2 - only if "Implicit SSL" in SSL/TLS settings is ON error exist, but without this parameter not works my FTPS uploads by CURL (?)

    3 - "monit" service checks proftpd`s state every 30 sec and cause this error


    /var/log/proftpd/tls.log fragment:

    ......

    >>2021-01-08 23:00:06,612 mod_tls/2.7[30134]: TLSOption UseImplicitSSL in effect, starting SSL/TLS handshake

    >>2021-01-08 23:00:11,613 mod_tls/2.7[30134]: unable to accept TLS connection: system call error: [0] Выполнено


    4 - if disable port check in "monit" config, all works fine


    /etc/monit/conf.d/openmediavault-proftpd.conf string:

    .....

    >> # if failed port 21 protocol ftp for 3 cycles then restart


    It is no true solution, but is acceptable in this moment

  • votdev could you please have a look to validate the suspected root cause " "monit" service checks proftpd`s state every 30 sec and cause this error"?

    omv 5.6.9-1 (usul) on RPi4/4GB with Kernel 5.10.17 and WittyPi 3 V2 RTC HAT

    2x 6TB HDD formatted with ext4 in Icy Box IB-RD3662-C31 / hardware supported RAID1

    For Read/Write performance of SMB shares hosted on this hardware see forum here

  • votdev could you please have a look to validate the suspected root cause " "monit" service checks proftpd`s state every 30 sec and cause this error"?

    Deep inspection configs and logs!


    1 - Simulating problem re-enabling port 21 check in monit config...


    Time in logs is corresponding


    every 30 sec monit detects error and restarts proftpd


    /var/log/syslog:


    Jan 9 20:01:09 slavaya-omv monit[27662]: Monit daemon with pid [27662] stopped

    Jan 9 20:01:09 slavaya-omv monit[27662]: '\slavaya-omv.local' Monit 5.26.0 stopped

    Jan 9 20:01:09 slavaya-omv monit[10898]: Stopping daemon monitor: monit.

    Jan 9 20:01:09 slavaya-omv systemd[1]: monit.service: Succeeded.

    Jan 9 20:01:09 slavaya-omv systemd[1]: Stopped LSB: service and resource monitoring daemon.

    Jan 9 20:01:29 slavaya-omv systemd[1]: Starting LSB: service and resource monitoring daemon...

    Jan 9 20:01:29 slavaya-omv monit[10990]: Starting Monit 5.26.0 daemon with http interface at /run/monit.sock

    Jan 9 20:01:29 slavaya-omv monit[10987]: Starting daemon monitor: monit.

    Jan 9 20:01:29 slavaya-omv systemd[1]: Started LSB: service and resource monitoring daemon.

    Jan 9 20:01:29 slavaya-omv monit[10992]: '\slavaya-omv.local' Monit 5.26.0 started

    Jan 9 20:01:34 slavaya-omv monit[10992]: 'proftpd' failed protocol test [FTP] at [localhost]:21 [TCP/IP] -- FTP: error receiving data -- Resource temporarily unavailable

    Jan 9 20:01:34 slavaya-omv proftpd[10994]: 192.168.254.112 (127.0.0.1[127.0.0.1]) - mod_tls.c: error initializing session: Отказано в доступе

    Jan 9 20:02:09 slavaya-omv monit[10992]: 'proftpd' failed protocol test [FTP] at [localhost]:21 [TCP/IP] -- FTP: error receiving data -- Resource temporarily unavailable

    Jan 9 20:02:09 slavaya-omv proftpd[11049]: 192.168.254.112 (127.0.0.1[127.0.0.1]) - mod_tls.c: error initializing session: Отказано в доступе

    Jan 9 20:02:45 slavaya-omv monit[10992]: 'proftpd' failed protocol test [FTP] at [localhost]:21 [TCP/IP] -- FTP: error receiving data -- Resource temporarily unavailable

    Jan 9 20:02:45 slavaya-omv monit[10992]: 'proftpd' trying to restart

    Jan 9 20:02:45 slavaya-omv monit[10992]: 'proftpd' stop: '/etc/init.d/proftpd stop'

    Jan 9 20:02:45 slavaya-omv proftpd[11103]: 192.168.254.112 (127.0.0.1[127.0.0.1]) - mod_tls.c: error initializing session: Отказано в доступе

    Jan 9 20:02:45 slavaya-omv systemd[1]: Stopping LSB: Starts ProFTPD daemon...

    Jan 9 20:02:45 slavaya-omv proftpd[31802]: 192.168.254.112 - ProFTPD killed (signal 15)

    Jan 9 20:02:45 slavaya-omv proftpd[31802]: 192.168.254.112 - ProFTPD 1.3.6 standalone mode SHUTDOWN

    Jan 9 20:02:45 slavaya-omv proftpd[11121]: Stopping ftp server: proftpd.

    Jan 9 20:02:45 slavaya-omv systemd[1]: proftpd.service: Succeeded.

    Jan 9 20:02:45 slavaya-omv systemd[1]: Stopped LSB: Starts ProFTPD daemon.

    Jan 9 20:02:45 slavaya-omv monit[10992]: 'proftpd' start: '/etc/init.d/proftpd restart'

    Jan 9 20:02:45 slavaya-omv systemd[1]: Starting LSB: Starts ProFTPD daemon...

    Jan 9 20:02:45 slavaya-omv proftpd[11150]: 192.168.254.112 - ProFTPD 1.3.6 (stable) (built Tue Mar 10 2020 23:03:08 UTC) standalone mode STARTUP

    Jan 9 20:02:45 slavaya-omv proftpd[11140]: Starting ftp server: proftpd.

    Jan 9 20:02:45 slavaya-omv systemd[1]: Started LSB: Starts ProFTPD daemon.

    Jan 9 20:03:21 slavaya-omv monit[10992]: 'proftpd' failed protocol test [FTP] at [localhost]:21 [TCP/IP] -- FTP: error receiving data -- Resource temporarily unavailable

    Jan 9 20:03:21 slavaya-omv monit[10992]: 'proftpd' trying to restart

    Jan 9 20:03:21 slavaya-omv monit[10992]: 'proftpd' stop: '/etc/init.d/proftpd stop'

    Jan 9 20:03:21 slavaya-omv proftpd[11196]: 192.168.254.112 (127.0.0.1[127.0.0.1]) - mod_tls.c: error initializing session: Отказано в доступе

    Jan 9 20:03:21 slavaya-omv systemd[1]: Stopping LSB: Starts ProFTPD daemon...

    Jan 9 20:03:21 slavaya-omv proftpd[11150]: 192.168.254.112 - ProFTPD killed (signal 15)

    Jan 9 20:03:21 slavaya-omv proftpd[11150]: 192.168.254.112 - ProFTPD 1.3.6 standalone mode SHUTDOWN

    Jan 9 20:03:21 slavaya-omv proftpd[11214]: Stopping ftp server: proftpd.

    Jan 9 20:03:21 slavaya-omv systemd[1]: proftpd.service: Succeeded.

    Jan 9 20:03:21 slavaya-omv systemd[1]: Stopped LSB: Starts ProFTPD daemon.

    Jan 9 20:03:21 slavaya-omv monit[10992]: 'proftpd' start: '/etc/init.d/proftpd restart'

    Jan 9 20:03:21 slavaya-omv systemd[1]: Starting LSB: Starts ProFTPD daemon...

    Jan 9 20:03:21 slavaya-omv proftpd[11242]: 192.168.254.112 - ProFTPD 1.3.6 (stable) (built Tue Mar 10 2020 23:03:08 UTC) standalone mode STARTUP

    Jan 9 20:03:21 slavaya-omv proftpd[11234]: Starting ftp server: proftpd.

    Jan 9 20:03:21 slavaya-omv systemd[1]: Started LSB: Starts ProFTPD daemon.

    Jan 9 20:03:57 slavaya-omv monit[10992]: 'proftpd' failed protocol test [FTP] at [localhost]:21 [TCP/IP] -- FTP: error receiving data -- Resource temporarily unavailable

    Jan 9 20:03:57 slavaya-omv monit[10992]: 'proftpd' trying to restart

    Jan 9 20:03:57 slavaya-omv monit[10992]: 'proftpd' stop: '/etc/init.d/proftpd stop'

    Jan 9 20:03:57 slavaya-omv proftpd[11289]: 192.168.254.112 (127.0.0.1[127.0.0.1]) - mod_tls.c: error initializing session: Отказано в доступе

    Jan 9 20:03:57 slavaya-omv systemd[1]: Stopping LSB: Starts ProFTPD daemon...

    Jan 9 20:03:57 slavaya-omv proftpd[11242]: 192.168.254.112 - ProFTPD killed (signal 15)

    Jan 9 20:03:57 slavaya-omv proftpd[11242]: 192.168.254.112 - ProFTPD 1.3.6 standalone mode SHUTDOWN

    Jan 9 20:03:57 slavaya-omv proftpd[11307]: Stopping ftp server: proftpd.

    Jan 9 20:03:57 slavaya-omv systemd[1]: proftpd.service: Succeeded.

    Jan 9 20:03:57 slavaya-omv systemd[1]: Stopped LSB: Starts ProFTPD daemon.

    Jan 9 20:03:57 slavaya-omv monit[10992]: 'proftpd' start: '/etc/init.d/proftpd restart'

    Jan 9 20:03:57 slavaya-omv systemd[1]: Starting LSB: Starts ProFTPD daemon...

    Jan 9 20:03:57 slavaya-omv proftpd[11334]: 192.168.254.112 - ProFTPD 1.3.6 (stable) (built Tue Mar 10 2020 23:03:08 UTC) standalone mode STARTUP

    Jan 9 20:03:57 slavaya-omv proftpd[11326]: Starting ftp server: proftpd.

    Jan 9 20:03:57 slavaya-omv systemd[1]: Started LSB: Starts ProFTPD daemon.

    Jan 9 20:04:33 slavaya-omv monit[10992]: 'proftpd' failed protocol test [FTP] at [localhost]:21 [TCP/IP] -- FTP: error receiving data -- Resource temporarily unavailable

    Jan 9 20:04:33 slavaya-omv monit[10992]: 'proftpd' trying to restart

    Jan 9 20:04:33 slavaya-omv monit[10992]: 'proftpd' stop: '/etc/init.d/proftpd stop'

    Jan 9 20:04:33 slavaya-omv proftpd[11381]: 192.168.254.112 (127.0.0.1[127.0.0.1]) - mod_tls.c: error initializing session: Отказано в доступе

    Jan 9 20:04:33 slavaya-omv systemd[1]: Stopping LSB: Starts ProFTPD daemon.......


    see attach - 10000 char limit

  • votdev could you please have a look to validate the suspected root cause " "monit" service checks proftpd`s state every 30 sec and cause this error"?

    I can not do everything. But based on the information that are available it seems that monit and/or proftpd has some issues with checking port 21 when implicit SSL is used. IMO this is a good starting point for digging into this issue. I'm happy to see ideas for useful improvements.

  • According to https://mmonit.com/monit/docum…nit.html#CONNECTION-TESTS, could you please do some tests using the configuration line if failed port 21 for 3 cycles then restart? The docs mention that the protocol should not be set if it is not in the list of supported protocols. Maybe monit is clever enough and it will fix the issue.


    Please open a bug report in this case, tracking such issues in the forum is impossible.

  • Thanks votdev dev it sounded like an issue requiring a developer to look into :)

    omv 5.6.9-1 (usul) on RPi4/4GB with Kernel 5.10.17 and WittyPi 3 V2 RTC HAT

    2x 6TB HDD formatted with ext4 in Icy Box IB-RD3662-C31 / hardware supported RAID1

    For Read/Write performance of SMB shares hosted on this hardware see forum here

  • Can we expect an update to OMV soon that will include the fix for this issue? (Hope I'm not coming across as impatient, but just trying to get an idea.)


    Or can one manually apply it, and if so, how? I'm looking at the commit on Github but it's a bit too complex for my humble mind... although I gather that it entails replacing a few specific config files.

Participate now!

Don’t have an account yet? Register yourself now and be a part of our community!