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.</br>
047 * On a test class or a test method using this feature, a default filter can be configured with the annotation
048 * {@link LogCaptureFeature.FilterOn} or a custom one implementing {@link LogCaptureFeature.Filter} class can be
049 * provided with the annotation {@link LogCaptureFeature.FilterWith} to select the log events to capture.</br>
050 * A {@link LogCaptureFeature.Result} instance is to be injected with {@link javax.inject.Inject} as an attribute of the
051 * test.</br>
052 * The method {@link LogCaptureFeature.Result#assertHasEvent()} can then be called from test methods to check that
053 * matching log calls (events) have been captured.
054 *
055 * @since 5.7
056 */
057public class LogCaptureFeature implements RunnerFeature {
058
059    private static final Logger log = LogManager.getLogger(LogCaptureFeature.class);
060
061    /**
062     * @since 5.7
063     * @since since 10.3, this exception is an {@link AssertionError}
064     */
065    public static class NoLogCaptureFilterException extends AssertionError {
066        private static final long serialVersionUID = 1L;
067    }
068
069    @Inherited
070    @Retention(RetentionPolicy.RUNTIME)
071    @Target({ ElementType.TYPE, ElementType.METHOD })
072    public @interface FilterWith {
073        /**
074         * Custom implementation of a filter to select event to capture.
075         */
076        Class<? extends LogCaptureFeature.Filter> value();
077    }
078
079    @Inherited
080    @Retention(RetentionPolicy.RUNTIME)
081    @Target({ ElementType.TYPE, ElementType.METHOD })
082    public @interface FilterOn {
083        /**
084         * Configuration for the default filter
085         */
086        String loggerName() default "";
087
088        String logLevel() default "";
089
090        Class<?> loggerClass() default Object.class;
091    }
092
093    /**
094     * Default Nuxeo filter which takes a logger name and a log level to accept only events matching both.
095     * <p>
096     * Null or empty criteria are converted to match all of them.
097     * <p>
098     * For instance, filter will match all loggers if given logger name is null or empty.
099     *
100     * @since 8.10
101     */
102    protected static class DefaultFilter implements LogCaptureFeature.Filter {
103
104        protected final String loggerName;
105
106        protected final Level logLevel;
107
108        public DefaultFilter(String loggerName, String logLevel) {
109            super();
110            this.loggerName = StringUtils.stripToNull(loggerName);
111            this.logLevel = StringUtils.isBlank(logLevel) ? null : Level.toLevel(logLevel);
112        }
113
114        @Override
115        public boolean accept(LogEvent event) {
116            if (logLevel != null && !logLevel.equals(event.getLevel())) {
117                return false;
118            }
119            return loggerName == null || loggerName.equals(event.getLoggerName());
120        }
121    }
122
123    /**
124     * Log result class.
125     */
126    public static class Result {
127        protected final List<LogEvent> caughtEvents = new ArrayList<>();
128
129        protected boolean noFilterFlag = false;
130
131        public void assertHasEvent() {
132            if (noFilterFlag) {
133                throw new LogCaptureFeature.NoLogCaptureFilterException();
134            }
135            assertFalse("No log result found", caughtEvents.isEmpty());
136        }
137
138        public void clear() {
139            caughtEvents.clear();
140            noFilterFlag = false;
141        }
142
143        public List<LogEvent> getCaughtEvents() {
144            return caughtEvents;
145        }
146
147        public List<String> getCaughtEventMessages() {
148            return caughtEvents.stream().map(LogEvent::getMessage).map(Message::getFormattedMessage).collect(toList());
149        }
150
151    }
152
153    @FunctionalInterface
154    public interface Filter {
155        /**
156         * {@link LogCaptureFeature} will capture the event if it does match the implementation condition.
157         */
158        boolean accept(LogEvent event);
159    }
160
161    /** Filter defined on class. */
162    protected Filter classFilter;
163
164    /** Filter defined on method. */
165    protected Filter methodFilter;
166
167    /** Filter used when appending a log to {@link #logAppender appender}. */
168    protected volatile Filter currentFilter;
169
170    protected final Result myResult = new Result();
171
172    /**
173     * A Log4j {@link Appender} added to {@link LoggerContext} at beginning of tests.
174     */
175    protected final Appender logAppender = new AbstractAppender("LOG_CAPTURE_APPENDER", null, null) {
176
177        @Override
178        public void append(LogEvent event) {
179            if (currentFilter == null) {
180                myResult.noFilterFlag = true;
181            } else if (currentFilter.accept(event)) {
182                myResult.caughtEvents.add(event);
183            }
184        }
185    };
186
187    @Override
188    public void beforeRun(FeaturesRunner runner) throws Exception {
189        // create class filter
190        classFilter = instantiateFilter(() -> runner.getConfig(FilterWith.class),
191                () -> runner.getConfig(FilterOn.class));
192        if (classFilter == null) {
193            log.info("Class {} uses LogCaptureFeature without defining a filter",
194                    runner.getTargetTestClass().getName());
195        }
196        // set current filter and start appender
197        currentFilter = classFilter;
198        logAppender.start();
199        LoggerContext.getContext(false).getRootLogger().addAppender(logAppender);
200    }
201
202    @Override
203    public void configure(FeaturesRunner runner, com.google.inject.Binder binder) {
204        binder.bind(Result.class).toInstance(myResult);
205    }
206
207    @Override
208    public void beforeMethodRun(FeaturesRunner runner, FrameworkMethod method, Object test) throws Exception {
209        // re-init result
210        myResult.clear();
211        // create method filter
212        methodFilter = instantiateFilter(() -> runner.getConfig(method, FilterWith.class),
213                () -> runner.getConfig(method, FilterOn.class));
214        if (methodFilter == null) {
215            log.info("Method {} uses LogCaptureFeature without defining a filter", method.getName());
216        }
217        // set current filter
218        currentFilter = methodFilter;
219    }
220
221    @Override
222    public void afterMethodRun(FeaturesRunner runner, FrameworkMethod method, Object test) {
223        // re-init result
224        myResult.clear();
225        // discard method filter
226        methodFilter = null;
227        // set current filter
228        currentFilter = classFilter;
229    }
230
231    @Override
232    public void afterRun(FeaturesRunner runner) {
233        // discard class filter
234        classFilter = null;
235        currentFilter = null;
236        // don't stop appender as it could still be called after removed (race condition)
237        // nevertheless this doesn't affect us as we're outside tests
238        LoggerContext.getContext(false).getRootLogger().removeAppender(logAppender);
239    }
240
241    protected Filter instantiateFilter(Supplier<FilterWith> filterWith, Supplier<FilterOn> filterOn) throws Exception {
242        // create filter
243        Filter filter;
244        FilterWith filterProvider = filterWith.get();
245        // value can be null even if JDK doesn't allow it
246        // this is due to our proxy which return the default value of annotation and in our case it doesn't exist
247        // noinspection ConstantConditions
248        if (filterProvider.value() == null) {
249            FilterOn defaultFilterConfig = filterOn.get();
250            // check if there's at least one attribute defined
251            if (isNotBlank(defaultFilterConfig.loggerName()) || isNotBlank(defaultFilterConfig.logLevel())
252                    || defaultFilterConfig.loggerClass() != Object.class) {
253                // switch between loggerClass or loggerName
254                if (defaultFilterConfig.loggerClass() != Object.class) {
255                    String loggerName = defaultFilterConfig.loggerClass().getName();
256                    filter = new DefaultFilter(loggerName, defaultFilterConfig.logLevel());
257                } else {
258                    filter = new DefaultFilter(defaultFilterConfig.loggerName(), defaultFilterConfig.logLevel());
259                }
260            } else {
261                return null;
262            }
263        } else {
264            filter = filterProvider.value().getDeclaredConstructor().newInstance();
265        }
266        return filter;
267    }
268}