IIS10 Passive FTPS: Client can list once, then fails until Microsoft FTP Service is restarted
Hello everyone, been having a lot of headaches with this one. Our corporation is attempting to use a service called MoveIT that will connect via 990 to our IIS systems so that we can use FTPS and transfer data back and forth. Everything is working on my systems, but I'm helping another team troubleshoot theirs and we have been having non-stop issues. We are able to restart the Microsoft FTP Service, and the MoveIT Client can connect and list the directory one time. Once they attempt to do other actions, they are met with the following error message:
Error getting directory listing: 2850 Could not list directory: The connection timed-out. Response: 150 Opening ASCII mode data connection.
Session history:
FTP got: PBSZ
FTP got: PROT C;P;
FTP got: CCC
FTP got: HOST
FTP got: SIZE
FTP got: MDTM
FTP got: REST STREAM
FTP got: 211 END
FTP snt: OPTS UTF8 ON
FTP got: 200 OPTS UTF8 command successful - UTF8 encoding now ON.
FTP snt: PWD
FTP got: 257 "/" is current directory.
FTP snt: CWD /MOVEITTest
FTP got: 250 CWD command successful.
FTP snt: PWD
FTP got: 257 "/MOVEITTest" is current directory.
FTP snt: PASV
FTP got: 227 Entering Passive Mode (###,###,###,###,19,139) Note: I am just hiding IP information
FTP snt: LIST
FTP got: 150 Opening ASCII mode data connection.
After doing the math for P1 and P2 that I learned ((P1*256)+P2), the port is correct as the range is 5000-5100.
The Server OS is Windows Server 2019 (The working server is 2016).
Windows Firewall is not enabled.
SEP was removed during troubleshooting and determined not to be the issue.
There is nothing really indicative in the Server logs for what is going on either.
Is this a known issue with something that might be causing it? There is nothing else that is running on this server.
Thanks!
Edit: Some additional information from the server side of things:
Here are some additional logs and abnormalities that I have seen.
Error message:
Error getting directory listing: 2850 Could not list directory: The connection timed-out. Response: 150 Opening ASCII mode data connection.
Session history:
FTP got: PBSZ
FTP got: PROT C;P;
FTP got: CCC
FTP got: HOST
FTP got: SIZE
FTP got: MDTM
FTP got: REST STREAM
FTP got: 211 END
FTP snt: OPTS UTF8 ON
FTP got: 200 OPTS UTF8 command successful - UTF8 encoding now ON.
FTP snt: PWD
FTP got: 257 "/" is current directory.
FTP snt: CWD /MOVEITTest
FTP got: 250 CWD command successful.
FTP snt: PWD
FTP got: 257 "/MOVEITTest" is current directory.
FTP snt: PASV
FTP got: 227 Entering Passive Mode (###,###,###,###,19,137).
FTP snt: LIST
FTP got: 150 Opening ASCII mode data connection.Press 'Ctrl-C' to copy this message to the clipboard.
You can see that on entering passive mode it is attempting to use port # 5001. Here is the log from the server:
2021-09-30 19:13:36 SOURCEIP 55595 - - DESTSERVER - DESTIP 990 ControlChannelOpened - - 0 0 0 0 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:13:36 SOURCEIP 55595 - FTPSVC2 DESTSERVER - DESTIP 990 USER SERVICEACCT 331 0 0 52 32 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:13:36 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PASS 230 0 0 50 21 63 0d12f004-bebc-49a6-a42f-6f30b24a3190 / -
2021-09-30 19:13:37 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 60 5 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:13:37 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 FEAT - 211 0 0 294 6 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:13:37 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 OPTS UTF8+ON 200 0 0 87 14 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:13:37 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 60 5 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:14:08 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 CWD /MOVEITTest 250 0 0 58 17 16 0d12f004-bebc-49a6-a42f-6f30b24a3190 /MOVEITTest -
2021-09-30 19:14:09 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 70 5 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:14:09 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PASV - 227 0 0 80 6 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:14:09 SOURCEIP 55702 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 5000 DataChannelOpened - - 0 0 0 0 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:14:09 SOURCEIP 55702 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 5000 DataChannelClosed - - 0 0 106 469 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:14:09 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 LIST - 226 0 0 229 475 125 0d12f004-bebc-49a6-a42f-6f30b24a3190 /MOVEITTest -
2021-09-30 19:15:10 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 Quit - 221 0 0 43 6 0 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:15:10 SOURCEIP 55595 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 ControlChannelClosed - - 0 0 3022 911 94359 0d12f004-bebc-49a6-a42f-6f30b24a3190 - -
2021-09-30 19:15:10 SOURCEIP 56034 - - DESTSERVER - DESTIP 990 ControlChannelOpened - - 0 0 0 0 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:10 SOURCEIP 56034 - FTPSVC2 DESTSERVER - DESTIP 990 USER SERVICEACCT 331 0 0 52 32 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:10 SOURCEIP 56034 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PASS 230 0 0 50 21 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 / -
2021-09-30 19:15:11 SOURCEIP 56034 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 60 5 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:11 SOURCEIP 56034 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 FEAT - 211 0 0 294 6 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:11 SOURCEIP 56034 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 OPTS UTF8+ON 200 0 0 87 14 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:12 SOURCEIP 56034 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 60 5 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:12 SOURCEIP 56034 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 Quit - 221 0 0 43 6 0 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:12 SOURCEIP 56034 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 ControlChannelClosed - - 0 0 2691 761 1281 bfe4aced-9028-46cb-b921-adcf5372fbb4 - -
2021-09-30 19:15:12 SOURCEIP 56037 - - DESTSERVER - DESTIP 990 ControlChannelOpened - - 0 0 0 0 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:12 SOURCEIP 56037 - FTPSVC2 DESTSERVER - DESTIP 990 USER SERVICEACCT 331 0 0 52 32 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:12 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PASS *** 230 0 0 50 21 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 / -
2021-09-30 19:15:12 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 60 5 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:12 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 FEAT - 211 0 0 294 6 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:12 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 OPTS UTF8+ON 200 0 0 87 14 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:13 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 60 5 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:14 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 CWD /MOVEITTest 250 0 0 58 17 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 /MOVEITTest -
2021-09-30 19:15:14 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 70 5 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:14 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PASV - 227 0 0 80 6 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:15:50 - - SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 5001 DataChannelClosed - - 258 15 0 0 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - Data+channel+timed+out.
2021-09-30 19:15:50 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 LIST - 550 1236 15 128 6 35485 1ef0031c-d106-4368-a99b-3fdd61ce39d5 /MOVEITTest Data+channel+timed+out.
2021-09-30 19:16:15 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 CWD /MOVEITTest 250 0 0 58 17 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 /MOVEITTest -
2021-09-30 19:16:15 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PWD - 257 0 0 70 5 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:16:15 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 PASV - 227 0 0 80 6 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:16:55 - - SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 5002 DataChannelClosed - - 258 15 0 0 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - Data+channel+timed+out.
2021-09-30 19:16:55 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 LIST - 550 1236 15 128 6 39391 1ef0031c-d106-4368-a99b-3fdd61ce39d5 /MOVEITTest Data+channel+timed+out.
2021-09-30 19:17:26 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 Quit - 221 0 0 43 6 0 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
2021-09-30 19:17:26 SOURCEIP 56037 SERVICEACCT FTPSVC2 DESTSERVER - DESTIP 990 ControlChannelClosed - - 0 0 3363 1061 134015 1ef0031c-d106-4368-a99b-3fdd61ce39d5 - -
Sorry for all of the sensoring. As you can see here, I believe it successfully listed using 5000 (DataChannelOpened). After the list (as reported by the person I'm working with), when it fails is when we get the error above using port 5001. You can see that there is no DataChannelOpened for any other port; just multiple lines for DataChannelClosed on the incremental port.
Very strange, but I hope this information helps.