From 9e95dd4821cbda62f6de879ec9d3ebe6b093483f Mon Sep 17 00:00:00 2001 From: Daniel Stenberg Date: Wed, 4 May 2005 21:49:30 +0000 Subject: improved logging (all FTP protocol data, both ways) to possibly help us realize why sometimes the control connection dies after a RETR has been sent --- tests/ftpserver.pl | 25 +++++++++++-------------- 1 file changed, 11 insertions(+), 14 deletions(-) diff --git a/tests/ftpserver.pl b/tests/ftpserver.pl index 6124dd78f..2c969e101 100644 --- a/tests/ftpserver.pl +++ b/tests/ftpserver.pl @@ -140,7 +140,7 @@ unlink($pidfile); startsf(); -logmsg sprintf("FTP server started on port IPv%d/$port\n", $ipv6?6:4); +logmsg sprintf("FTP server listens on port IPv%d/$port\n", $ipv6?6:4); open(PID, ">$pidfile"); print PID $$."\n"; close(PID); @@ -173,7 +173,11 @@ sub sendcontrol { select(undef, undef, undef, 0.01); } } - + my $log; + foreach $log (@_) { + $log =~ s/[\r\n]//g; + logmsg "> \"$log\"\n"; + } } # Send data to the client on the data stream @@ -263,7 +267,7 @@ sub close_dataconn { my ($closed)=@_; # non-zero if already disconnected if(!$closed) { - logmsg "time to kill the data connection\n"; + logmsg "* disconnect data connection\n"; print DWRITE "DISC\n"; my $i; sysread DREAD, $i, 5; @@ -271,14 +275,12 @@ sub close_dataconn { else { logmsg "data connection already disconnected\n"; } + logmsg "=====> Closed data connection\n"; - logmsg "time to quit sockfilt for data\n"; + logmsg "* quit sockfilt for data (pid $slavepid)\n"; print DWRITE "QUIT\n"; - logmsg "told data slave to die (pid $slavepid)\n"; waitpid $slavepid, 0; $slavepid=0; - logmsg "=====> Closed data connection\n"; - } my $rest=0; @@ -308,7 +310,6 @@ my @ftpdir=("total 20\r\n", senddata $_; } close_dataconn(0); - logmsg "done passing data\n"; sendcontrol "226 ASCII transfer complete\r\n"; return 0; } @@ -555,7 +556,7 @@ sub PASV_command { return 0; } - logmsg "sockfilt for data on pid $slavepid\n"; + logmsg "Run sockfilt for data on pid $slavepid\n"; # Find out what port we listen on my $i; @@ -582,17 +583,14 @@ sub PASV_command { if($cmd ne "EPSV") { # PASV reply - logmsg "replying to a $cmd command, waiting on port $pasvport\n"; sendcontrol sprintf("227 Entering Passive Mode (127,0,0,1,%d,%d)\n", ($pasvport/256), ($pasvport%256)); } else { # EPSV reply - logmsg "replying to a $cmd command, waiting on port $pasvport\n"; sendcontrol sprintf("229 Entering Passive Mode (|||%d|)\n", $pasvport); } - eval { local $SIG{ALRM} = sub { die "alarm\n" }; @@ -831,7 +829,7 @@ while(1) { my $FTPARG=$2; my $full=$_; - logmsg "Received \"$full\"\n"; + logmsg "< \"$full\"\n"; if($verbose) { print STDERR "IN: $full\n"; @@ -872,7 +870,6 @@ while(1) { # used enough number of times, now blank the customreply $customreply{$FTPCMD}=""; } - logmsg "$FTPCMD made to send '$text'\n"; } if($text) { sendcontrol "$text\r\n"; -- cgit v1.2.3