Log4j 2
  1. Log4j 2
  2. LOG4J2-659

Log files not properly rolled over to the folder.

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 2.0-rc1
    • Fix Version/s: None
    • Component/s: Appenders
    • Labels:
    • Environment:

      Java 7

      Description

      This is happening in our production environment. My application is using rolling file appender. In the beginning of this month the files are not rolled over to the folders as expected.

      2014-05 folder contains 06/01 and 06/02 rolled over files and 2014-06 folder contains 05/30 file

      In another server 2014-06 folder is not yet created still now and the log files on 06/01 and 06/02 are rolled over to the 2014-05 folder.

      Screen shots have been attached. In the screen shots file names are masked due to the compliance rules.

      Can you please advise what I need to do for resolving this issue?

      The configuration is as below.

      <?xml version="1.0" encoding="UTF-8"?>
      <configuration>
      <properties>
      <property name="logPattern">%c|%K

      {sessionId}

      |%t|%d

      {MM/dd/yyyy HH:mm:ss.SSS}

      |%p|%C|%M|%L|%K

      {msg}

      %n</property>
      <property name="filePattern">$

      {sys:logfilepath}

      //$$

      {date:yyyy-MM}

      //$

      {sys:oft.appserver}

      out%d

      {yyyy-MM-dd}

      .log</property>
      <property name="fileName">$

      {sys:logfilepath}

      //$

      {sys:oft.appserver}

      -out.log</property>
      </properties>
      <appenders>
      <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="logPattern"/>
      </Console>
      <RollingFile name="RollingFile" fileName="$

      {fileName}

      " filePattern="$

      {filePattern}

      ">
      <PatternLayout>
      <pattern>$

      {logPattern}

      </pattern>
      </PatternLayout>
      <Policies>
      <TimeBasedTriggeringPolicy />
      </Policies>
      </RollingFile>
      </appenders>
      <loggers>
      <AsyncLogger name="logtype" level="info" includeLocation="true" additivity="false">
      <AppenderRef ref="RollingFile"/>
      </AsyncLogger>
      <root level="info">
      <AppenderRef ref="Console"/>
      </root>
      </loggers>
      </configuration>

      1. Log4j.png
        16 kB
        sivan
      2. log4j.png
        10 kB
        sivan
      3. 2014-06.png
        4 kB
        sivan
      4. 2014-05.png
        12 kB
        sivan
      5. $$date_debug _trace.txt
        8 kB
        sivan
      6. $$$date_debug _trace.txt
        8 kB
        sivan

        Activity

        sivan created issue -
        Hide
        sivan added a comment -

        In the screen shots file name are masked due to the compliance rules.

        Show
        sivan added a comment - In the screen shots file name are masked due to the compliance rules.
        sivan made changes -
        Field Original Value New Value
        Attachment log4j.png [ 12648129 ]
        Attachment 2014-05.png [ 12648130 ]
        Attachment 2014-06.png [ 12648131 ]
        sivan made changes -
        Description This is happening in our production environment. My application is using rolling file appender. But in the beginning of this month the files are not rolled over to the folders as expected.

        2014-05 folder contains 06/01 and 06/02 rolled over files and 2014-06 folder contains 05/30 file

        Screen shots has been attached. In the screen shots file name are masked due to the compliance rules.

        Can you please advise what I need to do for resolving this issue?
        This is happening in our production environment. My application is using rolling file appender. In the beginning of this month the files are not rolled over to the folders as expected.

        2014-05 folder contains 06/01 and 06/02 rolled over files and 2014-06 folder contains 05/30 file

        Screen shots has been attached. In the screen shots file name are masked due to the compliance rules.

        Can you please advise what I need to do for resolving this issue?
        sivan made changes -
        Description This is happening in our production environment. My application is using rolling file appender. In the beginning of this month the files are not rolled over to the folders as expected.

        2014-05 folder contains 06/01 and 06/02 rolled over files and 2014-06 folder contains 05/30 file

        Screen shots has been attached. In the screen shots file name are masked due to the compliance rules.

        Can you please advise what I need to do for resolving this issue?
        This is happening in our production environment. My application is using rolling file appender. In the beginning of this month the files are not rolled over to the folders as expected.

        2014-05 folder contains 06/01 and 06/02 rolled over files and 2014-06 folder contains 05/30 file

        Screen shots has been attached. In the screen shots file name are masked due to the compliance rules.

        Can you please advise what I need to do for resolving this issue?

        The configuration is as below.

        <?xml version="1.0" encoding="UTF-8"?>
        <configuration>
        <properties>
        <property name="logPattern">%c|%K{sessionId}|%t|%d{MM/dd/yyyy HH:mm:ss.SSS}|%p|%C|%M|%L|%K{msg}%n</property>
        <property name="filePattern">${sys:logfilepath}//$${date:yyyy-MM}//${sys:oft.appserver}-out-%d{yyyy-MM-dd}.log</property>
        <property name="fileName">${sys:logfilepath}//${sys:oft.appserver}-out.log</property>
        </properties>
        <appenders>
        <Console name="Console" target="SYSTEM_OUT">
        <PatternLayout pattern="logPattern"/>
        </Console>
        <RollingFile name="RollingFile" fileName="${fileName}" filePattern="${filePattern}">
        <PatternLayout>
        <pattern>${logPattern}</pattern>
        </PatternLayout>
        <Policies>
        <TimeBasedTriggeringPolicy />
        </Policies>
        </RollingFile>
        </appenders>
        <loggers>
        <AsyncLogger name="logtype" level="info" includeLocation="true" additivity="false">
        <AppenderRef ref="RollingFile"/>
        </AsyncLogger>
        <root level="info">
        <AppenderRef ref="Console"/>
        </root>
        </loggers>
        </configuration>
        sivan made changes -
        Description This is happening in our production environment. My application is using rolling file appender. In the beginning of this month the files are not rolled over to the folders as expected.

        2014-05 folder contains 06/01 and 06/02 rolled over files and 2014-06 folder contains 05/30 file

        Screen shots has been attached. In the screen shots file name are masked due to the compliance rules.

        Can you please advise what I need to do for resolving this issue?

        The configuration is as below.

        <?xml version="1.0" encoding="UTF-8"?>
        <configuration>
        <properties>
        <property name="logPattern">%c|%K{sessionId}|%t|%d{MM/dd/yyyy HH:mm:ss.SSS}|%p|%C|%M|%L|%K{msg}%n</property>
        <property name="filePattern">${sys:logfilepath}//$${date:yyyy-MM}//${sys:oft.appserver}-out-%d{yyyy-MM-dd}.log</property>
        <property name="fileName">${sys:logfilepath}//${sys:oft.appserver}-out.log</property>
        </properties>
        <appenders>
        <Console name="Console" target="SYSTEM_OUT">
        <PatternLayout pattern="logPattern"/>
        </Console>
        <RollingFile name="RollingFile" fileName="${fileName}" filePattern="${filePattern}">
        <PatternLayout>
        <pattern>${logPattern}</pattern>
        </PatternLayout>
        <Policies>
        <TimeBasedTriggeringPolicy />
        </Policies>
        </RollingFile>
        </appenders>
        <loggers>
        <AsyncLogger name="logtype" level="info" includeLocation="true" additivity="false">
        <AppenderRef ref="RollingFile"/>
        </AsyncLogger>
        <root level="info">
        <AppenderRef ref="Console"/>
        </root>
        </loggers>
        </configuration>
        This is happening in our production environment. My application is using rolling file appender. In the beginning of this month the files are not rolled over to the folders as expected.

        2014-05 folder contains 06/01 and 06/02 rolled over files and 2014-06 folder contains 05/30 file

        In another server 2014-06 folder is not yet created still now and the log files on 06/01 and 06/02 are rolled over to the 2014-05 folder.

        Screen shots have been attached. In the screen shots file names are masked due to the compliance rules.

        Can you please advise what I need to do for resolving this issue?

        The configuration is as below.

        <?xml version="1.0" encoding="UTF-8"?>
        <configuration>
        <properties>
        <property name="logPattern">%c|%K{sessionId}|%t|%d{MM/dd/yyyy HH:mm:ss.SSS}|%p|%C|%M|%L|%K{msg}%n</property>
        <property name="filePattern">${sys:logfilepath}//$${date:yyyy-MM}//${sys:oft.appserver}-out-%d{yyyy-MM-dd}.log</property>
        <property name="fileName">${sys:logfilepath}//${sys:oft.appserver}-out.log</property>
        </properties>
        <appenders>
        <Console name="Console" target="SYSTEM_OUT">
        <PatternLayout pattern="logPattern"/>
        </Console>
        <RollingFile name="RollingFile" fileName="${fileName}" filePattern="${filePattern}">
        <PatternLayout>
        <pattern>${logPattern}</pattern>
        </PatternLayout>
        <Policies>
        <TimeBasedTriggeringPolicy />
        </Policies>
        </RollingFile>
        </appenders>
        <loggers>
        <AsyncLogger name="logtype" level="info" includeLocation="true" additivity="false">
        <AppenderRef ref="RollingFile"/>
        </AsyncLogger>
        <root level="info">
        <AppenderRef ref="Console"/>
        </root>
        </loggers>
        </configuration>
        Hide
        Ralph Goers added a comment - - edited

        Here is what I suspect what is happening.

        1. When the filePattern property is read the logfilepath and oft.appserver system properties are resolved. The date variable has one $ removed.
        2. When the RollingFileAppender is configured the date variable is resolved.
        3. When rollover occurs no variables are present in the path so only the file name is changed.

        To prove this you can add status="debug" to the configuration element. You should see in the log if the variable is resolved when the Appender is configured or not. You can also try changing $${date:} to $$${date:} and see if that resolves the problem.

        Show
        Ralph Goers added a comment - - edited Here is what I suspect what is happening. 1. When the filePattern property is read the logfilepath and oft.appserver system properties are resolved. The date variable has one $ removed. 2. When the RollingFileAppender is configured the date variable is resolved. 3. When rollover occurs no variables are present in the path so only the file name is changed. To prove this you can add status="debug" to the configuration element. You should see in the log if the variable is resolved when the Appender is configured or not. You can also try changing $${date:} to $$${date:} and see if that resolves the problem.
        Hide
        sivan added a comment -

        Attached is the debug trace on application start up.

        Show
        sivan added a comment - Attached is the debug trace on application start up.
        sivan made changes -
        Attachment $$date_debug _trace.txt [ 12648290 ]
        Attachment $$$date_debug _trace.txt [ 12648291 ]
        Hide
        sivan added a comment - - edited

        Thanks for your response.

        I tried with $$$date and $$date and size based triggering policy in my development machine. Both resolved the path successfully.
        Please find the attached debug trace on application start up

        Below is the bebug trace on log file rollover. ".\" is the application path in my dev machine.
        2014-06-04 12:11:41,908 DEBUG RollingFileManager executing synchronous FileRenameAction[.\PS0565-out.log to .\2014-06\PS0565-out-2014-06-04.log, renameEmptyFiles=false]

        Today I analyzed the log4j folder in our production environment and the common behaviours found are as below.

        1. 06/01 and 06/02 files are rolled over to the 2014-05 folder.
        2. 06/03 files are properly rolled over to the 2014-06 folder.
        3. Some 05/30 and 05/31 files are also rolled over to the 2014-06 folder.

        Can you please advise what else I need to do to resolve these 1 and 3 issues?

        Show
        sivan added a comment - - edited Thanks for your response. I tried with $$$date and $$date and size based triggering policy in my development machine. Both resolved the path successfully. Please find the attached debug trace on application start up Below is the bebug trace on log file rollover. ".\" is the application path in my dev machine. 2014-06-04 12:11:41,908 DEBUG RollingFileManager executing synchronous FileRenameAction [.\PS0565-out.log to .\2014-06\PS0565-out-2014-06-04.log, renameEmptyFiles=false] Today I analyzed the log4j folder in our production environment and the common behaviours found are as below. 1. 06/01 and 06/02 files are rolled over to the 2014-05 folder. 2. 06/03 files are properly rolled over to the 2014-06 folder. 3. Some 05/30 and 05/31 files are also rolled over to the 2014-06 folder. Can you please advise what else I need to do to resolve these 1 and 3 issues?
        Hide
        sivan added a comment -

        This folder is created on 06/03. But 06/02 files were not rolled over to this folder.

        Show
        sivan added a comment - This folder is created on 06/03. But 06/02 files were not rolled over to this folder.
        sivan made changes -
        Attachment Log4j.png [ 12648486 ]
        Hide
        sivan added a comment -

        Is anything else needed to resolve this issue?

        Show
        sivan added a comment - Is anything else needed to resolve this issue?
        Hide
        Gary Gregory added a comment -

        Have you tried building and testing with trunk?

        Gary

        Show
        Gary Gregory added a comment - Have you tried building and testing with trunk? Gary
        Hide
        sivan added a comment -

        Can you please elaborate?

        Show
        sivan added a comment - Can you please elaborate?
        Hide
        Gary Gregory added a comment -

        You can checkout and build the current source code from our repository. There have been many changes from 2.0-rc1.

        To get started, please see https://logging.apache.org/log4j/2.x/build.html

        You'll also need to install what you build with "mvn install", then change the Log4j version you use in your app to what was built, today that would be 2.0-rc2-SNAPSHOT.

        Show
        Gary Gregory added a comment - You can checkout and build the current source code from our repository. There have been many changes from 2.0-rc1. To get started, please see https://logging.apache.org/log4j/2.x/build.html You'll also need to install what you build with "mvn install", then change the Log4j version you use in your app to what was built, today that would be 2.0-rc2-SNAPSHOT.
        Hide
        Ralph Goers added a comment -

        $$$date_debug_trace.txt is showing correct behavior. As I expected, $$date_debug_trace.txt shows that the directory was resolved when the configuration was processed and would result in the directory only changing on a reconfiguration.

        It sounds like your production environment uses $$ instead of $$$. Please change to that and report if that solves the problem.

        Show
        Ralph Goers added a comment - $$$date_debug_trace.txt is showing correct behavior. As I expected, $$date_debug_trace.txt shows that the directory was resolved when the configuration was processed and would result in the directory only changing on a reconfiguration. It sounds like your production environment uses $$ instead of $$$. Please change to that and report if that solves the problem.
        Hide
        sivan added a comment - - edited

        Thanks Ralph for your great analysis and resolution.

        I checked-in the suggested change in our production branch. But the monthly rollover behavior can be verified in production only by the next month 07/01.

        But still why the log file of 05/30 rolled over to the folder 2014-06. The scenario is after 05/30, the hit for the next log entry was happened on 06/02 only.
        So I think the log file of 05/30 was rolled over to the newly created folder 2014-06.

        Is it correct? If yes, it should not happen and should rolled over to the folder 2014-05 only.

        Is any resolution for this?

        Show
        sivan added a comment - - edited Thanks Ralph for your great analysis and resolution. I checked-in the suggested change in our production branch. But the monthly rollover behavior can be verified in production only by the next month 07/01. But still why the log file of 05/30 rolled over to the folder 2014-06. The scenario is after 05/30, the hit for the next log entry was happened on 06/02 only. So I think the log file of 05/30 was rolled over to the newly created folder 2014-06. Is it correct? If yes, it should not happen and should rolled over to the folder 2014-05 only. Is any resolution for this?
        Hide
        Ralph Goers added a comment -

        I suspect that you restarted your server in June. The date lookup probably resolved to that instead of the file timestamp. If that happened that would be a bug.

        Show
        Ralph Goers added a comment - I suspect that you restarted your server in June. The date lookup probably resolved to that instead of the file timestamp. If that happened that would be a bug.
        Hide
        sivan added a comment -

        We restarts our production servers after the patch deployment on every week end.
        Is anything to do before stopping the server like stopping the log4j appender, addition of any file close method etc?

        Show
        sivan added a comment - We restarts our production servers after the patch deployment on every week end. Is anything to do before stopping the server like stopping the log4j appender, addition of any file close method etc?
        Remko Popma made changes -
        Labels Rollover
        Hide
        sivan added a comment -

        Thanks a lot Ralph.
        Now its working fine in our production environment and you can close this issue.

        Show
        sivan added a comment - Thanks a lot Ralph. Now its working fine in our production environment and you can close this issue.
        Hide
        sivan added a comment -

        I am closing this issue.

        Show
        sivan added a comment - I am closing this issue.
        Hide
        sivan added a comment -

        This has been fixed and is working fine now.

        Show
        sivan added a comment - This has been fixed and is working fine now.
        sivan made changes -
        Status Open [ 1 ] Closed [ 6 ]
        Resolution Fixed [ 1 ]
        Transition Time In Source Status Execution Times Last Executer Last Execution Date
        Open Open Closed Closed
        33d 17h 26m 1 sivan 07/Jul/14 06:26

          People

          • Assignee:
            Unassigned
            Reporter:
            sivan
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development