tests: fix a race condition in ftp server disconnect

If a client disconnected and reconnected quickly, before the ftp server
had a chance to respond, the protocol message/ack (ping/pong) sequence
got out of sync, causing messages sent to the old client to be delivered
to the new.  A disconnect must now be acknowledged and intermediate
requests thrown out until it is, which ensures that such synchronization
problems can't occur. This problem could affect ftp, pop3, imap and smtp
tests.

Fixes #12002
Closes #12049

2 files changed, 146 insertions, 26 deletions

diff --git a/tests/ftpserver.pl b/tests/ftpserver.pl
index dd8de2ec4..d0be36f15 100755
--- a/tests/ftpserver.pl
+++ b/tests/ftpserver.pl
@@ -670,6 +670,51 @@ sub protocolsetup {
     }
 }
 
+# Perform the disconnecgt handshake with sockfilt on the secondary connection
+# (the only connection we actively disconnect).
+# This involves waiting for the disconnect acknowledgmeent after the DISC
+# command, while throwing away anything else that might come in before
+# that.
+sub disc_handshake {
+    print DWRITE "DISC\n";
+    my $line;
+    my $nr;
+    while (5 == ($nr = sysread DREAD, $line, 5)) {
+        if($line eq "DATA\n") {
+            # Must read the data bytes to stay in sync
+            my $i;
+            sysread DREAD, $i, 5;
+
+            my $size = 0;
+            if($i =~ /^([0-9a-fA-F]{4})\n/) {
+                $size = hex($1);
+            }
+
+            read_datasockf(\$line, $size);
+
+            logmsg "> Throwing away $size bytes on closed connection\n";
+        }
+        elsif($line eq "DISC\n") {
+            logmsg "Fancy that; client wants to DISC, too\n";
+            printf DWRITE "ACKD\n";
+        }
+        elsif($line eq "ACKD\n") {
+            # Got the ack we were waiting for
+            last;
+        }
+        else {
+            logmsg "Ignoring: $line";
+            # sockfilt should not be sending us any other commands
+        }
+    }
+    if(!defined($nr)) {
+        logmsg "Error: pipe read error ($!) while waiting for ACKD";
+    }
+    elsif($nr <= 0) {
+        logmsg "Error: pipe EOF while waiting for ACKD";
+    }
+}
+
 sub close_dataconn {
     my ($closed)=@_; # non-zero if already disconnected
 
@@ -680,9 +725,7 @@ sub close_dataconn {
     if(!$closed) {
         if($datapid > 0) {
             logmsg "Server disconnects $datasockf_mode DATA connection\n";
-            print DWRITE "DISC\n";
-            my $i;
-            sysread DREAD, $i, 5;
+            disc_handshake();
             logmsg "Server disconnected $datasockf_mode DATA connection\n";
         }
         else {
@@ -940,6 +983,7 @@ sub DATA_smtp {
             elsif($line eq "DISC\n") {
                 # disconnect!
                 $disc=1;
+                printf SFWRITE "ACKD\n";
                 last;
             }
             else {
@@ -1286,6 +1330,7 @@ sub APPEND_imap {
             }
             elsif($line eq "DISC\n") {
                 logmsg "Unexpected disconnect!\n";
+                printf SFWRITE "ACKD\n";
                 last;
             }
             else {
@@ -2405,6 +2450,7 @@ sub STOR_ftp {
         elsif($line eq "DISC\n") {
             # disconnect!
             $disc=1;
+            printf DWRITE "ACKD\n";
             last;
         }
         else {
@@ -3156,6 +3202,7 @@ while(1) {
             logmsg "MAIN sockfilt said $i";
             if($i =~ /^DISC/) {
                 # disconnect
+                printf SFWRITE "ACKD\n";
                 last;
             }
             next;
diff --git a/tests/server/sockfilt.c b/tests/server/sockfilt.c
index 473b651f7..7e342e330 100644
--- a/tests/server/sockfilt.c
+++ b/tests/server/sockfilt.c
@@ -130,6 +130,10 @@
 #define DEFAULT_LOGFILE "log/sockfilt.log"
 #endif
 
+/* buffer is this excessively large only to be able to support things like
+  test 1003 which tests exceedingly large server response lines */
+#define BUFFER_SIZE 17010
+
 const char *serverlogfile = DEFAULT_LOGFILE;
 
 static bool verbose = FALSE;
@@ -386,6 +390,36 @@ static void lograw(unsigned char *buffer, ssize_t len)
     logmsg("'%s'", data);
 }
 
+/*
+ * handle the DATA command
+ * maxlen is the available space in buffer (input)
+ * *buffer_len is the amount of data in the buffer (output)
+ */
+static bool read_data_block(unsigned char *buffer, ssize_t maxlen,
+    ssize_t *buffer_len)
+{
+  if(!read_stdin(buffer, 5))
+    return FALSE;
+
+  buffer[5] = '\0';
+
+  *buffer_len = (ssize_t)strtol((char *)buffer, NULL, 16);
+  if(*buffer_len > maxlen) {
+    logmsg("ERROR: Buffer size (%zd bytes) too small for data size "
+           "(%zd bytes)", maxlen, *buffer_len);
+    return FALSE;
+  }
+  logmsg("> %zd bytes data, server => client", *buffer_len);
+
+  if(!read_stdin(buffer, *buffer_len))
+    return FALSE;
+
+  lograw(buffer, *buffer_len);
+
+  return TRUE;
+}
+
+
 #ifdef USE_WINSOCK
 /*
  * WinSock select() does not support standard file descriptors,
@@ -857,6 +891,63 @@ static int select_ws(int nfds, fd_set *readfds, fd_set *writefds,
 #define select(a,b,c,d,e) select_ws(a,b,c,d,e)
 #endif  /* USE_WINSOCK */
 
+
+/* Perform the disconnect handshake with sockfilt
+ * This involves waiting for the disconnect acknowledgmeent after the DISC
+ * command, while throwing away anything else that might come in before
+ * that.
+ */
+static bool disc_handshake(void)
+{
+  if(!write_stdout("DISC\n", 5))
+    return FALSE;
+
+  do {
+      unsigned char buffer[BUFFER_SIZE];
+      ssize_t buffer_len;
+      if(!read_stdin(buffer, 5))
+        return FALSE;
+      logmsg("Received %c%c%c%c (on stdin)",
+             buffer[0], buffer[1], buffer[2], buffer[3]);
+
+      if(!memcmp("ACKD", buffer, 4)) {
+        /* got the ack we were waiting for */
+        break;
+      }
+      else if(!memcmp("DISC", buffer, 4)) {
+        logmsg("Crikey! Client also wants to disconnect");
+        if(!write_stdout("ACKD\n", 5))
+          return FALSE;
+      }
+      else if(!memcmp("DATA", buffer, 4)) {
+        /* We must read more data to stay in sync */
+        if(!read_data_block(buffer, sizeof(buffer), &buffer_len))
+          return FALSE;
+
+        logmsg("Throwing again %zd data bytes", buffer_len);
+
+      }
+      else if(!memcmp("QUIT", buffer, 4)) {
+        /* just die */
+        logmsg("quits");
+        return FALSE;
+      }
+      else {
+        logmsg("Error: unexpected message; aborting");
+        /*
+         * The only other messages that could occur here are PING and PORT,
+         * and both of them occur at the start of a test when nothing should be
+         * trying to DISC. Therefore, we should not ever get here, but if we
+         * do, it's probably due to some kind of unclean shutdown situation so
+         * us shutting down is what we probably ought to be doing, anyway.
+         */
+        return FALSE;
+      }
+
+  } while(TRUE);
+  return TRUE;
+}
+
 /*
   sockfdp is a pointer to an established stream or CURL_SOCKET_BAD
 
@@ -876,9 +967,7 @@ static bool juggle(curl_socket_t *sockfdp,
   ssize_t rc;
   int error = 0;
 
- /* 'buffer' is this excessively large only to be able to support things like
-    test 1003 which tests exceedingly large server response lines */
-  unsigned char buffer[17010];
+  unsigned char buffer[BUFFER_SIZE];
   char data[16];
 
   if(got_exit_signal) {
@@ -1025,28 +1114,12 @@ static bool juggle(curl_socket_t *sockfdp,
     }
     else if(!memcmp("DATA", buffer, 4)) {
       /* data IN => data OUT */
-
-      if(!read_stdin(buffer, 5))
-        return FALSE;
-
-      buffer[5] = '\0';
-
-      buffer_len = (ssize_t)strtol((char *)buffer, NULL, 16);
-      if(buffer_len > (ssize_t)sizeof(buffer)) {
-        logmsg("ERROR: Buffer size (%zu bytes) too small for data size "
-               "(%zd bytes)", sizeof(buffer), buffer_len);
-        return FALSE;
-      }
-      logmsg("> %zd bytes data, server => client", buffer_len);
-
-      if(!read_stdin(buffer, buffer_len))
+      if(!read_data_block(buffer, sizeof(buffer), &buffer_len))
         return FALSE;
 
-      lograw(buffer, buffer_len);
-
       if(*mode == PASSIVE_LISTEN) {
         logmsg("*** We are disconnected!");
-        if(!write_stdout("DISC\n", 5))
+        if(!disc_handshake())
           return FALSE;
       }
       else {
@@ -1060,7 +1133,7 @@ static bool juggle(curl_socket_t *sockfdp,
     }
     else if(!memcmp("DISC", buffer, 4)) {
       /* disconnect! */
-      if(!write_stdout("DISC\n", 5))
+      if(!write_stdout("ACKD\n", 5))
         return FALSE;
       if(sockfd != CURL_SOCKET_BAD) {
         logmsg("====> Client forcibly disconnected");
@@ -1115,7 +1188,7 @@ static bool juggle(curl_socket_t *sockfdp,
 
     if(nread_socket <= 0) {
       logmsg("====> Client disconnect");
-      if(!write_stdout("DISC\n", 5))
+      if(!disc_handshake())
         return FALSE;
       sclose(sockfd);
       *sockfdp = CURL_SOCKET_BAD;