From 96edebf4d9ec656ec6ed83dca3bbc3947033c71d Mon Sep 17 00:00:00 2001 From: Yang Tse Date: Wed, 23 Apr 2008 23:55:34 +0000 Subject: improve synchronization between test harness runtests.pl script and test harness servers to minimize risk of false test failures. http://curl.haxx.se/mail/lib-2008-04/0392.html --- tests/ftp.pm | 23 ++++++++++++++++++++++- tests/ftpserver.pl | 15 ++++++++++++++- tests/runtests.pl | 29 +++++++++++++++++++++++++++++ tests/server/sws.c | 6 ++++++ tests/server/tftpd.c | 24 +++++++++++++++++++----- tests/server/util.c | 36 ++++++++++++++++++++++++++++++++++++ tests/server/util.h | 6 ++++++ 7 files changed, 132 insertions(+), 7 deletions(-) diff --git a/tests/ftp.pm b/tests/ftp.pm index b3cc14abb..421fee1a6 100644 --- a/tests/ftp.pm +++ b/tests/ftp.pm @@ -5,7 +5,7 @@ # | (__| |_| | _ <| |___ # \___|\___/|_| \_\_____| # -# Copyright (C) 1998 - 2006, Daniel Stenberg, , et al. +# Copyright (C) 1998 - 2008, Daniel Stenberg, , et al. # # This software is licensed as described in the file COPYING, which # you should have received as part of this distribution. The terms @@ -84,4 +84,25 @@ sub ftpkillslaves { } } + +sub set_advisor_read_lock { + my ($filename) = @_; + + if(open(FILEH, ">$filename")) { + close(FILEH); + return; + } + printf "Error creating lock file $filename error: $!"; +} + + +sub clear_advisor_read_lock { + my ($filename) = @_; + + if(-f $filename) { + unlink($filename); + } +} + + 1; diff --git a/tests/ftpserver.pl b/tests/ftpserver.pl index 02a048f13..ce82d642b 100644 --- a/tests/ftpserver.pl +++ b/tests/ftpserver.pl @@ -6,7 +6,7 @@ # | (__| |_| | _ <| |___ # \___|\___/|_| \_\_____| # -# Copyright (C) 1998 - 2007, Daniel Stenberg, , et al. +# Copyright (C) 1998 - 2008, Daniel Stenberg, , et al. # # This software is licensed as described in the file COPYING, which # you should have received as part of this distribution. The terms @@ -85,6 +85,8 @@ my $port = 8921; # just a default my $listenaddr = "127.0.0.1"; # just a default my $pidfile = ".ftpd.pid"; # a default, use --pidfile +my $SERVERLOGS_LOCK="log/serverlogs.lock"; # server logs advisor read lock + do { if($ARGV[0] eq "-v") { $verbose=1; @@ -121,6 +123,7 @@ sub catch_zap { my $signame = shift; print STDERR "ftpserver.pl received SIG$signame, exiting\n"; ftpkillslaves(1); + clear_advisor_read_lock($SERVERLOGS_LOCK); die "Somebody sent me a SIG$signame"; } $SIG{INT} = \&catch_zap; @@ -146,6 +149,7 @@ sub sysread_or_die { logmsg "Error: ftp$ftpdnum$ext sysread error: $!\n"; kill(9, $sfpid); waitpid($sfpid, 0); + clear_advisor_read_lock($SERVERLOGS_LOCK); die "Died in sysread_or_die() at $fcaller " . "line $lcaller. ftp$ftpdnum$ext sysread error: $!\n"; } @@ -155,6 +159,7 @@ sub sysread_or_die { logmsg "Error: ftp$ftpdnum$ext read zero\n"; kill(9, $sfpid); waitpid($sfpid, 0); + clear_advisor_read_lock($SERVERLOGS_LOCK); die "Died in sysread_or_die() at $fcaller " . "line $lcaller. ftp$ftpdnum$ext read zero\n"; } @@ -176,6 +181,7 @@ sub startsf { logmsg "Failed sockfilt command: $cmd\n"; kill(9, $sfpid); waitpid($sfpid, 0); + clear_advisor_read_lock($SERVERLOGS_LOCK); die "Failed to start sockfilt!"; } } @@ -784,6 +790,8 @@ while(1) { } logmsg "====> Client connect\n"; + set_advisor_read_lock($SERVERLOGS_LOCK); + # flush data: $| = 1; @@ -888,8 +896,13 @@ while(1) { } # while(1) logmsg "====> Client disconnected\n"; + + clear_advisor_read_lock($SERVERLOGS_LOCK); } print SFWRITE "QUIT\n"; waitpid $sfpid, 0; + +clear_advisor_read_lock($SERVERLOGS_LOCK); + exit; diff --git a/tests/runtests.pl b/tests/runtests.pl index 606c72dd5..857a28af2 100755 --- a/tests/runtests.pl +++ b/tests/runtests.pl @@ -120,6 +120,7 @@ my $SERVERIN="$LOGDIR/server.input"; # what curl sent the server my $SERVER2IN="$LOGDIR/server2.input"; # what curl sent the second server my $CURLLOG="$LOGDIR/curl.log"; # all command lines run my $FTPDCMD="$LOGDIR/ftpserver.cmd"; # copy ftp server instructions here +my $SERVERLOGS_LOCK="$LOGDIR/serverlogs.lock"; # server logs advisor read lock # Normally, all test cases should be run, but at times it is handy to # simply run a particular one: @@ -202,6 +203,10 @@ my $sshdvernum; # for socks server, ssh daemon version number my $sshdverstr; # for socks server, ssh daemon version string my $sshderror; # for socks server, ssh daemon version error +my $EXP_big_delay = 300; +my $EXP_max_delay = 0; +my $EXP_max_testn = 0; + ####################################################################### # variables the command line options may set # @@ -2096,6 +2101,27 @@ sub singletest { } } + # If a server logs advisor read lock file exists, it is an indication + # that the server has not yet finished writing out all its log files, + # including server request log files used for protocol verification. + # So, if the lock file exists the script waits here a certain amount + # of time until the server removes it, or the given time expires. + # Test harness ssh server does not have this synchronization mechanism, + # this implies that some ssh server based tests might need a small delay + # in the postcheck section to avoid false test failures. + + my $lockretry = ($testnum == 190) ? 10 : $EXP_big_delay ; + while((-f $SERVERLOGS_LOCK) && $lockretry--) { + sleep(1); + } + + if($testnum != 190) { + if($EXP_big_delay - $lockretry > $EXP_max_delay) { + $EXP_max_delay = $EXP_big_delay - $lockretry; + $EXP_max_testn = $testnum; + } + } + # run the postcheck command my @postcheck= getpart("client", "postcheck"); $cmd = $postcheck[0]; @@ -3120,6 +3146,9 @@ if($skipped) { logmsg ")\n"; } } + +logmsg "EXPERIMENTAL: lock max delay ($EXP_max_delay seconds) for test # $EXP_max_testn \n"; + if($total && ($ok != $total)) { exit 1; } diff --git a/tests/server/sws.c b/tests/server/sws.c index fc4123538..023fe270e 100644 --- a/tests/server/sws.c +++ b/tests/server/sws.c @@ -988,6 +988,8 @@ int main(int argc, char *argv[]) break; } + set_advisor_read_lock(SERVERLOGS_LOCK); + #ifdef CURL_SWS_FORK_ENABLED if(use_fork) { /* The fork enabled version just forks off the child and don't care @@ -1063,6 +1065,8 @@ int main(int argc, char *argv[]) logmsg("====> Client disconnect"); sclose(msgsock); + clear_advisor_read_lock(SERVERLOGS_LOCK); + if (req.testno == DOCNUMBER_QUIT) break; #ifdef CURL_SWS_FORK_ENABLED @@ -1072,6 +1076,8 @@ int main(int argc, char *argv[]) sclose(sock); + clear_advisor_read_lock(SERVERLOGS_LOCK); + return 0; } diff --git a/tests/server/tftpd.c b/tests/server/tftpd.c index a98791de6..bafe47cf6 100644 --- a/tests/server/tftpd.c +++ b/tests/server/tftpd.c @@ -415,6 +415,7 @@ int main(int argc, char **argv) int flag; int rc; struct testcase test; + int result = 0; while(argc>arg) { if(!strcmp("--version", argv[arg])) { @@ -518,20 +519,25 @@ int main(int argc, char **argv) (struct sockaddr *)&from, &fromlen); if (n < 0) { logmsg("recvfrom:\n"); - return 3; + result = 3; + break; } + set_advisor_read_lock(SERVERLOGS_LOCK); + from.sin_family = AF_INET; peer = socket(AF_INET, SOCK_DGRAM, 0); if (peer < 0) { logmsg("socket:\n"); - return 2; + result = 2; + break; } if (connect(peer, (struct sockaddr *)&from, sizeof(from)) < 0) { logmsg("connect: fail\n"); - return 1; + result = 1; + break; } maxtimeout = 5*TIMEOUT; @@ -545,8 +551,14 @@ int main(int argc, char **argv) free(test.buffer); } sclose(peer); + + clear_advisor_read_lock(SERVERLOGS_LOCK); + } while(1); - return 0; + + clear_advisor_read_lock(SERVERLOGS_LOCK); + + return result; } struct formats { @@ -734,8 +746,10 @@ static void timer(int signum) logmsg("alarm!"); timeout += rexmtval; - if (timeout >= maxtimeout) + if(timeout >= maxtimeout) { + clear_advisor_read_lock(SERVERLOGS_LOCK); exit(1); + } #ifdef HAVE_SIGSETJMP siglongjmp(timeoutbuf, 1); #endif diff --git a/tests/server/util.c b/tests/server/util.c index 8a2fa8814..64684545e 100644 --- a/tests/server/util.c +++ b/tests/server/util.c @@ -234,3 +234,39 @@ int write_pidfile(const char *filename) logmsg("Wrote pid %ld to %s", pid, filename); return 1; /* success */ } + +void set_advisor_read_lock(const char *filename) +{ + FILE *lockfile; + int error; + int res; + + do { + lockfile = fopen(filename, "wb"); + } while((lockfile == NULL) && ((error = ERRNO) == EINTR)); + if(lockfile == NULL) { + logmsg("Error creating lock file %s error: %d %s", + filename, error, strerror(error)); + return; + } + + do { + res = fclose(lockfile); + } while(res && ((error = ERRNO) == EINTR)); + if(res) + logmsg("Error closing lock file %s error: %d %s", + filename, error, strerror(error)); +} + +void clear_advisor_read_lock(const char *filename) +{ + int error; + int res; + + do { + res = unlink(filename); + } while(res && ((error = ERRNO) == EINTR)); + if(res) + logmsg("Error removing lock file %s error: %d %s", + filename, error, strerror(error)); +} diff --git a/tests/server/util.h b/tests/server/util.h index 4f07fcb05..9b9dd598b 100644 --- a/tests/server/util.h +++ b/tests/server/util.h @@ -27,6 +27,8 @@ void logmsg(const char *msg, ...); #define TEST_DATA_PATH "%s/data/test%ld" +#define SERVERLOGS_LOCK "log/serverlogs.lock" + /* global variable, where to find the 'data' dir */ extern const char *path; @@ -53,4 +55,8 @@ int wait_ms(int timeout_ms); int write_pidfile(const char *filename); +void set_advisor_read_lock(const char *filename); + +void clear_advisor_read_lock(const char *filename); + #endif /* __SERVER_UTIL_H */ -- cgit v1.2.1