brooklyn-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From aleds...@apache.org
Subject [1/2] brooklyn-server git commit: Test framework: avoid repeated stacktrace logging
Date Thu, 01 Dec 2016 16:19:17 GMT
Repository: brooklyn-server
Updated Branches:
  refs/heads/master 615c63574 -> bfaaa909e


Test framework: avoid repeated stacktrace logging


Project: http://git-wip-us.apache.org/repos/asf/brooklyn-server/repo
Commit: http://git-wip-us.apache.org/repos/asf/brooklyn-server/commit/816dc56a
Tree: http://git-wip-us.apache.org/repos/asf/brooklyn-server/tree/816dc56a
Diff: http://git-wip-us.apache.org/repos/asf/brooklyn-server/diff/816dc56a

Branch: refs/heads/master
Commit: 816dc56a6eec32f426b5d6a758e4b8890d523e3e
Parents: b11c87d
Author: Aled Sage <aled.sage@gmail.com>
Authored: Thu Dec 1 11:39:40 2016 +0000
Committer: Aled Sage <aled.sage@gmail.com>
Committed: Thu Dec 1 16:16:19 2016 +0000

----------------------------------------------------------------------
 .../brooklyn/test/framework/TestSensorTest.java | 62 +++++++++++++++++++-
 .../org/apache/brooklyn/test/LogWatcher.java    | 24 +++++++-
 .../apache/brooklyn/util/repeat/Repeater.java   |  9 ++-
 3 files changed, 92 insertions(+), 3 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/816dc56a/test-framework/src/test/java/org/apache/brooklyn/test/framework/TestSensorTest.java
----------------------------------------------------------------------
diff --git a/test-framework/src/test/java/org/apache/brooklyn/test/framework/TestSensorTest.java
b/test-framework/src/test/java/org/apache/brooklyn/test/framework/TestSensorTest.java
index d0a5ebc..906b25f 100644
--- a/test-framework/src/test/java/org/apache/brooklyn/test/framework/TestSensorTest.java
+++ b/test-framework/src/test/java/org/apache/brooklyn/test/framework/TestSensorTest.java
@@ -19,6 +19,9 @@
 
 package org.apache.brooklyn.test.framework;
 
+import static org.testng.Assert.assertEquals;
+import static org.testng.Assert.assertTrue;
+
 import java.util.ArrayList;
 import java.util.List;
 import java.util.Map;
@@ -28,20 +31,25 @@ import java.util.concurrent.Executors;
 import org.apache.brooklyn.api.entity.Entity;
 import org.apache.brooklyn.api.entity.EntitySpec;
 import org.apache.brooklyn.api.location.Location;
+import org.apache.brooklyn.api.mgmt.Task;
 import org.apache.brooklyn.api.sensor.AttributeSensor;
 import org.apache.brooklyn.core.config.ConfigKeys;
 import org.apache.brooklyn.core.entity.Attributes;
 import org.apache.brooklyn.core.entity.Entities;
 import org.apache.brooklyn.core.entity.EntityAsserts;
 import org.apache.brooklyn.core.entity.lifecycle.Lifecycle;
+import org.apache.brooklyn.core.entity.trait.Startable;
 import org.apache.brooklyn.core.sensor.AttributeSensorAndConfigKey;
 import org.apache.brooklyn.core.sensor.Sensors;
 import org.apache.brooklyn.core.test.BrooklynAppUnitTestSupport;
 import org.apache.brooklyn.core.test.entity.TestApplication;
 import org.apache.brooklyn.core.test.entity.TestEntity;
 import org.apache.brooklyn.test.Asserts;
+import org.apache.brooklyn.test.LogWatcher;
+import org.apache.brooklyn.test.LogWatcher.EventPredicates;
 import org.apache.brooklyn.util.exceptions.Exceptions;
 import org.apache.brooklyn.util.exceptions.PropagatedRuntimeException;
+import org.apache.brooklyn.util.repeat.Repeater;
 import org.apache.brooklyn.util.text.Identifiers;
 import org.apache.brooklyn.util.time.Duration;
 import org.apache.brooklyn.util.time.Time;
@@ -50,11 +58,14 @@ import org.testng.annotations.AfterMethod;
 import org.testng.annotations.BeforeMethod;
 import org.testng.annotations.Test;
 
+import com.google.common.base.Predicate;
 import com.google.common.base.Predicates;
 import com.google.common.collect.ImmutableList;
 import com.google.common.collect.ImmutableMap;
 import com.google.common.collect.Iterables;
 
+import ch.qos.logback.classic.spi.ILoggingEvent;
+
 public class TestSensorTest extends BrooklynAppUnitTestSupport {
 
     private static final AttributeSensorAndConfigKey<Boolean, Boolean> BOOLEAN_SENSOR
= ConfigKeys.newSensorAndConfigKey(Boolean.class, "boolean-sensor", "Boolean Sensor");
@@ -332,6 +343,55 @@ public class TestSensorTest extends BrooklynAppUnitTestSupport {
         assertStartFails(app, NullPointerException.class, Asserts.DEFAULT_LONG_TIMEOUT);
     }
 
+    @Test
+    public void testDoesNotLogStacktraceRepeatedly() throws Exception {
+        final long time = System.currentTimeMillis();
+        final String sensorValue = String.format("%s%s%s", Identifiers.makeRandomId(8), time,
Identifiers.makeRandomId(8));
+        
+        // Test case will repeatedly fail until we have finished our logging assertions.
+        // Then we'll let it complete by setting the sensor.
+        TestSensor testCase = app.createAndManageChild(EntitySpec.create(TestSensor.class)
+                .configure(TestSensor.TIMEOUT, Asserts.DEFAULT_LONG_TIMEOUT)
+                .configure(TestSensor.TARGET_ENTITY, app)
+                .configure(TestSensor.SENSOR_NAME, STRING_SENSOR.getName())
+                .configure(TestSensor.ASSERTIONS, newListAssertion("matches", String.format(".*%s.*",
time))));
+
+        String loggerName = Repeater.class.getName();
+        ch.qos.logback.classic.Level logLevel = ch.qos.logback.classic.Level.DEBUG;
+        Predicate<ILoggingEvent> repeatedFailureMsgMatcher = EventPredicates.containsMessage("repeated
failure; excluding stacktrace");
+        Predicate<ILoggingEvent> stacktraceMatcher = EventPredicates.containsExceptionStackLine(TestFrameworkAssertions.class,
"checkActualAgainstAssertions");
+        Predicate<ILoggingEvent> filter = Predicates.or(repeatedFailureMsgMatcher,
stacktraceMatcher);
+        LogWatcher watcher = new LogWatcher(loggerName, logLevel, filter);
+
+        watcher.start();
+        try {
+            // Invoke async; will let it complete after we see the log messages we expect
+            Task<?> task = Entities.invokeEffector(app, app, Startable.START, ImmutableMap.of("locations",
locs));
+
+            // Expect "excluding stacktrace" message at least once
+            List<ILoggingEvent> repeatedFailureMsgEvents = watcher.assertHasEventEventually(repeatedFailureMsgMatcher);
+            assertTrue(repeatedFailureMsgEvents.size() > 0, "repeatedFailureMsgEvents="+repeatedFailureMsgEvents.size());
+
+            // Expect stacktrace just once
+            List<ILoggingEvent> stacktraceEvents = watcher.assertHasEventEventually(stacktraceMatcher);
+            assertEquals(Integer.valueOf(stacktraceEvents.size()), Integer.valueOf(1), "stacktraceEvents="+stacktraceEvents.size());
+            
+            //Set STRING sensor
+            app.sensors().set(STRING_SENSOR, sensorValue);
+            task.get(Asserts.DEFAULT_LONG_TIMEOUT);
+            
+            assertTestSensorSucceeds(testCase);
+            
+            // And for good measure (in case we just checked too early last time), check
again 
+            // that we didn't get another stacktrace
+            stacktraceEvents = watcher.getEvents(stacktraceMatcher);
+            assertEquals(Integer.valueOf(stacktraceEvents.size()), Integer.valueOf(1), "stacktraceEvents="+stacktraceEvents.size());
+            
+        } finally {
+            watcher.close();
+        }
+    }
+
     protected void assertStartFails(TestApplication app, Class<? extends Throwable>
clazz) throws Exception {
         assertStartFails(app, clazz, null);
     }
@@ -360,7 +420,7 @@ public class TestSensorTest extends BrooklynAppUnitTestSupport {
         Entity entity = Iterables.find(Entities.descendantsWithoutSelf(app), Predicates.instanceOf(TestSensor.class));
         assertTestSensorFails((TestSensor) entity);
     }
-
+    
     protected void assertTestSensorSucceeds(TestSensor entity) {
         EntityAsserts.assertAttributeEqualsEventually(entity, Attributes.SERVICE_STATE_ACTUAL,
Lifecycle.RUNNING);
         EntityAsserts.assertAttributeEqualsEventually(entity, Attributes.SERVICE_UP, true);

http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/816dc56a/test-support/src/main/java/org/apache/brooklyn/test/LogWatcher.java
----------------------------------------------------------------------
diff --git a/test-support/src/main/java/org/apache/brooklyn/test/LogWatcher.java b/test-support/src/main/java/org/apache/brooklyn/test/LogWatcher.java
index 6baa852..ba29ad7 100644
--- a/test-support/src/main/java/org/apache/brooklyn/test/LogWatcher.java
+++ b/test-support/src/main/java/org/apache/brooklyn/test/LogWatcher.java
@@ -26,6 +26,7 @@ import java.io.Closeable;
 import java.util.Collections;
 import java.util.List;
 import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.concurrent.atomic.AtomicReference;
 
 import org.mockito.Mockito;
 import org.mockito.invocation.InvocationOnMock;
@@ -36,6 +37,7 @@ import org.slf4j.LoggerFactory;
 import com.google.common.annotations.Beta;
 import com.google.common.base.Predicate;
 import com.google.common.collect.ImmutableList;
+import com.google.common.collect.Iterables;
 import com.google.common.collect.Lists;
 
 import ch.qos.logback.classic.Level;
@@ -134,11 +136,25 @@ public class LogWatcher implements Closeable {
         assertFalse(events.isEmpty());
     }
 
-    public void assertHasEventEventually() {
+    public List<ILoggingEvent> assertHasEventEventually() {
         Asserts.succeedsEventually(new Runnable() {
             public void run() {
                 assertFalse(events.isEmpty());
             }});
+        return getEvents();
+    }
+
+    public List<ILoggingEvent> assertHasEventEventually(final Predicate<? super
ILoggingEvent> filter) {
+        final AtomicReference<List<ILoggingEvent>> result = new AtomicReference<>();
+        Asserts.succeedsEventually(new Runnable() {
+            public void run() {
+                synchronized (events) {
+                    Iterable<ILoggingEvent> filtered = Iterables.filter(events, filter);
+                    assertFalse(Iterables.isEmpty(filtered));
+                    result.set(ImmutableList.copyOf(filtered));
+                }
+            }});
+        return result.get();
     }
 
     public List<ILoggingEvent> getEvents() {
@@ -146,4 +162,10 @@ public class LogWatcher implements Closeable {
             return ImmutableList.copyOf(events);
         }
     }
+    
+    public List<ILoggingEvent> getEvents(Predicate<? super ILoggingEvent> filter)
{
+        synchronized (events) {
+            return ImmutableList.copyOf(Iterables.filter(events, filter));
+        }
+    }
 }

http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/816dc56a/utils/common/src/main/java/org/apache/brooklyn/util/repeat/Repeater.java
----------------------------------------------------------------------
diff --git a/utils/common/src/main/java/org/apache/brooklyn/util/repeat/Repeater.java b/utils/common/src/main/java/org/apache/brooklyn/util/repeat/Repeater.java
index 581a61b..a7fdc42 100644
--- a/utils/common/src/main/java/org/apache/brooklyn/util/repeat/Repeater.java
+++ b/utils/common/src/main/java/org/apache/brooklyn/util/repeat/Repeater.java
@@ -315,6 +315,7 @@ public class Repeater implements Callable<Boolean> {
         Preconditions.checkState(exitCondition != null, "until() method has not been called
to set the exit condition");
         Preconditions.checkState(delayOnIteration != null, "every() method (or other delaySupplier()
/ backoff() method) has not been called to set the loop delay");
 
+        boolean hasLoggedTransientException = false;
         Throwable lastError = null;
         int iterations = 0;
         CountdownTimer timer = timeLimit!=null ? CountdownTimer.newInstanceStarted(timeLimit)
: CountdownTimer.newInstancePaused(Duration.PRACTICALLY_FOREVER);
@@ -334,8 +335,14 @@ public class Repeater implements Callable<Boolean> {
             try {
                 lastError = null;
                 done = exitCondition.call();
+                hasLoggedTransientException = false;
             } catch (Throwable e) {
-                if (log.isDebugEnabled()) log.debug(description, e);
+                if (hasLoggedTransientException) {
+                    if (log.isDebugEnabled()) log.debug(description + " (repeated failure;
excluding stacktrace): " + e);
+                } else {
+                    if (log.isDebugEnabled()) log.debug(description, e);
+                    hasLoggedTransientException = true;
+                }
                 lastError = e;
                 if (rethrowImmediatelyCondition.apply(e)) throw Exceptions.propagate(e);
             }


Mime
View raw message