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

Resetting the log level of a Log4j2 Logger wrongly flags its LoggerConfiguration as explicitly configured #24298

Closed
ST-DDT opened this issue Nov 30, 2020 · 5 comments
Assignees
Labels
type: bug A general bug
Milestone

Comments

@ST-DDT
Copy link

ST-DDT commented Nov 30, 2020

Spring-Boot: v2.3.5.RELEASE
Log4J2: 2.13.3 (spring-managed)

#Display default configuration
$ curl http://$SERVER/actuator/loggers

{"levels":["OFF","FATAL","ERROR","WARN","INFO","DEBUG","TRACE"],"loggers":{
    "ROOT":{"configuredLevel":null,"effectiveLevel":"WARN"},
    "de":{"configuredLevel":null, "effectiveLevel":"WARN"},

#Configure de Log Level
$ curl http://$SERVER/actuator/loggers/de -d '{"configuredLevel":"info"}' -H "Content-Type: application/json"
$ curl http://$SERVER/actuator/loggers

{"levels":["OFF","FATAL","ERROR","WARN","INFO","DEBUG","TRACE"],"loggers":{
    "ROOT":{"configuredLevel":null,"effectiveLevel":"WARN"},
    "de":{"configuredLevel":"INFO","effectiveLevel":"INFO"},

#Reset/inherit de Log Level
$ curl http://$SERVER/actuator/loggers/de -d '{"configuredLevel":null}' -H "Content-Type: application/json"
$ curl http://$SERVER/actuator/loggers

{"levels":["OFF","FATAL","ERROR","WARN","INFO","DEBUG","TRACE"],"loggers":{
    "ROOT":{"configuredLevel":null,"effectiveLevel":"WARN"},
    "de":{"configuredLevel":"WARN", "effectiveLevel":"WARN"},

#Configure ROOT Log Level
$ curl http://$SERVER/actuator/loggers/ROOT -d '{"configuredLevel":"error"}' -H "Content-Type: application/json"
$ curl http://$SERVER/actuator/loggers

{"levels":["OFF","FATAL","ERROR","WARN","INFO","DEBUG","TRACE"],"loggers":{
    "ROOT":{"configuredLevel":null,"effectiveLevel":"ERROR"},
    "de":{"configuredLevel":"ERROR", "effectiveLevel":"ERROR"},

As you can see the last two jsons display de as configured, but the value (even for the configured flag) is inherited from ROOT.

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Nov 30, 2020
@snicoll
Copy link
Member

snicoll commented Nov 30, 2020

@ST-DDT thanks for the report. FTR, there is no need to specify a null configuredLevel according to the documentation.

That's not a problem with the actuator as it merely get that information from the LoggingSystem. When we reset the log level that doesn't remove the logging config but rather makes sure that the existing logging config inherits from its parent. Logback does not have the same behaviour so we need to investigate if we can request log4j to remove the logging config.

@snicoll snicoll changed the title Spring-Boot-Actuator-Log4j2 Loggers endpoint incorrectly reports loggers as configured after being reset to null/inherited Resetting the log level of a Log4j2 Logger wrongly flags its LoggerConfiguration as explicitly configured Nov 30, 2020
@snicoll
Copy link
Member

snicoll commented Nov 30, 2020

The problem can be reproduced by the following test:

@Test
void getLoggingConfigurationWithResetLevelShouldReturnLoggerWithNullConfiguredLevel() {
	this.loggingSystem.beforeInitialize();
	this.loggingSystem.initialize(null, null, null);
	this.loggingSystem.setLogLevel("com.example", LogLevel.WARN);
	this.loggingSystem.setLogLevel("com.example.test", LogLevel.DEBUG);
	LoggerConfiguration configuration = this.loggingSystem.getLoggerConfiguration("com.example.test");
	assertThat(configuration).isEqualTo(new LoggerConfiguration("com.example.test", LogLevel.DEBUG, LogLevel.DEBUG));
	this.loggingSystem.setLogLevel("com.example.test", null);
	LoggerConfiguration updatedConfiguration = this.loggingSystem.getLoggerConfiguration("com.example.test");
	assertThat(updatedConfiguration).isEqualTo(new LoggerConfiguration("com.example.test", null, LogLevel.WARN));
}

@snicoll snicoll added type: bug A general bug and removed status: waiting-for-triage An issue we've not yet triaged labels Nov 30, 2020
@snicoll snicoll added this to the 2.2.x milestone Nov 30, 2020
@mbhave mbhave self-assigned this Nov 30, 2020
@mbhave
Copy link
Contributor

mbhave commented Dec 1, 2020

Log4J2 LoggerConfig, returns the parent's log level if the log level for that logger is null. I'm not sure how we can tell if the logLevel itself is null without reflection.

@mbhave mbhave added the for: team-meeting An issue we'd like to discuss as a team to make progress label Dec 3, 2020
@philwebb philwebb self-assigned this Dec 4, 2020
philwebb added a commit to philwebb/spring-boot that referenced this issue Dec 10, 2020
Update `Log4J2LoggingSystem` so that call to `setLevel` with a `null`
level with remove the logger if it was previously configured by a
`LoggingSystem` call.

To track which loggers have been configured by us, and which have been
configure directly by the user a custom `LoggerConfig` subclass is
used. We'll only remove `LevelSetLoggerConfig` classes, for any others
we'll call `setLevel()` on the config.

Prior to this commit, it was impossible to set then reset a logger
level using the actuator endpoint. This is because Log4J doesn't provide
a way to get the actual configured level. If the `setLevel(null)` has
been applied, then `getLevel()` will return the value of the parent
logger or a default value of `ERROR`.

Closes spring-projectsgh-24298
philwebb added a commit to philwebb/spring-boot that referenced this issue Dec 10, 2020
Update `Log4J2LoggingSystem` so that call to `setLevel` with a `null`
level with remove the logger if it was previously configured by a
`LoggingSystem` call.

To track which loggers have been configured by us, and which have been
configure directly by the user, a custom `LoggerConfig` subclass is
used. We'll only remove `LevelSetLoggerConfig` classes, for any others
we'll call `setLevel(null)` on the config.

Prior to this commit, it was impossible to set then reset a logger
level using the actuator endpoint. This is because Log4J doesn't provide
a way to get the actual configured level. If the `setLevel(null)` has
been applied, then `getLevel()` will return the value of the parent
logger or a default value of `ERROR`.

Closes spring-projectsgh-24298
@philwebb
Copy link
Member

I've had a go at fixing this one in https://github.com/philwebb/spring-boot/tree/gh-24298. The commit message describes the idea behind the fix.

I'm not confident enough to merge it without a review.

@philwebb philwebb removed the for: team-meeting An issue we'd like to discuss as a team to make progress label Dec 14, 2020
@philwebb philwebb modified the milestones: 2.2.x, 2.3.x Dec 16, 2020
@philwebb philwebb modified the milestones: 2.3.x, 2.5.x Apr 14, 2021
@snicoll
Copy link
Member

snicoll commented Apr 15, 2021

I did review that commit back then and I seem to remember that LevelSetLoggerConfig could be a problem if AsyncLoggerConfig is used. Reading the commit again, I am not so sure anymore. Or maybe it was for a different issue?

@philwebb philwebb modified the milestones: 2.5.x, 2.5.0-RC1 Apr 15, 2021
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