[logback-user] Logback Rolling policy issue.

7 Mar 2014

      Dear logback team,

I am using logback-1.1.1 and slf4j-1.7.6.

I am getting logs files generated in following format: 
'someErrorLog_IS_UNDEFINED.log' which is undesired.

My logback.xml is:

<?xml version="1.0" encoding="UTF-8"?>

<!--<configuration debug="true" scan="true" scanPeriod="30 seconds">-->

<configuration>

<!-- <property name="LOG_HOME" value="/home/logs"/> -->

<property name="LOG_HOME" value="C:/Logs"/>

     <property name="infoLogName" value="someInfoLog"/>

<property name="errorLogName" value="someErrorLog"/>

     <timestamp key="bySecond" datePattern="yyyyMMdd'T'HHmmss"/>

<appender name="infofileAppender" 
class="ch.qos.logback.core.rolling.RollingFileAppender">

<!-- <file>C:/Logs/myLogFile.log</file>-->

<file>C:/Logs/someInfoLog.log</file>

<append>true</append>

         <rollingPolicy 
class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

<!-- rollover daily -->

          <fileNamePattern>C:/Logs/someInfoLog.log.%d{'.'yyyy-MM-dd}</fileNamePattern>

<!-- <fileNamePattern>mylog-%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern> -->

<maxHistory>1</maxHistory>

<timeBasedFileNamingAndTriggeringPolicy 
class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">

<!-- or whenever the file size reaches 100MB -->

<maxFileSize>1MB</maxFileSize>

</timeBasedFileNamingAndTriggeringPolicy>

</rollingPolicy>

         <encoder>

<!-- <pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %highlight(%-5level)  
%cyan(%-20.30logger{35}) [%file:%line] - %msg%n</pattern>-->

<pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %-20.50logger{35} - 
%msg%n</pattern>

<!-- <immediateFlush>false</immediateFlush>-->

<immediateFlush>false</immediateFlush>

<outputPatternAsHeader>true</outputPatternAsHeader>

</encoder>

     </appender>

     <appender name="errorfileAppender" 
class="ch.qos.logback.core.rolling.RollingFileAppender">

<!-- <file>C:/Logs/myLogFile.log</file>-->

<file>${LOG_HOME}/${someErrorLog}.log</file>

<append>true</append>

         <rollingPolicy 
class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

<!-- rollover daily -->

<fileNamePattern>${someErrorLog}.%d{yyyy-MM-dd}.%i.log.zip</fileNamePattern>

<!-- <fileNamePattern>mylog-%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern> -->

<maxHistory>30</maxHistory>

<timeBasedFileNamingAndTriggeringPolicy 
class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">

<!-- or whenever the file size reaches 100MB -->

<maxFileSize>25MB</maxFileSize>

</timeBasedFileNamingAndTriggeringPolicy>

</rollingPolicy>

         <encoder>

<!-- <pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %highlight(%-5level)  
%cyan(%-20.30logger{35}) [%file:%line] - %msg%n</pattern>-->

<pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %-20.50logger{35} - 
%msg%n</pattern>

<immediateFlush>true</immediateFlush>

<outputPatternAsHeader>true</outputPatternAsHeader>

</encoder>

         <filter class="ch.qos.logback.classic.filter.LevelFilter">

<level>ERROR</level>

<onMatch>ACCEPT</onMatch>

<onMismatch>DENY</onMismatch>

</filter>

     </appender>

     <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">

<append>true</append>

<encoder>

<pattern>%-30(%d{HH:mm:ss.SSS} [%thread]) %-5level %-20.50logger{35} - 
%msg%n</pattern>

</encoder>

</appender>

<root level="TRACE" additivity="true">

<appender-ref ref="infofileAppender" />

<appender-ref ref="errorfileAppender"/>

</root>

</configuration>

I am using glassfish 4 web profile server.

The logs printed while stratup are:

INFO: 15:11:25,188 |-INFO in 
ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource 
[logback.groovy]

15:11:25,189 |-INFO in ch.qos.logback.classic.LoggerContext[default] - 
Could NOT find resource [logback-test.xml]

15:11:25,190 |-INFO in ch.qos.logback.classic.LoggerContext[default] - 
Found resource [logback.xml] at 
[file:/C:/workspaces/NetBeans/SomeProject7/build/web/WEB-INF/classes/logback.xml]

15:11:25,412 |-INFO in 
ch.qos.logback.classic.joran.action.ConfigurationAction - debug 
attribute not set

15:11:25,449 |-INFO in ch.qos.logback.core.joran.action.TimestampAction 
- Using current interpretation time, i.e. now, as time reference.

15:11:25,451 |-INFO in ch.qos.logback.core.joran.action.TimestampAction 
- Adding property to the context with key="bySecond" and 
value="20140307T151125" to the LOCAL scope

15:11:25,451 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - 
About to instantiate appender of type 
[ch.qos.logback.core.rolling.RollingFileAppender]

15:11:25,464 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - 
Naming appender as [infofileAppender]

15:11:25,754 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No 
compression will be used

15:11:25,758 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will 
use the pattern C:/Logs/someInfoLog.log.%d{'.'yyyy-MM-dd} for the active 
file

15:11:25,765 |-INFO in 
ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b 
<mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b> - The 
date pattern is '.' from file name pattern 
'C:/Logs/someInfoLog.log.%d{'.'yyyy-MM-dd}'.

15:11:25,765 |-INFO in 
ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b 
<mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b> - 
Unknown periodicity.

15:11:25,765 |-INFO in 
ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b 
<mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1405f8b> - 
Setting initial period to Fri Mar 07 15:11:25 IST 2014

15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@32:25 
<mailto:ch.qos.logback.core.joran.spi.Interpreter@32:25> - 
RuntimeException in Action for tag [rollingPolicy] 
java.lang.IllegalStateException: Unknown periodicity type.

at java.lang.IllegalStateException: Unknown periodicity type.

at           at 
ch.qos.logback.core.rolling.helper.RollingCalendar.getRelativeDate(RollingCalendar.java:234)

at           at 
ch.qos.logback.core.rolling.helper.RollingCalendar.getNextTriggeringDate(RollingCalendar.java:241)

at           at 
ch.qos.logback.core.rolling.helper.RollingCalendar.getNextTriggeringMillis(RollingCalendar.java:64)

at           at 
ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBase.computeNextCheck(TimeBasedFileNamingAndTriggeringPolicyBase.java:75)

at           at 
ch.qos.logback.core.rolling.TimeBasedFileNamingAndTriggeringPolicyBase.start(TimeBasedFileNamingAndTriggeringPolicyBase.java:67)

at           at 
ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP.start(SizeAndTimeBasedFNATP.java:38)

at           at 
ch.qos.logback.core.rolling.TimeBasedRollingPolicy.start(TimeBasedRollingPolicy.java:90)

at           at 
ch.qos.logback.core.joran.action.NestedComplexPropertyIA.end(NestedComplexPropertyIA.java:167)

at           at 
ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)

at           at 
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)

at           at 
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)

at           at 
ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)

at           at 
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)

at           at 
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)

at           at 
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)

at           at 
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)

at           at 
ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)

at           at 
ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150)

at           at 
org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)

at           at 
org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)

at           at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)

at           at 
org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)

at           at 
org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)

at           at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)

at           at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)

at           at 
com.edubond.web.security.AuthorizationListener.<clinit>(AuthorizationListener.java:30)

at           at java.lang.Class.forName0(Native Method)

at           at java.lang.Class.forName(Class.java:266)

at           at com.sun.faces.util.Util.loadClass(Util.java:301)

at           at 
com.sun.faces.config.processor.AbstractConfigProcessor.loadClass(AbstractConfigProcessor.java:376)

at           at 
com.sun.faces.config.processor.AbstractConfigProcessor.createInstance(AbstractConfigProcessor.java:278)

at           at 
com.sun.faces.config.processor.LifecycleConfigProcessor.addPhaseListeners(LifecycleConfigProcessor.java:132)

at           at 
com.sun.faces.config.processor.LifecycleConfigProcessor.process(LifecycleConfigProcessor.java:111)

at           at 
com.sun.faces.config.processor.AbstractConfigProcessor.invokeNext(AbstractConfigProcessor.java:152)

at           at 
com.sun.faces.config.processor.FactoryConfigProcessor.process(FactoryConfigProcessor.java:239)

at           at 
com.sun.faces.config.ConfigManager.initialize(ConfigManager.java:435)

at           at 
com.sun.faces.config.ConfigureListener.contextInitialized(ConfigureListener.java:214)

at           at 
org.apache.catalina.core.StandardContext.contextListenerStart(StandardContext.java:5362)

at           at 
com.sun.enterprise.web.WebModule.contextListenerStart(WebModule.java:743)

at           at 
org.apache.catalina.core.StandardContext.start(StandardContext.java:5898)

at           at com.sun.enterprise.web.WebModule.start(WebModule.java:691)

at           at 
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:1041)

at           at 
org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:1024)

at           at 
org.apache.catalina.core.StandardHost.addChild(StandardHost.java:747)

at           at 
com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:2278)

at           at 
com.sun.enterprise.web.WebContainer.loadWebModule(WebContainer.java:1924)

at           at 
com.sun.enterprise.web.WebApplication.start(WebApplication.java:139)

at           at 
org.glassfish.internal.data.EngineRef.start(EngineRef.java:122)

at           at 
org.glassfish.internal.data.ModuleInfo.start(ModuleInfo.java:291)

at           at 
org.glassfish.internal.data.ApplicationInfo.start(ApplicationInfo.java:352)

at           at 
com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:497)

at           at 
com.sun.enterprise.v3.server.ApplicationLifecycle.deploy(ApplicationLifecycle.java:219)

at           at 
org.glassfish.deployment.admin.DeployCommand.execute(DeployCommand.java:491)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:527)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:523)

at           at java.security.AccessController.doPrivileged(Native Method)

at           at javax.security.auth.Subject.doAs(Subject.java:356)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl$2.execute(CommandRunnerImpl.java:522)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:546)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:1423)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl.access$1500(CommandRunnerImpl.java:108)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1762)

at           at 
com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1674)

at           at 
com.sun.enterprise.v3.admin.AdminAdapter.doCommand(AdminAdapter.java:534)

at           at 
com.sun.enterprise.v3.admin.AdminAdapter.onMissingResource(AdminAdapter.java:224)

at           at 
org.glassfish.grizzly.http.server.StaticHttpHandler.service(StaticHttpHandler.java:297)

at           at 
com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:246)

at           at 
org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:191)

at           at org.glassfish.grizzly.http.server.HttpHandler.doHan

INFO: dle(HttpHandler.java:168)

at           at 
org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:189)

at           at 
org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)

at           at 
org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:288)

at           at 
org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:206)

at           at 
org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:136)

at           at 
org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:114)

at           at 
org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)

at           at 
org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:838)

at           at 
org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:113)

at           at 
org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:115)

at           at 
org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:55)

at           at 
org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:135)

at           at 
org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:564)

at           at 
org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:544)

at           at java.lang.Thread.run(Thread.java:722)

15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@34:18 
<mailto:ch.qos.logback.core.joran.spi.Interpreter@34:18> - no applicable 
action for [encoder], current ElementPath  is 
[[configuration][appender][encoder]]

15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@36:22 
<mailto:ch.qos.logback.core.joran.spi.Interpreter@36:22> - no applicable 
action for [pattern], current ElementPath  is 
[[configuration][appender][encoder][pattern]]

15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@38:29 
<mailto:ch.qos.logback.core.joran.spi.Interpreter@38:29> - no applicable 
action for [immediateFlush], current ElementPath is 
[[configuration][appender][encoder][immediateFlush]]

15:11:25,767 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@39:36 
<mailto:ch.qos.logback.core.joran.spi.Interpreter@39:36> - no applicable 
action for [outputPatternAsHeader], current ElementPath  is 
[[configuration][appender][encoder][outputPatternAsHeader]]

15:11:25,769 |-WARN in 
ch.qos.logback.core.rolling.RollingFileAppender[infofileAppender] - No 
TriggeringPolicy was set for the RollingFileAppender named infofileAppender

15:11:25,769 |-WARN in 
ch.qos.logback.core.rolling.RollingFileAppender[infofileAppender] - For 
more information, please visit http://logback.qos.ch/codes.html#rfa_no_tp

15:11:25,769 |-WARN in ch.qos.logback.core.joran.action.AppenderAction - 
The object at the of the stack is not the appender named 
[infofileAppender] pushed earlier.

15:11:25,769 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - 
About to instantiate appender of type 
[ch.qos.logback.core.rolling.RollingFileAppender]

15:11:25,769 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - 
Naming appender as [errorfileAppender]

15:11:25,770 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will 
use zip compression

15:11:25,770 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will 
use the pattern someErrorLog_IS_UNDEFINED.%d{yyyy-MM-dd}.%i.log for the 
active file

15:11:25,771 |-INFO in 
ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2 
<mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2> - The 
date pattern is 'yyyy-MM-dd' from file name pattern 
'someErrorLog_IS_UNDEFINED.%d{yyyy-MM-dd}.%i.log.zip'.

15:11:25,771 |-INFO in 
ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2 
<mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2> - 
Roll-over at midnight.

15:11:25,771 |-INFO in 
ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2 
<mailto:ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@ab1de2> - 
Setting initial period to Mon Mar 03 15:52:40 IST 2014

15:11:25,775 |-INFO in 
ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming 
default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for 
[encoder] property

15:11:25,901 |-INFO in 
ch.qos.logback.core.rolling.RollingFileAppender[errorfileAppender] - 
Active log file name: C:/Logs/someErrorLog_IS_UNDEFINED.log

15:11:25,901 |-INFO in 
ch.qos.logback.core.rolling.RollingFileAppender[errorfileAppender] - 
File property is set to [C:/Logs/someErrorLog_IS_UNDEFINED.log]

15:11:25,908 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - 
About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]

15:11:25,915 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - 
Naming appender as [STDOUT]

15:11:25,920 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@77:17 
<mailto:ch.qos.logback.core.joran.spi.Interpreter@77:17> - no applicable 
action for [append], current ElementPath  is 
[[configuration][appender][append]]

15:11:25,920 |-INFO in 
ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming 
default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for 
[encoder] property

15:11:25,921 |-INFO in 
ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of 
ROOT logger to TRACE

15:11:25,921 |-INFO in 
ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender 
named [infofileAppender] to Logger[ROOT]

15:11:25,923 |-INFO in 
ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender 
named [errorfileAppender] to Logger[ROOT]

15:11:25,923 |-INFO in 
ch.qos.logback.classic.joran.action.ConfigurationAction - End of 
configuration.

15:11:25,925 |-INFO in 
ch.qos.logback.classic.joran.JoranConfigurator@370ff5 
<mailto:ch.qos.logback.classic.joran.JoranConfigurator@370ff5> - 
Registering current configuration as safe fallback point

Please tell what is wrong in my configuration file? FileAppender is not 
working as expected.

Regards,

Chandra

This e-mail and all material transmitted with it are for the use of the 
intended recipient(s) ONLY and contains confidential and/or privileged 
information. If you are not the intended recipient, please contact the 
sender by reply e-mail and destroy all copies and the original message. 
Any unauthorized review, use, disclosure, dissemination, forwarding, 
printing or copying of this email or any action taken pursuant to the 
contents of the present e-mail is strictly prohibited and is unlawful. 
The recipient acknowledges that Comviva Technologies Limited or its 
management or directors, are unable to exercise control or ensure the 
integrity over /of the contents of the information contained in e-mail. 
Any views expressed herein are those of the individual sender only and 
no binding nature of the contents shall be implied or assumed unless the 
sender does so expressly with due authority of Comviva Technologies 
Limited. E-mail and any contents transmitted with it are prone to 
viruses and related defects despite all efforts to avoid such by Comviva 
Technologies Limited.

[logback-user] Logback Rolling policy issue.

Chandraprakash