/* * Copyright 2012-2017 the original author or authors. * * Licensed 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. */ package org.springframework.boot.context.logging; import java.io.File; import java.io.IOException; import java.util.List; import java.util.concurrent.CountDownLatch; import java.util.concurrent.TimeUnit; import java.util.logging.Handler; import java.util.logging.LogManager; import java.util.logging.Logger; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; import org.apache.commons.logging.impl.SLF4JLogFactory; import org.junit.After; import org.junit.Before; import org.junit.Rule; import org.junit.Test; import org.junit.rules.ExpectedException; import org.junit.rules.TemporaryFolder; import org.junit.runner.RunWith; import org.slf4j.bridge.SLF4JBridgeHandler; import org.springframework.boot.ApplicationPid; import org.springframework.boot.SpringApplication; import org.springframework.boot.context.event.ApplicationFailedEvent; import org.springframework.boot.context.event.ApplicationStartingEvent; import org.springframework.boot.context.properties.source.ConfigurationPropertySources; import org.springframework.boot.junit.runner.classpath.ClassPathExclusions; import org.springframework.boot.junit.runner.classpath.ModifiedClassPathRunner; import org.springframework.boot.logging.AbstractLoggingSystem; import org.springframework.boot.logging.LogFile; import org.springframework.boot.logging.LogLevel; import org.springframework.boot.logging.LoggerConfiguration; import org.springframework.boot.logging.LoggingInitializationContext; import org.springframework.boot.logging.LoggingSystem; import org.springframework.boot.logging.java.JavaLoggingSystem; import org.springframework.boot.testutil.InternalOutputCapture; import org.springframework.context.ApplicationEvent; import org.springframework.context.ApplicationListener; import org.springframework.context.event.ContextClosedEvent; import org.springframework.context.event.SimpleApplicationEventMulticaster; import org.springframework.context.support.GenericApplicationContext; import org.springframework.core.env.ConfigurableEnvironment; import org.springframework.test.context.support.TestPropertySourceUtils; import org.springframework.test.util.ReflectionTestUtils; import static org.assertj.core.api.Assertions.assertThat; import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.not; /** * Tests for {@link LoggingApplicationListener} with Logback. * * @author Dave Syer * @author Phillip Webb * @author Andy Wilkinson * @author Stephane Nicoll * @author Ben Hale */ @RunWith(ModifiedClassPathRunner.class) @ClassPathExclusions("log4j*.jar") public class LoggingApplicationListenerTests { private static final String[] NO_ARGS = {}; @Rule public ExpectedException thrown = ExpectedException.none(); @Rule public TemporaryFolder temporaryFolder = new TemporaryFolder(); @Rule public InternalOutputCapture outputCapture = new InternalOutputCapture(); private final LoggingApplicationListener initializer = new LoggingApplicationListener(); private final Log logger = new SLF4JLogFactory().getInstance(getClass()); private final SpringApplication springApplication = new SpringApplication(); private final GenericApplicationContext context = new GenericApplicationContext(); @Before public void init() throws SecurityException, IOException { LogManager.getLogManager().readConfiguration( JavaLoggingSystem.class.getResourceAsStream("logging.properties")); multicastEvent(new ApplicationStartingEvent(new SpringApplication(), NO_ARGS)); new File("target/foo.log").delete(); new File(tmpDir() + "/spring.log").delete(); ConfigurableEnvironment environment = this.context.getEnvironment(); ConfigurationPropertySources.attach(environment); } @After public void clear() { LoggingSystem.get(getClass().getClassLoader()).cleanUp(); System.clearProperty(LoggingSystem.class.getName()); System.clearProperty("LOG_FILE"); System.clearProperty("LOG_PATH"); System.clearProperty("PID"); System.clearProperty("LOG_EXCEPTION_CONVERSION_WORD"); System.clearProperty("CONSOLE_LOG_PATTERN"); System.clearProperty("FILE_LOG_PATTERN"); System.clearProperty("LOG_LEVEL_PATTERN"); System.clearProperty(LoggingSystem.SYSTEM_PROPERTY); if (this.context != null) { this.context.close(); } } private String tmpDir() { String path = this.context.getEnvironment() .resolvePlaceholders("${java.io.tmpdir}"); path = path.replace("\\", "/"); if (path.endsWith("/")) { path = path.substring(0, path.length() - 1); } return path; } @Test public void baseConfigLocation() { this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.outputCapture.expect(containsString("Hello world")); this.outputCapture.expect(not(containsString("???"))); this.outputCapture.expect(containsString("[junit-")); this.logger.info("Hello world", new RuntimeException("Expected")); assertThat(new File(tmpDir() + "/spring.log").exists()).isFalse(); } @Test public void overrideConfigLocation() { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.info("Hello world"); String output = this.outputCapture.toString().trim(); assertThat(output).contains("Hello world").doesNotContain("???") .startsWith("LOG_FILE_IS_UNDEFINED").endsWith("BOOTBOOT"); } @Test public void overrideConfigDoesNotExist() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.config=doesnotexist.xml"); this.thrown.expect(IllegalStateException.class); this.outputCapture.expect(containsString( "Logging system failed to initialize using configuration from 'doesnotexist.xml'")); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); } @Test public void azureDefaultLoggingConfigDoesNotCauseAFailure() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.config: -Djava.util.logging.config.file=\"d:\\home\\site\\wwwroot\\bin\\apache-tomcat-7.0.52\\conf\\logging.properties\""); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.info("Hello world"); String output = this.outputCapture.toString().trim(); assertThat(output).contains("Hello world").doesNotContain("???"); assertThat(new File(tmpDir() + "/spring.log").exists()).isFalse(); } @Test public void tomcatNopLoggingConfigDoesNotCauseAFailure() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "LOGGING_CONFIG: -Dnop"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.info("Hello world"); String output = this.outputCapture.toString().trim(); assertThat(output).contains("Hello world").doesNotContain("???"); assertThat(new File(tmpDir() + "/spring.log").exists()).isFalse(); } @Test public void overrideConfigBroken() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.config=classpath:logback-broken.xml"); this.thrown.expect(IllegalStateException.class); this.outputCapture.expect(containsString( "Logging system failed to initialize using configuration from 'classpath:logback-broken.xml'")); this.outputCapture.expect(containsString("ConsolAppender")); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); } @Test public void addLogFileProperty() { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml", "logging.file=target/foo.log"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class); logger.info("Hello world"); String output = this.outputCapture.toString().trim(); assertThat(output).startsWith("target/foo.log"); } @Test public void addLogFilePropertyWithDefault() { assertThat(new File("target/foo.log").exists()).isFalse(); TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.file=target/foo.log"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class); logger.info("Hello world"); assertThat(new File("target/foo.log").exists()).isTrue(); } @Test public void addLogPathProperty() { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.config=classpath:logback-nondefault.xml", "logging.path=target/foo/"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); Log logger = LogFactory.getLog(LoggingApplicationListenerTests.class); logger.info("Hello world"); String output = this.outputCapture.toString().trim(); assertThat(output).startsWith("target/foo/spring.log"); } @Test public void parseDebugArg() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "debug"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.trace("testattrace"); assertThat(this.outputCapture.toString()).contains("testatdebug"); assertThat(this.outputCapture.toString()).doesNotContain("testattrace"); } @Test public void parseTraceArg() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "trace"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.trace("testattrace"); assertThat(this.outputCapture.toString()).contains("testatdebug"); assertThat(this.outputCapture.toString()).contains("testattrace"); } @Test public void disableDebugArg() { disableDebugTraceArg("debug=false"); } @Test public void disableTraceArg() { disableDebugTraceArg("trace=false"); } private void disableDebugTraceArg(String... environment) { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, environment); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.trace("testattrace"); assertThat(this.outputCapture.toString()).doesNotContain("testatdebug"); assertThat(this.outputCapture.toString()).doesNotContain("testattrace"); } @Test public void parseLevels() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=TRACE"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.trace("testattrace"); assertThat(this.outputCapture.toString()).contains("testatdebug"); assertThat(this.outputCapture.toString()).contains("testattrace"); } @Test public void parseLevelsCaseInsensitive() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=TrAcE"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.trace("testattrace"); assertThat(this.outputCapture.toString()).contains("testatdebug"); assertThat(this.outputCapture.toString()).contains("testattrace"); } @Test public void parseLevelsWithPlaceholder() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "foo=TRACE", "logging.level.org.springframework.boot=${foo}"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.trace("testattrace"); assertThat(this.outputCapture.toString()).contains("testatdebug"); assertThat(this.outputCapture.toString()).contains("testattrace"); } @Test public void parseLevelsFails() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=GARBAGE"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); assertThat(this.outputCapture.toString()).doesNotContain("testatdebug") .contains("Cannot set level: GARBAGE"); } @Test public void parseLevelsNone() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=OFF"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.fatal("testatfatal"); assertThat(this.outputCapture.toString()).doesNotContain("testatdebug") .doesNotContain("testatfatal"); } @Test public void parseLevelsMapsFalseToOff() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.level.org.springframework.boot=false"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); this.logger.fatal("testatfatal"); assertThat(this.outputCapture.toString()).doesNotContain("testatdebug") .doesNotContain("testatfatal"); } @Test public void parseArgsDisabled() throws Exception { this.initializer.setParseArgs(false); TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "debug"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); assertThat(this.outputCapture.toString()).doesNotContain("testatdebug"); } @Test public void parseArgsDoesntReplace() throws Exception { this.initializer.setSpringBootLogging(LogLevel.ERROR); this.initializer.setParseArgs(false); multicastEvent(new ApplicationStartingEvent(this.springApplication, new String[] { "--debug" })); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.logger.debug("testatdebug"); assertThat(this.outputCapture.toString()).doesNotContain("testatdebug"); } @Test public void bridgeHandlerLifecycle() throws Exception { assertThat(bridgeHandlerInstalled()).isTrue(); multicastEvent(new ContextClosedEvent(this.context)); assertThat(bridgeHandlerInstalled()).isFalse(); } @Test public void defaultExceptionConversionWord() throws Exception { this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.outputCapture.expect(containsString("Hello world")); this.outputCapture.expect( not(containsString("Wrapped by: java.lang.RuntimeException: Wrapper"))); this.logger.info("Hello world", new RuntimeException("Wrapper", new RuntimeException("Expected"))); } @Test public void overrideExceptionConversionWord() throws Exception { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.exceptionConversionWord=%rEx"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); this.outputCapture.expect(containsString("Hello world")); this.outputCapture.expect( containsString("Wrapped by: java.lang.RuntimeException: Wrapper")); this.logger.info("Hello world", new RuntimeException("Wrapper", new RuntimeException("Expected"))); } @Test public void shutdownHookIsNotRegisteredByDefault() throws Exception { TestLoggingApplicationListener listener = new TestLoggingApplicationListener(); System.setProperty(LoggingSystem.class.getName(), TestShutdownHandlerLoggingSystem.class.getName()); multicastEvent(listener, new ApplicationStartingEvent(new SpringApplication(), NO_ARGS)); listener.initialize(this.context.getEnvironment(), this.context.getClassLoader()); assertThat(listener.shutdownHook).isNull(); } @Test public void shutdownHookCanBeRegistered() throws Exception { TestLoggingApplicationListener listener = new TestLoggingApplicationListener(); System.setProperty(LoggingSystem.class.getName(), TestShutdownHandlerLoggingSystem.class.getName()); TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.register_shutdown_hook=true"); multicastEvent(listener, new ApplicationStartingEvent(new SpringApplication(), NO_ARGS)); listener.initialize(this.context.getEnvironment(), this.context.getClassLoader()); assertThat(listener.shutdownHook).isNotNull(); listener.shutdownHook.start(); assertThat(TestShutdownHandlerLoggingSystem.shutdownLatch.await(30, TimeUnit.SECONDS)).isTrue(); } @Test public void closingContextCleansUpLoggingSystem() { System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName()); multicastEvent( new ApplicationStartingEvent(this.springApplication, new String[0])); TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils .getField(this.initializer, "loggingSystem"); assertThat(loggingSystem.cleanedUp).isFalse(); multicastEvent(new ContextClosedEvent(this.context)); assertThat(loggingSystem.cleanedUp).isTrue(); } @Test public void closingChildContextDoesNotCleanUpLoggingSystem() { System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName()); multicastEvent( new ApplicationStartingEvent(this.springApplication, new String[0])); TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils .getField(this.initializer, "loggingSystem"); assertThat(loggingSystem.cleanedUp).isFalse(); GenericApplicationContext childContext = new GenericApplicationContext(); childContext.setParent(this.context); multicastEvent(new ContextClosedEvent(childContext)); assertThat(loggingSystem.cleanedUp).isFalse(); multicastEvent(new ContextClosedEvent(this.context)); assertThat(loggingSystem.cleanedUp).isTrue(); childContext.close(); } @Test public void systemPropertiesAreSetForLoggingConfiguration() { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.exception-conversion-word=conversion", "logging.file=target/log", "logging.path=path", "logging.pattern.console=console", "logging.pattern.file=file", "logging.pattern.level=level"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); assertThat(System.getProperty("CONSOLE_LOG_PATTERN")).isEqualTo("console"); assertThat(System.getProperty("FILE_LOG_PATTERN")).isEqualTo("file"); assertThat(System.getProperty("LOG_EXCEPTION_CONVERSION_WORD")) .isEqualTo("conversion"); assertThat(System.getProperty("LOG_FILE")).isEqualTo("target/log"); assertThat(System.getProperty("LOG_LEVEL_PATTERN")).isEqualTo("level"); assertThat(System.getProperty("LOG_PATH")).isEqualTo("path"); assertThat(System.getProperty("PID")).isNotNull(); } @Test public void environmentPropertiesIgnoreUnresolvablePlaceholders() { // gh-7719 TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.pattern.console=console ${pid}"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); assertThat(System.getProperty("CONSOLE_LOG_PATTERN")).isEqualTo("console ${pid}"); } @Test public void logFilePropertiesCanReferenceSystemProperties() { TestPropertySourceUtils.addInlinedPropertiesToEnvironment(this.context, "logging.file=target/${PID}.log"); this.initializer.initialize(this.context.getEnvironment(), this.context.getClassLoader()); assertThat(System.getProperty("LOG_FILE")) .isEqualTo("target/" + new ApplicationPid().toString() + ".log"); } @Test public void applicationFailedEventCleansUpLoggingSystem() { System.setProperty(LoggingSystem.SYSTEM_PROPERTY, TestCleanupLoggingSystem.class.getName()); multicastEvent( new ApplicationStartingEvent(this.springApplication, new String[0])); TestCleanupLoggingSystem loggingSystem = (TestCleanupLoggingSystem) ReflectionTestUtils .getField(this.initializer, "loggingSystem"); assertThat(loggingSystem.cleanedUp).isFalse(); multicastEvent(new ApplicationFailedEvent(this.springApplication, new String[0], new GenericApplicationContext(), new Exception())); assertThat(loggingSystem.cleanedUp).isTrue(); } private void multicastEvent(ApplicationEvent event) { multicastEvent(this.initializer, event); } private void multicastEvent(ApplicationListener<?> listener, ApplicationEvent event) { SimpleApplicationEventMulticaster multicaster = new SimpleApplicationEventMulticaster(); multicaster.addApplicationListener(listener); multicaster.multicastEvent(event); } private boolean bridgeHandlerInstalled() { Logger rootLogger = LogManager.getLogManager().getLogger(""); Handler[] handlers = rootLogger.getHandlers(); for (Handler handler : handlers) { if (handler instanceof SLF4JBridgeHandler) { return true; } } return false; } public static class TestShutdownHandlerLoggingSystem extends AbstractLoggingSystem { private static CountDownLatch shutdownLatch; public TestShutdownHandlerLoggingSystem(ClassLoader classLoader) { super(classLoader); TestShutdownHandlerLoggingSystem.shutdownLatch = new CountDownLatch(1); } @Override protected String[] getStandardConfigLocations() { return new String[] { "foo.bar" }; } @Override protected void loadDefaults(LoggingInitializationContext initializationContext, LogFile logFile) { } @Override protected void loadConfiguration( LoggingInitializationContext initializationContext, String location, LogFile logFile) { } @Override public void setLogLevel(String loggerName, LogLevel level) { } @Override public List<LoggerConfiguration> getLoggerConfigurations() { return null; } @Override public LoggerConfiguration getLoggerConfiguration(String loggerName) { return null; } @Override public Runnable getShutdownHandler() { return new Runnable() { @Override public void run() { TestShutdownHandlerLoggingSystem.shutdownLatch.countDown(); } }; } } public static class TestLoggingApplicationListener extends LoggingApplicationListener { private Thread shutdownHook; @Override void registerShutdownHook(Thread shutdownHook) { this.shutdownHook = shutdownHook; } } public static final class TestCleanupLoggingSystem extends LoggingSystem { private boolean cleanedUp = false; public TestCleanupLoggingSystem(ClassLoader classLoader) { } @Override public void beforeInitialize() { } @Override public void setLogLevel(String loggerName, LogLevel level) { } @Override public List<LoggerConfiguration> getLoggerConfigurations() { return null; } @Override public LoggerConfiguration getLoggerConfiguration(String loggerName) { return null; } @Override public void cleanUp() { this.cleanedUp = true; } } }