Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

When using log4j2 log4j2-test.* files are not detected #17001

Closed
JanecekPetr opened this issue May 29, 2019 · 5 comments
Closed

When using log4j2 log4j2-test.* files are not detected #17001

JanecekPetr opened this issue May 29, 2019 · 5 comments
Assignees
Labels
type: bug A general bug
Milestone

Comments

@JanecekPetr
Copy link

When using log4j2 via the spring-boot-starter-log4j2, I'd expect the log4j2-test.xml file (actually, all *-test.*, as seen here: https://logging.apache.org/log4j/2.x/manual/configuration.html#Automatic_Configuration) to be picked up and used by Spring for unit tests.

We want to use log4j2, and have separate logging config files for tests and in the final artifact.

The log4j2 project specifies an exact order in which log config files should be picked up: https://logging.apache.org/log4j/2.x/manual/configuration.html#Automatic_Configuration

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label May 29, 2019
@wilkinsona
Copy link
Member

wilkinsona commented May 29, 2019

log4j2-test.xml files should be picked up as expected. Here's the output from launching a @SpringBootTest-annotated test class with an empty log4j2-test.xml file:

[Fatal Error] log4j2-test.xml:1:1: Premature end of file.
ERROR StatusLogger Error parsing /Users/awilkinson/dev/workspaces/spring-projects/spring-boot/2.1.x/gh-17001/target/test-classes/log4j2-test.xml
 org.xml.sax.SAXParseException; systemId: file:///Users/awilkinson/dev/workspaces/spring-projects/spring-boot/2.1.x/gh-17001/target/test-classes/log4j2-test.xml; lineNumber: 1; columnNumber: 1; Premature end of file.
	at com.sun.org.apache.xerces.internal.parsers.DOMParser.parse(DOMParser.java:257)
	at com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderImpl.parse(DocumentBuilderImpl.java:339)
	at org.apache.logging.log4j.core.config.xml.XmlConfiguration.<init>(XmlConfiguration.java:95)
	at org.apache.logging.log4j.core.config.xml.XmlConfigurationFactory.getConfiguration(XmlConfigurationFactory.java:46)
	at org.apache.logging.log4j.core.config.ConfigurationFactory$Factory.getConfiguration(ConfigurationFactory.java:454)
	at org.apache.logging.log4j.core.config.ConfigurationFactory$Factory.getConfiguration(ConfigurationFactory.java:382)
	at org.apache.logging.log4j.core.config.ConfigurationFactory.getConfiguration(ConfigurationFactory.java:261)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:616)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:637)
	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:231)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:153)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45)
	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:194)
	at org.apache.commons.logging.LogAdapter$Log4jLog.<clinit>(LogAdapter.java:155)
	at org.apache.commons.logging.LogAdapter$Log4jAdapter.createLog(LogAdapter.java:122)
	at org.apache.commons.logging.LogAdapter.createLog(LogAdapter.java:89)
	at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:67)
	at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:59)
	at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.<clinit>(SpringJUnit4ClassRunner.java:99)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at org.junit.internal.builders.AnnotatedBuilder.buildRunner(AnnotatedBuilder.java:104)
	at org.junit.internal.builders.AnnotatedBuilder.runnerForClass(AnnotatedBuilder.java:86)
	at org.junit.runners.model.RunnerBuilder.safeRunnerForClass(RunnerBuilder.java:59)
	at org.junit.internal.builders.AllDefaultPossibilitiesBuilder.runnerForClass(AllDefaultPossibilitiesBuilder.java:26)
	at org.junit.runners.model.RunnerBuilder.safeRunnerForClass(RunnerBuilder.java:59)
	at org.junit.internal.requests.ClassRequest.getRunner(ClassRequest.java:33)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestLoader.createUnfilteredTest(JUnit4TestLoader.java:90)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestLoader.createTest(JUnit4TestLoader.java:76)
	at org.eclipse.jdt.internal.junit4.runner.JUnit4TestLoader.loadTests(JUnit4TestLoader.java:49)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:525)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:763)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:463)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:209)
ERROR StatusLogger No logging configuration

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.1.5.RELEASE)

2019-05-29 14:07:50.431  INFO 2653 --- [           main] c.e.d.Gh17001ApplicationTests            : Starting Gh17001ApplicationTests on Andys-MacBook-Pro.local with PID 2653 (started by awilkinson in /Users/awilkinson/dev/workspaces/spring-projects/spring-boot/2.1.x/gh-17001)
2019-05-29 14:07:50.433  INFO 2653 --- [           main] c.e.d.Gh17001ApplicationTests            : No active profile set, falling back to default profiles: default
2019-05-29 14:07:50.743  INFO 2653 --- [           main] c.e.d.Gh17001ApplicationTests            : Started Gh17001ApplicationTests in 0.472 seconds (JVM running for 1.331)

As you can see from the error caused by it being empty, the file has been picked up.

If you would like us to spend some more time investigating, please take the time to provide a minimal sample that reproduces the problem either as a separate GitHub repository or as a zip attached to this issue.

@wilkinsona wilkinsona added the status: waiting-for-feedback We need additional information before we can continue label May 29, 2019
@spring-projects-issues
Copy link
Collaborator

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

@spring-projects-issues spring-projects-issues added the status: feedback-reminder We've sent a reminder that we need additional information before we can continue label Jun 5, 2019
@spring-projects-issues
Copy link
Collaborator

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.

@spring-projects-issues spring-projects-issues removed status: waiting-for-feedback We need additional information before we can continue status: feedback-reminder We've sent a reminder that we need additional information before we can continue status: waiting-for-triage An issue we've not yet triaged labels Jun 12, 2019
@dewa-actico
Copy link

@wilkinsona I am not the original author if the issue, but still - a demo showing the problem:
I attached a demo here:demo 17001.zip
Running the test will show log output. Although its disabled. If the file is renamed to log4j2.xml, it will no longer show messages.
Spring seems to initialize the logging a second time, falling back to the default config.

@wilkinsona
Copy link
Member

Thanks very much, @dewa-actico. That's given me what I needed to pinpoint the problem. Log4j2LoggingSystem does not consider log4j2-test files in its standard config locations:

@Override
protected String[] getStandardConfigLocations() {
return getCurrentlySupportedConfigLocations();
}
private String[] getCurrentlySupportedConfigLocations() {
List<String> supportedConfigLocations = new ArrayList<>();
supportedConfigLocations.add("log4j2.properties");
if (isClassAvailable("com.fasterxml.jackson.dataformat.yaml.YAMLParser")) {
Collections.addAll(supportedConfigLocations, "log4j2.yaml", "log4j2.yml");
}
if (isClassAvailable("com.fasterxml.jackson.databind.ObjectMapper")) {
Collections.addAll(supportedConfigLocations, "log4j2.json", "log4j2.jsn");
}
supportedConfigLocations.add("log4j2.xml");
return StringUtils.toStringArray(supportedConfigLocations);
}

By contrast, LogbackLoggingSystem does consider logback-test files in its standard config locations:

@Override
protected String[] getStandardConfigLocations() {
return new String[] { "logback-test.groovy", "logback-test.xml", "logback.groovy", "logback.xml" };
}

The result of this is the log4j2-test.xml will be picked up when Log4j2 is first bootstrapping itself, but it will then be missed when Spring Boot's logging system is (potentially) reconfiguring things.

@wilkinsona wilkinsona reopened this Apr 6, 2020
@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Apr 6, 2020
@wilkinsona wilkinsona added type: bug A general bug and removed status: waiting-for-triage An issue we've not yet triaged labels Apr 6, 2020
@wilkinsona wilkinsona added this to the 2.2.x milestone Apr 6, 2020
@mbhave mbhave self-assigned this May 5, 2020
@mbhave mbhave modified the milestones: 2.2.x, 2.2.7 May 5, 2020
@mbhave mbhave closed this as completed in 43e7ccd May 5, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug A general bug
Projects
None yet
Development

No branches or pull requests

5 participants