Log4j2 - current date file append not working

Question

I'm trying to save current logs to the catalina log with appended current date.

Log4j2.xml looks like:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
<Appenders>
    <RollingFile name="CATALINA"
                 fileName   ="${sys:catalina.base}/logs/catalina.log"
                 filePattern="${sys:catalina.base}/logs/catalina.%d{yyyy-MM-dd}-%i.log">
        <PatternLayout pattern="[TID=%tid] %d %-5p %c- %m%n"/>
        <TimeBasedTriggeringPolicy modulate="true" />
    </RollingFile>
</Appenders>
<Loggers>
    <Root level="DEBUG" >
        <AppenderRef ref="CATALINA" />
    </Root>
</Loggers>
</Configuration>

but is saved as catalina.log without current date.

I have moved from log4j where I have properties which were doing that job:

log4j.appender.CATALINA=org.apache.log4j.rolling.RollingFileAppender
log4j.appender.CATALINA.RollingPolicy=org.apache.log4j.rolling.TimeBasedRollingPolicy
log4j.appender.CATALINA.RollingPolicy.FileNamePattern=${catalina.base}/logs/catalina.%d{yyyy-MM-dd}.log

I'm using log4j2 version 2.3 due to code uses JDK6.

Also I have went to catalina.properties and removed log4j*.jar from the jarsToSkip property, per Vasan suggestion, but still current date is not appended to current catalina log.

Tomcat startup logs:

Mar 19, 2018 3:00:31 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 619 ms
Mar 19, 2018 3:00:31 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Mar 19, 2018 3:00:31 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.22
Mar 19, 2018 3:00:31 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive monitor.war
Mar 19, 2018 3:00:31 PM org.apache.catalina.loader.WebappClassLoader validateJarFile
INFO: validateJarFile(/usr/local//apache-tomcat-7.0.22/webapps/msg-monitor/WEB-INF/lib/javax.servlet-3.0.jar) - jar not loaded. See Servlet Spec 2.3, section 9.7.2. Offending class: javax/servlet/Servlet.class
Mar 19, 2018 3:00:31 PM org.apache.catalina.loader.WebappClassLoader validateJarFile
INFO: validateJarFile(/usr/local/apache-tomcat-7.0.22/webapps/msg-monitor/WEB-INF/lib/servlet-api-2.5.jar) - jar not loaded. See Servlet Spec 2.3, section 9.7.2. Offending class: javax/servlet/Servlet.class
Mar 19, 2018 3:00:31 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Mar 19, 2018 3:00:31 PM org.springframework.web.context.ContextLoader initWebApplicationContext
INFO: Root WebApplicationContext: initialization started
Mar 19, 2018 3:00:31 PM org.springframework.context.support.AbstractApplicationContext prepareRefresh
INFO: Refreshing org.springframework.web.context.support.XmlWebApplicationContext@5e1558dc: display name [Root WebApplicationContext]; startup date [Mon Mar 19 15:00:31 EDT 2018]; root of context hierarchy
Mar 19, 2018 3:00:31 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions
INFO: Loading XML bean definitions from ServletContext resource [/WEB-INF/applicationContext.xml]
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
Mar 19, 2018 3:00:32 PM org.springframework.context.support.AbstractApplicationContext obtainFreshBeanFactory
INFO: Bean factory for application context [org.springframework.web.context.support.XmlWebApplicationContext@5e1558dc]: org.springframework.beans.factory.support.DefaultListableBeanFactory@2e7cf883
Mar 19, 2018 3:00:32 PM org.springframework.core.io.support.PropertiesLoaderSupport loadProperties
INFO: Loading properties file from class path resource [properties/monitor.properties]
Mar 19, 2018 3:00:32 PM org.springframework.context.support.AbstractApplicationContext$BeanPostProcessorChecker postProcessAfterInitialization
INFO: Bean 'org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter#718ddc48' is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
Mar 19, 2018 3:00:32 PM org.springframework.context.support.AbstractApplicationContext$BeanPostProcessorChecker postProcessAfterInitialization
INFO: Bean 'dataSource' is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
Mar 19, 2018 3:00:32 PM org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean createNativeEntityManagerFactory
INFO: Building JPA container EntityManagerFactory for persistence unit 'direct-msg-monitor-store'
Mar 19, 2018 3:00:33 PM org.springframework.context.support.AbstractApplicationContext$BeanPostProcessorChecker postProcessAfterInitialization
INFO: Bean 'entityManagerFactory' is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
Mar 19, 2018 3:00:33 PM org.springframework.context.support.AbstractApplicationContext$BeanPostProcessorChecker postProcessAfterInitialization
INFO: Bean 'org.springframework.transaction.annotation.AnnotationTransactionAttributeSource#0' is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
Mar 19, 2018 3:00:33 PM org.springframework.context.support.AbstractApplicationContext$BeanPostProcessorChecker postProcessAfterInitialization
INFO: Bean 'org.springframework.transaction.config.internalTransactionAdvisor' is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
Mar 19, 2018 3:00:33 PM org.springframework.beans.factory.support.DefaultListableBeanFactory preInstantiateSingletons
INFO: Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@2e7cf883: defining beans [org.springframework.context.annotation.internalPersistenceAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,txJSONProvider,healthCheckResource,txsResource,aggregationDAOImpl,notificationDuplicationDAOImpl,org.springframework.aop.config.internalAutoProxyCreator,org.springframework.transaction.annotation.AnnotationTransactionAttributeSource#0,org.springframework.transaction.interceptor.TransactionInterceptor#0,org.springframework.transaction.config.internalTransactionAdvisor,org.springframework.dao.annotation.PersistenceExceptionTranslationPostProcessor#0,entityManagerFactory,dataSource,transactionManager,notificationDuplicationDAO,duplicationStateManager,org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0,generalTimeoutCondition,reliableTimeoutCondition,varaiableTimeoutCondition,generalCompletionCondition,reliableCompletionCondition,variableCompletionCondition,aggregationStrategy,msgIdCorrelator,textAssemblerFactory,textBodyGenerator,dsnGenerator,dsnMessageProcessor,smtpClientFactory,dsnSender,aggregationDAO,directMonitoringRepo,msgMonitoringProducerTemplate,consumerTemplate,camel-1:beanPostProcessor,camel-1]; root of factory hierarchy
Mar 19, 2018 3:00:34 PM org.springframework.web.context.ContextLoader initWebApplicationContext
INFO: Root WebApplicationContext: initialization completed in 2804 ms
Mar 19, 2018 3:00:35 PM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [1,265] milliseconds.
Mar 19, 2018 3:00:36 PM com.sun.jersey.spi.spring.container.servlet.SpringServlet getContext
INFO: Using default applicationContext
Mar 19, 2018 3:00:36 PM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
INFO: Initiating Jersey application, version 'Jersey: 1.6 03/25/2011 01:14 PM'
Mar 19, 2018 3:00:36 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive service.war

Any clue what I have set wrong?

Answer 1

Try below configuration for printing current date in log file name -

     <RollingFile name="CATALINA"
                 fileName   ="${sys:catalina.base}/logs/catalina.${date:yyyy-MM-dd}.log"
                 filePattern="${sys:catalina.base}/logs/catalina.%d{yyyy-MM-dd}.log">
        <PatternLayout pattern="[TID=%tid] %d %-5p %c- %m%n"/>
        <TimeBasedTriggeringPolicy modulate="true" />
    </RollingFile>

Answer 2

This version of tomcat skips scanning for any JAR matching the pattern log4j*.jar. The pattern is statically configured in catalina.properties (in tomcat.util.scan.DefaultJarScanner.jarsToSkip property) that is bundled with tomcat.

Due to this, it does not read the log4j2 ServletContainerInitializer which sets log4j2 up for web applications. So you'll need to change the properties file to remove the log4j* pattern.

Reference