Increase default verbosity in some timing tests

infrastructure/buildenv-testmain-template.cpp

@@ -71,6 +71,7 @@ std::string bbackupd_args = QUIET_PROCESS,
 	bbstored_args = QUIET_PROCESS,
 	bbackupquery_args,
 	test_args;
+bool bbackupd_args_overridden = false, bbstored_args_overridden = false;
 
 bool filedes_initialised = false;
 
@@ -285,6 +286,7 @@ int main(int argc, char * const * argv)
 					bbackupd_args += " ";
 				}
 				bbackupd_args += optarg;
+				bbackupd_args_overridden = true;
 			}
 			break;
 
@@ -314,6 +316,7 @@ int main(int argc, char * const * argv)
 			{
 				bbstored_args += " ";
 				bbstored_args += optarg;
+				bbstored_args_overridden = true;
 			}
 			break;
 

lib/backupstore/StoreTestUtils.cpp

@@ -266,11 +266,11 @@ bool check_reference_counts()
 	return counts_ok;
 }
 
-bool StartServer()
+bool StartServer(const std::string& daemon_args)
 {
-	bbstored_pid = StartDaemon(bbstored_pid,
-		BBSTORED " " + bbstored_args + " testfiles/bbstored.conf",
-		"testfiles/bbstored.pid");
+	const std::string& daemon_args_final(daemon_args.size() ? daemon_args : bbstored_args);
+	bbstored_pid = StartDaemon(bbstored_pid, BBSTORED " " + daemon_args_final +
+		" testfiles/bbstored.conf", "testfiles/bbstored.pid");
 	return bbstored_pid != 0;
 }
 
@@ -282,11 +282,11 @@ bool StopServer(bool wait_for_process)
 	return result;
 }
 
-bool StartClient(const std::string& bbackupd_conf_file)
+bool StartClient(const std::string& bbackupd_conf_file, const std::string& daemon_args)
 {
-	bbackupd_pid = StartDaemon(bbackupd_pid,
-		BBACKUPD " " + bbackupd_args + " " + bbackupd_conf_file,
-		"testfiles/bbackupd.pid");
+	const std::string& daemon_args_final(daemon_args.size() ? daemon_args : bbackupd_args);
+	bbackupd_pid = StartDaemon(bbackupd_pid, BBACKUPD " " + daemon_args_final +
+		" -c " + bbackupd_conf_file, "testfiles/bbackupd.pid");
 	return bbackupd_pid != 0;
 }
 

lib/backupstore/StoreTestUtils.h

@@ -66,13 +66,14 @@ bool run_housekeeping_and_check_account();
 bool check_reference_counts();
 
 //! Starts the bbstored test server running, which must not already be running.
-bool StartServer();
+bool StartServer(const std::string& daemon_args = "");
 
 //! Stops the currently running bbstored test server.
 bool StopServer(bool wait_for_process = false);
 
 //! Starts the bbackupd client running, which must not already be running.
-bool StartClient(const std::string& bbackupd_conf_file = "testfiles/bbackupd.conf");
+bool StartClient(const std::string& bbackupd_conf_file = "testfiles/bbackupd.conf",
+	const std::string& daemon_args = "");
 
 //! Stops the currently running bbackupd client.
 bool StopClient(bool wait_for_process = false);

lib/common/Test.h

@@ -41,6 +41,7 @@ extern int num_tests_selected;
 extern int old_failure_count;
 extern std::string first_fail_file;
 extern std::string bbackupd_args, bbstored_args, bbackupquery_args, test_args;
+extern bool bbackupd_args_overridden, bbstored_args_overridden;
 extern std::list<std::string> run_only_named_tests;
 extern std::string current_test_name;
 extern std::map<std::string, std::string> s_test_status;

test/backupstorefix/testbackupstorefix.cpp

@@ -548,8 +548,11 @@ int test(int argc, const char *argv[])
 	BOX_INFO("  === Test that an entry pointing to a directory whose "
 		"raidfile is corrupted doesn't crash");
 
-	// Start the bbstored server
-	TEST_THAT_OR(StartServer(), return 1);
+	// Start the bbstored server. Enable logging to help debug if the store is unexpectedly
+	// locked when we try to check or query it (race conditions):
+	std::string daemon_args(bbstored_args_overridden ? bbstored_args :
+		"-kT -Winfo -tbbstored");
+	TEST_THAT_OR(StartServer(daemon_args), return 1);
 
 	// Instead of starting a client, read the file listing file created by
 	// testbackupstorefix.pl and upload them in the correct order, so that the object
@@ -804,7 +807,7 @@ int test(int argc, const char *argv[])
 		// Start the server again, so testbackupstorefix.pl can run bbackupquery which
 		// connects to it. Except on win32, where we didn't stop it earlier.
 #ifndef WIN32
-		TEST_THAT(StartServer());
+		TEST_THAT(StartServer(daemon_args));
 #endif
 
 		// Check

test/bbackupd/testbbackupd.cpp

@@ -2591,14 +2591,17 @@ bool test_delete_update_and_symlink_files()
 	TEARDOWN_TEST_BBACKUPD();
 }
 
-// Check that store errors are reported neatly. This test uses an independent
-// daemon to check the daemon's backup loop delay, so it's easier to debug
-// with the command: ./t -VTttest -e test_store_error_reporting
-// --bbackupd-args=-kTtbbackupd
+// Check that store errors are reported neatly.
 bool test_store_error_reporting()
 {
 	SETUP_WITH_BBSTORED();
-	TEST_THAT(StartClient());
+
+	// Start the bbackupd client. Enable logging to help debug race
+	// conditions causing test failure:
+	std::string daemon_args(bbackupd_args_overridden ? bbackupd_args :
+		"-kT -Wnotice -tbbackupd");
+	TEST_THAT_OR(StartClient("testfiles/bbackupd.conf", daemon_args), FAIL);
+
 	wait_for_sync_end();
 
 	// TODO FIXME dedent
@@ -3548,14 +3551,23 @@ bool test_sync_files_with_timestamps_in_future()
 // Check change of store marker pauses daemon
 bool test_changing_client_store_marker_pauses_daemon()
 {
+	// Debugging this test requires INFO level logging
+	Logger::LevelGuard increase_to_info(Logging::GetConsole(), Log::INFO);
+
 	SETUP_WITH_BBSTORED();
-	TEST_THAT(StartClient());
+
+	// Start the bbackupd client. Enable logging to help debug race
+	// conditions causing test failure:
+	std::string daemon_args(bbackupd_args_overridden ? bbackupd_args :
+		"-kT -Wnotice -tbbackupd");
+	TEST_THAT_OR(StartClient("testfiles/bbackupd.conf", daemon_args), FAIL);
 
 	// Wait for the client to upload all current files. We also time
 	// approximately how long a sync takes.
 	box_time_t sync_start_time = GetCurrentBoxTime();
 	sync_and_wait();
 	box_time_t sync_time = GetCurrentBoxTime() - sync_start_time;
+	BOX_INFO("Sync takes " << BOX_FORMAT_MICROSECONDS(sync_time));
 
 	// Time how long a compare takes. On NetBSD it's 3 seconds, and that
 	// interferes with test timing unless we account for it.