001/* 002 * (C) Copyright 2012-2018 Nuxeo (http://nuxeo.com/) and others. 003 * 004 * Licensed under the Apache License, Version 2.0 (the "License"); 005 * you may not use this file except in compliance with the License. 006 * You may obtain a copy of the License at 007 * 008 * http://www.apache.org/licenses/LICENSE-2.0 009 * 010 * Unless required by applicable law or agreed to in writing, software 011 * distributed under the License is distributed on an "AS IS" BASIS, 012 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 013 * See the License for the specific language governing permissions and 014 * limitations under the License. 015 * 016 * Contributors: 017 * Sun Seng David TAN <stan@nuxeo.com>, slacoin, jcarsique 018 */ 019package org.nuxeo.runtime.test.runner; 020 021import static java.util.stream.Collectors.toList; 022import static org.apache.commons.lang3.StringUtils.isNotBlank; 023import static org.junit.Assert.assertFalse; 024 025import java.lang.annotation.ElementType; 026import java.lang.annotation.Inherited; 027import java.lang.annotation.Retention; 028import java.lang.annotation.RetentionPolicy; 029import java.lang.annotation.Target; 030import java.util.ArrayList; 031import java.util.List; 032import java.util.function.Supplier; 033 034import org.apache.commons.lang3.StringUtils; 035import org.apache.logging.log4j.Level; 036import org.apache.logging.log4j.LogManager; 037import org.apache.logging.log4j.Logger; 038import org.apache.logging.log4j.core.Appender; 039import org.apache.logging.log4j.core.LogEvent; 040import org.apache.logging.log4j.core.LoggerContext; 041import org.apache.logging.log4j.core.appender.AbstractAppender; 042import org.apache.logging.log4j.message.Message; 043import org.junit.runners.model.FrameworkMethod; 044 045/** 046 * Test feature to capture from a log4j appender to check that some log4j calls have been correctly called. 047 * <p> 048 * On a test class or a test method using this feature, a default filter can be configured with the annotation 049 * {@link LogCaptureFeature.FilterOn} or a custom one implementing {@link LogCaptureFeature.Filter} class can be 050 * provided with the annotation {@link LogCaptureFeature.FilterWith} to select the log events to capture. 051 * <p> 052 * A {@link LogCaptureFeature.Result} instance is to be injected with {@link javax.inject.Inject} as an attribute of the 053 * test. 054 * <p> 055 * The method {@link LogCaptureFeature.Result#assertHasEvent()} can then be called from test methods to check that 056 * matching log calls (events) have been captured. 057 * 058 * @since 5.7 059 */ 060public class LogCaptureFeature implements RunnerFeature { 061 062 private static final Logger log = LogManager.getLogger(LogCaptureFeature.class); 063 064 /** 065 * @since 5.7 066 * @since since 10.3, this exception is an {@link AssertionError} 067 */ 068 public static class NoLogCaptureFilterException extends AssertionError { 069 private static final long serialVersionUID = 1L; 070 } 071 072 @Inherited 073 @Retention(RetentionPolicy.RUNTIME) 074 @Target({ ElementType.TYPE, ElementType.METHOD }) 075 public @interface FilterWith { 076 /** 077 * Custom implementation of a filter to select event to capture. 078 */ 079 Class<? extends LogCaptureFeature.Filter> value(); 080 } 081 082 @Inherited 083 @Retention(RetentionPolicy.RUNTIME) 084 @Target({ ElementType.TYPE, ElementType.METHOD }) 085 public @interface FilterOn { 086 /** 087 * Configuration for the default filter 088 */ 089 String loggerName() default ""; 090 091 String logLevel() default ""; 092 093 Class<?> loggerClass() default Object.class; 094 } 095 096 /** 097 * Default Nuxeo filter which takes a logger name and a log level to accept only events matching both. 098 * <p> 099 * Null or empty criteria are converted to match all of them. 100 * <p> 101 * For instance, filter will match all loggers if given logger name is null or empty. 102 * 103 * @since 8.10 104 */ 105 protected static class DefaultFilter implements LogCaptureFeature.Filter { 106 107 protected final String loggerName; 108 109 protected final Level logLevel; 110 111 public DefaultFilter(String loggerName, String logLevel) { 112 super(); 113 this.loggerName = StringUtils.stripToNull(loggerName); 114 this.logLevel = StringUtils.isBlank(logLevel) ? null : Level.toLevel(logLevel); 115 } 116 117 @Override 118 public boolean accept(LogEvent event) { 119 if (logLevel != null && !logLevel.equals(event.getLevel())) { 120 return false; 121 } 122 return loggerName == null || loggerName.equals(event.getLoggerName()); 123 } 124 } 125 126 /** 127 * Log result class. 128 */ 129 public static class Result { 130 protected final List<LogEvent> caughtEvents = new ArrayList<>(); 131 132 protected boolean noFilterFlag = false; 133 134 public void assertHasEvent() { 135 if (noFilterFlag) { 136 throw new LogCaptureFeature.NoLogCaptureFilterException(); 137 } 138 assertFalse("No log result found", caughtEvents.isEmpty()); 139 } 140 141 public void clear() { 142 caughtEvents.clear(); 143 noFilterFlag = false; 144 } 145 146 public List<LogEvent> getCaughtEvents() { 147 return caughtEvents; 148 } 149 150 public List<String> getCaughtEventMessages() { 151 return caughtEvents.stream().map(LogEvent::getMessage).map(Message::getFormattedMessage).collect(toList()); 152 } 153 154 } 155 156 @FunctionalInterface 157 public interface Filter { 158 /** 159 * {@link LogCaptureFeature} will capture the event if it does match the implementation condition. 160 */ 161 boolean accept(LogEvent event); 162 } 163 164 /** Filter defined on class. */ 165 protected Filter classFilter; 166 167 /** Filter defined on method. */ 168 protected Filter methodFilter; 169 170 /** Filter used when appending a log to {@link #logAppender appender}. */ 171 protected volatile Filter currentFilter; 172 173 protected final Result myResult = new Result(); 174 175 /** 176 * A Log4j {@link Appender} added to {@link LoggerContext} at beginning of tests. 177 */ 178 protected final Appender logAppender = new AbstractAppender("LOG_CAPTURE_APPENDER", null, null) { 179 180 @Override 181 public void append(LogEvent event) { 182 if (currentFilter == null) { 183 myResult.noFilterFlag = true; 184 } else if (currentFilter.accept(event)) { 185 myResult.caughtEvents.add(event); 186 } 187 } 188 }; 189 190 @Override 191 public void beforeRun(FeaturesRunner runner) throws Exception { 192 // create class filter 193 classFilter = instantiateFilter(() -> runner.getConfig(FilterWith.class), 194 () -> runner.getConfig(FilterOn.class)); 195 if (classFilter == null) { 196 log.info("Class {} uses LogCaptureFeature without defining a filter", 197 runner.getTargetTestClass().getName()); 198 } 199 // set current filter and start appender 200 currentFilter = classFilter; 201 logAppender.start(); 202 LoggerContext.getContext(false).getRootLogger().addAppender(logAppender); 203 } 204 205 @Override 206 public void configure(FeaturesRunner runner, com.google.inject.Binder binder) { 207 binder.bind(Result.class).toInstance(myResult); 208 } 209 210 @Override 211 public void beforeMethodRun(FeaturesRunner runner, FrameworkMethod method, Object test) throws Exception { 212 // re-init result 213 myResult.clear(); 214 // create method filter 215 methodFilter = instantiateFilter(() -> runner.getConfig(method, FilterWith.class), 216 () -> runner.getConfig(method, FilterOn.class)); 217 if (methodFilter == null) { 218 log.info("Method {} uses LogCaptureFeature without defining a filter", method.getName()); 219 } 220 // set current filter 221 currentFilter = methodFilter; 222 } 223 224 @Override 225 public void afterMethodRun(FeaturesRunner runner, FrameworkMethod method, Object test) { 226 // re-init result 227 myResult.clear(); 228 // discard method filter 229 methodFilter = null; 230 // set current filter 231 currentFilter = classFilter; 232 } 233 234 @Override 235 public void afterRun(FeaturesRunner runner) { 236 // discard class filter 237 classFilter = null; 238 currentFilter = null; 239 // don't stop appender as it could still be called after removed (race condition) 240 // nevertheless this doesn't affect us as we're outside tests 241 LoggerContext.getContext(false).getRootLogger().removeAppender(logAppender); 242 } 243 244 protected Filter instantiateFilter(Supplier<FilterWith> filterWith, Supplier<FilterOn> filterOn) throws Exception { 245 // create filter 246 Filter filter; 247 FilterWith filterProvider = filterWith.get(); 248 // value can be null even if JDK doesn't allow it 249 // this is due to our proxy which return the default value of annotation and in our case it doesn't exist 250 // noinspection ConstantConditions 251 if (filterProvider.value() == null) { 252 FilterOn defaultFilterConfig = filterOn.get(); 253 // check if there's at least one attribute defined 254 if (isNotBlank(defaultFilterConfig.loggerName()) || isNotBlank(defaultFilterConfig.logLevel()) 255 || defaultFilterConfig.loggerClass() != Object.class) { 256 // switch between loggerClass or loggerName 257 if (defaultFilterConfig.loggerClass() != Object.class) { 258 String loggerName = defaultFilterConfig.loggerClass().getName(); 259 filter = new DefaultFilter(loggerName, defaultFilterConfig.logLevel()); 260 } else { 261 filter = new DefaultFilter(defaultFilterConfig.loggerName(), defaultFilterConfig.logLevel()); 262 } 263 } else { 264 return null; 265 } 266 } else { 267 filter = filterProvider.value().getDeclaredConstructor().newInstance(); 268 } 269 return filter; 270 } 271}