spring-bootspring-logback

Can't start spring boot application when logback-access.xml uses both TimeBasedRollingPolicy and SizeAndTimeBasedRollingPolicy


I have the following logback-access.xml file. My application is on jdk 21 and spring boot 3.3.4.

<configuration>
  <appender name="ACCESS_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <!-- Specify the active access log file name -->
    <file>logs/access.log</file>

    <!-- Define the rolling policy -->
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>logs/access-%d{yyyy-MM-dd}.log</fileNamePattern>
      <maxHistory>30</maxHistory>
      <timeBasedFileNamingAndTriggeringPolicy 
class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <maxFileSize>10MB</maxFileSize>
      </timeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>

    <!-- Define the encoder for access log formatting -->
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
      <layout class="ch.qos.logback.access.PatternLayout">
        <pattern>%h %l %u [%t] "%r" %s %b %D %I</pattern>
      </layout>
    </encoder>
  </appender>

  <appender-ref ref="ACCESS_FILE" />
</configuration>

I intentionally have both the TimeBasedRollingPolicy and the SizeAndTimeBasedRollingPolicy. However, when they are both defined this way, I get the following exception on startup of my spring boot application:

org.springframework.context.ApplicationContextException: Unable to start web server
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.onRefresh(ServletWebServerApplicationContext.java:165) ~[spring-boot-3.3.4.jar:3.3.4]
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:619) ~[spring-context-6.1.13.jar:6.1.13]
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146) ~[spring-boot-3.3.4.jar:3.3.4]
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754) ~[spring-boot-3.3.4.jar:3.3.4]
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:456) ~[spring-boot-3.3.4.jar:3.3.4]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:335) ~[spring-boot-3.3.4.jar:3.3.4]
     at fbi.prometheus.whapi.writeback.rest.WritebackApplication.main(WritebackApplication.java:31) ~[classes/:na]
    Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'tomcatServletWebServerFactory' defined in class path resource [org/springframework/boot/autoconfigure/web/servlet/ServletWebServerFactoryConfiguration$EmbeddedTomcat.class]: Error creating bean with name 'logbackAccessTomcatWebServerFactoryCustomizer' defined in class path resource [dev/akkinoc/spring/boot/logback/access/tomcat/LogbackAccessTomcatConfiguration.class]: Unsatisfied dependency expressed through method 'logbackAccessTomcatWebServerFactoryCustomizer' parameter 0: Error creating bean with name 'logbackAccessContext' defined in class path resource [dev/akkinoc/spring/boot/logback/access/LogbackAccessAutoConfiguration.class]: Failed to instantiate [dev.akkinoc.spring.boot.logback.access.LogbackAccessContext]: Factory method 'logbackAccessContext' threw exception with message: The FileNamePattern option must be set before using TimeBasedRollingPolicy. See also http://logback.qos.ch/codes.html#tbr_fnp_not_set
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:607) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:522) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:337) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:335) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:205) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.getWebServerFactory(ServletWebServerApplicationContext.java:223) ~[spring-boot-3.3.4.jar:3.3.4]
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.createWebServer(ServletWebServerApplicationContext.java:186) ~[spring-boot-3.3.4.jar:3.3.4]
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.onRefresh(ServletWebServerApplicationContext.java:162) ~[spring-boot-3.3.4.jar:3.3.4]
  ... 6 common frames omitted
 Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'logbackAccessTomcatWebServerFactoryCustomizer' defined in class path resource [dev/akkinoc/spring/boot/logback/access/tomcat/LogbackAccessTomcatConfiguration.class]: Unsatisfied dependency expressed through method 'logbackAccessTomcatWebServerFactoryCustomizer' parameter 0: Error creating bean with name 'logbackAccessContext' defined in class path resource [dev/akkinoc/spring/boot/logback/access/LogbackAccessAutoConfiguration.class]: Failed to instantiate [dev.akkinoc.spring.boot.logback.access.LogbackAccessContext]: Factory method 'logbackAccessContext' threw exception with message: The FileNamePattern option must be set before using TimeBasedRollingPolicy. See also http://logback.qos.ch/codes.html#tbr_fnp_not_set
at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:795) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:542) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1355) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1185) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:562) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:522) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:337) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:335) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeansOfType(DefaultListableBeanFactory.java:665) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.boot.web.server.WebServerFactoryCustomizerBeanPostProcessor.getWebServerFactoryCustomizerBeans(WebServerFactoryCustomizerBeanPostProcessor.java:87) ~[spring-boot-3.3.4.jar:3.3.4]
at org.springframework.boot.web.server.WebServerFactoryCustomizerBeanPostProcessor.getCustomizers(WebServerFactoryCustomizerBeanPostProcessor.java:78) ~[spring-boot-3.3.4.jar:3.3.4]
at org.springframework.boot.web.server.WebServerFactoryCustomizerBeanPostProcessor.postProcessBeforeInitialization(WebServerFactoryCustomizerBeanPostProcessor.java:70) ~[spring-boot-3.3.4.jar:3.3.4]
at org.springframework.boot.web.server.WebServerFactoryCustomizerBeanPostProcessor.postProcessBeforeInitialization(WebServerFactoryCustomizerBeanPostProcessor.java:58) ~[spring-boot-3.3.4.jar:3.3.4]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:422) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1798) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:600) ~[spring-beans-6.1.13.jar:6.1.13]
... 14 common frames omitted
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'logbackAccessContext' defined in class path resource [dev/akkinoc/spring/boot/logback/access/LogbackAccessAutoConfiguration.class]: Failed to instantiate [dev.akkinoc.spring.boot.logback.access.LogbackAccessContext]: Factory method 'logbackAccessContext' threw exception with message: The FileNamePattern option must be set before using TimeBasedRollingPolicy. See also http://logback.qos.ch/codes.html#tbr_fnp_not_set
at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:648) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:636) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1355) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1185) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:562) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:522) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:337) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:335) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:254) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1443) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1353) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:904) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:782) ~[spring-beans-6.1.13.jar:6.1.13]
... 31 common frames omitted
Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [dev.akkinoc.spring.boot.logback.access.LogbackAccessContext]: Factory method 'logbackAccessContext' threw exception with message: The FileNamePattern option must be set before using TimeBasedRollingPolicy. See also http://logback.qos.ch/codes.html#tbr_fnp_not_set
at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:178) ~[spring-beans-6.1.13.jar:6.1.13]
at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:644) ~[spring-beans-6.1.13.jar:6.1.13]
... 45 common frames omitted
Caused by: java.lang.IllegalStateException: The FileNamePattern option must be set before using TimeBasedRollingPolicy. See also http://logback.qos.ch/codes.html#tbr_fnp_not_set
at ch.qos.logback.core.rolling.TimeBasedRollingPolicy.start(TimeBasedRollingPolicy.java:76) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy.start(SizeAndTimeBasedRollingPolicy.java:43) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.ImplicitModelHandler.postHandleComplex(ImplicitModelHandler.java:207) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.ImplicitModelHandler.postHandle(ImplicitModelHandler.java:186) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:257) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.DefaultProcessor.traversalLoop(DefaultProcessor.java:90) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.model.processor.DefaultProcessor.process(DefaultProcessor.java:106) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.joran.GenericXMLConfigurator.processModel(GenericXMLConfigurator.java:222) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:178) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:123) ~[logback-core-1.5.8.jar:1.5.8]
at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:66) ~[logback-core-1.5.8.jar:1.5.8]
at dev.akkinoc.spring.boot.logback.access.LogbackAccessContext.<init>(LogbackAccessContext.kt:47) ~[logback-access-spring-boot-starter-4.3.1.jar:4.3.1]
at dev.akkinoc.spring.boot.logback.access.LogbackAccessAutoConfiguration.logbackAccessContext(LogbackAccessAutoConfiguration.kt:59) ~[logback-access-spring-boot-starter-4.3.1.jar:4.3.1]
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[na:na]
at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:146) ~[spring-beans-6.1.13.jar:6.1.13]
... 46 common frames omitted


Process finished with exit code 1

The last "caused by" the important part, regarding "The FileNamePattern option must be set before using TimeBasedRollingPolicy".

However, the FileNamePattern is defined higher in the rollingPolicy, as can be seen. If I comment out the timeBasedFileNamingAndTriggeringPolicy, then I do not get the exception, however as I said, I believe I lose the ability to roll over the log file based on both time and file size.

I would grateful for any suggestions. Thanks!


Solution

  • You can use SizeAndTimeBasedRollingPolicy directly to rotate files based on both time and size.

            <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
                <fileNamePattern>logs/access-%d{yyyy-MM-dd}-%i.log</fileNamePattern>
                <maxHistory>30</maxHistory>
                <maxFileSize>10MB</maxFileSize>
            </rollingPolicy>
    

    No need to have timeBasedFileNamingAndTriggeringPolicy inside TimeBasedRollingPolicy.