diff --git a/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestFileSystemOperationsWithThreads.java b/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestFileSystemOperationsWithThreads.java index 343391f024..ce3cdee5c1 100644 --- a/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestFileSystemOperationsWithThreads.java +++ b/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestFileSystemOperationsWithThreads.java @@ -20,6 +20,7 @@ import static org.junit.Assert.assertFalse; import static org.junit.Assert.assertTrue; +import static org.junit.Assert.fail; import java.io.IOException; import java.net.URI; @@ -27,6 +28,7 @@ import java.util.concurrent.ThreadPoolExecutor; import java.util.concurrent.TimeUnit; +import org.apache.commons.logging.impl.Log4JLogger; import org.apache.hadoop.conf.Configuration; import org.apache.hadoop.fs.FileSystem; import org.apache.hadoop.fs.Path; @@ -37,8 +39,6 @@ import org.junit.Test; import org.junit.rules.ExpectedException; import org.mockito.Mockito; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * Tests the Native Azure file system (WASB) using parallel threads for rename and delete operations. @@ -68,8 +68,8 @@ public void setUp() throws Exception { fs.initialize(uri, conf); // Capture logs - logs = LogCapturer.captureLogs( - LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME)); + logs = LogCapturer.captureLogs(new Log4JLogger(org.apache.log4j.Logger + .getRootLogger())); } /* @@ -131,17 +131,19 @@ public void testRenameSmallFolderWithThreads() throws Exception { // Validate from logs that threads are created. String content = logs.getOutput(); - assertTrue(content.contains("ms with threads: " + expectedThreadsCreated)); + assertInLog(content, "ms with threads: " + expectedThreadsCreated); // Validate thread executions for (int i = 0; i < expectedThreadsCreated; i++) { - assertTrue(content.contains("AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i)); + assertInLog(content, + "AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i); } // Also ensure that we haven't spawned extra threads. if (expectedThreadsCreated < renameThreads) { for (int i = expectedThreadsCreated; i < renameThreads; i++) { - assertFalse(content.contains("AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i)); + assertNotInLog(content, + "AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i); } } } @@ -158,11 +160,12 @@ public void testRenameLargeFolderWithThreads() throws Exception { // Validate from logs that threads are created. String content = logs.getOutput(); - assertTrue(content.contains("ms with threads: " + renameThreads)); + assertInLog(content, "ms with threads: " + renameThreads); // Validate thread executions for (int i = 0; i < renameThreads; i++) { - assertTrue(content.contains("AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i)); + assertInLog(content, + "AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i); } } @@ -184,11 +187,45 @@ public void testRenameLargeFolderDisableThreads() throws Exception { // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Disabling threads for Rename operation as thread count 0")); + assertInLog(content, + "Disabling threads for Rename operation as thread count 0"); // Validate no thread executions for (int i = 0; i < renameThreads; i++) { - assertFalse(content.contains("AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i)); + String term = "AzureBlobRenameThread-" + + Thread.currentThread().getName() + + "-" + i; + assertNotInLog(content, term); + } + } + + /** + * Assert that a log contains the given term. + * @param content log output + * @param term search term + */ + protected void assertInLog(String content, String term) { + assertTrue("Empty log", !content.isEmpty()); + if (!content.contains(term)) { + String message = "No " + term + " found in logs"; + LOG.error(message); + System.err.println(content); + fail(message); + } + } + + /** + * Assert that a log does not contain the given term. + * @param content log output + * @param term search term + */ + protected void assertNotInLog(String content, String term) { + assertTrue("Empty log", !content.isEmpty()); + if (content.contains(term)) { + String message = term + " found in logs"; + LOG.error(message); + System.err.println(content); + fail(message); } } @@ -210,11 +247,13 @@ public void testRenameSmallFolderDisableThreadsDisableFlatListing() throws Excep // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Disabling threads for Rename operation as thread count 1")); + assertInLog(content, + "Disabling threads for Rename operation as thread count 1"); // Validate no thread executions for (int i = 0; i < renameThreads; i++) { - assertFalse(content.contains("AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i)); + assertNotInLog(content, + "AzureBlobRenameThread-" + Thread.currentThread().getName() + "-" + i); } } @@ -254,17 +293,19 @@ public void testDeleteSmallFolderWithThreads() throws Exception { // Validate from logs that threads are enabled. String content = logs.getOutput(); - assertTrue(content.contains("ms with threads: " + expectedThreadsCreated)); + assertInLog(content, "ms with threads: " + expectedThreadsCreated); // Validate thread executions for (int i = 0; i < expectedThreadsCreated; i++) { - assertTrue(content.contains("AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i)); + assertInLog(content, + "AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i); } // Also ensure that we haven't spawned extra threads. if (expectedThreadsCreated < deleteThreads) { for (int i = expectedThreadsCreated; i < deleteThreads; i++) { - assertFalse(content.contains("AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i)); + assertNotInLog(content, + "AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i); } } } @@ -280,11 +321,12 @@ public void testDeleteLargeFolderWithThreads() throws Exception { // Validate from logs that threads are enabled. String content = logs.getOutput(); - assertTrue(content.contains("ms with threads: " + deleteThreads)); + assertInLog(content, "ms with threads: " + deleteThreads); // Validate thread executions for (int i = 0; i < deleteThreads; i++) { - assertTrue(content.contains("AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i)); + assertInLog(content, + "AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i); } } @@ -304,11 +346,13 @@ public void testDeleteLargeFolderDisableThreads() throws Exception { // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Disabling threads for Delete operation as thread count 0")); + assertInLog(content, + "Disabling threads for Delete operation as thread count 0"); // Validate no thread executions for (int i = 0; i < deleteThreads; i++) { - assertFalse(content.contains("AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i)); + assertNotInLog(content, + "AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i); } } @@ -329,11 +373,13 @@ public void testDeleteSmallFolderDisableThreadsDisableFlatListing() throws Excep // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Disabling threads for Delete operation as thread count 1")); + assertInLog(content, + "Disabling threads for Delete operation as thread count 1"); // Validate no thread executions for (int i = 0; i < deleteThreads; i++) { - assertFalse(content.contains("AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i)); + assertNotInLog(content, + "AzureBlobDeleteThread-" + Thread.currentThread().getName() + "-" + i); } } @@ -361,8 +407,8 @@ public void testDeleteThreadPoolExceptionFailure() throws Exception { // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Failed to create thread pool with threads")); - assertTrue(content.contains("Serializing the Delete operation")); + assertInLog(content, "Failed to create thread pool with threads"); + assertInLog(content, "Serializing the Delete operation"); } /* @@ -393,8 +439,9 @@ public void testDeleteThreadPoolExecuteFailure() throws Exception { // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Rejected execution of thread for Delete operation on blob")); - assertTrue(content.contains("Serializing the Delete operation")); + assertInLog(content, + "Rejected execution of thread for Delete operation on blob"); + assertInLog(content, "Serializing the Delete operation"); } /* @@ -427,8 +474,10 @@ public void testDeleteThreadPoolExecuteSingleThreadFailure() throws Exception { // Validate from logs that threads are enabled and unused threads. String content = logs.getOutput(); - assertTrue(content.contains("Using thread pool for Delete operation with threads 7")); - assertTrue(content.contains("6 threads not used for Delete operation on blob")); + assertInLog(content, + "Using thread pool for Delete operation with threads 7"); + assertInLog(content, + "6 threads not used for Delete operation on blob"); } /* @@ -472,9 +521,11 @@ public void testDeleteThreadPoolTerminationFailure() throws Exception { // Validate from logs that threads are enabled and delete operation is failed. String content = logs.getOutput(); - assertTrue(content.contains("Using thread pool for Delete operation with threads")); - assertTrue(content.contains("Threads got interrupted Delete blob operation")); - assertTrue(content.contains("Delete failed as operation on subfolders and files failed.")); + assertInLog(content, + "Using thread pool for Delete operation with threads"); + assertInLog(content, "Threads got interrupted Delete blob operation"); + assertInLog(content, + "Delete failed as operation on subfolders and files failed."); } /* @@ -496,10 +547,12 @@ public void testDeleteSingleDeleteFailure() throws Exception { // Validate from logs that threads are enabled and delete operation failed. String content = logs.getOutput(); - assertTrue(content.contains("Using thread pool for Delete operation with threads")); - assertTrue(content.contains("Delete operation failed for file " + path)); - assertTrue(content.contains("Terminating execution of Delete operation now as some other thread already got exception or operation failed")); - assertTrue(content.contains("Failed to delete files / subfolders in blob")); + assertInLog(content, + "Using thread pool for Delete operation with threads"); + assertInLog(content, "Delete operation failed for file " + path); + assertInLog(content, + "Terminating execution of Delete operation now as some other thread already got exception or operation failed"); + assertInLog(content, "Failed to delete files / subfolders in blob"); } /* @@ -528,9 +581,12 @@ public void testDeleteSingleDeleteException() throws Exception { // Validate from logs that threads are enabled and delete operation failed. String content = logs.getOutput(); - assertTrue(content.contains("Using thread pool for Delete operation with threads")); - assertTrue(content.contains("Encountered Exception for Delete operation for file " + path)); - assertTrue(content.contains("Terminating execution of Delete operation now as some other thread already got exception or operation failed")); + assertInLog(content, + "Using thread pool for Delete operation with threads"); + assertInLog(content, + "Encountered Exception for Delete operation for file " + path); + assertInLog(content, + "Terminating execution of Delete operation now as some other thread already got exception or operation failed"); } /* @@ -556,8 +612,8 @@ public void testRenameThreadPoolExceptionFailure() throws Exception { // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Failed to create thread pool with threads")); - assertTrue(content.contains("Serializing the Rename operation")); + assertInLog(content, "Failed to create thread pool with threads"); + assertInLog(content, "Serializing the Rename operation"); } /* @@ -587,8 +643,9 @@ public void testRenameThreadPoolExecuteFailure() throws Exception { // Validate from logs that threads are disabled. String content = logs.getOutput(); - assertTrue(content.contains("Rejected execution of thread for Rename operation on blob")); - assertTrue(content.contains("Serializing the Rename operation")); + assertInLog(content, + "Rejected execution of thread for Rename operation on blob"); + assertInLog(content, "Serializing the Rename operation"); } /* @@ -621,8 +678,10 @@ public void testRenameThreadPoolExecuteSingleThreadFailure() throws Exception { // Validate from logs that threads are enabled and unused threads exists. String content = logs.getOutput(); - assertTrue(content.contains("Using thread pool for Rename operation with threads 7")); - assertTrue(content.contains("6 threads not used for Rename operation on blob")); + assertInLog(content, + "Using thread pool for Rename operation with threads 7"); + assertInLog(content, + "6 threads not used for Rename operation on blob"); } /* @@ -666,9 +725,11 @@ public void testRenameThreadPoolTerminationFailure() throws Exception { // Validate from logs that threads are enabled and rename operation is failed. String content = logs.getOutput(); - assertTrue(content.contains("Using thread pool for Rename operation with threads")); - assertTrue(content.contains("Threads got interrupted Rename blob operation")); - assertTrue(content.contains("Rename failed as operation on subfolders and files failed.")); + assertInLog(content, + "Using thread pool for Rename operation with threads"); + assertInLog(content, "Threads got interrupted Rename blob operation"); + assertInLog(content, + "Rename failed as operation on subfolders and files failed."); } /* @@ -707,9 +768,12 @@ public void testRenameSingleRenameException() throws Exception { // Validate from logs that threads are enabled and delete operation failed. String content = logs.getOutput(); - assertTrue(content.contains("Using thread pool for Rename operation with threads")); - assertTrue(content.contains("Encountered Exception for Rename operation for file " + path)); - assertTrue(content.contains("Terminating execution of Rename operation now as some other thread already got exception or operation failed")); + assertInLog(content, + "Using thread pool for Rename operation with threads"); + assertInLog(content, + "Encountered Exception for Rename operation for file " + path); + assertInLog(content, + "Terminating execution of Rename operation now as some other thread already got exception or operation failed"); } @Override diff --git a/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestNativeAzureFileSystemClientLogging.java b/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestNativeAzureFileSystemClientLogging.java index caecfdeb0e..4114e60dd9 100644 --- a/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestNativeAzureFileSystemClientLogging.java +++ b/hadoop-tools/hadoop-azure/src/test/java/org/apache/hadoop/fs/azure/TestNativeAzureFileSystemClientLogging.java @@ -24,12 +24,12 @@ import java.net.URI; import java.util.StringTokenizer; +import org.apache.commons.logging.impl.Log4JLogger; import org.apache.hadoop.conf.Configuration; import org.apache.hadoop.fs.Path; import org.apache.hadoop.test.GenericTestUtils.LogCapturer; +import org.apache.log4j.Logger; import org.junit.Test; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; /** * Test to validate Azure storage client side logging. Tests works only when @@ -97,29 +97,39 @@ private void performWASBOperations() throws Exception { @Test public void testLoggingEnabled() throws Exception { - LogCapturer logs = LogCapturer.captureLogs( - LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME)); + LogCapturer logs = LogCapturer.captureLogs(new Log4JLogger(Logger + .getRootLogger())); // Update configuration based on the Test. updateFileSystemConfiguration(true); performWASBOperations(); - assertTrue(verifyStorageClientLogs(logs.getOutput(), TEMP_DIR)); + String output = getLogOutput(logs); + assertTrue("Log entry " + TEMP_DIR + " not found in " + output, + verifyStorageClientLogs(output, TEMP_DIR)); + } + + protected String getLogOutput(LogCapturer logs) { + String output = logs.getOutput(); + assertTrue("No log created/captured", !output.isEmpty()); + return output; } @Test public void testLoggingDisabled() throws Exception { - LogCapturer logs = LogCapturer.captureLogs( - LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME)); + LogCapturer logs = LogCapturer.captureLogs(new Log4JLogger(Logger + .getRootLogger())); // Update configuration based on the Test. updateFileSystemConfiguration(false); performWASBOperations(); + String output = getLogOutput(logs); - assertFalse(verifyStorageClientLogs(logs.getOutput(), TEMP_DIR)); + assertFalse("Log entry " + TEMP_DIR + " found in " + output, + verifyStorageClientLogs(output, TEMP_DIR)); } @Override