From 7d62f0d9b8ac9f2b58682891ecd6e2daab2114aa Mon Sep 17 00:00:00 2001 From: Dan Fandrich Date: Mon, 5 Jun 2023 14:50:15 -0700 Subject: [PATCH] runtests; give each server a unique log lock file Logs are written by several servers and all of them must be finished writing before the test results can be determined. This means each server must have its own lock file rather than sharing a single one, which is how it was done up to now. Previously, the first server to complete a test would clear the lock before the other server was done, which caused flaky tests. Lock files are now all found in their own directory, so counting locks equals counting the files in that directory. The result is that the proxy logs are now reliably written which actually changes the expected output for two tests. Fixes #11231 Closes #11259 --- tests/data/test1509 | 1 + tests/data/test503 | 1 + tests/ftpserver.pl | 7 +++++-- tests/globalconfig.pm | 2 ++ tests/runner.pm | 22 +++++++++++++++++++--- tests/runtests.pl | 17 ++++++++++++----- tests/server/mqttd.c | 4 ++-- tests/server/rtspd.c | 4 ++-- tests/server/sws.c | 9 ++++++--- tests/server/tftpd.c | 4 ++-- tests/server/util.h | 3 +-- 11 files changed, 53 insertions(+), 21 deletions(-) diff --git a/tests/data/test1509 b/tests/data/test1509 index 5bf55cb63..7c427bf7f 100644 --- a/tests/data/test1509 +++ b/tests/data/test1509 @@ -78,6 +78,7 @@ CONNECT the.old.moo.%TESTNUMBER:%HTTPPORT HTTP/1.1 Host: the.old.moo.%TESTNUMBER:%HTTPPORT Proxy-Connection: Keep-Alive +[DISCONNECT] GET /%TESTNUMBER HTTP/1.1 diff --git a/tests/data/test503 b/tests/data/test503 index 11a58f4be..d8e04aa65 100644 --- a/tests/data/test503 +++ b/tests/data/test503 @@ -76,6 +76,7 @@ Host: machine.%TESTNUMBER:%HTTPPORT Proxy-Authorization: Basic dGVzdDppbmc= Proxy-Connection: Keep-Alive +[DISCONNECT] GET /%TESTNUMBER HTTP/1.1 diff --git a/tests/ftpserver.pl b/tests/ftpserver.pl index 6459691c9..26f79591e 100755 --- a/tests/ftpserver.pl +++ b/tests/ftpserver.pl @@ -78,6 +78,10 @@ use pathhelp qw( exe_ext ); +use globalconfig qw( + $LOCKDIR + ); + #********************************************************************** # global vars... # @@ -114,7 +118,6 @@ my $datasockf_logfile; # log file for secondary connection sockfilt process #********************************************************************** # global vars used for server logs advisor read lock handling # -my $SERVERLOGS_LOCK = "serverlogs.lock"; my $serverlogs_lockfile; my $serverlogslocked = 0; @@ -3040,7 +3043,6 @@ if(!$logfile) { $mainsockf_pidfile = mainsockf_pidfilename($piddir, $proto, $ipvnum, $idnum); $mainsockf_logfile = mainsockf_logfilename($logdir, $proto, $ipvnum, $idnum); -$serverlogs_lockfile = "$logdir/$SERVERLOGS_LOCK"; if($proto eq 'ftp') { $datasockf_pidfile = datasockf_pidfilename($piddir, $proto, $ipvnum, $idnum); @@ -3049,6 +3051,7 @@ if($proto eq 'ftp') { } $srvrname = servername_str($proto, $ipvnum, $idnum); +$serverlogs_lockfile = "$logdir/$LOCKDIR/${srvrname}.lock"; $idstr = "$idnum" if($idnum > 1); diff --git a/tests/globalconfig.pm b/tests/globalconfig.pm index af52760ff..7280b9381 100644 --- a/tests/globalconfig.pm +++ b/tests/globalconfig.pm @@ -42,6 +42,7 @@ BEGIN { $has_shared $LIBDIR $listonly + $LOCKDIR $LOGDIR $memanalyze $MEMDUMP @@ -100,6 +101,7 @@ our $memanalyze="$perl $srcdir/memanalyze.pl"; our $valgrind; # path to valgrind, or empty if disabled # paths in $LOGDIR +our $LOCKDIR = "lock"; # root of the server directory with lock files our $PIDDIR = "server"; # root of the server directory with PID files our $SERVERIN="server.input"; # what curl sent the server our $PROXYIN="proxy.input"; # what curl sent the proxy diff --git a/tests/runner.pm b/tests/runner.pm index e4cf75ff3..a017d8c08 100644 --- a/tests/runner.pm +++ b/tests/runner.pm @@ -125,7 +125,6 @@ our $tortalloc; my %oldenv; # environment variables before test is started my $UNITDIR="./unit"; my $CURLLOG="$LOGDIR/commands.log"; # all command lines run -my $SERVERLOGS_LOCK="$LOGDIR/serverlogs.lock"; # server logs advisor read lock my $defserverlogslocktimeout = 2; # timeout to await server logs lock removal my $defpostcommanddelay = 0; # delay between command and postcheck sections my $multiprocess; # nonzero with a separate test runner process @@ -202,6 +201,7 @@ sub runner_init { # Set this directory as ours $LOGDIR = $logdir; mkdir("$LOGDIR/$PIDDIR", 0777); + mkdir("$LOGDIR/$LOCKDIR", 0777); # Initialize various server variables initserverconfig(); @@ -349,6 +349,20 @@ sub readtestkeywords { } +####################################################################### +# Return a list of log locks that still exist +# +sub logslocked { + opendir(my $lockdir, "$LOGDIR/$LOCKDIR"); + my @locks; + foreach (readdir $lockdir) { + if(/^(.*)\.lock$/) { + push @locks, $1; + } + } + return @locks; +} + ####################################################################### # Memory allocation test and failure torture testing. # @@ -966,13 +980,15 @@ sub singletest_clean { } if($serverlogslocktimeout) { my $lockretry = $serverlogslocktimeout * 20; - while((-f $SERVERLOGS_LOCK) && $lockretry--) { + my @locks; + while((@locks = logslocked()) && $lockretry--) { portable_sleep(0.05); } if(($lockretry < 0) && ($serverlogslocktimeout >= $defserverlogslocktimeout)) { logmsg "Warning: server logs lock timeout ", - "($serverlogslocktimeout seconds) expired\n"; + "($serverlogslocktimeout seconds) expired (locks: " . + join(", ", @locks) . ")\n"; } } diff --git a/tests/runtests.pl b/tests/runtests.pl index e7f927f9a..b1d894d72 100755 --- a/tests/runtests.pl +++ b/tests/runtests.pl @@ -330,8 +330,10 @@ sub cleardir { opendir(my $dh, $dir) || return 0; # can't open dir while($file = readdir($dh)) { - # Don't clear the $PIDDIR since those need to live beyond one test - if(($file !~ /^(\.|\.\.)\z/) && "$file" ne $PIDDIR) { + # Don't clear the $PIDDIR or $LOCKDIR since those need to live beyond + # one test + if(($file !~ /^(\.|\.\.)\z/) && + "$file" ne $PIDDIR && "$file" ne $LOCKDIR) { if(-d "$dir/$file") { if(!cleardir("$dir/$file")) { $done = 0; @@ -1716,9 +1718,12 @@ sub singletest { if($singletest_state{$runnerid} == ST_INIT) { my $logdir = getrunnerlogdir($runnerid); - # first, remove all lingering log files - if(!cleardir($logdir) && $clearlocks) { - runnerac_clearlocks($runnerid, $logdir); + # first, remove all lingering log & lock files + if((!cleardir($logdir) || !cleardir("$logdir/$LOCKDIR")) + && $clearlocks) { + # On Windows, lock files can't be deleted when the process still + # has them open, so kill those processes first + runnerac_clearlocks($runnerid, "$logdir/$LOCKDIR"); $singletest_state{$runnerid} = ST_CLEARLOCKS; } else { $singletest_state{$runnerid} = ST_INITED; @@ -2432,6 +2437,7 @@ if ($gdbthis) { # Maybe create & use & delete a temporary directory in that function cleardir($LOGDIR); mkdir($LOGDIR, 0777); +mkdir("$LOGDIR/$LOCKDIR", 0777); ####################################################################### # initialize some variables @@ -2777,6 +2783,7 @@ while () { if($ridready) { # This runner is ready to be serviced my $testnum = $runnersrunning{$ridready}; + defined $testnum || die 'Internal error: test for runner unknown'; delete $runnersrunning{$ridready}; my ($error, $again) = singletest($ridready, $testnum, $countforrunner{$ridready}, $totaltests); if($again) { diff --git a/tests/server/mqttd.c b/tests/server/mqttd.c index ba1ed198a..85b10d1f1 100644 --- a/tests/server/mqttd.c +++ b/tests/server/mqttd.c @@ -1016,8 +1016,8 @@ int main(int argc, char *argv[]) } } - msnprintf(loglockfile, sizeof(loglockfile), "%s/%s", - logdir, SERVERLOGS_LOCK); + msnprintf(loglockfile, sizeof(loglockfile), "%s/%s/mqtt-%s.lock", + logdir, SERVERLOGS_LOCKDIR, ipv_inuse); #ifdef WIN32 win32_init(); diff --git a/tests/server/rtspd.c b/tests/server/rtspd.c index 8cbbca7ee..b352507da 100644 --- a/tests/server/rtspd.c +++ b/tests/server/rtspd.c @@ -1149,8 +1149,8 @@ int main(int argc, char *argv[]) } } - msnprintf(loglockfile, sizeof(loglockfile), "%s/%s", - logdir, SERVERLOGS_LOCK); + msnprintf(loglockfile, sizeof(loglockfile), "%s/%s/rtsp-%s.lock", + logdir, SERVERLOGS_LOCKDIR, ipv_inuse); #ifdef WIN32 win32_init(); diff --git a/tests/server/sws.c b/tests/server/sws.c index f74d32cbf..e88a746b3 100644 --- a/tests/server/sws.c +++ b/tests/server/sws.c @@ -1964,6 +1964,7 @@ int main(int argc, char *argv[]) char port_str[11]; const char *location_str = port_str; int keepalive_secs = 5; + const char *protocol_type = "HTTP"; /* a default CONNECT port is basically pointless but still ... */ size_t socket_idx; @@ -2008,6 +2009,7 @@ int main(int argc, char *argv[]) else if(!strcmp("--gopher", argv[arg])) { arg++; use_gopher = TRUE; + protocol_type = "GOPHER"; end_of_headers = "\r\n"; /* gopher style is much simpler */ } else if(!strcmp("--ipv4", argv[arg])) { @@ -2109,8 +2111,9 @@ int main(int argc, char *argv[]) } } - msnprintf(loglockfile, sizeof(loglockfile), "%s/%s", - logdir, SERVERLOGS_LOCK); + msnprintf(loglockfile, sizeof(loglockfile), "%s/%s/sws-%s%s-%s.lock", + logdir, SERVERLOGS_LOCKDIR, protocol_type, + is_proxy ? "-proxy" : "", socket_type); #ifdef WIN32 win32_init(); @@ -2227,7 +2230,7 @@ int main(int argc, char *argv[]) msnprintf(port_str, sizeof(port_str), "port %hu", port); logmsg("Running %s %s version on %s", - use_gopher?"GOPHER":"HTTP", socket_type, location_str); + protocol_type, socket_type, location_str); /* start accepting connections */ rc = listen(sock, 5); diff --git a/tests/server/tftpd.c b/tests/server/tftpd.c index 3601d9e9d..e9bdaf9c6 100644 --- a/tests/server/tftpd.c +++ b/tests/server/tftpd.c @@ -647,8 +647,8 @@ int main(int argc, char **argv) } } - msnprintf(loglockfile, sizeof(loglockfile), "%s/%s", - logdir, SERVERLOGS_LOCK); + msnprintf(loglockfile, sizeof(loglockfile), "%s/%s/tftp-%s.lock", + logdir, SERVERLOGS_LOCKDIR, ipv_inuse); #ifdef WIN32 win32_init(); diff --git a/tests/server/util.h b/tests/server/util.h index 32db08031..842e1aad7 100644 --- a/tests/server/util.h +++ b/tests/server/util.h @@ -31,8 +31,7 @@ long timediff(struct timeval newer, struct timeval older); #define TEST_DATA_PATH "%s/data/test%ld" #define ALTTEST_DATA_PATH "%s/test%ld" - -#define SERVERLOGS_LOCK "serverlogs.lock" +#define SERVERLOGS_LOCKDIR "lock" /* within logdir */ /* global variable, where to find the 'data' dir */ extern const char *path;