2nolife / akka-ftp

The open source FTP server with Akka, Spray and AngularJS
GNU Lesser General Public License v3.0
3 stars 1 forks source link

closing data connection #1

Closed ahoy-jon closed 7 years ago

ahoy-jon commented 7 years ago

Hi, I was trying your project, but the uploads are failing half of the time (and I can't really pinpoint where there could be a problem).

I use curl for the upload :

curl -v -T plouf1 ftp://localhost:2021 --user admin:admin

And for some reason the data connection dies.

Here is the complete error log (3 uploads, failing, success, failing), do you have any clues ?

sbt run                                                                             
Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=2G; support was removed in 8.0
[info] Loading global plugins from /Users/jon/.sbt/0.13/plugins
[info] Loading project definition from /Users/jon/Project/akka-ftp/project
[info] Set current project to akka-ftp (in build file:/Users/jon/Project/akka-ftp/)
[info] Running com.coldcore.akkaftp.main
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$c] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@556197aa)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$b] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@13018191)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$a] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@44c6a3eb)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$d] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@4a014503)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$e] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@6d70a4e2)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$f] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@63b7573c)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$g] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@56bcfa40)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$h] - started (com.coldcore.akkaftp.ftp.executor.TaskNode@587b1ee7)
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$c] - started (com.coldcore.akkaftp.ftp.datafilter.SessionKeeperNode@194614dc)
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$d] - started (com.coldcore.akkaftp.ftp.datafilter.SessionKeeperNode@5f99fcda)
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$d] - now watched by Actor[akka://akkaftp-system/user/session-keeper/node#753791161]
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$c] - now watched by Actor[akka://akkaftp-system/user/session-keeper/node#753791161]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$a] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$b] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$b] - started (com.coldcore.akkaftp.ftp.datafilter.SessionKeeperNode@4e3ec89b)
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$b] - now watched by Actor[akka://akkaftp-system/user/session-keeper/node#753791161]
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$a] - started (com.coldcore.akkaftp.ftp.datafilter.SessionKeeperNode@6788cf92)
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper/node/$a] - now watched by Actor[akka://akkaftp-system/user/session-keeper/node#753791161]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$e] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$c] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$d] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$f] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector] - started (com.coldcore.akkaftp.ftp.connection.DataConnector@2bf40cfa)
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector] - now supervising Actor[akka://akkaftp-system/user/data-connector/node#-121150606]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$g] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor/node/$h] - now watched by Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor] - started (com.coldcore.akkaftp.ftp.executor.TaskExecutor@57a9762f)
23:13:19 DEBUG [akka://akkaftp-system/user/task-executor] - now supervising Actor[akka://akkaftp-system/user/task-executor/node#-1791313190]
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper] - started (com.coldcore.akkaftp.ftp.datafilter.SessionKeeper@ede7255)
23:13:19 DEBUG [akka://akkaftp-system/user/session-keeper] - now supervising Actor[akka://akkaftp-system/user/session-keeper/node#753791161]
23:13:19 DEBUG [akka://akkaftp-system/user/traffic-counter] - started (com.coldcore.akkaftp.ftp.datafilter.TrafficCounter@1f1d476b)
23:13:19 INFO  [akka://akkaftp-system/user/data-connector/node/$c] - Bound data connector to 0.0.0.0:6003
23:13:19 INFO  [akka://akkaftp-system/user/ctrl-connector] - Bound Akka FTP to 0.0.0.0:2021
23:13:19 DEBUG [akka://akkaftp-system/user/ctrl-connector] - started (com.coldcore.akkaftp.ftp.connection.ControlConnector@63d501a1)
23:13:19 INFO  [akka://akkaftp-system/user/data-connector/node/$a] - Bound data connector to 0.0.0.0:6001
23:13:19 INFO  [akka://akkaftp-system/user/data-connector/node/$b] - Bound data connector to 0.0.0.0:6002
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$c] - started (com.coldcore.akkaftp.ftp.connection.DataConnectorNode@55cfd077)
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$c] - now watched by Actor[akka://akkaftp-system/user/data-connector/node#-121150606]
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$a] - started (com.coldcore.akkaftp.ftp.connection.DataConnectorNode@7efa181f)
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$b] - started (com.coldcore.akkaftp.ftp.connection.DataConnectorNode@7d27764b)
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$a] - now watched by Actor[akka://akkaftp-system/user/data-connector/node#-121150606]
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$b] - now watched by Actor[akka://akkaftp-system/user/data-connector/node#-121150606]
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$b] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/0#830120717]
23:13:19 DEBUG [akka://akkaftp-system/user/ctrl-connector] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/1#-1556309395]
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$c] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/2#-842632532]
23:13:19 DEBUG [akka://akkaftp-system/user/data-connector/node/$a] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/3#343840867]
23:13:19 INFO  [akka://akkaftp-system/user/rest-service] - Bound Akka FTP REST service to 0.0.0.0:8021
23:13:20 DEBUG [akka://akkaftp-system/user/rest-service] - started (com.coldcore.akkaftp.rest.service.RestService@1f2016ff)
23:13:20 DEBUG [akka://akkaftp-system/user/rest-service] - now watched by Actor[akka://akkaftp-system/user/IO-HTTP/listener-0#179941894]
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/5#-304231519]
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector] - Remote address /0:0:0:0:0:0:0:1:58633 connected
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector] - now supervising Actor[akka://akkaftp-system/user/ctrl-connector/conn-1#650098760]
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/5#-304231519]
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - started (com.coldcore.akkaftp.ftp.connection.ControlConnection@79ab95b2)
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/5#-304231519]
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 220 Welcome to Akka FTP - the open source FTP server
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 ---> USER admin
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 331 User name okay, need password.
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 ---> PASS admin
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 230 User logged in, proceed.
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 ---> PWD
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 257 "/" is current directory.
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 ---> EPSV
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 229 Entering Extended Passive Mode (|||6001|)
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 ---> TYPE I
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/6#-1016952254]
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a] - Remote address /0:0:0:0:0:0:0:1:58634 connected
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 200 Type set to I
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 ---> STOR plouf1
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a] - now supervising Actor[akka://akkaftp-system/user/data-connector/node/$a/conn-3#1015665156]
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/6#-1016952254]
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a/conn-3] - started (com.coldcore.akkaftp.ftp.connection.DataConnection@5874425d)
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a/conn-3] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/6#-1016952254]
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 150 Opening I mode data connection for plouf1.
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 interrupt state ON
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a/conn-3] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/6#-1016952254]
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a/conn-3] - Connection for remote address /0:0:0:0:0:0:0:1:58634 died
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a/conn-3] - Closing connection to remote address /0:0:0:0:0:0:0:1:58634
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 426 Connection closed, transfer aborted.
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 interrupt state OFF
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 ---> QUIT
23:13:32 DEBUG [akka://akkaftp-system/user/data-connector/node/$a/conn-3] - stopped
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - /0:0:0:0:0:0:0:1:58633 <--- 221 Logged out, closing control connection as soon as data transferred.
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/5#-304231519]
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - Connection for remote address /0:0:0:0:0:0:0:1:58633 closed
23:13:32 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-1] - stopped
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/7#-1507495124]
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector] - Remote address /0:0:0:0:0:0:0:1:58636 connected
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector] - now supervising Actor[akka://akkaftp-system/user/ctrl-connector/conn-4#-1124348075]
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/7#-1507495124]
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - started (com.coldcore.akkaftp.ftp.connection.ControlConnection@23d84d90)
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/7#-1507495124]
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 220 Welcome to Akka FTP - the open source FTP server
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 ---> USER admin
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 331 User name okay, need password.
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 ---> PASS admin
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 230 User logged in, proceed.
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 ---> PWD
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 257 "/" is current directory.
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 ---> EPSV
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 229 Entering Extended Passive Mode (|||6002|)
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 ---> TYPE I
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 200 Type set to I
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 ---> STOR plouf1
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/8#-1027715453]
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b] - Remote address /0:0:0:0:0:0:0:1:58637 connected
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 150 Opening I mode data connection for plouf1.
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 interrupt state ON
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b] - now supervising Actor[akka://akkaftp-system/user/data-connector/node/$b/conn-6#-1827658506]
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b/conn-6] - started (com.coldcore.akkaftp.ftp.connection.DataConnection@9e4eb70)
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/8#-1027715453]
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b/conn-6] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/8#-1027715453]
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b/conn-6] - Starting data trasfer with /0:0:0:0:0:0:0:1:58637
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b/conn-6] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/8#-1027715453]
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b/conn-6] - /0:0:0:0:0:0:0:1:58637 ---> 90068 bytes
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b/conn-6] - Closing connection to remote address /0:0:0:0:0:0:0:1:58637
23:13:39 DEBUG [akka://akkaftp-system/user/data-connector/node/$b/conn-6] - stopped
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 226 Transfer completed for "plouf1".
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 interrupt state OFF
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 ---> QUIT
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - /0:0:0:0:0:0:0:1:58636 <--- 221 Logged out, closing control connection as soon as data transferred.
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/7#-1507495124]
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - Connection for remote address /0:0:0:0:0:0:0:1:58636 closed
23:13:39 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-4] - stopped
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/9#-1700012497]
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector] - Remote address /0:0:0:0:0:0:0:1:58638 connected
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector] - now supervising Actor[akka://akkaftp-system/user/ctrl-connector/conn-7#2075981733]
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/9#-1700012497]
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - started (com.coldcore.akkaftp.ftp.connection.ControlConnection@cd36c21)
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/9#-1700012497]
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 220 Welcome to Akka FTP - the open source FTP server
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 ---> USER admin
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 331 User name okay, need password.
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 ---> PASS admin
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 230 User logged in, proceed.
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 ---> PWD
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 257 "/" is current directory.
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 ---> EPSV
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 229 Entering Extended Passive Mode (|||6003|)
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 ---> TYPE I
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 200 Type set to I
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 ---> STOR plouf1
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/10#1454529131]
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c] - Remote address /0:0:0:0:0:0:0:1:58639 connected
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c] - now supervising Actor[akka://akkaftp-system/user/data-connector/node/$c/conn-9#856666353]
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/10#1454529131]
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c/conn-9] - started (com.coldcore.akkaftp.ftp.connection.DataConnection@67505cfd)
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c/conn-9] - now watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/10#1454529131]
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 150 Opening I mode data connection for plouf1.
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 interrupt state ON
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c/conn-9] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/10#1454529131]
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c/conn-9] - Connection for remote address /0:0:0:0:0:0:0:1:58639 died
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c/conn-9] - Closing connection to remote address /0:0:0:0:0:0:0:1:58639
23:14:06 DEBUG [akka://akkaftp-system/user/data-connector/node/$c/conn-9] - stopped
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 426 Connection closed, transfer aborted.
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 interrupt state OFF
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 ---> QUIT
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - /0:0:0:0:0:0:0:1:58638 <--- 221 Logged out, closing control connection as soon as data transferred.
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - no longer watched by Actor[akka://akkaftp-system/system/IO-TCP/selectors/$a/9#-1700012497]
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - Connection for remote address /0:0:0:0:0:0:0:1:58638 closed
23:14:06 DEBUG [akka://akkaftp-system/user/ctrl-connector/conn-7] - stopped
2nolife commented 7 years ago

I will try your curl example and come back to you.

Regards, Sergei

ahoy-jon commented 7 years ago

Thanks Sergei,

I tried to understand, this test is failing on my machine (the first iteration).

package com.coldcore.akkaftp.it
package test

import java.io.{File, PrintWriter}

import com.coldcore.akkaftp.it.Utils.delay
import com.coldcore.akkaftp.it.client.{FtpClient, Reply}
import com.coldcore.akkaftp.it.server.{CreateSampleFiles, FtpServer}
import org.scalatest.{BeforeAndAfterAll, Matchers, WordSpec}

class UploadWithCurl extends WordSpec with BeforeAndAfterAll with Matchers with CreateSampleFiles {

  val server = new FtpServer

  "curl scenario" should {

    server.start()

    import scala.concurrent.duration._
    createSampleFiles()

    def tryUpload(): Int = {
      val f = File.createTempFile("temp-file-name", ".tmp")
      f.deleteOnExit()
      f.createNewFile()
      val path = f.getAbsolutePath

      val writer = new PrintWriter(f)
      writer.write("hello")
      writer.close()

      import sys.process._
      s"curl -v -T $path ftp://127.0.0.1:2021 --user myuser:myuser" !
    }

    (0 to 10).map(_ -> tryUpload()) should be( (0 to 10).map(_ -> 0))
  }
}
2nolife commented 7 years ago

Thanks for the test case, it helped to debug the issue. After a bit of digging the code I see why it is failing. A data connection is not yet ready to accept client data. STOR command prepares the data connection but there is a delay before it gets ready. While running on the same (fast and multicore) machine the client can send the data and terminate before the data connection understands what is about to happen. The easiest fix is to delay a 150 reply to the client by 100ms: tick time of the data connection readiness check. The better solution would be a notification sent back from the data connection to the STOR command, before it sends a 150 reply to the client. I will apply the delay fix, for now.

Fixed in the “1.1” version.