From 0f32f487990588a472e24204da685bf3f308db49 Mon Sep 17 00:00:00 2001 From: Jonathan Austin Date: Fri, 4 Oct 2024 18:37:28 +1000 Subject: [PATCH] Improve performance unit test messaging and increase padding factors to help avoid intermittent fails --- CHANGELOG.md | 1 + .../AbstractWComponentTestCase.java | 72 +++++++++++-------- .../SerializationPerformance_Test.java | 43 +++-------- .../WComponentsPerformance_Test.java | 5 +- .../WebXmlRenderingPerformance_Test.java | 25 ++++--- .../servlet/WServletPerformance_Test.java | 11 ++- .../util/HTMLSanitizerPerformance_Test.java | 10 ++- 7 files changed, 78 insertions(+), 89 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index fe762cfcd..dc5be0c01 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -19,6 +19,7 @@ * The latest version of the shade plugin used to create the examples lde dependency jar has changed how it handles the reduced pom files. The reduced pom removes all the dependencies which impacts the use of the main attached jar so its creation has been disabled. +* Improve performance unit test messaging and increase padding factors to help avoid intermittent fails. ## 1.5.35 diff --git a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/AbstractWComponentTestCase.java b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/AbstractWComponentTestCase.java index 5115cc54c..97f880d56 100755 --- a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/AbstractWComponentTestCase.java +++ b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/AbstractWComponentTestCase.java @@ -3,13 +3,6 @@ import com.github.bordertech.wcomponents.util.Duplet; import com.github.bordertech.wcomponents.util.ReflectionUtil; import com.github.bordertech.wcomponents.util.SystemException; -import org.junit.Assert; -import org.apache.commons.beanutils.PropertyUtils; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; -import org.junit.After; - -import java.io.Serializable; import java.lang.management.ManagementFactory; import java.lang.management.ThreadMXBean; import java.lang.reflect.Method; @@ -19,6 +12,11 @@ import java.util.Map; import java.util.function.BiConsumer; import java.util.function.Function; +import org.apache.commons.beanutils.PropertyUtils; +import org.apache.commons.logging.Log; +import org.apache.commons.logging.LogFactory; +import org.junit.After; +import org.junit.Assert; /** * This class includes features useful for the testing of WComponents. @@ -35,6 +33,12 @@ public abstract class AbstractWComponentTestCase { */ private static final Log LOG = LogFactory.getLog(AbstractWComponentTestCase.class); + /** + * The number of repetitions to use for testing serialization time. This should be set to be greater than the + * minimum number of invocations required to trigger JIT compilation. + */ + public static final int NUM_REPETITIONS = 2000; + /** * Creates a UI Context. * @@ -63,7 +67,7 @@ public void resetContext() { UIContextHolder.reset(); } -/** + /** * This method will test that the getter/setter methods on a component are returning the correct values in its (i) * initial state (ii) default state and (iii) user context. *

@@ -81,11 +85,11 @@ public void resetContext() { * @param userContextValue the value to be used with a user context */ protected void assertAccessorsCorrect( - final C component, - final Function getter, - final BiConsumer setter, - final T initValue, - final T defaultValue, final T userContextValue) { + final C component, + final Function getter, + final BiConsumer setter, + final T initValue, + final T defaultValue, final T userContextValue) { try { // Check initial value checkValue("", "Initial value.", initValue, getter.apply(component)); @@ -142,13 +146,13 @@ protected void assertAccessorsCorrect( * @param setterArgs the value of the setter's second argument */ protected void assertAccessorsCorrect( - final C component, - final Function getter, - final TriConsumer setter, - final T initValue, - final T defaultValue, - final T userContextValue, - final U setterArgs) { + final C component, + final Function getter, + final TriConsumer setter, + final T initValue, + final T defaultValue, + final T userContextValue, + final U setterArgs) { try { // Check initial value checkValue("", "Initial value.", initValue, getter.apply(component)); @@ -179,7 +183,7 @@ protected void assertAccessorsCorrect( // Check default value still correct checkValue("", "Reset.", defaultValue, getter.apply(component)); - + } finally { resetContext(); } @@ -207,7 +211,7 @@ private void assertComponentModelUsesDefaultOnCreation(AbstractWComponent wCompo * @param setterArgs array matching the variable argument type */ private void assertComponentModelUsesDefaultOnSameValue(AbstractWComponent wComponent, String method, - Object userContextValue, Object setterArgs[]) { + Object userContextValue, Object setterArgs[]) { wComponent.setLocked(false); // Set default model invokeSetMethod(wComponent, method, userContextValue, setterArgs); @@ -234,12 +238,12 @@ private void assertComponentModelUsesDefaultOnSameValue(AbstractWComponent wComp * * @param wComponent the component the model is being created from * @param method the method used to change the model - * @param userContextValue the value to be used within the user context. Must be different to the value stored in the - * default model for this test. + * @param userContextValue the value to be used within the user context. Must be different to the value stored in + * the default model for this test. * @param setterArgs array matching the variable argument type */ private void assertComponentModelDoesNotUseDefaultOnDifferentValue(AbstractWComponent wComponent, String method, - Object userContextValue, Object setterArgs[]) { + Object userContextValue, Object setterArgs[]) { // Create a default model using whatever values are set for the wComponent wComponent.setLocked(true); ComponentModel shared = wComponent.getDefaultModel(); @@ -263,7 +267,7 @@ private void assertComponentModelDoesNotUseDefaultOnDifferentValue(AbstractWComp * @param setterArgs array matching the variable argument type */ private void assertDuplicateUserModelNotCreatedOnSameValue(AbstractWComponent wComponent, String method, - Object userContextValue, Object setterArgs[]) { + Object userContextValue, Object setterArgs[]) { wComponent.setLocked(true); // Set the UI context and set a value to the current model @@ -300,14 +304,15 @@ protected void assertNoDuplicateComponentModels(AbstractWComponent wComponent, S } /** - * Overloading method for {@link AbstractWComponentTestCase#assertNoDuplicateComponentModels(AbstractWComponent, String, Object, Object[])}. + * Overloading method for + * {@link AbstractWComponentTestCase#assertNoDuplicateComponentModels(AbstractWComponent, String, Object, Object[])}. * * @param wComponent the component the model is being created from * @param method the method used to change the model * @param userContextValue the value to be used within the user context */ protected void assertNoDuplicateComponentModels(AbstractWComponent wComponent, String method, - Object userContextValue) { + Object userContextValue) { assertNoDuplicateComponentModels(wComponent, method, userContextValue, null); } @@ -375,6 +380,17 @@ public void run() { return result[0]; } + /** + * Asserts that first is less than second. + * + * @param text the assertion text. + * @param first the first parameter to check. + * @param second the second parameter to check. + */ + protected void assertLessThan(final String text, final long first, final long second) { + Assert.assertTrue(text + ": " + first + " < " + second, first < second); + } + /** * Modifies the component's flags. This is necessary for testing as some of the setter methods are intentionally not * visible in the public API. diff --git a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/SerializationPerformance_Test.java b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/SerializationPerformance_Test.java index 836c47c1d..ceea8ba06 100755 --- a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/SerializationPerformance_Test.java +++ b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/SerializationPerformance_Test.java @@ -19,7 +19,6 @@ import java.util.List; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; -import org.junit.Assert; import org.junit.Test; import org.junit.experimental.categories.Category; @@ -33,12 +32,6 @@ @Category(PerformanceTests.class) public class SerializationPerformance_Test extends AbstractWComponentTestCase { - /** - * The number of repetitions to use for testing serialization time. This should be set to be greater than the - * minimum number of invocations required to trigger JIT compilation. - */ - private static final int NUM_REPETITIONS = 2000; - /** * The logger instance for this class. */ @@ -59,8 +52,7 @@ public void testSerializationSize() throws Exception { LOG.info("Optimised size - clean session: " + registeredSize); LOG.info("default size - clean session: " + nonRegisteredSize); - assertLessThan("Optimised size should be smaller than default", registeredSize, - nonRegisteredSize); + assertLessThan("Optimised size should be smaller than default", registeredSize, nonRegisteredSize); // Test used session - 50% components with models createUserModels(nonRegistered, nonRegisteredContext, 50); @@ -71,8 +63,7 @@ public void testSerializationSize() throws Exception { LOG.info("Optimised size - 50% models: " + registeredSize); LOG.info("default size - 50% models: " + nonRegisteredSize); - assertLessThan("Optimised size should be smaller than default", registeredSize, - nonRegisteredSize); + assertLessThan("Optimised size should be smaller than default", registeredSize, nonRegisteredSize); // Test used session - 100% components with models createUserModels(nonRegistered, nonRegisteredContext, 100); @@ -83,8 +74,7 @@ public void testSerializationSize() throws Exception { LOG.info("Optimised size - 100% models: " + registeredSize); LOG.info("default size - 100% models: " + nonRegisteredSize); - assertLessThan("Optimised size should be smaller than default", registeredSize, - nonRegisteredSize); + assertLessThan("Optimised size should be smaller than default", registeredSize, nonRegisteredSize); } @Test @@ -117,14 +107,12 @@ public void testSerializationTime() throws Exception { UIContext registeredContext = createUIContext(); // Test clean session - long nonRegisteredTime = serializeSession(nonRegistered, nonRegisteredContext, - NUM_REPETITIONS); + long nonRegisteredTime = serializeSession(nonRegistered, nonRegisteredContext, NUM_REPETITIONS); long registeredTime = serializeSession(registered, registeredContext, NUM_REPETITIONS); LOG.info("Optimised time - clean session: " + (registeredTime / 1000000.0) + "ms"); LOG.info("default time - clean session: " + (nonRegisteredTime / 1000000.0) + "ms"); - assertLessThan("Optimised time should be less than default time", registeredTime, - nonRegisteredTime); + assertLessThan("Optimised time should be less than default time", registeredTime, nonRegisteredTime); // Test used session - 50% components with models createUserModels(nonRegistered, nonRegisteredContext, 50); @@ -135,8 +123,7 @@ public void testSerializationTime() throws Exception { LOG.info("Optimised time - 50% models: " + (registeredTime / 1000000.0) + "ms"); LOG.info("default time - 50% models: " + (nonRegisteredTime / 1000000.0) + "ms"); - assertLessThan("Optimised time should be less than default time", registeredTime, - nonRegisteredTime); + assertLessThan("Optimised time should be less than default time", registeredTime, nonRegisteredTime); // Test used session - 100% components with models createUserModels(nonRegistered, nonRegisteredContext, 100); @@ -147,8 +134,7 @@ public void testSerializationTime() throws Exception { LOG.info("Optimised time - 100% models: " + (registeredTime / 1000000.0) + "ms"); LOG.info("default time - 100% models: " + (nonRegisteredTime / 1000000.0) + "ms"); - assertLessThan("Optimised time should be less than default time", registeredTime, - nonRegisteredTime); + assertLessThan("Optimised time should be less than default time", registeredTime, nonRegisteredTime); } @Test @@ -168,7 +154,9 @@ public void testSerializationTimeScaling() throws Exception { LOG.info("Optimised time - 50% models 1x: " + (registered1Time / 1000000.0) + "ms"); LOG.info("Optimised time - 50% models 10x: " + (registered10Time / 1000000.0) + "ms"); - assertLessThan("Time scaling should be O(n)", registered10Time, registered1Time * 10); + + // Should be a factor of x10 for O(n) but use x12 as a padding factor to avoid intermittent fails + assertLessThan("Time scaling should be O(n)", registered10Time, registered1Time * 12); } /** @@ -299,17 +287,6 @@ private void findWComponents(final WComponent comp, final List resul } } - /** - * Asserts that first is less than second. - * - * @param text the assertion text. - * @param first the first parameter to check. - * @param second the second parameter to check. - */ - private static void assertLessThan(final String text, final long first, final long second) { - Assert.assertTrue(text + ": " + first + " < " + second, first < second); - } - /** * AllComponents instantiated with 10 repetitions. This needs to be created as a subclass as the UIRegistry uses the * class name. diff --git a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/WComponentsPerformance_Test.java b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/WComponentsPerformance_Test.java index 6de97037f..0cb81141a 100755 --- a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/WComponentsPerformance_Test.java +++ b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/WComponentsPerformance_Test.java @@ -70,7 +70,7 @@ public void testOtherImplementationCorrectness() throws Exception { @Test public void testRequestHandlingPerformance() throws Exception { - final int numLoops = 2000; + final int numLoops = NUM_REPETITIONS; long simpleTime = timeOtherServlet(numLoops) / numLoops; long wcomponentTime = timeWComponentProcessing(numLoops) / numLoops; @@ -78,8 +78,7 @@ public void testRequestHandlingPerformance() throws Exception { LOG.info("Simple request handling time: " + (simpleTime / 1000000.0) + "ms"); LOG.info("WComponent request handling time: " + (wcomponentTime / 1000000.0) + "ms"); - Assert.assertTrue("WComponent request handling time should not exceed 10x simple time", - wcomponentTime < simpleTime * 10); + assertLessThan("WComponent request handling time should not exceed 12x simple time", wcomponentTime, simpleTime * 12); } /** diff --git a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/render/webxml/WebXmlRenderingPerformance_Test.java b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/render/webxml/WebXmlRenderingPerformance_Test.java index 740b0db1c..bd2fb7182 100755 --- a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/render/webxml/WebXmlRenderingPerformance_Test.java +++ b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/render/webxml/WebXmlRenderingPerformance_Test.java @@ -37,12 +37,6 @@ @Category(PerformanceTests.class) public class WebXmlRenderingPerformance_Test extends AbstractWComponentTestCase { - /** - * The number of repetitions to use for testing serialization time. This should be set to be greater than the - * minimum number of invocations required to trigger JIT compilation. - */ - private static final int NUM_REPETITIONS = 2000; - /** * The logger instance for this class. */ @@ -57,9 +51,9 @@ public void testRenderingPerformance() throws Exception { // Render and store the XML to compare against setActiveContext(uic); StringWriter tempStringWriter = new StringWriter(); - PrintWriter tempPrintWriter = new PrintWriter(tempStringWriter); - component.paint(new WebXmlRenderContext(tempPrintWriter)); - tempPrintWriter.close(); + try (PrintWriter tempPrintWriter = new PrintWriter(tempStringWriter)) { + component.paint(new WebXmlRenderContext(tempPrintWriter)); + } resetContext(); // Run the test writing raw bytes to a writer - no computation necessary @@ -111,8 +105,8 @@ public void run() { LOG.info("Raw write time: " + (rawTime / 1000000.0) + "ms"); LOG.info("WComponent render time: " + (renderTime / 1000000.0) + "ms"); - Assert.assertTrue("WComponent render time should not exceed 5x raw write time", - renderTime < rawTime * 5); + + assertLessThan("WComponent render time should not exceed 6x raw write time", renderTime, rawTime * 6); } @Test @@ -162,7 +156,10 @@ public void run() { LOG.info("Render 1x time: " + (renderTime1 / 1000000.0) + "ms"); LOG.info("Render 10x time: " + (renderTime10 / 1000000.0) + "ms"); - Assert.assertTrue("Render time scaling should be O(n)", renderTime10 < renderTime1 * 12); + + // Should be a factor of x10 for O(n) but use x12 as a padding factor to avoid intermittent fails + assertLessThan("Render time scaling should be O(n)", renderTime10, renderTime1 * 12); + } @Test @@ -215,7 +212,9 @@ public void run() { LOG.info("Render Component time: " + (renderTime1 / 1000000.0) + "ms"); LOG.info("Render Component/Chain time: " + (renderTimeChain / 1000000.0) + "ms"); - Assert.assertTrue("Render with Chain time scaling should not be more than 3x.", renderTimeChain < renderTime1 * 3); + + assertLessThan("Render with Chain time scaling should not be more than 4x.", renderTimeChain, renderTime1 * 4); + } /** diff --git a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/servlet/WServletPerformance_Test.java b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/servlet/WServletPerformance_Test.java index 21007ad00..703b75a55 100755 --- a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/servlet/WServletPerformance_Test.java +++ b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/servlet/WServletPerformance_Test.java @@ -8,9 +8,9 @@ import com.github.bordertech.wcomponents.Request; import com.github.bordertech.wcomponents.UIContext; import com.github.bordertech.wcomponents.WApplication; -import com.github.bordertech.wcomponents.WContainer; import com.github.bordertech.wcomponents.WButton; import com.github.bordertech.wcomponents.WComponent; +import com.github.bordertech.wcomponents.WContainer; import com.github.bordertech.wcomponents.WLabel; import com.github.bordertech.wcomponents.WTextField; import com.github.bordertech.wcomponents.WebUtilities; @@ -102,7 +102,7 @@ public void testOtherServletAppCorrectness() throws Exception { @Test public void testServletPerformance() throws Exception { - final int numLoops = 2000; + final int numLoops = NUM_REPETITIONS; // Run the test with the simple servlet long simpleTime = timeOtherServlet(numLoops) / numLoops; @@ -111,8 +111,7 @@ public void testServletPerformance() throws Exception { LOG.info("Simple servlet time: " + (simpleTime / 1000000.0) + "ms"); LOG.info("WComponent servlet time: " + (wservletTime / 1000000.0) + "ms"); - Assert.assertTrue("WComponent servlet time should not exceed 10x simple time", - wservletTime < simpleTime * 10); + assertLessThan("WComponent servlet time should not exceed 12x simple time", wservletTime, simpleTime * 12); } /** @@ -399,12 +398,12 @@ private void doRender(final HttpServletRequest request, final HttpServletRespons "\n"); writer.print( "\n"); + getProperty(formBean, "property1") + "\"/>"); writer.print( "\n"); writer.print( "\n"); + getProperty(formBean, "property2") + "\"/>"); writer.print("\n"); writer.print("\n"); diff --git a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/util/HTMLSanitizerPerformance_Test.java b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/util/HTMLSanitizerPerformance_Test.java index 0ab0d14f3..54fc6c61d 100644 --- a/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/util/HTMLSanitizerPerformance_Test.java +++ b/wcomponents-core/src/test/java/com/github/bordertech/wcomponents/util/HTMLSanitizerPerformance_Test.java @@ -4,12 +4,12 @@ import com.github.bordertech.wcomponents.PerformanceTests; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; -import org.junit.Assert; import org.junit.Test; import org.junit.experimental.categories.Category; /** * Rudimentary performance test of HTML Sanitizer. + * * @author Mark Reeves * @since 1.2.0 */ @@ -49,7 +49,6 @@ public class HTMLSanitizerPerformance_Test extends AbstractWComponentTestCase { + "justo sapien.

"; - @Test public void testSanitizerPerformance2() { final int fewLoops = 20; @@ -61,20 +60,19 @@ public void testSanitizerPerformance2() { long fewLoopTime = fewLoopTotalTime / fewLoops; long manyLoopTime = manyLoopTotalTime / manyLoops; - LOG.info(String.valueOf(fewLoops) + " runs of sanitizer time: " + (fewLoopTotalTime / 1000000000.0) + "s"); LOG.info(String.valueOf(manyLoops) + " runs of sanitizer time: " + (manyLoopTotalTime / 1000000000.0) + "s"); LOG.info(String.valueOf(fewLoops) + " runs of sanitizer time: " + (fewLoopTime / 1000000.0) + "ms per run"); LOG.info(String.valueOf(manyLoops) + " runs of sanitizer time: " + (manyLoopTime / 1000000.0) + "ms per run"); - Assert.assertTrue("Sanitizing many entries should not exceed sanitizing few", - manyLoopTime <= fewLoopTime); - } + assertLessThan("Sanitizing many entries should not exceed sanitizing few", manyLoopTime, fewLoopTime); + } /** * run many sanitized getData calls. + * * @param count the number of loops to run * @return the time taken to run all the runnables. */