I am using spring-boot-starter-actuator to expose my application logging over HTTP, this used to work but starting from Spring Boot 2.1.7.RELEASE a 404 error response is returned when querying the endpoint /actuator/logfile. The actuator endpoint is available:
_links:
self:
href: 'http://host:port/application/actuator'
templated: false
logfile:
href: 'http://host:port/application/actuator/logfile'
templated: false
This issue looks like the one described in issue 17434, but I am not using any generated random values, just a fixed logging file name.
The same issue is present in 2.1.8.RELASE, the problem disappears when downgrading to 2.1.6.RELEASE
Comment From: wilkinsona
Thanks for the report but I cannot reproduce the behaviour that you have described. The endpoint works as expected for me with 2.1.8.RELEASE:
$ curl localhost:8080/actuator/logfile
2019-09-10 09:27:53.224 INFO 19960 --- [main] o.s.boot.SpringApplication :
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.1.8.RELEASE)
2019-09-10 09:27:53.287 INFO 19960 --- [main] com.example.demo.Gh18191Application : Starting Gh18191Application on Andys-MacBook-Pro.local with PID 19960 (/Users/awilkinson/dev/workspaces/spring-projects/spring-boot/master/gh-18191/target/classes started by awilkinson in /Users/awilkinson/dev/workspaces/spring-projects/spring-boot/master/gh-18191)
2019-09-10 09:27:53.287 INFO 19960 --- [main] com.example.demo.Gh18191Application : No active profile set, falling back to default profiles: default
2019-09-10 09:27:54.129 INFO 19960 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2019-09-10 09:27:54.155 INFO 19960 --- [main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2019-09-10 09:27:54.156 INFO 19960 --- [main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.24]
2019-09-10 09:27:54.238 INFO 19960 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2019-09-10 09:27:54.238 INFO 19960 --- [main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 923 ms
2019-09-10 09:27:54.634 INFO 19960 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'
2019-09-10 09:27:54.808 INFO 19960 --- [main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 16 endpoint(s) beneath base path '/actuator'
2019-09-10 09:27:54.867 INFO 19960 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2019-09-10 09:27:54.870 INFO 19960 --- [main] com.example.demo.Gh18191Application : Started Gh18191Application in 1.865 seconds (JVM running for 2.127)
2019-09-10 09:27:57.142 INFO 19960 --- [http-nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2019-09-10 09:27:57.142 INFO 19960 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2019-09-10 09:27:57.147 INFO 19960 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 5 ms
The above is produced with the following configuration in application.properties:
logging.file=demo.log
management.endpoints.web.exposure.include=*
spring.main.banner-mode=log
It continues to work if I set the context path to /application:
server.servlet.context-path=/application
$ curl localhost:8080/application/actuator/logfile
2019-09-10 09:30:17.929 INFO 20202 --- [main] o.s.boot.SpringApplication :
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.1.8.RELEASE)
2019-09-10 09:30:17.988 INFO 20202 --- [main] com.example.demo.Gh18191Application : Starting Gh18191Application on Andys-MacBook-Pro.local with PID 20202 (/Users/awilkinson/dev/workspaces/spring-projects/spring-boot/master/gh-18191/target/classes started by awilkinson in /Users/awilkinson/dev/workspaces/spring-projects/spring-boot/master/gh-18191)
2019-09-10 09:30:17.989 INFO 20202 --- [main] com.example.demo.Gh18191Application : No active profile set, falling back to default profiles: default
2019-09-10 09:30:18.872 INFO 20202 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2019-09-10 09:30:18.895 INFO 20202 --- [main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2019-09-10 09:30:18.896 INFO 20202 --- [main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.24]
2019-09-10 09:30:18.969 INFO 20202 --- [main] o.a.c.c.C.[.[localhost].[/application] : Initializing Spring embedded WebApplicationContext
2019-09-10 09:30:18.970 INFO 20202 --- [main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 952 ms
2019-09-10 09:30:19.358 INFO 20202 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'
2019-09-10 09:30:19.537 INFO 20202 --- [main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 16 endpoint(s) beneath base path '/actuator'
2019-09-10 09:30:19.595 INFO 20202 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '/application'
2019-09-10 09:30:19.598 INFO 20202 --- [main] com.example.demo.Gh18191Application : Started Gh18191Application in 1.893 seconds (JVM running for 2.245)
2019-09-10 09:30:21.249 INFO 20202 --- [http-nio-8080-exec-1] o.a.c.c.C.[.[localhost].[/application] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2019-09-10 09:30:21.249 INFO 20202 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2019-09-10 09:30:21.254 INFO 20202 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 5 ms
If you would like us to spend some more time investigating, please spend some time providing a minimal example and precise instructions that reproduce the problem, preferably as a zipped project attached to this issue.
Comment From: bzeemeijer
After doing some more tests, the problem seems to be caused by the combination Spring Boot 2.1.7.RELEASE+ and Spring Cloud Config Server. When I retrieve the properties through Spring Cloud Config Server, the 404 error occurs, when I put the same properties in application.yml, everything works fine. I have included a zip file with a demo project which relies on a default Spring Cloud Config Server. The configuration served by this server is located in application.yml. You should be able to reproduce the issue with this project. configuration.zip logging-demo.zip
Comment From: wilkinsona
Thank you. I've reproduced the problem. The change in behaviour is due to the fix for https://github.com/spring-projects/spring-boot/issues/17434. When the application's environment prepared event is fired, the properties that come from the config server aren't present. As a result, the logging.file property is absent and, as it's now only read once, that results in the log file being unavailable via the actuator's endpoint.
Comment From: bzeemeijer
Glad you are able to reproduce the issue! Do you expect this bug to be fixed in the near future?
Comment From: wilkinsona
It's too early to say.
My current opinion is that the change made to fix #17434 has revealed a bug in Spring Cloud. It doesn't feel right to me that it is updating the environment after the environment prepared event has been published. This is happening because it uses an ApplicationContextInitializer to load the configuration and update the environment. Ideally, it would be using an EnvironmentPostProcessor instead. /cc @spencergibb
Comment From: wilkinsona
Until we figure out the best way to fix this, you can work around the problem by setting the external-file property on the logfile endpoint:
management:
endpoint:
logfile:
external_file: demo.log
Comment From: bzeemeijer
Thank you for providing the workaround, this is a good temporary solution which works.
Comment From: wilkinsona
Any thoughts on this, @spencergibb?
Comment From: spencergibb
I guess I'm a bit unsure about where "it uses an ApplicationContextInitializer" is.
Comment From: wilkinsona
I think PropertySourceBoostrapConfiguration is the ApplicationContextInitializer that I was referring to.
Comment From: spencergibb
:+1: so that actually gets triggered during the bootstrap phase which is triggered by BootstrapApplicationListener on ApplicationEnvironmentPreparedEvent. We spin up a new SpringApplication, extract it's environment and then create a parent application context for the regular SpringApplication. I've not looked into the ramifications of changing that class to an EnvironmentPostProcessor.
Comment From: wilkinsona
Thanks, @spencergibb. Manipulating the environment in ApplicationEnvironmentPreparedEvent is too late. The work really needs to be done in an EnvironmentPostProcessor. Not only will that fix the issue described here, but it will also address the numerous problems we've had over the years with Cloud reinitialising Boot's logging system. If the changes to the environment were made at the correct point in the lifecycle, I believe that this code would no longer be necessary. This would fix #13077 and make #8235 obsolete. I have opened https://github.com/spring-cloud/spring-cloud-commons/issues/608.
I'm going to close this issue for now. If changes are needed in Boot to get Cloud to where we'd like it to be, we can re-open this issue or open a new issue as appropriate.
Comment From: mxoop
yaml endpoint: logfile: external_file: demo.log
logging: file: name: ./logs/admin-client.log management: endpoint: logfile: external_file: admin-client.log
not work,404
Comment From: wilkinsona
@mxoop an issue that was closed 4 years ago isn't the right place for this. If you'd like some help, please post a question on Stack Overflow. Before doing that, please double-check your configuration. Given that you don't appear to be using an output redirect, your configuration of management.endpoint.logfile.external_file is probably incorrect and may not be needed at all.