You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@brooklyn.apache.org by tb...@apache.org on 2018/02/15 10:49:25 UTC
[06/13] brooklyn-server git commit: Assert on log output
Assert on log output
Project: http://git-wip-us.apache.org/repos/asf/brooklyn-server/repo
Commit: http://git-wip-us.apache.org/repos/asf/brooklyn-server/commit/643aa9c1
Tree: http://git-wip-us.apache.org/repos/asf/brooklyn-server/tree/643aa9c1
Diff: http://git-wip-us.apache.org/repos/asf/brooklyn-server/diff/643aa9c1
Branch: refs/heads/master
Commit: 643aa9c1e4643b37ec96f7dcebfcf4cb3c78c6bd
Parents: d456333
Author: Geoff Macartney <ge...@cloudsoftcorp.com>
Authored: Fri Jan 26 17:38:34 2018 +0000
Committer: Geoff Macartney <ge...@cloudsoftcorp.com>
Committed: Fri Feb 9 21:09:20 2018 +0000
----------------------------------------------------------------------
.../core/entity/ApplicationLoggingTest.java | 51 +++++++-
.../brooklyn/logback-appender-stdout.xml | 35 -----
.../org/apache/brooklyn/test/LogWatcher.java | 131 ++++++++++++-------
3 files changed, 129 insertions(+), 88 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/643aa9c1/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java
----------------------------------------------------------------------
diff --git a/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java b/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java
index 3fc57ec..2e74593 100644
--- a/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java
+++ b/core/src/test/java/org/apache/brooklyn/core/entity/ApplicationLoggingTest.java
@@ -18,6 +18,10 @@
*/
package org.apache.brooklyn.core.entity;
+import static com.google.common.base.Predicates.and;
+import static org.apache.brooklyn.test.LogWatcher.EventPredicates.containsMessage;
+import static org.apache.brooklyn.test.LogWatcher.EventPredicates.matchesPatterns;
+
import java.util.ArrayDeque;
import java.util.Collection;
import java.util.Deque;
@@ -34,15 +38,21 @@ import org.apache.brooklyn.core.test.entity.TestApplication;
import org.apache.brooklyn.core.test.entity.TestApplicationImpl;
import org.apache.brooklyn.core.test.entity.TestEntity;
import org.apache.brooklyn.core.test.entity.TestEntityImpl;
+import org.apache.brooklyn.test.LogWatcher;
import org.apache.brooklyn.util.collections.QuorumCheck;
import org.apache.brooklyn.util.exceptions.Exceptions;
+import org.apache.brooklyn.util.text.Strings;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
-import org.slf4j.MDC;
import org.testng.annotations.Test;
+import com.google.common.base.Predicate;
+import com.google.common.base.Predicates;
import com.google.common.collect.ImmutableList;
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+
@Test
public class ApplicationLoggingTest extends BrooklynAppUnitTestSupport {
private static final Logger LOG = LoggerFactory.getLogger(ApplicationLoggingTest.class);
@@ -131,18 +141,49 @@ public class ApplicationLoggingTest extends BrooklynAppUnitTestSupport {
@Test
public void testLogging() throws Exception {
+ String loggerName = ApplicationLoggingTest.class.getName();
+ ch.qos.logback.classic.Level logLevel = ch.qos.logback.classic.Level.INFO;
Deque<String> ids = new ArrayDeque<>();
ids.push(app.getId());
final TestEntityWithLogging entity = app.createAndManageChild(EntitySpec.create(TestEntityWithLogging.class));
final TestEntityWithLogging child = entity.addChild(EntitySpec.create(EntitySpec.create(TestEntityWithLogging.class)));
- app.start(ImmutableList.of(app.newSimulatedLocation()));
- assertHealthEventually(app, Lifecycle.RUNNING, true);
- app.stop();
- assertHealthEventually(app, Lifecycle.STOPPED, false);
+ LogWatcher watcher = new LogWatcher(loggerName, logLevel, containsMessage(app.getId()));
+
+ watcher.start();
+ try {
+ app.start(ImmutableList.of(app.newSimulatedLocation()));
+ assertHealthEventually(app, Lifecycle.RUNNING, true);
+ app.stop();
+ assertHealthEventually(app, Lifecycle.STOPPED, false);
+ watcher.assertHasEvent(matchesPatterns(".*" + app.getApplicationId() + ".*Hello world.*"));
+ watcher.assertHasEvent(matchesPatterns(".*"
+ + ImmutableList.of(app.getId(), entity.getId()).toString()
+ + ".*from entity.*" + entity.getId() + ".*"));
+ watcher.assertHasEvent(matchesPatterns(".*" +
+ ImmutableList.of(app.getId(), entity.getId()).toString()
+ + ".*from entity.*" + entity.getId() + ".*"));
+ watcher.assertHasEvent(matchesPatterns(".*" +
+ ImmutableList.of(app.getId(), entity.getId(), child.getId()).toString()
+ + ".*from entity.*" + child.getId() + ".*"));
+ } finally {
+ watcher.close();
+ }
}
+ @Test
+ public void testOne() {
+ LogWatcher watcher = new LogWatcher(LOG.getName(), Level.DEBUG, Predicates.alwaysTrue());
+
+ watcher.start();
+ try {
+ LOG.error("Test message");
+ } finally {
+ watcher.close();
+ }
+ }
+
private void assertHealthEventually(Entity entity, Lifecycle expectedState, Boolean expectedUp) {
EntityAsserts.assertAttributeEqualsEventually(entity, Attributes.SERVICE_STATE_ACTUAL, expectedState);
EntityAsserts.assertAttributeEqualsEventually(entity, Attributes.SERVICE_UP, expectedUp);
http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/643aa9c1/core/src/test/resources/brooklyn/logback-appender-stdout.xml
----------------------------------------------------------------------
diff --git a/core/src/test/resources/brooklyn/logback-appender-stdout.xml b/core/src/test/resources/brooklyn/logback-appender-stdout.xml
deleted file mode 100644
index e612042..0000000
--- a/core/src/test/resources/brooklyn/logback-appender-stdout.xml
+++ /dev/null
@@ -1,35 +0,0 @@
-<?xml version="1.0" encoding="UTF-8"?>
-<!--
- Licensed to the Apache Software Foundation (ASF) under one
- or more contributor license agreements. See the NOTICE file
- distributed with this work for additional information
- regarding copyright ownership. The ASF licenses this file
- to you under the Apache License, Version 2.0 (the
- "License"); you may not use this file except in compliance
- with the License. You may obtain a copy of the License at
-
- http://www.apache.org/licenses/LICENSE-2.0
-
- Unless required by applicable law or agreed to in writing,
- software distributed under the License is distributed on an
- "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
- KIND, either express or implied. See the License for the
- specific language governing permissions and limitations
- under the License.
--->
-<included>
-
- <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
- <encoder>
- <pattern>%d %-5level %X{entity.ids} %msg%n%xEx{0}</pattern>
- </encoder>
- <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
- <level>INFO</level>
- </filter>
- </appender>
-
- <root>
- <appender-ref ref="STDOUT" />
- </root>
-
-</included>
http://git-wip-us.apache.org/repos/asf/brooklyn-server/blob/643aa9c1/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 90b87e4..16d27b0 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
@@ -24,17 +24,17 @@ import static org.testng.Assert.assertFalse;
import java.io.ByteArrayOutputStream;
import java.io.Closeable;
+import java.io.IOException;
+import java.lang.reflect.Proxy;
import java.io.PrintStream;
import java.util.Collections;
import java.util.List;
import java.util.Map;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicReference;
+import java.util.function.BiPredicate;
import org.apache.brooklyn.util.time.Time;
-import org.mockito.Mockito;
-import org.mockito.invocation.InvocationOnMock;
-import org.mockito.stubbing.Answer;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@@ -46,10 +46,12 @@ import com.google.common.collect.Lists;
import com.google.common.collect.Maps;
import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.LoggerContext;
+import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.spi.IThrowableProxy;
import ch.qos.logback.classic.spi.StackTraceElementProxy;
-import ch.qos.logback.core.Appender;
+import ch.qos.logback.core.OutputStreamAppender;
/**
* Testing utility that registers an appender to watch a given logback logger, and records events
@@ -67,35 +69,40 @@ public class LogWatcher implements Closeable {
public static Predicate<ILoggingEvent> containsMessage(final String expected) {
return containsMessages(expected);
}
-
- public static Predicate<ILoggingEvent> containsMessages(final String... expecteds) {
- return new Predicate<ILoggingEvent>() {
- @Override public boolean apply(ILoggingEvent input) {
- if (input == null) return false;
- String msg = input.getFormattedMessage();
- if (msg == null) return false;
- for (String expected : expecteds) {
- if (!msg.contains(expected)) return false;
- }
- return true;
+
+ public static Predicate<ILoggingEvent> matchPredicate(BiPredicate<String, String> pred,
+ final String... expecteds) {
+ return event -> {
+ if (event == null) return false;
+ String msg = event.getFormattedMessage();
+ if (msg == null) return false;
+ for (String expected : expecteds) {
+ if (!pred.test(msg.trim(), expected)) return false;
}
+ return true;
};
}
-
+
+ public static Predicate<ILoggingEvent> matchesPatterns(final String... patterns) {
+ return matchPredicate(String::matches, patterns);
+ }
+
+ public static Predicate<ILoggingEvent> containsMessages(final String... expecteds) {
+ return matchPredicate(String::contains, expecteds);
+ }
+
public static Predicate<ILoggingEvent> containsExceptionStackLine(final Class<?> clazz, final String methodName) {
- return new Predicate<ILoggingEvent>() {
- @Override public boolean apply(ILoggingEvent input) {
- IThrowableProxy throwable = (input != null) ? input.getThrowableProxy() : null;
- if (throwable != null) {
- for (StackTraceElementProxy line : throwable.getStackTraceElementProxyArray()) {
- if (line.getStackTraceElement().getClassName().contains(clazz.getSimpleName())
- && line.getStackTraceElement().getMethodName().contains(methodName)) {
- return true;
- }
+ return event -> {
+ IThrowableProxy throwable = (event != null) ? event.getThrowableProxy() : null;
+ if (throwable != null) {
+ for (StackTraceElementProxy line : throwable.getStackTraceElementProxyArray()) {
+ if (line.getStackTraceElement().getClassName().contains(clazz.getSimpleName())
+ && line.getStackTraceElement().getMethodName().contains(methodName)) {
+ return true;
}
}
- return false;
}
+ return false;
};
}
@@ -124,7 +131,6 @@ public class LogWatcher implements Closeable {
}
};
}
-
public static Predicate<ILoggingEvent> containsExceptionClassname(final String expected) {
return new Predicate<ILoggingEvent>() {
@Override public boolean apply(ILoggingEvent input) {
@@ -135,7 +141,6 @@ public class LogWatcher implements Closeable {
}
};
}
-
public static Predicate<ILoggingEvent> levelGeaterOrEqual(final Level expectedLevel) {
return new Predicate<ILoggingEvent>() {
@Override public boolean apply(ILoggingEvent input) {
@@ -150,7 +155,7 @@ public class LogWatcher implements Closeable {
private final List<ILoggingEvent> events = Collections.synchronizedList(Lists.<ILoggingEvent>newLinkedList());
private final AtomicBoolean closed = new AtomicBoolean();
private final ch.qos.logback.classic.Level loggerLevel;
- private final Appender<ILoggingEvent> appender;
+ private final OutputStreamAppender<ILoggingEvent> appender;
private final List<ch.qos.logback.classic.Logger> watchedLoggers = Lists.newArrayList();
private volatile Map<ch.qos.logback.classic.Logger, Level> origLevels = Maps.newLinkedHashMap();
@@ -160,29 +165,61 @@ public class LogWatcher implements Closeable {
@SuppressWarnings("unchecked")
public LogWatcher(Iterable<String> loggerNames, ch.qos.logback.classic.Level loggerLevel, final Predicate<? super ILoggingEvent> filter) {
- for (String loggerName : loggerNames) {
- Logger logger = LoggerFactory.getLogger(checkNotNull(loggerName, "loggerName"));
- watchedLoggers.add((ch.qos.logback.classic.Logger) logger);
- }
+
this.loggerLevel = checkNotNull(loggerLevel, "loggerLevel");
- this.appender = Mockito.mock(Appender.class);
-
- Mockito.when(appender.getName()).thenReturn("MOCK");
- Answer<Void> answer = new Answer<Void>() {
+ LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
+
+ this.appender = new OutputStreamAppender<ILoggingEvent>() {
@Override
- public Void answer(InvocationOnMock invocation) throws Throwable {
- ILoggingEvent event = invocation.getArgument(0);
- if (event != null && filter.apply(event)) {
- events.add(event);
- }
+ protected void append(ILoggingEvent event) {
+ super.append(event);
+
LOG.trace("level="+event.getLevel()+"; event="+event+"; msg="+event.getFormattedMessage());
- return null;
}
};
- Mockito.doAnswer(answer).when(appender).doAppend(Mockito.<ILoggingEvent>any());
+
+ PatternLayoutEncoder ple = new PatternLayoutEncoder() {
+ @Override
+ public void doEncode(ILoggingEvent event) throws IOException {
+ final String txt = layout.doLayout(event);
+ ILoggingEvent formatted = (ILoggingEvent) Proxy.newProxyInstance(
+ ILoggingEvent.class.getClassLoader(),
+ new Class<?>[]{ILoggingEvent.class},
+ (proxy, method, args) -> {
+ if (method.getName().endsWith("Message") || method.getName().equals("toString")) {
+ return txt;
+ } else {
+ return method.invoke(event, args);
+ }
+ });
+ if (event != null && filter.apply(formatted)) {
+ events.add(formatted);
+ }
+
+ super.doEncode(event);
+ }
+ };
+
+ ple.setPattern(">>>> %d{ISO8601} %X{entity.ids} %-5.5p %3X{bundle.id} %c{1.} [%.16t] %m%n");
+ ple.setContext(lc);
+ ple.start();
+
+ this.appender.setContext(lc);
+ this.appender.setEncoder(ple);
+ this.appender.setOutputStream(System.out);
+ this.appender.start();
+
+ for (String loggerName : loggerNames) {
+ final ch.qos.logback.classic.Logger logger = (ch.qos.logback.classic.Logger)LoggerFactory.getLogger(checkNotNull(loggerName, "loggerName"));
+ logger.addAppender(this.appender);
+ logger.setLevel(this.loggerLevel);
+ logger.setAdditive(false);
+ watchedLoggers.add((ch.qos.logback.classic.Logger) logger);
+ }
}
public void start() {
+
checkState(!closed.get(), "Cannot start LogWatcher after closed");
for (ch.qos.logback.classic.Logger watchedLogger : watchedLoggers) {
origLevels.put(watchedLogger, watchedLogger.getLevel());
@@ -252,20 +289,18 @@ public class LogWatcher implements Closeable {
public void printEvents() {
printEvents(System.out, getEvents());
}
-
public String printEventsToString() {
return printEventsToString(getEvents());
}
-
+
public String printEventsToString(Iterable<? extends ILoggingEvent> events) {
ByteArrayOutputStream baos = new ByteArrayOutputStream();
printEvents(new PrintStream(baos), events);
return new String(baos.toByteArray());
}
-
public void printEvents(PrintStream stream, Iterable<? extends ILoggingEvent> events) {
for (ILoggingEvent event : events) {
- stream.println(Time.makeDateString(event.getTimeStamp()) + ": " + event.getThreadName()
+ stream.println(Time.makeDateString(event.getTimeStamp()) + ": " + event.getThreadName()
+ ": " + event.getLevel() + ": " + event.getMessage());
IThrowableProxy throwable = event.getThrowableProxy();
if (throwable != null) {