Log4j 2
  1. Log4j 2
  2. LOG4J2-380

RollingFile Appender is placing archived logs in the wrong directory

    Details

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

      System timezone is UTC

      Description

      I'm using RollingFile appender with archiving to a separate directory.
      The archive directory pattern is yyyy-MM.
      Up until 2013-08-30, everything worked just fine.
      All the logs for August were placed inside directory 2013-08

      On 2013-09-01 00:01, log4j2 placed the log for 2013-08-31 inside directory 2013-09, instead of 2013-08

      -bash-4.1$ ls -l 2013-09
      total 8
      rw-rw-r- 1 tomcat tomcat 4846 Sep 1 00:01 rws-2013-08-31.log.gz

      Here's the configuration I'm using:

      
      <RollingFile name="RollingFile" fileName="${base}/rws.log" filePattern="${base}/$${date:yyyy-MM}/rws-%d{yyyy-MM-dd}.log.gz">
         <PatternLayout>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}{UTC} [%t] %p %c{1} - %m%n</pattern>
         </PatternLayout>
         <Policies>
           <TimeBasedTriggeringPolicy/>
         </Policies>
      </RollingFile>
      
      

        Activity

        Harel E. created issue -
        Harel E. made changes -
        Field Original Value New Value
        Description I'm using RollingFile appender with archiving to a separate directory.
        The archive directory pattern is yyyy-MM.
        Up until 2013-08-30, everything worked just fine.
        All the logs for August were placed inside directory 2013-08

        On 2013-09-01 00:01, log4j2 placed the log for 2013-08-31 inside directory 2013-09, instead of 2013-08

        -bash-4.1$ ls -l 2013-09
        total 8
        -rw-rw-r-- 1 tomcat tomcat 4846 Sep 1 00:01 rws-2013-08-31.log.gz


        Here's the configuration I'm using:



        <RollingFile name="RollingFile" fileName="${base}/rws.log"
                             filePattern="${base}/$${date:yyyy-MM}/rws-%d{yyyy-MM-dd}.log.gz">
                    <PatternLayout>
                        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}{UTC} [%t] %p %c{1} - %m%n</pattern>
                    </PatternLayout>
                    <Policies>
                        <TimeBasedTriggeringPolicy/>
                    </Policies>
                </RollingFile>

        I'm using RollingFile appender with archiving to a separate directory.
        The archive directory pattern is yyyy-MM.
        Up until 2013-08-30, everything worked just fine.
        All the logs for August were placed inside directory 2013-08

        On 2013-09-01 00:01, log4j2 placed the log for 2013-08-31 inside directory 2013-09, instead of 2013-08

        -bash-4.1$ ls -l 2013-09
        total 8
        -rw-rw-r-- 1 tomcat tomcat 4846 Sep 1 00:01 rws-2013-08-31.log.gz


        Here's the configuration I'm using:


        {code:xml}

        <RollingFile name="RollingFile" fileName="${base}/rws.log" filePattern="${base}/$${date:yyyy-MM}/rws-%d{yyyy-MM-dd}.log.gz">
           <PatternLayout>
              <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}{UTC} [%t] %p %c{1} - %m%n</pattern>
           </PatternLayout>
           <Policies>
             <TimeBasedTriggeringPolicy/>
           </Policies>
        </RollingFile>

        {code}
        Hide
        Ralph Goers added a comment -

        This is because the variable $

        {date:}

        gets the current date, so $

        {date:yyyy-MM}

        is being resolved in September instead of August because that is when the rollover is occurring. Since the Lookup has no relationship with the RollingFileAppender it really has no way of knowing the file date is for the prior month.

        We will have to find some way to cause the filePattern to be able to pass the %d date to the Lookup.

        Show
        Ralph Goers added a comment - This is because the variable $ {date:} gets the current date, so $ {date:yyyy-MM} is being resolved in September instead of August because that is when the rollover is occurring. Since the Lookup has no relationship with the RollingFileAppender it really has no way of knowing the file date is for the prior month. We will have to find some way to cause the filePattern to be able to pass the %d date to the Lookup.
        Hide
        Harel E. added a comment - - edited

        If log4j is doing the right this for the filename, Does it make sense to use %d for the folder as well?

        For example:  ${base}/%d{yyyy-MM}/app-%d{MM-dd-yyyy}.log.gz
        
        Show
        Harel E. added a comment - - edited If log4j is doing the right this for the filename, Does it make sense to use %d for the folder as well? For example: ${base}/%d{yyyy-MM}/app-%d{MM-dd-yyyy}.log.gz
        Hide
        Ralph Goers added a comment -

        You do not want to use %d twice. The RollingFileAppender uses the pattern to determine the rollover frequency.

        Show
        Ralph Goers added a comment - You do not want to use %d twice. The RollingFileAppender uses the pattern to determine the rollover frequency.
        Hide
        Ralph Goers added a comment -

        Fixed in revision 1519776. When used in a filePattern $

        {date:}

        will now use the rollover timestamp instead of the current time.

        Show
        Ralph Goers added a comment - Fixed in revision 1519776. When used in a filePattern $ {date:} will now use the rollover timestamp instead of the current time.
        Hide
        Ralph Goers added a comment -

        Please verify and close.

        Show
        Ralph Goers added a comment - Please verify and close.
        Ralph Goers made changes -
        Status Open [ 1 ] Resolved [ 5 ]
        Assignee Ralph Goers [ ralph.goers@dslextreme.com ]
        Fix Version/s 2.0-beta9 [ 12324756 ]
        Resolution Fixed [ 1 ]
        Hide
        Harel E. added a comment -

        Running the same use case as before, log4j2 now placed the log for 2013-08-31 (app-08-31-2013.log.gz) inside directory 2013-08
        I also check the next day, and 2013-09-01 was placed in 2013-09.

        Thanks for the quick fix.

        Show
        Harel E. added a comment - Running the same use case as before, log4j2 now placed the log for 2013-08-31 (app-08-31-2013.log.gz) inside directory 2013-08 I also check the next day, and 2013-09-01 was placed in 2013-09. Thanks for the quick fix.
        Harel E. made changes -
        Status Resolved [ 5 ] Closed [ 6 ]
        Transition Time In Source Status Execution Times Last Executer Last Execution Date
        Open Open Resolved Resolved
        1d 18h 56m 1 Ralph Goers 03/Sep/13 19:10
        Resolved Resolved Closed Closed
        8h 12m 1 Harel E. 04/Sep/13 03:22

          People

          • Assignee:
            Ralph Goers
            Reporter:
            Harel E.
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development