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}