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

Document logger environment variable restrictions #17958

Closed
vpavic opened this issue Aug 25, 2019 · 6 comments

Comments

@vpavic
Copy link
Member

commented Aug 25, 2019

I'm trying to configure log level for a concrete logger using environment variable, but am unable to do so since binding doesn't appear to work correctly in this case.

This can be easily reproduce using a simple Spring Boot application consisting of only spring-boot-starter-web. For example, setting log level for org.springframework.web.context using LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB_CONTEXT works:

$ env LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB_CONTEXT=DEBUG java -jar build/libs/spring-boot-sample.jar 

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

2019-08-25 21:32:35.719  INFO 429 --- [           main] sample.SampleApplication                 : Starting SampleApplication on thinkpad with PID 429 (/home/vpavic/dev/projects/misc/spring-boot-sample/build/libs/spring-boot-sample.jar started by vpavic in /home/vpavic/dev/projects/misc/spring-boot-sample)
2019-08-25 21:32:35.723  INFO 429 --- [           main] sample.SampleApplication                 : No active profile set, falling back to default profiles: default
2019-08-25 21:32:36.706  INFO 429 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2019-08-25 21:32:36.750  INFO 429 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2019-08-25 21:32:36.750  INFO 429 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.22]
2019-08-25 21:32:36.849  INFO 429 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2019-08-25 21:32:36.849 DEBUG 429 --- [           main] o.s.web.context.ContextLoader            : Published root WebApplicationContext as ServletContext attribute with name [org.springframework.web.context.WebApplicationContext.ROOT]
2019-08-25 21:32:36.849  INFO 429 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1076 ms
2019-08-25 21:32:37.050  INFO 429 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-08-25 21:32:37.228  INFO 429 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2019-08-25 21:32:37.232  INFO 429 --- [           main] sample.SampleApplication                 : Started SampleApplication in 1.96 seconds (JVM running for 2.289)

(notice the DEBUG log message)

However trying to set log level for org.springframework.web.context.ContextLoader doesn't work:

$ env LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB_CONTEXT_CONTEXTLOADER=DEBUG java -jar build/libs/spring-boot-sample.jar 

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

2019-08-25 21:32:47.995  INFO 515 --- [           main] sample.SampleApplication                 : Starting SampleApplication on thinkpad with PID 515 (/home/vpavic/dev/projects/misc/spring-boot-sample/build/libs/spring-boot-sample.jar started by vpavic in /home/vpavic/dev/projects/misc/spring-boot-sample)
2019-08-25 21:32:47.999  INFO 515 --- [           main] sample.SampleApplication                 : No active profile set, falling back to default profiles: default
2019-08-25 21:32:48.921  INFO 515 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2019-08-25 21:32:48.994  INFO 515 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2019-08-25 21:32:48.995  INFO 515 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.22]
2019-08-25 21:32:49.108  INFO 515 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2019-08-25 21:32:49.108  INFO 515 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1030 ms
2019-08-25 21:32:49.327  INFO 515 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-08-25 21:32:49.519  INFO 515 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2019-08-25 21:32:49.523  INFO 515 --- [           main] sample.SampleApplication                 : Started SampleApplication in 1.97 seconds (JVM running for 2.353)

I've also tried with:

$ env LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB_CONTEXT_CONTEXT_LOADER=DEBUG java -jar build/libs/spring-boot-sample.jar 

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

2019-08-25 21:32:56.356  INFO 596 --- [           main] sample.SampleApplication                 : Starting SampleApplication on thinkpad with PID 596 (/home/vpavic/dev/projects/misc/spring-boot-sample/build/libs/spring-boot-sample.jar started by vpavic in /home/vpavic/dev/projects/misc/spring-boot-sample)
2019-08-25 21:32:56.362  INFO 596 --- [           main] sample.SampleApplication                 : No active profile set, falling back to default profiles: default
2019-08-25 21:32:57.308  INFO 596 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2019-08-25 21:32:57.361  INFO 596 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2019-08-25 21:32:57.362  INFO 596 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.22]
2019-08-25 21:32:57.445  INFO 596 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2019-08-25 21:32:57.446  INFO 596 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1035 ms
2019-08-25 21:32:57.664  INFO 596 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-08-25 21:32:57.827  INFO 596 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2019-08-25 21:32:57.831  INFO 596 --- [           main] sample.SampleApplication                 : Started SampleApplication in 1.888 seconds (JVM running for 2.279)

The issue is that LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB_CONTEXT_CONTEXTLOADER gets resolved to org.springframework.web.context.contextloader in LoggingApplicationListener#setLogLevels which obviously won't configure the desired logger. I would assume there should be some special handling for setting concrete loggers. I didn't find anything in reference documentation about this limitation.

@Sauhardstark

This comment was marked as outdated.

Copy link

commented Aug 26, 2019

@vpavic
Hi, you can make it work by setting it as
logging.level.org.springframework.web.context.ContextLoader = DEBUG

So if you run the command
env logging.level.org.springframework.web.context.ContextLoader = DEBUG java -jar build/libs/spring-boot-sample.jar

it will work exactly as expected. One other way I found would require the Logger class in ch.qos.logback.classic to to add an else after the if statement

            if (childName.equals(childName_i)) {
                return childLogger_i;
            }

If you add an else if statement checking again but this time with equalsIgnoreCase()

           else if (childName.equalsIgnoreCase(childName_i)) {
                return childLogger_i;
            }

Since we can't do that here, my suggestion would be to go with the first approach

@vpavic

This comment was marked as outdated.

Copy link
Member Author

commented Aug 26, 2019

The dot is not a valid character in a shell identifier - while it works using env (which is used here only for demonstration purposes) you'll not be able to export such a variable.

@philwebb

This comment has been minimized.

Copy link
Member

commented Aug 26, 2019

I'm trying to think how we can fix this. One option would be to try and make all logger lookups case-insensitive, but I'm really not sure how we can do that. Another might be try and find a class name that matches the logger name (using some case-insensitive search) then use the found class name to get the correct case back.

I'll flag this one for team attention to see if anyone else has some bright ideas.

@wilkinsona

This comment has been minimized.

Copy link
Member

commented Aug 27, 2019

With both Logback (a list of loggers) and Log4j2 (a map of name -> logger config) it is possible to perform a case insensitive match for existing loggers when setting a log level. However, that would not help when the level is being set before the logger has been created. Setting the level would then create the logger with a name that does not match the one used in application code. We could further refine this by trying to find a class name that is a case-insensitive match for the logger name as @philwebb suggests above.

Other than using SPRING_APPLICATION_JSON I don't have any other ideas here at the moment, let alone bright ones.

@philwebb

This comment has been minimized.

Copy link
Member

commented Aug 28, 2019

See also #17975 for another issue that would be impossible to set in environment variables.

@philwebb philwebb added this to the 2.1.x milestone Aug 29, 2019
@philwebb philwebb changed the title Unable to configure log level for specific logger using environment variable Document logger environment variable restrictions Aug 29, 2019
@philwebb

This comment has been minimized.

Copy link
Member

commented Aug 29, 2019

We'll make this one a documentation issue since there's no easy fix. I've opened #18003 to see if we can't come up with a better long term solution.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
5 participants
You can’t perform that action at this time.