summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
Diffstat
-rw-r--r--lib/common/Test.cpp86
-rw-r--r--lib/common/Test.h2
-rw-r--r--test/backupstorepatch/testbackupstorepatch.cpp2
-rw-r--r--test/bbackupd/testbbackupd.cpp147
4 files changed, 162 insertions, 75 deletions
diff --git a/lib/common/Test.cpp b/lib/common/Test.cpp
index 04d778c1..e903f41e 100644
--- a/lib/common/Test.cpp
+++ b/lib/common/Test.cpp
@@ -229,7 +229,14 @@ int WaitForServerStartup(const char *pidFile, int pidIfKnown)
#endif
// time for it to start up
- ::fprintf(stdout, "Waiting for server to start: ");
+ if (Logging::GetGlobalLevel() >= Log::TRACE)
+ {
+ BOX_TRACE("Waiting for server to start");
+ }
+ else
+ {
+ ::fprintf(stdout, "Waiting for server to start: ");
+ }
for (int i = 0; i < 15; i++)
{
@@ -243,8 +250,12 @@ int WaitForServerStartup(const char *pidFile, int pidIfKnown)
break;
}
- ::fprintf(stdout, ".");
- ::fflush(stdout);
+ if (Logging::GetGlobalLevel() < Log::TRACE)
+ {
+ ::fprintf(stdout, ".");
+ ::fflush(stdout);
+ }
+
::sleep(1);
}
@@ -253,19 +264,42 @@ int WaitForServerStartup(const char *pidFile, int pidIfKnown)
if (pidIfKnown && !ServerIsAlive(pidIfKnown))
{
- ::fprintf(stdout, " server died!\n");
+ if (Logging::GetGlobalLevel() >= Log::TRACE)
+ {
+ BOX_ERROR("server died!");
+ }
+ else
+ {
+ ::fprintf(stdout, " server died!\n");
+ }
+
TEST_FAIL_WITH_MESSAGE("Server died!");
return -1;
}
if (!TestFileNotEmpty(pidFile))
{
- ::fprintf(stdout, " timed out!\n");
+ if (Logging::GetGlobalLevel() >= Log::TRACE)
+ {
+ BOX_ERROR("timed out!");
+ }
+ else
+ {
+ ::fprintf(stdout, " timed out!\n");
+ }
+
TEST_FAIL_WITH_MESSAGE("Server didn't save PID file");
return -1;
}
- ::fprintf(stdout, " done.\n");
+ if (Logging::GetGlobalLevel() >= Log::TRACE)
+ {
+ BOX_TRACE("Server started");
+ }
+ else
+ {
+ ::fprintf(stdout, " done.\n");
+ }
// wait a second for the pid to be written to the file
::sleep(1);
@@ -278,8 +312,9 @@ int WaitForServerStartup(const char *pidFile, int pidIfKnown)
if (pidIfKnown && pid != pidIfKnown)
{
- printf("Server wrote wrong pid to file (%s): expected %d "
- "but found %d\n", pidFile, pidIfKnown, pid);
+ BOX_ERROR("Server wrote wrong pid to file (" << pidFile <<
+ "): expected " << pidIfKnown << " but found " <<
+ pid);
TEST_FAIL_WITH_MESSAGE("Server wrote wrong pid to file");
return -1;
}
@@ -381,22 +416,43 @@ void terminate_bbackupd(int pid)
// Wait a given number of seconds for something to complete
-void wait_for_operation(int seconds)
+void wait_for_operation(int seconds, char* message)
{
- printf("Waiting: ");
- fflush(stdout);
+ if (Logging::GetGlobalLevel() >= Log::TRACE)
+ {
+ BOX_TRACE("Waiting " << seconds << " seconds for " << message);
+ }
+ else
+ {
+ printf("Waiting for %s: ", message);
+ fflush(stdout);
+ }
+
for(int l = 0; l < seconds; ++l)
{
sleep(1);
- printf(".");
+ if (Logging::GetGlobalLevel() < Log::TRACE)
+ {
+ printf(".");
+ fflush(stdout);
+ }
+ }
+
+ if (Logging::GetGlobalLevel() >= Log::TRACE)
+ {
+ BOX_TRACE("Finished waiting for " << message);
+ }
+ else
+ {
+ printf(" done.\n");
fflush(stdout);
}
- printf(" done.\n");
- fflush(stdout);
}
void safe_sleep(int seconds)
{
+ BOX_TRACE("sleeping for " << seconds << " seconds");
+
#ifdef WIN32
Sleep(seconds * 1000);
#else
@@ -404,7 +460,6 @@ void safe_sleep(int seconds)
memset(&ts, 0, sizeof(ts));
ts.tv_sec = seconds;
ts.tv_nsec = 0;
- BOX_TRACE("sleeping for " << seconds << " seconds");
while (nanosleep(&ts, &ts) == -1 && errno == EINTR)
{
BOX_TRACE("safe_sleep interrupted with " <<
@@ -415,4 +470,3 @@ void safe_sleep(int seconds)
#endif
}
-
diff --git a/lib/common/Test.h b/lib/common/Test.h
index 9cbfb706..362b43af 100644
--- a/lib/common/Test.h
+++ b/lib/common/Test.h
@@ -158,7 +158,7 @@ void sync_and_wait();
void terminate_bbackupd(int pid);
// Wait a given number of seconds for something to complete
-void wait_for_operation(int seconds);
+void wait_for_operation(int seconds, char* message);
void safe_sleep(int seconds);
#endif // TEST__H
diff --git a/test/backupstorepatch/testbackupstorepatch.cpp b/test/backupstorepatch/testbackupstorepatch.cpp
index 4fbf296a..23b01b15 100644
--- a/test/backupstorepatch/testbackupstorepatch.cpp
+++ b/test/backupstorepatch/testbackupstorepatch.cpp
@@ -578,7 +578,7 @@ int test(int argc, const char *argv[])
#ifdef WIN32
// Cannot signal bbstored to do housekeeping now,
// so just wait until we're sure it's done
- wait_for_operation(12);
+ wait_for_operation(12, "housekeeping to run");
#else
// Send the server a restart signal, so it does
// housekeeping immediately, and wait for it to happen
diff --git a/test/bbackupd/testbbackupd.cpp b/test/bbackupd/testbbackupd.cpp
index 9d82a11b..89c4d288 100644
--- a/test/bbackupd/testbbackupd.cpp
+++ b/test/bbackupd/testbbackupd.cpp
@@ -87,9 +87,9 @@
// two cycles and a bit
#define TIME_TO_WAIT_FOR_BACKUP_OPERATION 12
-void wait_for_backup_operation(int seconds = TIME_TO_WAIT_FOR_BACKUP_OPERATION)
+void wait_for_backup_operation(char* message)
{
- wait_for_operation(seconds);
+ wait_for_operation(TIME_TO_WAIT_FOR_BACKUP_OPERATION, message);
}
int bbstored_pid = 0;
@@ -889,7 +889,7 @@ int test_bbackupd()
TEST_THAT(close(fd) == 0);
int pid = start_internal_daemon();
- wait_for_backup_operation();
+ wait_for_backup_operation("internal daemon to run a sync");
TEST_THAT(stop_internal_daemon(pid));
// two-second delay on the first read() of f1
@@ -910,7 +910,8 @@ int test_bbackupd()
"Buffer write");
TEST_THAT(close(fd) == 0);
- wait_for_backup_operation();
+ wait_for_backup_operation("internal daemon to sync "
+ "spacetest/f1");
// can't test whether intercept was triggered, because
// it's in a different process.
// TEST_THAT(intercept_triggered());
@@ -985,7 +986,8 @@ int test_bbackupd()
"Buffer write");
TEST_THAT(close(fd) == 0);
- wait_for_backup_operation();
+ wait_for_backup_operation("internal daemon to sync "
+ "spacetest/f1 again");
// can't test whether intercept was triggered, because
// it's in a different process.
// TEST_THAT(intercept_triggered());
@@ -1050,7 +1052,8 @@ int test_bbackupd()
"Buffer write");
TEST_THAT(close(fd) == 0);
- wait_for_backup_operation();
+ wait_for_backup_operation("internal daemon to sync "
+ "spacetest/f1 again");
// can't test whether intercept was triggered, because
// it's in a different process.
// TEST_THAT(intercept_triggered());
@@ -1139,7 +1142,8 @@ int test_bbackupd()
"Buffer write");
TEST_THAT(close(fd) == 0);
- wait_for_backup_operation();
+ wait_for_backup_operation("internal dameon to scan "
+ "spacetest/d1");
// can't test whether intercept was triggered, because
// it's in a different process.
// TEST_THAT(intercept_triggered());
@@ -1284,10 +1288,10 @@ int test_bbackupd()
// housekeeping deleted them, the backup cannot complete
// if the limit is 20 blocks.
- BOX_TRACE("Waiting for bbackupd to notice that the "
+ BOX_TRACE("Waiting for sync for bbackupd to notice that the "
"store is full");
wait_for_sync_end();
- BOX_TRACE("done.");
+ BOX_TRACE("Sync finished.");
BOX_TRACE("Compare to check that there are differences");
int compareReturnValue = ::system(BBACKUPQUERY " "
@@ -1297,7 +1301,7 @@ int test_bbackupd()
TEST_RETURN(compareReturnValue,
BackupQueries::ReturnCode::Compare_Different);
TestRemoteProcessMemLeaks("bbackupquery.memleaks");
- BOX_TRACE("done.");
+ BOX_TRACE("Compare finished.");
// Check that the notify script was run
TEST_THAT(TestFileExists("testfiles/notifyran.store-full.1"));
@@ -1307,9 +1311,8 @@ int test_bbackupd()
// Kill the daemon
terminate_bbackupd(bbackupd_pid);
- BOX_TRACE("Wait for housekeeping to remove the deleted files");
- wait_for_backup_operation(5);
- BOX_TRACE("done.");
+ wait_for_operation(5, "housekeeping to remove the "
+ "deleted files");
// This removes f1 and d7, which were previously marked
// as deleted, so total usage drops by 4 blocks to 24.
@@ -1470,9 +1473,8 @@ int test_bbackupd()
return 1;
}
- BOX_TRACE("Wait for housekeeping to remove the deleted files");
- wait_for_backup_operation(5);
- BOX_TRACE("done.");
+ wait_for_operation(5, "housekeeping to remove the "
+ "deleted files");
BOX_TRACE("Check that the files were removed");
{
@@ -1606,9 +1608,7 @@ int test_bbackupd()
"| ( cd testfiles && tar xf - )") == 0);
#endif
- BOX_TRACE("Wait for bbackupd to upload more files");
- wait_for_backup_operation();
- BOX_TRACE("done.");
+ wait_for_backup_operation("bbackupd to upload more files");
// Check that the contents of the store are the same
// as the contents of the disc
@@ -1803,8 +1803,8 @@ int test_bbackupd()
// also test symlink-to-self loop does not break restore
TEST_THAT(symlink("self", SYM_DIR "/self") == 0);
- ::wait_for_operation(4);
- ::sync_and_wait();
+ wait_for_operation(4, "symlinks to be old enough");
+ sync_and_wait();
// Check that the backup was successful, i.e. no differences
int compareReturnValue = ::system(BBACKUPQUERY " "
@@ -2207,7 +2207,8 @@ int test_bbackupd()
fs.Close();
}
- wait_for_backup_operation();
+ wait_for_backup_operation("upload of file with unicode name");
+
// Compare to check that the file was uploaded
compareReturnValue = ::system(BBACKUPQUERY " -Wwarning "
"-c testfiles/bbackupd.conf \"compare -acQ\" quit");
@@ -2541,7 +2542,8 @@ int test_bbackupd()
}
// wait for backup daemon to do it's stuff, and compare again
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync the changes");
+
compareReturnValue = ::system(BBACKUPQUERY " -Wwarning "
"-c testfiles/bbackupd.conf "
"-l testfiles/query2.log "
@@ -2586,7 +2588,8 @@ int test_bbackupd()
TEST_THAT(close(fd1) == 0);
}
- wait_for_backup_operation(4);
+ wait_for_operation(4, "bbackupd to try to access the store");
+
// Check that an error was reported just once
TEST_THAT(TestFileExists("testfiles/notifyran.backup-error.1"));
TEST_THAT(!TestFileExists("testfiles/notifyran.backup-error.2"));
@@ -2644,9 +2647,11 @@ int test_bbackupd()
TEST_THAT(close(fd1) == 0);
}
- // bbackupd should pause for about 90 seconds from store_fixed_time,
- // so check that it hasn't run after 85 seconds from store_fixed_time
- wait_for_backup_operation(85 - time(NULL) + store_fixed_time);
+ // bbackupd should pause for about 90 seconds from
+ // store_fixed_time, so check that it hasn't run after
+ // 85 seconds after store_fixed_time
+ wait_for_operation(85 - time(NULL) + store_fixed_time,
+ "just before bbackupd recovers");
TEST_THAT(!TestFileExists("testfiles/"
"notifyran.backup-start.wait-snapshot.1"));
@@ -2660,7 +2665,7 @@ int test_bbackupd()
TestRemoteProcessMemLeaks("bbackupquery.memleaks");
// wait another 10 seconds, bbackup should have run
- wait_for_backup_operation(10);
+ wait_for_operation(10, "bbackupd to recover");
TEST_THAT(TestFileExists("testfiles/"
"notifyran.backup-start.wait-snapshot.1"));
@@ -2742,9 +2747,11 @@ int test_bbackupd()
TEST_THAT(close(fd1) == 0);
}
- // bbackupd should pause for about 90 seconds from store_fixed_time,
- // so check that it hasn't run after 85 seconds from store_fixed_time
- wait_for_backup_operation(85 - time(NULL) + store_fixed_time);
+ // bbackupd should pause for about 90 seconds from
+ // store_fixed_time, so check that it hasn't run after
+ // 85 seconds from store_fixed_time
+ wait_for_operation(85 - time(NULL) + store_fixed_time,
+ "just before bbackupd recovers");
TEST_THAT(!TestFileExists("testfiles/"
"notifyran.backup-start.wait-automatic.1"));
@@ -2758,7 +2765,7 @@ int test_bbackupd()
TestRemoteProcessMemLeaks("bbackupquery.memleaks");
// wait another 10 seconds, bbackup should have run
- wait_for_backup_operation(10);
+ wait_for_operation(10, "bbackupd to recover");
TEST_THAT(TestFileExists("testfiles/"
"notifyran.backup-start.wait-automatic.1"));
@@ -2801,7 +2808,7 @@ int test_bbackupd()
== 0);
#endif
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync the changes");
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3c.log "
@@ -2830,7 +2837,8 @@ int test_bbackupd()
"testfiles/TestDir1/x1/dir-to-file") == 0);
#endif
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync the changes");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3d.log "
@@ -2862,7 +2870,8 @@ int test_bbackupd()
== 0);
#endif
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync the changes");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3e.log "
@@ -2894,7 +2903,8 @@ int test_bbackupd()
"testfiles/TestDir1/x1/dir-to-file") == 0);
#endif
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync the changes");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3f.log "
@@ -2924,9 +2934,12 @@ int test_bbackupd()
TEST_THAT(close(fd2) == 0);
TEST_THAT(TestFileExists("testfiles/TestDir1/untracked-1"));
TEST_THAT(TestFileExists("testfiles/TestDir1/untracked-2"));
- wait_for_operation(5);
+
// back up both files
- wait_for_backup_operation();
+ wait_for_operation(5, "untracked files to be old enough");
+ wait_for_backup_operation("bbackupd to sync the "
+ "untracked files");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3g.log "
@@ -2944,7 +2957,10 @@ int test_bbackupd()
"testfiles/TestDir1/untracked-2") == 0);
TEST_THAT(!TestFileExists("testfiles/TestDir1/untracked-1"));
TEST_THAT( TestFileExists("testfiles/TestDir1/untracked-2"));
- wait_for_backup_operation();
+
+ wait_for_backup_operation("bbackupd to sync the untracked "
+ "files again");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3g.log "
@@ -2977,9 +2993,11 @@ int test_bbackupd()
TEST_THAT(close(fd2) == 0);
TEST_THAT(TestFileExists("testfiles/TestDir1/tracked-1"));
TEST_THAT(TestFileExists("testfiles/TestDir1/tracked-2"));
- wait_for_operation(5);
+
// back up both files
- wait_for_backup_operation();
+ wait_for_operation(5, "tracked files to be old enough");
+ wait_for_backup_operation("bbackupd to sync the tracked files");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3h.log "
@@ -2997,7 +3015,10 @@ int test_bbackupd()
"testfiles/TestDir1/tracked-2") == 0);
TEST_THAT(!TestFileExists("testfiles/TestDir1/tracked-1"));
TEST_THAT( TestFileExists("testfiles/TestDir1/tracked-2"));
- wait_for_backup_operation();
+
+ wait_for_backup_operation("bbackupd to sync the tracked "
+ "files again");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3i.log "
@@ -3018,7 +3039,8 @@ int test_bbackupd()
TEST_THAT(::rename("testfiles/TestDir1/df9834.dsf",
"testfiles/TestDir1/x1/dsfdsfs98.fd") == 0);
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3j.log "
@@ -3056,7 +3078,8 @@ int test_bbackupd()
#endif
// Wait and test
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync old files");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3k.log "
@@ -3239,7 +3262,8 @@ int test_bbackupd()
}
// Wait and test...
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to try to sync "
+ "unreadable file");
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3o.log "
@@ -3343,7 +3367,9 @@ int test_bbackupd()
::chmod("testfiles/TestDir1/df9834.dsf", 0423);
// Wait and test
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync deletion "
+ "of directory");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query4.log "
@@ -3544,7 +3570,8 @@ int test_bbackupd()
#endif
// Wait and test
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackupd to sync new files");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query5.log "
@@ -3562,7 +3589,9 @@ int test_bbackupd()
printf("\n==== Rename directory\n");
TEST_THAT(rename("testfiles/TestDir1/sub23/dhsfdss",
"testfiles/TestDir1/renamed-dir") == 0);
- wait_for_backup_operation();
+
+ wait_for_backup_operation("bbackupd to sync renamed directory");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query6.log "
@@ -3588,7 +3617,9 @@ int test_bbackupd()
"testfiles/TestDir1/df324-ren") == 0);
TEST_THAT(rename("testfiles/TestDir1/sub23/find2perl",
"testfiles/TestDir1/find2perl-ren") == 0);
- wait_for_backup_operation();
+
+ wait_for_backup_operation("bbackupd to sync renamed files");
+
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query6.log "
@@ -3631,7 +3662,7 @@ int test_bbackupd()
}
// Wait and test
- wait_for_backup_operation();
+ wait_for_backup_operation("bbackup to sync future file");
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query3e.log "
@@ -3698,9 +3729,11 @@ int test_bbackupd()
::fclose(f);
}
- // Wait and test that there *are* differences
- wait_for_backup_operation((TIME_TO_WAIT_FOR_BACKUP_OPERATION *
- 3) / 2); // little bit longer than usual
+ // Wait a little bit longer than usual
+ wait_for_operation((TIME_TO_WAIT_FOR_BACKUP_OPERATION *
+ 3) / 2, "bbackupd to detect changed store marker");
+
+ // Test that there *are* differences
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query6.log "
@@ -3714,9 +3747,8 @@ int test_bbackupd()
if (!ServerIsAlive(bbackupd_pid)) return 1;
if (!ServerIsAlive(bbstored_pid)) return 1;
- printf("\n==== Waiting for bbackupd to recover\n");
// 100 seconds - (12*3/2)
- wait_for_operation(82);
+ wait_for_operation(82, "bbackupd to recover");
TEST_THAT(ServerIsAlive(bbackupd_pid));
TEST_THAT(ServerIsAlive(bbstored_pid));
@@ -3947,8 +3979,9 @@ int test_bbackupd()
if(bbackupd_pid != -1 && bbackupd_pid != 0)
{
// Wait and compare (a little bit longer than usual)
- wait_for_backup_operation(
- (TIME_TO_WAIT_FOR_BACKUP_OPERATION*3) / 2);
+ wait_for_operation(
+ (TIME_TO_WAIT_FOR_BACKUP_OPERATION*3) / 2,
+ "bbackupd to sync everything");
compareReturnValue = ::system(BBACKUPQUERY " "
"-c testfiles/bbackupd.conf "
"-l testfiles/query4a.log "
generated by cgit v1.2.3 (git 2.25.1) at 2024-04-19 18:34:24 +0000