From 0335899fa72615fdee2759a197c48ed89014c9f8 Mon Sep 17 00:00:00 2001 From: Kedar Sankar Behera Date: Thu, 3 May 2018 16:12:04 -0700 Subject: [PATCH] Reduced logging and other improvements to console output (#453) --- conf/log4j.properties | 12 +- .../drill/test/framework/ConnectionPool.java | 3 +- .../drill/test/framework/DBMetaData.java | 6 +- .../drill/test/framework/DrillTestJdbc.java | 9 +- .../drill/test/framework/DrillTestOdbc.java | 14 +- .../drill/test/framework/DrillTestScript.java | 3 +- .../drill/test/framework/ShellRunner.java | 4 +- .../drill/test/framework/TestDriver.java | 161 +++++++----------- .../drill/test/framework/TestVerifier.java | 2 +- .../apache/drill/test/framework/Utils.java | 8 +- 10 files changed, 90 insertions(+), 132 deletions(-) diff --git a/conf/log4j.properties b/conf/log4j.properties index 02ef9698b..a1bea6b25 100755 --- a/conf/log4j.properties +++ b/conf/log4j.properties @@ -1,6 +1,6 @@ # Root logger option -log4j.rootLogger=INFO, file, stdout - +log4j.rootLogger=ERROR, file, stdout +log4j.logger.DrillTestLogger=INFO, Drill # Direct log messages to ./drill.log.timestamp file log4j.appender.file = org.apache.log4j.rolling.RollingFileAppender log4j.appender.file.rollingPolicy = org.apache.log4j.rolling.TimeBasedRollingPolicy @@ -14,5 +14,13 @@ log4j.appender.stdout.Target=System.out log4j.appender.stdout.layout=org.apache.log4j.PatternLayout log4j.appender.stdout.layout.ConversionPattern=%m%n +# Direct log messages to stdout +log4j.appender.Drill=org.apache.log4j.ConsoleAppender +log4j.appender.Drill.Target=System.out +log4j.appender.Drill.layout=org.apache.log4j.PatternLayout +log4j.appender.Drill.layout.ConversionPattern=%m%n + +log4j.additivity.DrillTestLogger=false + log4j.logger.org.apache.curator=WARN log4j.logger.org.apache.zookeeper=WARN diff --git a/framework/src/main/java/org/apache/drill/test/framework/ConnectionPool.java b/framework/src/main/java/org/apache/drill/test/framework/ConnectionPool.java index c89bfb6a1..736b5b2d2 100644 --- a/framework/src/main/java/org/apache/drill/test/framework/ConnectionPool.java +++ b/framework/src/main/java/org/apache/drill/test/framework/ConnectionPool.java @@ -29,8 +29,7 @@ import java.util.Queue; public class ConnectionPool implements AutoCloseable { - private static final Logger LOG = Logger.getLogger(ConnectionPool.class); - + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); private final Map> connections; private Properties connectionProperties; diff --git a/framework/src/main/java/org/apache/drill/test/framework/DBMetaData.java b/framework/src/main/java/org/apache/drill/test/framework/DBMetaData.java index 114ff3b9d..d3b883b34 100644 --- a/framework/src/main/java/org/apache/drill/test/framework/DBMetaData.java +++ b/framework/src/main/java/org/apache/drill/test/framework/DBMetaData.java @@ -27,8 +27,8 @@ */ public class DBMetaData { - private static final Logger LOG = Logger.getLogger(DBMetaData.class); - private DatabaseMetaData md = null; + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); + private DatabaseMetaData md = null; public DBMetaData(DatabaseMetaData md) { this.md = md; } @@ -93,4 +93,4 @@ public String toString() { } } -} \ No newline at end of file +} diff --git a/framework/src/main/java/org/apache/drill/test/framework/DrillTestJdbc.java b/framework/src/main/java/org/apache/drill/test/framework/DrillTestJdbc.java index db0184163..64b03e536 100644 --- a/framework/src/main/java/org/apache/drill/test/framework/DrillTestJdbc.java +++ b/framework/src/main/java/org/apache/drill/test/framework/DrillTestJdbc.java @@ -40,7 +40,7 @@ import java.util.concurrent.atomic.AtomicBoolean; public class DrillTestJdbc implements DrillTest { - private static final Logger LOG = Logger.getLogger(DrillTestJdbc.class); + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); private static final String LINE_BREAK = "------------------------------------------------------------------------"; private ConnectionPool connectionPool; @@ -63,6 +63,7 @@ public class DrillTestJdbc implements DrillTest { private Random rand = new Random(); private Statement statement = null; private AtomicBoolean doneProcessingResultSet = new AtomicBoolean(false); + public static final CmdParam cmdParam = new CmdParam(); private int id; private int totalCases; private String queryID; @@ -162,10 +163,8 @@ public void run() { LOG.info("[" + testStatus + "] (" + stopwatch + ") " + modeler.queryFilename + " (ConnectionID: " + connection.hashCode() + ")"); } - if((++countTestsCompleted %100==0 && countTestsCompleted <= totalCases) || (countTestsCompleted == totalCases)){ - LOG.info(LINE_BREAK); - LOG.info("Execution completed for " + countTestsCompleted + " (out of " + totalCases + ") tests"); - LOG.info(LINE_BREAK); + if((++countTestsCompleted %100==0 && countTestsCompleted <= (totalCases*TestDriver.cmdParam.iterations*TestDriver.cmdParam.clones))||(countTestsCompleted>=totalCases && countTestsCompleted%totalCases==0)){ + LOG.info(LINE_BREAK+"\nExecution completed for " + countTestsCompleted + " (out of " + (totalCases*TestDriver.cmdParam.iterations*TestDriver.cmdParam.clones) + ") tests\n"+LINE_BREAK); } } } diff --git a/framework/src/main/java/org/apache/drill/test/framework/DrillTestOdbc.java b/framework/src/main/java/org/apache/drill/test/framework/DrillTestOdbc.java index 579ad579d..6c2af3ba0 100644 --- a/framework/src/main/java/org/apache/drill/test/framework/DrillTestOdbc.java +++ b/framework/src/main/java/org/apache/drill/test/framework/DrillTestOdbc.java @@ -42,8 +42,7 @@ import java.util.concurrent.atomic.AtomicBoolean; public class DrillTestOdbc implements DrillTest{ - private static final Logger LOG = Logger.getLogger(DrillTestOdbc.class); - + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); private String query = null; private String outputFilename; private volatile TestStatus testStatus = TestStatus.PENDING; @@ -56,7 +55,6 @@ public class DrillTestOdbc implements DrillTest{ private Thread thread; private int id; private int totalCases; - private static volatile int noOfCasesCompleted; public DrillTestOdbc(DrillTestCase modeler, int id, int totalCases) { @@ -153,12 +151,10 @@ public void run() { LOG.info(testStatus + " (" + stopwatch + ") " + modeler.script + " " + modeler.queryFilename); - if(++noOfCasesCompleted%100==0 && noOfCasesCompleted <= totalCases){ - LOG.info("----------------------------------------------------------------------------------------------------------------"); - - LOG.info("Execution completed for "+(noOfCasesCompleted)+" out of "+ - (totalCases)+" tests"); - LOG.info("----------------------------------------------------------------------------------------------------------------\n"); + if((++noOfCasesCompleted%100==0 && noOfCasesCompleted <= (totalCases*TestDriver.cmdParam.iterations*TestDriver.cmdParam.clones))||(noOfCasesCompleted>=totalCases && noOfCasesCompleted%totalCases==0)){ + LOG.info("----------------------------------------------------------------------------------------------------------------\nExecution completed for "+(noOfCasesCompleted)+" out of "+ + (totalCases*TestDriver.cmdParam.iterations*TestDriver.cmdParam.clones)+" tests\n----------------------------------------------------------------------------------------------------------------"); + } } } diff --git a/framework/src/main/java/org/apache/drill/test/framework/DrillTestScript.java b/framework/src/main/java/org/apache/drill/test/framework/DrillTestScript.java index a1d75e090..58bb0cf02 100644 --- a/framework/src/main/java/org/apache/drill/test/framework/DrillTestScript.java +++ b/framework/src/main/java/org/apache/drill/test/framework/DrillTestScript.java @@ -39,8 +39,7 @@ import java.util.concurrent.atomic.AtomicBoolean; public class DrillTestScript implements DrillTest { - private static final Logger LOG = Logger.getLogger(DrillTestScript.class); - + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); private String query; private String outputFilename; private volatile TestStatus testStatus = TestStatus.PENDING; diff --git a/framework/src/main/java/org/apache/drill/test/framework/ShellRunner.java b/framework/src/main/java/org/apache/drill/test/framework/ShellRunner.java index f6e8c3ba0..b96a7afbe 100644 --- a/framework/src/main/java/org/apache/drill/test/framework/ShellRunner.java +++ b/framework/src/main/java/org/apache/drill/test/framework/ShellRunner.java @@ -26,8 +26,8 @@ public enum ShellRunner implements Closeable { INSTANCE; - private static final Logger LOG = LoggerFactory.getLogger(ShellRunner.class); - private ExecutorService executors = Executors.newCachedThreadPool(); + private static final Logger LOG = LoggerFactory.getLogger("DrillTestLogger"); + private ExecutorService executors = Executors.newCachedThreadPool(); public CmdConsOut execCmd(String cmd) { Preconditions.checkArgument(!Strings.isNullOrEmpty(cmd), "cmd is invalid"); diff --git a/framework/src/main/java/org/apache/drill/test/framework/TestDriver.java b/framework/src/main/java/org/apache/drill/test/framework/TestDriver.java index f4811acf1..3e55ba48b 100644 --- a/framework/src/main/java/org/apache/drill/test/framework/TestDriver.java +++ b/framework/src/main/java/org/apache/drill/test/framework/TestDriver.java @@ -50,7 +50,7 @@ import java.sql.DatabaseMetaData; public class TestDriver { - private static final Logger LOG = Logger.getLogger(TestDriver.class); + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); private Connection connection = null; public static String commitId, version; private String[] injectionKeys = {"DRILL_VERSION"}; @@ -95,9 +95,7 @@ public static void main(String[] args) throws Exception { LOG.error("Exiting due to uncaught exception", e); errorCode = -1; } finally { - LOG.info("\n" + DrillTestDefaults.LINE_BREAK); - LOG.info("RUN STATUS"); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info("\n"+DrillTestDefaults.LINE_BREAK+"\nRUN STATUS\n"+DrillTestDefaults.LINE_BREAK); LOG.info("Exit Code : " + errorCode); LOG.info("Exit Status : " + ((errorCode==0) ? "SUCCESS" : "FAILURE")); LOG.info("\nRun Started : " + startDate); @@ -136,21 +134,10 @@ public static Properties createConnectionProperties() { public int runTests() throws Exception { - List passingTests = Lists.newArrayList(); - List dataVerificationFailures = Lists.newArrayList(); - List planVerificationFailures = Lists.newArrayList(); - List executionFailures = Lists.newArrayList(); - List timeoutFailures = Lists.newArrayList(); - List canceledTests = Lists.newArrayList(); - List randomFailures = Lists.newArrayList(); - List failingTests = Lists.newArrayList(); - CancelingExecutor executor = new CancelingExecutor(cmdParam.threads, cmdParam.timeout); + CancelingExecutor executor = new CancelingExecutor(cmdParam.threads, cmdParam.timeout); final Stopwatch stopwatch = Stopwatch.createStarted(); - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("PRE-CHECK"); - LOG.info(DrillTestDefaults.LINE_BREAK); try { connection = connectionPool.getOrCreateConnection(); } catch (SQLException e) { @@ -160,7 +147,7 @@ public int runTests() throws Exception { //Record JDBC driver name, version and other metadata info DatabaseMetaData dm = connection.getMetaData(); - LOG.info(DrillTestDefaults.LINE_BREAK + new DBMetaData(dm).toString() + DrillTestDefaults.LINE_BREAK); + LOG.info(DrillTestDefaults.LINE_BREAK +"\nJDBC DRIVER METADATA CATALOG\n"+DrillTestDefaults.LINE_BREAK+"\n"+ new DBMetaData(dm).toString() + DrillTestDefaults.LINE_BREAK); /* LOG.info(DrillTestDefaults.LINE_BREAK + "Product name = " + dm.getDatabaseProductName() + "\n" + "Product version = " + dm.getDatabaseProductVersion() + "\n" + "Product major version = " + dm.getDatabaseMajorVersion() + "\n" @@ -179,16 +166,10 @@ public int runTests() throws Exception { + numberOfClusterNodes + ";\n\t>> Number of drillbits = " + numberOfDrillbits); System.exit(-1); } - LOG.info("> Number of cluster nodes configured = " + numberOfClusterNodes); - LOG.info("> Number of drillbits running = " + numberOfDrillbits); - LOG.info("\n> Pre-check duration " + stopwatch); - stopwatch.reset().start(); - LOG.info("\n"+DrillTestDefaults.LINE_BREAK); - LOG.info("SETUP"); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info("\n"+DrillTestDefaults.LINE_BREAK+"\nINIT\n"+DrillTestDefaults.LINE_BREAK); setup(); - LOG.info("\n> Setup duration: " + stopwatch); + LOG.info("> INIT duration: " + stopwatch+"\n"+DrillTestDefaults.LINE_BREAK); List drillTestCases = Utils.getDrillTestCases(); List tests = Lists.newArrayList(); @@ -219,15 +200,21 @@ public int runTests() throws Exception { } for (i = 1; i < cmdParam.iterations+1; i++) { + + List passingTests = Lists.newArrayList(); + List dataVerificationFailures = Lists.newArrayList(); + List planVerificationFailures = Lists.newArrayList(); + List executionFailures = Lists.newArrayList(); + List timeoutFailures = Lists.newArrayList(); + List canceledTests = Lists.newArrayList(); + List randomFailures = Lists.newArrayList(); + List failingTests = Lists.newArrayList(); + + //PREPARATION stopwatch.reset().start(); - LOG.info("\n"+DrillTestDefaults.LINE_BREAK); - LOG.info("PREPARATION"); - LOG.info(DrillTestDefaults.LINE_BREAK); if (cmdParam.generate) { prepareData(drillTestCases); } - LOG.info("> Preparation duration: " + stopwatch); - stopwatch.reset().start(); Collections.shuffle(tests, new Random()); @@ -282,9 +269,7 @@ public int runTests() throws Exception { } } - LOG.info("\n"+DrillTestDefaults.LINE_BREAK); - LOG.info("RUNNING TESTS - ITERATION " + i + " (of "+ cmdParam.iterations + ")"); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info("\n"+DrillTestDefaults.LINE_BREAK+"\nRUNNING TESTS - ITERATION " + i + " (of "+ cmdParam.iterations + ")\n"+DrillTestDefaults.LINE_BREAK); executor.executeAll(tests); if (cmdParam.trackMemory) { @@ -324,10 +309,8 @@ public int runTests() throws Exception { * To prevent long runtimes, cmdParam.threads is chosen as an arbitrary max limit. * If total failed tests are higher than the max defined above, we do not isolate random failures. */ - if(failingTests.size() <= cmdParam.threads){ - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("ISOLATING RANDOM FAILURES - Execution attempt 2 (of 2)"); - LOG.info(DrillTestDefaults.LINE_BREAK); + if(failingTests.size() > 0 && failingTests.size() <= cmdParam.threads){ + LOG.info(DrillTestDefaults.LINE_BREAK+"\nISOLATING RANDOM FAILURES - Execution attempt 2 (of 2)\n"+DrillTestDefaults.LINE_BREAK); executor.executeAll(failingTests); for(DrillTest test : failingTests){ TestStatus testStatus = test.getTestStatus(); @@ -355,16 +338,14 @@ else if(timeoutFailures.contains(test)){ } if(executionFailures.size()>0 || dataVerificationFailures.size()>0 || planVerificationFailures.size()>0 || timeoutFailures.size()>0) { - LOG.info("\n"+DrillTestDefaults.LINE_BREAK); - LOG.info("ITERATION FAILURES"); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info("\n"+DrillTestDefaults.LINE_BREAK+"\nITERATION FAILURES\n"+DrillTestDefaults.LINE_BREAK); } if(executionFailures.size()>0){ LOG.info("\nExecution Failures:\n"); for (DrillTest test : executionFailures) { LOG.info("Query: " + test.getInputFile() + "\n" + test.getQuery()); - LOG.info("Exception:\n", test.getException()); + LOG.info("\nException:\n", test.getException()); } } @@ -372,7 +353,7 @@ else if(timeoutFailures.contains(test)){ LOG.info("\nData Verification Failures:\n"); for (DrillTest test : dataVerificationFailures) { LOG.info("Query: " + test.getInputFile()+ "\n" + test.getQuery()); - LOG.info("Baseline: "+ test.getExpectedFile() + "\n"); + LOG.info("\nBaseline: "+ test.getExpectedFile()); LOG.info(test.getException().getMessage()); } } @@ -381,7 +362,7 @@ else if(timeoutFailures.contains(test)){ LOG.info("\nPlan Verification Failures:\n"); for (DrillTest test : planVerificationFailures) { LOG.info("Query: " + test.getInputFile()+ "\n" + test.getQuery()); - LOG.info("Baseline: "+ test.getExpectedFile() + "\n"); + LOG.info("\nBaseline: "+ test.getExpectedFile()); LOG.info(test.getException().getMessage()); } } @@ -390,7 +371,7 @@ else if(timeoutFailures.contains(test)){ LOG.info("\nTimeout Failures:\n"); for (DrillTest test : timeoutFailures) { LOG.info("Query: " + test.getInputFile() + "\n" + test.getQuery()); - LOG.info("Timed out"); + LOG.info("Timed out\n"); } } @@ -398,7 +379,7 @@ else if(timeoutFailures.contains(test)){ LOG.info("\nRandom Failures:\n"); for (DrillTest test : randomFailures) { LOG.info("Query: " + test.getInputFile() + "\n" + test.getQuery()); - LOG.info("Exception:\n", test.getException()); + LOG.info("\nException:\n", test.getException()); } } @@ -410,51 +391,44 @@ else if(timeoutFailures.contains(test)){ } if(executionFailures.size()>0 || dataVerificationFailures.size()>0 || planVerificationFailures.size()>0 || timeoutFailures.size()>0 || randomFailures.size()>0) { - LOG.info("\n"+DrillTestDefaults.LINE_BREAK); - LOG.info("ITERATION RESULTS"); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info("\n"+DrillTestDefaults.LINE_BREAK+"\nITERATION RESULTS\n"+DrillTestDefaults.LINE_BREAK); } if(executionFailures.size()>0){ LOG.info("Execution Failures:\n"); for (DrillTest test : executionFailures) { - if(test.getExpectedFile()!=""){ + if(test.getExpectedFile()!=""){ LOG.info(test.getInputFile()); - } - LOG.info("\n"); + } } } if(dataVerificationFailures.size()>0){ - LOG.info("Data Verification Failures:\n"); + LOG.info("\nData Verification Failures:\n"); for (DrillTest test : dataVerificationFailures) { LOG.info(test.getInputFile()); } - LOG.info("\n"); } if(planVerificationFailures.size()>0){ - LOG.info("Plan Verification Failures:\n"); + LOG.info("\nPlan Verification Failures:\n"); for (DrillTest test : planVerificationFailures) { LOG.info(test.getInputFile()); } - LOG.info("\n"); } if(timeoutFailures.size()>0){ - LOG.info("Timeouts:\n"); + LOG.info("\nTimeouts:\n"); for (DrillTest test : timeoutFailures) { LOG.info(test.getInputFile()); } - LOG.info("\n"); } if(randomFailures.size()>0){ - LOG.info("Random Failures:\n"); + LOG.info("\nRandom Failures:\n"); for (DrillTest test : randomFailures) { - LOG.info(test.getInputFile()); + LOG.info(test.getInputFile()); } - LOG.info("\n"); } // Special handling for repeated runs @@ -465,28 +439,24 @@ else if(timeoutFailures.contains(test)){ // Special handling for running tests tagged as failed if(cmdParam.runFailed == true){ if(passingTests.size()>0){ - LOG.info("Passing Tests:\n"); + LOG.info("\nPassing Tests:\n"); for (DrillTest test : passingTests) { LOG.info(test.getInputFile()); } - LOG.info("\n"); } if(executionFailures.size()>0) { - LOG.info("Execution Failures (invalid tests):\n"); + LOG.info("\nExecution Failures (invalid tests):\n"); for (DrillTest test : executionFailures) { if (test.getExpectedFile() == "") { LOG.info(test.getInputFile()); } } - LOG.info("\n"); } } - - LOG.info("\n"+DrillTestDefaults.LINE_BREAK); - LOG.info("ITERATION SUMMARY"); - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("Total Tests : " + countTotalTests); + LOG.info("\n"+DrillTestDefaults.LINE_BREAK+"\n"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nITERATION SUMMARY\n"+DrillTestDefaults.LINE_BREAK); + LOG.info("Total Tests : " + (countTotalTests*cmdParam.clones)); LOG.info("Passing Tests : " + passingTests.size()); LOG.info("Failing Tests : " + (executionFailures.size() + dataVerificationFailures.size() + planVerificationFailures.size() + timeoutFailures.size())+"\n"); LOG.info("> Execution Failures : " + executionFailures.size()); @@ -507,17 +477,13 @@ else if(timeoutFailures.contains(test)){ LOG.info("\nIteration " + i + " (of " + cmdParam.iterations + ") duration: " + stopwatch); if (cmdParam.trackMemory) { - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info(String.format("\nMemory Consumption:\n\t\theap(M)\t\tdirect(M)\tjvm_direct(M)\n" + - " before:\t%d\t\t%d\t\t%d\n after:\t%d\t\t%d\t\t%d", memUsage[0][0], memUsage[0][1], memUsage[0][2], - memUsage[1][0], memUsage[1][1], memUsage[1][2])); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info(DrillTestDefaults.LINE_BREAK+"\n"+String.format("\nMemory Consumption:\n\t\theap(M)\t\tdirect(M)\tjvm_direct(M)\n" + + " before:\t%d\t\t%d\t\t%d\n after:\t%d\t\t%d\t\t%d", memUsage[0][0], memUsage[0][1], memUsage[0][2], + memUsage[1][0], memUsage[1][1], memUsage[1][2])+"\n"+DrillTestDefaults.LINE_BREAK); } if(cmdParam.generateReports) { - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("GENERATING REPORT"); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nGENERATING REPORT\n"+DrillTestDefaults.LINE_BREAK); generateReports(tests, i); } @@ -536,21 +502,18 @@ else if(timeoutFailures.contains(test)){ } if (cmdParam.iterations > 1) { - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info(String.format("\nCompleted %d iterations.\n Passing tests: %d \n Random failures: %d \n" + + LOG.info(DrillTestDefaults.LINE_BREAK+"\n"+String.format("\nCompleted %d iterations.\n Passing tests: %d \n Random failures: %d \n" + " Execution Failures: %d\n Data Verification Failures: %d\n Plan Verification Failures: %d" + - "\n Timeouts: %d\n Canceled: %d", i-1, totalPassingTests, totalRandomFailures,totalExecutionFailures, - totalDataVerificationFailures, totalPlanVerificationFailures, totalTimeoutFailures, totalCancelledFailures)); + "\n Timeouts: %d\n Canceled: %d", i-1, totalPassingTests, totalRandomFailures,totalExecutionFailures, + totalDataVerificationFailures, totalPlanVerificationFailures, totalTimeoutFailures, totalCancelledFailures)); if(finalRandomFailures.size()>0){ - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("Random Failures:"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nRandom Failures:"); for(DrillTest test : finalRandomFailures){ LOG.info(test.getInputFile()); } } if(finalExecutionFailures.size()>0){ - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("Execution Failures:"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nExecution Failures:"); for (DrillTest test : finalExecutionFailures) { if(test.getExpectedFile()!=""){ LOG.info(test.getInputFile()); @@ -566,37 +529,32 @@ else if(timeoutFailures.contains(test)){ } } if(finalDataVerificationFailures.size()>0){ - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("Data Verification Failures"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nData Verification Failures"); for(DrillTest test : finalDataVerificationFailures){ LOG.info(test.getInputFile()); } } if(finalPlanVerificationFailures.size()>0){ - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("Plan Verification Failures"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nPlan Verification Failures"); for(DrillTest test : finalPlanVerificationFailures){ LOG.info(test.getInputFile()); } } if(finalCancelledFailures.size()>0){ - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("Cancelled Failures"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nCancelled Failures"); for(DrillTest test : finalCancelledFailures){ LOG.info(test.getInputFile()); } } if(finalTimeoutFailures.size()>0){ - LOG.info(DrillTestDefaults.LINE_BREAK); - LOG.info("Timeout Failures"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nTimeout Failures"); for(DrillTest test : finalTimeoutFailures){ LOG.info(test.getInputFile()); } } } - LOG.info("\n"+DrillTestDefaults.LINE_BREAK); - LOG.info("TEARDOWN"); - LOG.info(DrillTestDefaults.LINE_BREAK); + LOG.info(DrillTestDefaults.LINE_BREAK+"\n"); + LOG.info(DrillTestDefaults.LINE_BREAK+"\nTEARDOWN\n"+DrillTestDefaults.LINE_BREAK); teardown(); executor.close(); @@ -610,7 +568,7 @@ public void setup() throws IOException, InterruptedException, URISyntaxException new File(DrillTestDefaults.DRILL_OUTPUT_DIR).mkdir(); } - LOG.info("> Uploading storage plugins\n"); + LOG.info("> Uploading storage plugins"); String templatePath = DrillTestDefaults.CWD + "/conf/plugin-templates/common/"; Utils.updateDrillStoragePlugins(templatePath); @@ -622,7 +580,7 @@ public void setup() throws IOException, InterruptedException, URISyntaxException Utils.updateDrillStoragePlugins(templatePath); String beforeRunQueryFilename = DrillTestDefaults.CWD + "/" + cmdParam.beforeRunQueryFilename; - LOG.info("\n> Executing queries\n"); + LOG.info("\n> Executing init queries\n"); LOG.info(">> Path: " + beforeRunQueryFilename + "\n"); try { String[] setupQueries = Utils.getSqlStatements(beforeRunQueryFilename); @@ -631,7 +589,6 @@ public void setup() throws IOException, InterruptedException, URISyntaxException LOG.info(">> Query: " + query + ";"); LOG.info(Utils.getSqlResult(Utils.execSQL(query, connection))); } - LOG.info(DrillTestDefaults.LINE_BREAK); // Initializing variables for reporting String getCommitId = "SELECT version, commit_id from sys.version"; @@ -753,7 +710,7 @@ public void run() { LOG.info("> Generating Data"); genExecutor.executeAll(genTasks); genExecutor.close(); - LOG.info(">> Generation duration: " + stopwatch + "\n"); + LOG.info("\n>> Generation duration: " + stopwatch + "\n"); if (restartDrillbits) { restartDrill(); @@ -971,15 +928,13 @@ private int restartDrill() { int exitCode = 0; String command = DrillTestDefaults.CWD + "/" + DrillTestDefaults.RESTART_DRILL_SCRIPT; File commandFile = new File(command); - LOG.info("\n> Restarting drillbits"); if (commandFile.exists() && commandFile.canExecute()) { + LOG.info("\n> Executing Post Build Script"); LOG.info("\n>> Path: " + command); exitCode = Utils.execCmd(command).exitCode; if (exitCode != 0) { LOG.error("\n>> Error restarting drillbits"); } - } else { - LOG.error("\n>> Script (" + command + ") does not exist or cannot be executed"); } return exitCode; } diff --git a/framework/src/main/java/org/apache/drill/test/framework/TestVerifier.java b/framework/src/main/java/org/apache/drill/test/framework/TestVerifier.java index c5731878a..b700eaec4 100755 --- a/framework/src/main/java/org/apache/drill/test/framework/TestVerifier.java +++ b/framework/src/main/java/org/apache/drill/test/framework/TestVerifier.java @@ -49,7 +49,7 @@ * */ public class TestVerifier { - private static final Logger LOG = Logger.getLogger(TestVerifier.class); + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); private static final int MAX_MISMATCH_SIZE = 10; public TestStatus testStatus = TestStatus.PENDING; private int mapSize = 0; diff --git a/framework/src/main/java/org/apache/drill/test/framework/Utils.java b/framework/src/main/java/org/apache/drill/test/framework/Utils.java index ba93e7d6a..2d95f7cba 100755 --- a/framework/src/main/java/org/apache/drill/test/framework/Utils.java +++ b/framework/src/main/java/org/apache/drill/test/framework/Utils.java @@ -72,7 +72,7 @@ * */ public class Utils { - private static final Logger LOG = Logger.getLogger(Utils.class); + private static final Logger LOG = Logger.getLogger("DrillTestLogger"); private static final Map sqlTypes; private static final Map sqlNullabilities; private static HttpClient client; @@ -603,14 +603,16 @@ public static String getExistingDrillStoragePlugin(String ipAddress, * @throws InterruptedException */ public static void updateDrillStoragePlugins(String templatePath) throws InterruptedException { - LOG.info(">> Path: " + templatePath + "\n"); + LOG.info("\n>> Path: " + templatePath + "\n"); File[] templateFiles = new File(templatePath).listFiles(); for (File templateFile : templateFiles) { String filename = templateFile.getName(); LOG.info(">> Updating File: " + filename); String pluginType = filename.substring(0, filename.indexOf('-')); boolean isSuccess = Utils.updateDrillStoragePlugin(templateFile.getAbsolutePath(), pluginType, DrillTestDefaults.FS_MODE); - LOG.info(">> Update file " + filename + (isSuccess ? " succeeded" : " failed")); + if(!isSuccess){ + LOG.info(">> Update file " + filename + " failed"); + } Thread.sleep(200); } }