brooklyn-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From tbou...@apache.org
Subject [06/13] brooklyn-server git commit: Assert on log output
Date Thu, 15 Feb 2018 10:49:25 GMT
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 <geoff.macartney@cloudsoftcorp.com>
Authored: Fri Jan 26 17:38:34 2018 +0000
Committer: Geoff Macartney <geoff.macartney@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) {


Mime
View raw message