From bd0c4912630ab7e4a2045d576bf60541f5aab93c Mon Sep 17 00:00:00 2001 From: dragonmacher <48328597+dragonmacher@users.noreply.github.com> Date: Wed, 19 Jul 2023 12:47:47 -0400 Subject: [PATCH] GP-3615 - Added a test harness method to make it easier to change log output from a test. The test harness will reset any changes made at the end of the test. --- .../widgets/table/SelectionManagerTest.java | 12 +-- .../script/GhidraScriptMgrPlugin2Test.java | 13 +-- .../AbstractFunctionSignatureMarkupTest.java | 10 +-- .../filechooser/GhidraFileChooserTest.java | 63 +++++++------- .../generic/test/AbstractGenericTest.java | 85 ++++++++++++++++++- .../framework/LoggingInitialization.java | 29 ++++--- .../graph/job/VisualGraphJobRunnerTest.java | 45 +++++----- .../java/ghidra/framework/task/GTaskTest.java | 14 +-- .../SleighCompileRegressionTest.java | 4 +- 9 files changed, 170 insertions(+), 105 deletions(-) diff --git a/Ghidra/Features/Base/src/test.slow/java/docking/widgets/table/SelectionManagerTest.java b/Ghidra/Features/Base/src/test.slow/java/docking/widgets/table/SelectionManagerTest.java index 87164f59cf..4718eeff34 100644 --- a/Ghidra/Features/Base/src/test.slow/java/docking/widgets/table/SelectionManagerTest.java +++ b/Ghidra/Features/Base/src/test.slow/java/docking/widgets/table/SelectionManagerTest.java @@ -27,14 +27,13 @@ import java.util.concurrent.atomic.AtomicReference; import javax.swing.*; import javax.swing.table.TableModel; -import org.apache.logging.log4j.*; -import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.junit.*; import docking.widgets.filter.FilterOptions; import docking.widgets.table.threaded.ThreadedTableModelStub; import ghidra.docking.settings.Settings; -import ghidra.framework.LoggingInitialization; import ghidra.framework.plugintool.ServiceProvider; import ghidra.test.AbstractGhidraHeadedIntegrationTest; import ghidra.util.datastruct.Accumulator; @@ -55,16 +54,11 @@ public class SelectionManagerTest extends AbstractGhidraHeadedIntegrationTest { private Logger logger; - public SelectionManagerTest() { - super(); - } - @Before public void setUp() throws Exception { - LoggingInitialization.initializeLoggingSystem(); logger = LogManager.getLogger(SelectionManager.class); - Configurator.setLevel(logger.getName(), Level.DEBUG); +// setLogLevel(SelectionManager.class, Level.DEBUG); logger.trace("\n\nsetUp(): " + testName.getMethodName()); diff --git a/Ghidra/Features/Base/src/test.slow/java/ghidra/app/plugin/core/script/GhidraScriptMgrPlugin2Test.java b/Ghidra/Features/Base/src/test.slow/java/ghidra/app/plugin/core/script/GhidraScriptMgrPlugin2Test.java index 7a9f5b9f90..6dfda2a23d 100644 --- a/Ghidra/Features/Base/src/test.slow/java/ghidra/app/plugin/core/script/GhidraScriptMgrPlugin2Test.java +++ b/Ghidra/Features/Base/src/test.slow/java/ghidra/app/plugin/core/script/GhidraScriptMgrPlugin2Test.java @@ -20,8 +20,7 @@ import static org.junit.Assert.*; import java.io.*; import java.nio.file.Path; -import org.apache.logging.log4j.*; -import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.Level; import org.junit.Test; import docking.test.AbstractDockingTest; @@ -38,7 +37,6 @@ import utilities.util.FileUtilities; public class GhidraScriptMgrPlugin2Test extends AbstractGhidraScriptMgrPluginTest { public GhidraScriptMgrPlugin2Test() { - super(); } @Test @@ -150,8 +148,7 @@ public class GhidraScriptMgrPlugin2Test extends AbstractGhidraScriptMgrPluginTes assertTrue("Unable to delete class files from the user scripts directory", isEmpty); // remove all class files from the user script bin dir - File userScriptsBinDir = - getBinDirFromScriptFile(new ResourceFile(newScriptFile)).toFile(); + File userScriptsBinDir = getBinDirFromScriptFile(new ResourceFile(newScriptFile)).toFile(); File[] userScriptBinDirFiles; if (userScriptsBinDir.exists()) { userScriptBinDirFiles = userScriptsBinDir.listFiles(classFileFilter); @@ -195,8 +192,7 @@ public class GhidraScriptMgrPlugin2Test extends AbstractGhidraScriptMgrPluginTes waitForScriptCompletion(scriptID, 20000); // verify that the generated class file is placed in the default scripting home/bin - File userScriptsBinDir = - getBinDirFromScriptFile(systemScriptFile).toFile(); + File userScriptsBinDir = getBinDirFromScriptFile(systemScriptFile).toFile(); String className = scriptName.replace(".java", ".class"); File expectedClassFile = new File(userScriptsBinDir, className); @@ -251,8 +247,7 @@ public class GhidraScriptMgrPlugin2Test extends AbstractGhidraScriptMgrPluginTes public void testRenameWithTreeFilter() throws Exception { // debug - Logger logger = LogManager.getLogger(SelectionManager.class); - Configurator.setLevel(logger.getName(), Level.TRACE); + setLogLevel(SelectionManager.class, Level.TRACE); pressNewButton(); diff --git a/Ghidra/Features/VersionTracking/src/test/java/ghidra/feature/vt/api/markupitem/AbstractFunctionSignatureMarkupTest.java b/Ghidra/Features/VersionTracking/src/test/java/ghidra/feature/vt/api/markupitem/AbstractFunctionSignatureMarkupTest.java index e79b10eed5..a854a9d8aa 100644 --- a/Ghidra/Features/VersionTracking/src/test/java/ghidra/feature/vt/api/markupitem/AbstractFunctionSignatureMarkupTest.java +++ b/Ghidra/Features/VersionTracking/src/test/java/ghidra/feature/vt/api/markupitem/AbstractFunctionSignatureMarkupTest.java @@ -21,8 +21,7 @@ import static org.junit.Assert.*; import java.util.*; -import org.apache.logging.log4j.*; -import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.Level; import org.junit.After; import org.junit.Before; @@ -119,11 +118,8 @@ public abstract class AbstractFunctionSignatureMarkupTest controller = vtTestEnv.getVTController(); vtTestEnv.showTool(); - Logger functionLogger = LogManager.getLogger(FunctionDB.class); - Configurator.setLevel(functionLogger.getName(), Level.TRACE); - - Logger variableLogger = LogManager.getLogger(VariableSymbolDB.class); - Configurator.setLevel(variableLogger.getName(), Level.TRACE); + setLogLevel(FunctionDB.class, Level.TRACE); + setLogLevel(VariableSymbolDB.class, Level.TRACE); } private void disableAutoAnalysis(Program program) { diff --git a/Ghidra/Framework/Docking/src/test.slow/java/docking/widgets/filechooser/GhidraFileChooserTest.java b/Ghidra/Framework/Docking/src/test.slow/java/docking/widgets/filechooser/GhidraFileChooserTest.java index 663e318fbd..f14a5997d0 100644 --- a/Ghidra/Framework/Docking/src/test.slow/java/docking/widgets/filechooser/GhidraFileChooserTest.java +++ b/Ghidra/Framework/Docking/src/test.slow/java/docking/widgets/filechooser/GhidraFileChooserTest.java @@ -41,8 +41,7 @@ import javax.swing.table.JTableHeader; import org.apache.commons.io.FileUtils; import org.apache.commons.lang3.ArrayUtils; import org.apache.commons.lang3.StringUtils; -import org.apache.logging.log4j.*; -import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.Level; import org.junit.*; import docking.*; @@ -52,7 +51,8 @@ import docking.widgets.DropDownSelectionTextField; import docking.widgets.SpyDropDownWindowVisibilityListener; import docking.widgets.table.*; import generic.concurrent.ConcurrentQ; -import ghidra.framework.*; +import ghidra.framework.OperatingSystem; +import ghidra.framework.Platform; import ghidra.framework.preferences.Preferences; import ghidra.util.Msg; import ghidra.util.filechooser.ExtensionFileFilter; @@ -241,7 +241,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { // 3) Double-click on the root drive. // 3) Boom. - // hack: the focus listeners can trigger an editCancelled(), which is a problem in + // hack: the focus listeners can trigger an editCancelled(), which is a problem in // parallel mode DirectoryList dirlist = getListView(); removeFocusListeners(dirlist); @@ -275,7 +275,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { DirectoryList dirlist = getListView(); - // hack: the focus listeners can trigger an editCancelled(), which is a problem in + // hack: the focus listeners can trigger an editCancelled(), which is a problem in // parallel mode removeFocusListeners(dirlist); @@ -336,7 +336,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { String name = "Foo_" + Math.random(); setText(editorField, name); - // cannot use triggerEnter() here because that uses the actionPerformed() of the + // cannot use triggerEnter() here because that uses the actionPerformed() of the // text field and our editor uses a key listener triggerEnter(editorField); waitForSwing(); @@ -698,7 +698,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { setMode(FILES_AND_DIRECTORIES); DirectoryList dirlist = getListView(); - // hack: the focus listeners can trigger an editCancelled(), which is a problem in + // hack: the focus listeners can trigger an editCancelled(), which is a problem in // parallel mode removeFocusListeners(dirlist); @@ -864,8 +864,8 @@ public class GhidraFileChooserTest extends AbstractDockingTest { @Test public void testDirectoryInFileOnlyMode_Selection_NoTextFieldText() throws Exception { - /* - * test when a user single clicks a directory name and clicks the action button + /* + * test when a user single clicks a directory name and clicks the action button * when the filename text field is empty */ @@ -892,8 +892,8 @@ public class GhidraFileChooserTest extends AbstractDockingTest { @Test public void testDirectoryInFileOnlyMode_Selection_WithTextFieldText() throws Exception { - /* - * test when a user single clicks a directory name and clicks the action button + /* + * test when a user single clicks a directory name and clicks the action button * when the filename text field has a value */ @@ -1351,7 +1351,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { } /* - * Tests GhidraFileChooser's Desktop button to ensure it changes to the user's native + * Tests GhidraFileChooser's Desktop button to ensure it changes to the user's native * desktop directory. This test is skipped if there is no native desktop directory. */ @Test @@ -1372,13 +1372,13 @@ public class GhidraFileChooserTest extends AbstractDockingTest { } /* - * Tests GhidraFileChooser's Desktop button to ensure it is disabled when there is no + * Tests GhidraFileChooser's Desktop button to ensure it is disabled when there is no * user Desktop directory */ @Test public void testMissingDesktop() throws Exception { - // close existing chooser window so we can make a new special one + // close existing chooser window so we can make a new special one runSwing(() -> chooser.close()); waitForSwing(); @@ -1405,7 +1405,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { } /* - * Tests GhidraFileChooser's Desktop button to ensure it is works by creating a + * Tests GhidraFileChooser's Desktop button to ensure it is works by creating a * fake user desktop directory. */ @Test @@ -1556,9 +1556,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { // // Enable tracing to catch odd test failure - LoggingInitialization.initializeLoggingSystem(); - Logger logger = LogManager.getLogger(GhidraFileChooser.class); - Configurator.setLevel(logger.getName(), Level.TRACE); + setLogLevel(GhidraFileChooser.class, Level.TRACE); final JComponent component = chooser.getComponent(); Dimension originalSize = component.getSize(); @@ -1591,9 +1589,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { // // Enable tracing to catch odd test failure - LoggingInitialization.initializeLoggingSystem(); - Logger logger = LogManager.getLogger(GhidraFileChooser.class); - Configurator.setLevel(logger.getName(), Level.TRACE); + setLogLevel(GhidraFileChooser.class, Level.TRACE); JComponent component = chooser.getComponent(); EmptyBorderToggleButton detailsButton = @@ -1621,7 +1617,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { @Test public void testFilenameAutoLookup_InTable() throws Exception { - // Note: the table auto lookup is tested elsewhere. This test is just making sure that + // Note: the table auto lookup is tested elsewhere. This test is just making sure that // the feature responds within the file chooser. // dir file names start with 'a_...', 'b_...', etc @@ -1899,9 +1895,9 @@ public class GhidraFileChooserTest extends AbstractDockingTest { File file = files.files.get(0); selectFiles(file); - // + // // A single file selection will set the text field text - // + // waitForChooser(); String filenameFieldText = getFilenameFieldText(); assertEquals("Filename text field not updated upon file selection", file.getName(), @@ -1909,7 +1905,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { // // A multi-selection will clear the text field text - // + // selectFiles(files.files); waitForChooser(); filenameFieldText = getFilenameFieldText(); @@ -1918,7 +1914,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { // // Clear the multi-selection; a single file selection will set the text field text - // + // selectFiles(file); waitForChooser(); filenameFieldText = getFilenameFieldText(); @@ -2045,8 +2041,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { // debug code if (expected != actual) { - waitForCondition(() -> expected == actual, - "Wrong list index selected "); + waitForCondition(() -> expected == actual, "Wrong list index selected "); } } @@ -2119,8 +2114,8 @@ public class GhidraFileChooserTest extends AbstractDockingTest { } private void setTableMode() { - AbstractButton button = (AbstractButton) findComponentByName(chooser.getComponent(), - "DETAILS_BUTTON"); + AbstractButton button = + (AbstractButton) findComponentByName(chooser.getComponent(), "DETAILS_BUTTON"); boolean isSelected = runSwing(() -> button.isSelected()); if (!isSelected) { // toggle from the table 'details mode' @@ -2129,8 +2124,8 @@ public class GhidraFileChooserTest extends AbstractDockingTest { } private void setListMode() { - AbstractButton button = (AbstractButton) findComponentByName(chooser.getComponent(), - "DETAILS_BUTTON"); + AbstractButton button = + (AbstractButton) findComponentByName(chooser.getComponent(), "DETAILS_BUTTON"); boolean isSelected = runSwing(() -> button.isSelected()); if (isSelected) { // toggle from the table 'details mode' @@ -2343,7 +2338,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { // Batch mode has focus issue when running in parallel. In this case, update // the drop-down field to disable closing the popup window during focus changes. By // only doing this in batch mode, the test can still be run by a developer with - // the normal behavior. + // the normal behavior. return; } @@ -2884,7 +2879,7 @@ public class GhidraFileChooserTest extends AbstractDockingTest { //================================================================================================== // Inner Classes -//================================================================================================== +//================================================================================================== /** Simple container class for newly created dirs and files */ private class TestFiles { diff --git a/Ghidra/Framework/Generic/src/main/java/generic/test/AbstractGenericTest.java b/Ghidra/Framework/Generic/src/main/java/generic/test/AbstractGenericTest.java index edb1480f8f..1c240ba8fb 100644 --- a/Ghidra/Framework/Generic/src/main/java/generic/test/AbstractGenericTest.java +++ b/Ghidra/Framework/Generic/src/main/java/generic/test/AbstractGenericTest.java @@ -15,6 +15,8 @@ */ package generic.test; +import static org.junit.Assert.*; + import java.awt.*; import java.awt.image.BufferedImage; import java.io.*; @@ -27,6 +29,12 @@ import java.util.regex.Pattern; import javax.swing.SwingUtilities; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.config.*; +import org.junit.After; import org.junit.Rule; import org.junit.rules.*; import org.junit.runner.Description; @@ -36,8 +44,7 @@ import generic.test.rule.Repeated; import generic.test.rule.RepeatedTestRule; import generic.util.WindowUtilities; import ghidra.GhidraTestApplicationLayout; -import ghidra.framework.Application; -import ghidra.framework.ApplicationConfiguration; +import ghidra.framework.*; import ghidra.util.Msg; import ghidra.util.SystemUtilities; import ghidra.util.exception.AssertException; @@ -67,6 +74,8 @@ public abstract class AbstractGenericTest extends AbstractGTest { private volatile boolean hasFailed; + private boolean logSettingsChanged; + public TestWatcher watchman = new TestWatcher() { @Override @@ -114,6 +123,13 @@ public abstract class AbstractGenericTest extends AbstractGTest { @Rule public TestRule repeatedRule = new RepeatedTestRule(); + @After + public void resetLogging() { + if (logSettingsChanged) { + LoggingInitialization.reinitialize(); + } + } + private void debugBatch(String message) { if (BATCH_MODE) { Msg.debug(AbstractGenericTest.class, message); @@ -232,6 +248,71 @@ public abstract class AbstractGenericTest extends AbstractGTest { // perform diagnostic stuff here when a test has failed } + /** + * A convenience method for {@link #setLogLevel(String, Level)}. + * + * @param loggerClazz the logger class + * @param newLevel the new level + */ + protected void setLogLevel(Class loggerClazz, Level newLevel) { + setLogLevel(loggerClazz.getName(), newLevel); + } + + /** + * A convenience method to change the log level of the given logger name. The logger name is + * typically the class name that contains specialized logging. You may also pass a package + * name to get logging for all classes in that package. + * See {@link Configurator#setLevel(String, Level)} + *

+ * The console appender's log level will be changed if needed to ensure that messages for the + * given log level are displayed. + *

+ * The log system will be reset to the default settings when the test is finished. + * + * @param loggerName the logger name + * @param newLevel the new log level to use + */ + protected void setLogLevel(String loggerName, Level newLevel) { + + logSettingsChanged = true; + + Configurator.setLevel(loggerName, newLevel); + + LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false); + Configuration configuration = loggerContext.getConfiguration(); + LoggerConfig rootLoggerConfiguration = configuration.getLoggers().get(""); + + AppenderRef consoleAppender = getConsoleAppender(configuration, rootLoggerConfiguration); + Level currentLevel = consoleAppender.getLevel(); + if (currentLevel.compareTo(newLevel) > 0) { + // the requested level is lower than the current level, so the messages will be shown + return; + } + + // Note: we have to tell the console appender to change its level as well. Otherwise, users + // may not see their messages in the console. It is set to DEBUG by default. + String consoleAppenderName = "console"; + rootLoggerConfiguration.removeAppender(consoleAppenderName); + Appender appender = configuration.getAppender(consoleAppenderName); + rootLoggerConfiguration.addAppender(appender, newLevel, null); + loggerContext.updateLoggers(); + } + + private AppenderRef getConsoleAppender(Configuration configuration, + LoggerConfig rootLoggerConfigiguration) { + String consoleAppenderName = "console"; + List appenders = rootLoggerConfigiguration.getAppenderRefs(); + for (AppenderRef ref : appenders) { + String refName = ref.getRef(); + if (refName.equals(consoleAppenderName)) { + return ref; + } + } + + fail("Unable to find the logging console appender"); + return null; + } + /** * Returns the window parent of c. If c is a window, then c is returned. * diff --git a/Ghidra/Framework/Generic/src/main/java/ghidra/framework/LoggingInitialization.java b/Ghidra/Framework/Generic/src/main/java/ghidra/framework/LoggingInitialization.java index 36a04c5d4c..fe7b5fe740 100644 --- a/Ghidra/Framework/Generic/src/main/java/ghidra/framework/LoggingInitialization.java +++ b/Ghidra/Framework/Generic/src/main/java/ghidra/framework/LoggingInitialization.java @@ -152,9 +152,9 @@ public class LoggingInitialization { } /** - * Use this to override the default application log file, before you initialize the logging + * Use this to override the default application log file, before you initialize the logging * system. - * + * * @param file The file to use as the application log file */ synchronized static void setApplicationLogFile(File file) { @@ -167,13 +167,12 @@ public class LoggingInitialization { } APPLICATION_LOG_FILE = file; - // Need to set the system property that the log4j2 configuration reads in order to - // determine the log file name. Once that's set, the log configuration must be 'kicked' to + // Need to set the system property that the log4j2 configuration reads in order to + // determine the log file name. Once that's set, the log configuration must be 'kicked' to // pick up the change. System.setProperty("logFilename", file.getAbsolutePath()); - if (INITIALIZED) { - ((LoggerContext) LogManager.getContext(false)).reconfigure(); - } + + reinitialize(); } /** @@ -191,7 +190,7 @@ public class LoggingInitialization { /** * Use this to override the default application log file, before you * initialize the logging system. - * + * * @param file The file to use as the application log file */ synchronized static void setScriptLogFile(File file) { @@ -204,11 +203,21 @@ public class LoggingInitialization { } SCRIPT_LOG_FILE = file; - // Need to set the system property that the log4j2 configuration reads in order to - // determine the script log file name. Once that's set, the log configuration must be + // Need to set the system property that the log4j2 configuration reads in order to + // determine the script log file name. Once that's set, the log configuration must be // 'kicked' to pick up the change. System.setProperty("scriptLogFilename", file.getAbsolutePath()); + reinitialize(); + } + + /** + * Signals to reload the log settings from the log configuration files in use. This is useful + * for tests that wish to temporarily change log settings, restoring them when done. + *

+ * This method will do nothing if {@link #initializeLoggingSystem()} has not been called. + */ + public synchronized static void reinitialize() { if (INITIALIZED) { ((LoggerContext) LogManager.getContext(false)).reconfigure(); } diff --git a/Ghidra/Framework/Graph/src/test.slow/java/ghidra/graph/job/VisualGraphJobRunnerTest.java b/Ghidra/Framework/Graph/src/test.slow/java/ghidra/graph/job/VisualGraphJobRunnerTest.java index ba286a0054..caef81907b 100644 --- a/Ghidra/Framework/Graph/src/test.slow/java/ghidra/graph/job/VisualGraphJobRunnerTest.java +++ b/Ghidra/Framework/Graph/src/test.slow/java/ghidra/graph/job/VisualGraphJobRunnerTest.java @@ -28,7 +28,6 @@ import org.junit.*; import generic.test.AbstractGTest; import generic.test.AbstractGuiTest; -import ghidra.framework.LoggingInitialization; import ghidra.util.Msg; import ghidra.util.SystemUtilities; import ghidra.util.datastruct.WeakDataStructureFactory; @@ -40,7 +39,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { // something reasonable: too large makes the test slower; too small, then the test can timeout private static final int RUN_TIME_MILLIS_JOB_THREAD_MAX = 1000; - // keep this relatively low, since non-shortcut-able jobs run to completion + // keep this relatively low, since non-shortcut-able jobs run to completion private static final int RUN_TIME_MILLIS_NON_SHORTCUTTABLE = 1000; private static final int RUN_TIME_MILLIS_FOR_JOB_TO_GET_STARTED = DEFAULT_WAIT_TIMEOUT; @@ -57,20 +56,14 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { System.setProperty(SystemUtilities.HEADLESS_PROPERTY, "false"); - LoggingInitialization.initializeLoggingSystem(); logger = LogManager.getLogger(GraphJobRunner.class); - // enable tracing for debugging (note: this still requires the active log4j file - // to have the 'console' appender set to 'TRACE' -// Configurator.setLevel(logger.getName(), org.apache.logging.log4j.Level.TRACE); -// -// Logger myLogger = LogManager.getLogger(VisualGraphJobRunnerTest.class); -// Configurator.setLevel(myLogger.getName(), org.apache.logging.log4j.Level.TRACE); + // use this to see the tracing output + // setLogLevel("ghidra.graph.job", Level.TRACE); } @After public void tearDown() { - for (JobExecutionThread t : jobThreads) { t.killThread(); } @@ -78,6 +71,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { @Test public void testRunJob() { + BasicJob basicJob = new BasicJob(); schedule(basicJob); waitForJobToStart(basicJob); @@ -102,7 +96,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { @Test public void testRunJobShortCutsRunningJob() { // - // Test that running a new job will shortcut any currently running job that is + // Test that running a new job will shortcut any currently running job that is // shortcut-able // @@ -125,7 +119,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { @Test public void testRunJobDoesNotShortCutJobsThatCannotBeShortcut() { // - // Test that running a new job will not shortcut any currently running job that is + // Test that running a new job will not shortcut any currently running job that is // not shortcut-able // @@ -146,7 +140,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { @Test public void testRunJobShortCutsQueuedJobsButLastOne() { - // + // // Test that we can add many jobs and that they all will be shortcut except for the last // one, which will be executed. // @@ -177,7 +171,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { @Test public void testSchedule_ShortCutsQueuedJobs_ButNotThoseThatCannotBeShortcutOrThoseThatFollow() { - // + // // Test that we can add many jobs, with some in the middle that are not shortcut-able. // We expect those before that element to be shortcut. Those after that element should // be run. @@ -399,7 +393,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { jobRunner.schedule(pending2); // - // At this point, the latch job is waiting for us to signal a finish. We will not + // At this point, the latch job is waiting for us to signal a finish. We will not // call finish, but instead, dispose the queue. // jobRunner.dispose(); @@ -431,7 +425,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { //================================================================================================== // Private Methods -//================================================================================================== +//================================================================================================== private void schedule(GraphJob job) { jobRunner.schedule(job); @@ -461,7 +455,17 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { } } - logger.trace("\n\n\t@Test - done waiting\n\n"); + // The job may already be finished while the thread is busy cleaning up. We need to wait + // for the thread to be finished as well. + waitForJobThreads(); + + logger.trace("\n\n\t@Test - done waiting - is busy?: " + jobRunner.isBusy() + "\n\n"); + } + + private void waitForJobThreads() { + for (JobExecutionThread t : jobThreads) { + waitFor(() -> t.isFinished); + } } private void assertFinishedAndShortcut(AbstractTestGraphJob... jobs) { @@ -796,7 +800,6 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { private class NonShortcuttableJob extends TimeBasedJob { NonShortcuttableJob() { - super(); } NonShortcuttableJob(long runtime) { @@ -814,7 +817,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { } } - // A job that will block until told to proceed, which allows this test to manipulate how + // A job that will block until told to proceed, which allows this test to manipulate how // the job runner queue get managed; this job will actually block the job queue private class NonShortcuttableLatchJob extends AbstractTestGraphJob { @@ -857,7 +860,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { } } - // A job that will block until told to proceed, which allows this test to manipulate how + // A job that will block until told to proceed, which allows this test to manipulate how // the job runner queue get managed; this job will actually block the job queue private class ShortcuttableLatchJob extends AbstractTestGraphJob { @@ -865,7 +868,7 @@ public class VisualGraphJobRunnerTest extends AbstractGuiTest { @Override public boolean canShortcut() { - // this class needs to be shortcut-able so that the job runner being tested + // this class needs to be shortcut-able so that the job runner being tested // will attempt to shortcut it return true; } diff --git a/Ghidra/Framework/Project/src/test/java/ghidra/framework/task/GTaskTest.java b/Ghidra/Framework/Project/src/test/java/ghidra/framework/task/GTaskTest.java index ef81f624e5..26415348f8 100644 --- a/Ghidra/Framework/Project/src/test/java/ghidra/framework/task/GTaskTest.java +++ b/Ghidra/Framework/Project/src/test/java/ghidra/framework/task/GTaskTest.java @@ -23,8 +23,7 @@ import java.util.List; import java.util.concurrent.CountDownLatch; import java.util.concurrent.TimeUnit; -import org.apache.logging.log4j.*; -import org.apache.logging.log4j.core.config.Configurator; +import org.apache.logging.log4j.Level; import org.junit.*; import generic.concurrent.GThreadPool; @@ -46,7 +45,6 @@ public class GTaskTest extends AbstractGenericTest { }; public GTaskTest() { - super(); } @Before @@ -420,8 +418,7 @@ public class GTaskTest extends AbstractGenericTest { public void testExceptionInTaskListenerTaskCompleted() { // disable printing of exception below - Logger logger = LogManager.getLogger(GTaskManager.class); - Configurator.setLevel(logger.getName(), Level.OFF); + setLogLevel(GTaskManager.class, Level.OFF); gTaskManager.addTaskListener(new GTaskListenerAdapter() { @Override @@ -434,16 +431,13 @@ public class GTaskTest extends AbstractGenericTest { // this is testing that the exception does cause the taskManager to timeout still busy waitForTaskManager(); - - Configurator.setLevel(logger.getName(), Level.DEBUG); } @Test public void testExceptionInTaskListenerTaskStarted() { // disable printing of exception below - Logger logger = LogManager.getLogger(GTaskManager.class); - Configurator.setLevel(logger.getName(), Level.OFF); + setLogLevel(GTaskManager.class, Level.OFF); gTaskManager.addTaskListener(new GTaskListenerAdapter() { @Override @@ -456,8 +450,6 @@ public class GTaskTest extends AbstractGenericTest { // this is testing that the exception does cause the taskManager to timeout still busy waitForTaskManager(); - - Configurator.setLevel(logger.getName(), Level.DEBUG); } private void cancelCurrentTask() { diff --git a/Ghidra/Test/IntegrationTest/src/test.slow/java/ghidra/pcodeCPort/slgh_compile/regression/SleighCompileRegressionTest.java b/Ghidra/Test/IntegrationTest/src/test.slow/java/ghidra/pcodeCPort/slgh_compile/regression/SleighCompileRegressionTest.java index 6fe4024ff5..3b854a2620 100644 --- a/Ghidra/Test/IntegrationTest/src/test.slow/java/ghidra/pcodeCPort/slgh_compile/regression/SleighCompileRegressionTest.java +++ b/Ghidra/Test/IntegrationTest/src/test.slow/java/ghidra/pcodeCPort/slgh_compile/regression/SleighCompileRegressionTest.java @@ -19,7 +19,8 @@ package ghidra.pcodeCPort.slgh_compile.regression; import static org.junit.Assert.*; import java.io.*; -import java.util.*; +import java.util.Iterator; +import java.util.List; import java.util.regex.Pattern; import org.antlr.runtime.RecognitionException; @@ -66,7 +67,6 @@ public class SleighCompileRegressionTest extends AbstractGenericTest { StringBuffer summary = new StringBuffer(); - LoggingInitialization.initializeLoggingSystem(); List inputs = getSlaspecFiles(); Iterator ii = inputs.iterator();