Add unit test coverage for S3 upload

CMakeLists.txt

@@ -4,6 +4,7 @@ project( xrootd-http/s3 )
 
 option( XROOTD_PLUGINS_BUILD_UNITTESTS "Build the scitokens-cpp unit tests" OFF )
 option( XROOTD_PLUGINS_EXTERNAL_GTEST "Use an external/pre-installed copy of GTest" OFF )
+option( VALGRIND "Run select unit tests under valgrind" OFF )
 
 set( CMAKE_MODULE_PATH ${PROJECT_SOURCE_DIR}/cmake )
 set( CMAKE_BUILD_TYPE Debug )
@@ -20,6 +21,10 @@ if(NOT XROOTD_PLUGIN_VERSION)
   set(XROOTD_PLUGIN_VERSION ${XROOTD_PLUGIN_VERSION} CACHE INTERNAL "")
 endif()
 
+if(VALGRIND)
+  find_program(VALGRIND_BIN valgrind REQUIRED)
+endif()
+
 macro(use_cxx17)
   if (CMAKE_VERSION VERSION_LESS "3.1")
     if (CMAKE_CXX_COMPILER_ID STREQUAL "GNU")
@@ -57,17 +62,29 @@ endif()
 
 include_directories(${XROOTD_INCLUDES} ${CURL_INCLUDE_DIRS} ${LIBCRYPTO_INCLUDE_DIRS})
 
-add_library(XrdS3 SHARED src/CurlUtil.cc src/S3File.cc src/S3Directory.cc src/S3AccessInfo.cc src/S3FileSystem.cc src/AWSv4-impl.cc src/S3Commands.cc src/HTTPCommands.cc src/TokenFile.cc src/stl_string_utils.cc src/shortfile.cc src/logging.cc)
-add_library(XrdHTTPServer SHARED src/CurlUtil.cc src/HTTPFile.cc src/HTTPFileSystem.cc src/HTTPCommands.cc src/TokenFile.cc src/stl_string_utils.cc src/shortfile.cc src/logging.cc)
+# On Linux, we hide all the symbols for the final libraries, exposing only what's needed for the XRootD
+# runtime loader.  So here we create the object library and will create a separate one for testing with
+# the symbols exposed.
+add_library(XrdS3Obj OBJECT src/CurlUtil.cc src/S3File.cc src/S3Directory.cc src/S3AccessInfo.cc src/S3FileSystem.cc src/AWSv4-impl.cc src/S3Commands.cc src/HTTPCommands.cc src/TokenFile.cc src/stl_string_utils.cc src/shortfile.cc src/logging.cc)
+target_include_directories(XrdS3Obj INTERFACE tinyxml2::tinyxml2)
+set_target_properties(XrdS3Obj PROPERTIES POSITION_INDEPENDENT_CODE ON)
+target_link_libraries(XrdS3Obj -ldl ${XROOTD_UTILS_LIB} ${XROOTD_SERVER_LIB} ${CURL_LIBRARIES} ${LIBCRYPTO_LIBRARIES} tinyxml2::tinyxml2 Threads::Threads)
+
+add_library(XrdS3 MODULE "$<TARGET_OBJECTS:XrdS3Obj>")
+target_link_libraries(XrdS3 XrdS3Obj)
 
-target_link_libraries(XrdS3 -ldl ${XROOTD_UTILS_LIB} ${XROOTD_SERVER_LIB} ${CURL_LIBRARIES} ${LIBCRYPTO_LIBRARIES} tinyxml2::tinyxml2 Threads::Threads)
-target_link_libraries(XrdHTTPServer -ldl ${XROOTD_UTILS_LIB} ${XROOTD_SERVER_LIB} ${CURL_LIBRARIES} ${LIBCRYPTO_LIBRARIES} Threads::Threads)
+add_library(XrdHTTPServerObj OBJECT src/CurlUtil.cc src/HTTPFile.cc src/HTTPFileSystem.cc src/HTTPCommands.cc src/TokenFile.cc src/stl_string_utils.cc src/shortfile.cc src/logging.cc)
+set_target_properties(XrdHTTPServerObj PROPERTIES POSITION_INDEPENDENT_CODE ON)
+target_link_libraries(XrdHTTPServerObj -ldl ${XROOTD_UTILS_LIB} ${XROOTD_SERVER_LIB} ${CURL_LIBRARIES} ${LIBCRYPTO_LIBRARIES} Threads::Threads)
+
+add_library(XrdHTTPServer MODULE "$<TARGET_OBJECTS:XrdHTTPServerObj>")
+target_link_libraries(XrdHTTPServer XrdHTTPServerObj)
 
 # The CMake documentation strongly advises against using these macros; instead, the pkg_check_modules
 # is supposed to fill out the full path to ${LIBCRYPTO_LIBRARIES}.  As of cmake 3.26.1, this does not
 # appear to be the case on Mac OS X.  Remove once no longer necessary!
-target_link_directories(XrdS3 PUBLIC ${LIBCRYPTO_LIBRARY_DIRS})
-target_link_directories(XrdHTTPServer PUBLIC ${LIBCRYPTO_LIBRARY_DIRS})
+target_link_directories(XrdS3Obj PUBLIC ${LIBCRYPTO_LIBRARY_DIRS})
+target_link_directories(XrdHTTPServerObj PUBLIC ${LIBCRYPTO_LIBRARY_DIRS})
 
 if(NOT APPLE)
   set_target_properties(XrdS3 PROPERTIES OUTPUT_NAME "XrdS3-${XROOTD_PLUGIN_VERSION}" SUFFIX ".so" LINK_FLAGS "-Wl,--version-script=${CMAKE_SOURCE_DIR}/configs/export-lib-symbols")
@@ -85,6 +102,11 @@ install(
 )
 
 if( XROOTD_PLUGINS_BUILD_UNITTESTS )
+  add_library(XrdS3Testing SHARED "$<TARGET_OBJECTS:XrdS3Obj>")
+  target_link_libraries(XrdS3Testing XrdS3Obj)
+  add_library(XrdHTTPServerTesting SHARED "$<TARGET_OBJECTS:XrdHTTPServerObj>")
+  target_link_libraries(XrdHTTPServerTesting XrdHTTPServerObj)
+
   if( NOT XROOTD_PLUGINS_EXTERNAL_GTEST )
     include(ExternalProject)
     ExternalProject_Add(gtest

src/CurlUtil.cc

@@ -187,7 +187,7 @@ void CurlWorker::Run() {
 	// is waiting on it is undefined behavior.
 	auto queue_ref = m_queue;
 	auto &queue = *queue_ref.get();
-	m_logger.Log(LogMask::Debug, "CurlWorker::Run", "Started a curl worker");
+	m_logger.Log(LogMask::Debug, "Run", "Started a curl worker");
 
 	CURLM *multi_handle = curl_multi_init();
 	if (multi_handle == nullptr) {
@@ -213,7 +213,7 @@ void CurlWorker::Run() {
 			}
 			auto curl = queue.GetHandle();
 			if (curl == nullptr) {
-				m_logger.Log(LogMask::Debug, "CurlWorker",
+				m_logger.Log(LogMask::Debug, "Run",
 							 "Unable to allocate a curl handle");
 				op->Fail("E_NOMEM", "Unable to get allocate a curl handle");
 				continue;
@@ -223,7 +223,7 @@ void CurlWorker::Run() {
 					op->Fail(op->getErrorCode(), op->getErrorMessage());
 				}
 			} catch (...) {
-				m_logger.Log(LogMask::Debug, "CurlWorker",
+				m_logger.Log(LogMask::Debug, "Run",
 							 "Unable to setup the curl handle");
 				op->Fail("E_NOMEM",
 						 "Failed to setup the curl handle for the operation");
@@ -236,8 +236,7 @@ void CurlWorker::Run() {
 					std::stringstream ss;
 					ss << "Unable to add operation to the curl multi-handle: "
 					   << curl_multi_strerror(mres);
-					m_logger.Log(LogMask::Debug, "CurlWorker",
-								 ss.str().c_str());
+					m_logger.Log(LogMask::Debug, "Run", ss.str().c_str());
 				}
 				op->Fail("E_CURL_LIB",
 						 "Unable to add operation to the curl multi-handle");
@@ -253,7 +252,7 @@ void CurlWorker::Run() {
 			if (m_logger.getMsgMask() & LogMask::Debug) {
 				std::stringstream ss;
 				ss << "Curl worker thread " << getpid() << " is running "
-				   << running_handles << "operations";
+				   << running_handles << " operations";
 				m_logger.Log(LogMask::Debug, "CurlWorker", ss.str().c_str());
 			}
 			last_marker = now;
@@ -298,6 +297,8 @@ void CurlWorker::Run() {
 				}
 				auto &op = iter->second;
 				auto res = msg->data.result;
+				m_logger.Log(LogMask::Dump, "Run",
+							 "Processing result from curl");
 				op->ProcessCurlResult(iter->first, res);
 				op->ReleaseHandle(iter->first);
 				running_handles -= 1;

src/HTTPCommands.cc

@@ -115,61 +115,72 @@ bool HTTPRequest::SendHTTPRequest(const std::string &payload) {
 	return sendPreparedRequest(hostUrl, payload);
 }
 
-static void dump(const char *text, FILE *stream, unsigned char *ptr,
+static void dump(XrdSysError *log, const char *text, unsigned char *ptr,
 				 size_t size) {
 	size_t i;
 	size_t c;
 	unsigned int width = 0x10;
+	if (!log)
+		return;
 
-	fprintf(stream, "%s, %10.10ld bytes (0x%8.8lx)\n", text, (long)size,
-			(long)size);
+	std::stringstream ss;
+	std::string stream;
+	formatstr(stream, "%s, %10.10ld bytes (0x%8.8lx)\n", text, (long)size,
+			  (long)size);
+	ss << stream;
 
 	for (i = 0; i < size; i += width) {
-		fprintf(stream, "%4.4lx: ", (long)i);
+		formatstr(stream, "%4.4lx: ", (long)i);
+		ss << stream;
 
 		/* show hex to the left */
 		for (c = 0; c < width; c++) {
-			if (i + c < size)
-				fprintf(stream, "%02x ", ptr[i + c]);
-			else
-				fputs("   ", stream);
+			if (i + c < size) {
+				formatstr(stream, "%02x ", ptr[i + c]);
+				ss << stream;
+			} else {
+				ss << "   ";
+			}
 		}
 
 		/* show data on the right */
 		for (c = 0; (c < width) && (i + c < size); c++) {
 			char x =
 				(ptr[i + c] >= 0x20 && ptr[i + c] < 0x80) ? ptr[i + c] : '.';
-			fputc(x, stream);
+			ss << x;
 		}
-
-		fputc('\n', stream); /* newline */
+		ss << std::endl;
 	}
+	log->Log(LogMask::Dump, "Curl", ss.str().c_str());
 }
 
-static void dump_plain(const char *text, FILE *stream, unsigned char *ptr,
-					   size_t size) {
-	fprintf(stream, "%s, %10.10ld bytes (0x%8.8lx)\n", text, (long)size,
-			(long)size);
-	fwrite(ptr, 1, size, stream);
-	fputs("\n", stream);
+static void dumpPlain(XrdSysError *log, const char *text, unsigned char *ptr,
+					  size_t size) {
+	if (!log)
+		return;
+	std::string info;
+	formatstr(info, "%s, %10.10ld bytes (0x%8.8lx)\n", text, (long)size,
+			  (long)size);
+	log->Log(LogMask::Dump, "Curl", info.c_str());
 }
 
 int debugCallback(CURL *handle, curl_infotype ci, char *data, size_t size,
 				  void *clientp) {
 	const char *text;
 	(void)handle; /* prevent compiler warning */
-	(void)clientp;
+	auto log = static_cast<XrdSysError *>(clientp);
+	if (!log)
+		return 0;
 
 	switch (ci) {
 	case CURLINFO_TEXT:
-		fputs("== Info: ", stderr);
-		fwrite(data, size, 1, stderr);
+		log->Log(LogMask::Dump, "CurlInfo", std::string(data, size).c_str());
 	default: /* in case a new one is introduced to shock us */
 		return 0;
 
 	case CURLINFO_HEADER_OUT:
 		text = "=> Send header";
-		dump_plain(text, stderr, (unsigned char *)data, size);
+		dumpPlain(log, text, (unsigned char *)data, size);
 		break;
 	}
 	return 0;
@@ -179,18 +190,25 @@ int debugAndDumpCallback(CURL *handle, curl_infotype ci, char *data,
 						 size_t size, void *clientp) {
 	const char *text;
 	(void)handle; /* prevent compiler warning */
-	(void)clientp;
+	auto log = reinterpret_cast<XrdSysError *>(clientp);
+	if (!log)
+		return 0;
 
+	std::stringstream ss;
 	switch (ci) {
 	case CURLINFO_TEXT:
-		fputs("== Info: ", stderr);
-		fwrite(data, size, 1, stderr);
+		if (size && data[size - 1] == '\n') {
+			ss << std::string(data, size - 1);
+		} else {
+			ss << std::string(data, size);
+		}
+		log->Log(LogMask::Dump, "CurlInfo", ss.str().c_str());
 	default: /* in case a new one is introduced to shock us */
 		return 0;
 
 	case CURLINFO_HEADER_OUT:
 		text = "=> Send header";
-		dump_plain(text, stderr, (unsigned char *)data, size);
+		dumpPlain(log, text, (unsigned char *)data, size);
 		break;
 	case CURLINFO_DATA_OUT:
 		text = "=> Send data";
@@ -208,7 +226,7 @@ int debugAndDumpCallback(CURL *handle, curl_infotype ci, char *data,
 		text = "<= Recv SSL data";
 		break;
 	}
-	dump(text, stderr, (unsigned char *)data, size);
+	dump(log, text, (unsigned char *)data, size);
 	return 0;
 }
 
@@ -467,18 +485,45 @@ bool HTTPRequest::SetupHandle(CURL *curl) {
 
 	rv = curl_easy_setopt(curl, CURLOPT_HTTPHEADER, m_header_list.get());
 	if (rv != CURLE_OK) {
-		this->errorCode = "E_CURL_LIB";
-		this->errorMessage = "curl_easy_setopt( CURLOPT_HTTPHEADER ) failed.";
+		errorCode = "E_CURL_LIB";
+		errorMessage = "curl_easy_setopt( CURLOPT_HTTPHEADER ) failed.";
 		return false;
 	}
 	if (m_log.getMsgMask() & LogMask::Debug) {
 		rv = curl_easy_setopt(curl, CURLOPT_DEBUGFUNCTION, debugCallback);
-		rv = curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L);
+		if (rv != CURLE_OK) {
+			errorCode = "E_CURL_LIB";
+			errorMessage = "Failed to set the debug function";
+			return false;
+		}
+		rv = curl_easy_setopt(curl, CURLOPT_DEBUGDATA, &m_log);
+		if (rv != CURLE_OK) {
+			errorCode = "E_CURL_LIB";
+			errorMessage = "Failed to set the debug function handler data";
+			return false;
+		}
 	}
 	if (m_log.getMsgMask() & LogMask::Dump) {
 		rv =
 			curl_easy_setopt(curl, CURLOPT_DEBUGFUNCTION, debugAndDumpCallback);
-		rv = curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L);
+		if (rv != CURLE_OK) {
+			errorCode = "E_CURL_LIB";
+			errorMessage = "Failed to set the debug function";
+			return false;
+		}
+		rv = curl_easy_setopt(curl, CURLOPT_DEBUGDATA, &m_log);
+		if (rv != CURLE_OK) {
+			errorCode = "E_CURL_LIB";
+			errorMessage = "Failed to set the debug function handler data";
+			return false;
+		}
+	}
+	if (m_log.getMsgMask() & (LogMask::Dump | LogMask::Debug)) {
+		if (curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L) != CURLE_OK) {
+			errorCode = "E_CURL_LIB";
+			errorMessage = "Failed to enable verbose mode for libcurl";
+			return false;
+		}
 	}
 
 	return true;

src/logging.cc

@@ -37,7 +37,7 @@ std::string XrdHTTPServer::LogMaskToString(int mask) {
 		has_entry = true;
 	}
 	if (mask & LogMask::Debug) {
-		ss << "debug";
+		ss << (has_entry ? ", " : "") << "debug";
 		has_entry = true;
 	}
 	if (mask & LogMask::Info) {

test/CMakeLists.txt

@@ -1,29 +1,10 @@
-add_executable( s3-gtest s3_tests.cc
-  ../src/AWSv4-impl.cc
-  ../src/CurlUtil.cc
-  ../src/logging.cc
-  ../src/S3AccessInfo.cc
-  ../src/S3Directory.cc
-  ../src/S3File.cc
-  ../src/S3FileSystem.cc
-  ../src/shortfile.cc
-  ../src/stl_string_utils.cc
-  ../src/TokenFile.cc
-  ../src/HTTPCommands.cc
-  ../src/S3Commands.cc
-)
+add_executable( s3-gtest s3_tests.cc )
 
-add_executable( http-gtest http_tests.cc
-  ../src/CurlUtil.cc
-  ../src/HTTPFile.cc
-  ../src/HTTPFileSystem.cc
-  ../src/HTTPCommands.cc
-  ../src/stl_string_utils.cc
-  ../src/TokenFile.cc
-  ../src/shortfile.cc
-  ../src/logging.cc
-)
+add_executable( s3-unit-test s3_unit_tests.cc )
 
+add_executable( http-gtest http_tests.cc )
+
+include(GoogleTest)
 
 if(XROOTD_PLUGINS_EXTERNAL_GTEST)
     set(LIBGTEST "gtest")
@@ -34,9 +15,16 @@ else()
     set(LIBGTEST "${CMAKE_BINARY_DIR}/external/gtest/src/gtest-build/lib/libgtest.a")
 endif()
 
-target_link_libraries(s3-gtest XrdS3 "${LIBGTEST}" pthread)
-target_link_libraries(http-gtest XrdHTTPServer "${LIBGTEST}" pthread)
+target_link_libraries(s3-gtest XrdS3Testing "${LIBGTEST}" pthread)
+target_link_libraries(s3-unit-test XrdS3Testing "${LIBGTEST}" pthread)
+target_link_libraries(http-gtest XrdHTTPServerTesting "${LIBGTEST}" pthread)
 
+gtest_add_tests(TARGET s3-unit-test TEST_LIST s3UnitTests)
+set_tests_properties(${s3UnitTests}
+  PROPERTIES
+    FIXTURES_REQUIRED S3::s3_basic
+    ENVIRONMENT "ENV_FILE=${CMAKE_BINARY_DIR}/tests/s3_basic/setup.sh"
+)
 
 add_test(
   NAME
@@ -52,6 +40,20 @@ add_test(
     ${CMAKE_CURRENT_BINARY_DIR}/http-gtest "${CMAKE_BINARY_DIR}/tests/basic/setup.sh"
 )
 
+if (VALGRIND)
+  add_test(
+    NAME
+      valgrind-s3
+    COMMAND
+      ${VALGRIND_BIN} ${CMAKE_CURRENT_BINARY_DIR}/s3-unit-test -R FileSystemS3Fixture.UploadLargePartAligned
+  )
+
+  set_tests_properties(valgrind-s3
+    PROPERTIES
+      FIXTURES_REQUIRED S3::s3_basic
+  )
+endif()
+
 set_tests_properties(http-unit
   PROPERTIES
     FIXTURES_REQUIRED HTTP::basic