DailyRollingFileAppender rolls logs into files dated with a date in 1970 - BUG ID 46570

[Lesley Tay <Le...@macquarie.com>]

Hi all,

I've raised a bug for this
<https://issues.apache.org/bugzilla/show_bug.cgi?id=46570>
but wanted to send this out to the mailing list in case someone else has

seen this before.


We have a java 1.4.2_11 app running on Weblogic 8.1. Our Log4j version
is
1.2.14. 

Our logs are set to roll on a daily basis at midnight. We've noticed
that for 1
application, the logs have sometimes have a datestamp with a date in
1970.
It occurs every few days and I was wondering if anyone else has come
across
this issue. The usage of the app can be high and the logs can get to
100mbs in
size.

An example of what we see in unix with the log file names:
appname-appenv_host.log.1970-02-05.zip
appname-appenv_host.2009-01-08.zip

where both logs contain entries for the exact same day. Typically the
log with
the 1970 date has 1 entry only, and the log with the correct date will
have the
rest of the correct entries for the log (i.e. it flows on if you read
the
logging statements in order, no duplicate entries in either log file).
We've
also usually seen 1 log statement only in the log named with a 1970
date.

Has anyone else ever seen anything like this? We have this same version
of
log4j in another app and have not seen the problem. We believe this may
be a
result of the size of the log i.e. larger log file, larger probability
of this
date corruption problem happening during the rollover.

Here is our appender config snippet:

    <appender name="FILE"
class="org.apache.log4j.DailyRollingFileAppender">
        <param name="File"
value="${app.logdir}/${appname}-${appenv}__HOSTNAME_.log"/>
        <param name="Append" value="true"/>

        <!-- Rollover at midnight each day -->
        <param name="DatePattern" value="'.'yyyy-MM-dd"/>

        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern"
value="%d{ISO8601}\t%-5p\t(%t)\t{%x}\t[%c{1}]\t%m%n" />
        </layout>
    </appender>

    <appender name="MAIL" class="org.apache.log4j.net.SMTPAppender">
        <param name="Threshold" value="ERROR"/>
        <param name="SMTPHost" value="server"/>
        <param name="To" value="to_email"/>
        <param name="From" value="from_email"/>
        <param name="Subject" value="blah"/>
        <param name="BufferSize" value="1"/>
        <layout class="org.apache.log4j.PatternLayout">
                <param name="ConversionPattern" value="%p -
%d{ISO8601}%nCategory: %c%nNDC: %x%nThread: %t%n%nMessage:%n%m%n"/>
        </layout>
    </appender>

    <appender name="ASYNC" class="org.apache.log4j.AsyncAppender">
        <appender-ref ref="MAIL"/>
        <appender-ref ref="FILE"/>
    </appender>

    <root>
        <level value="INFO"/>
        <appender-ref ref="ASYNC"/>
    </root>


Also while looking at the DailyRollingFileAppender code, we noticed that
there
seems to be some un-threadsafe use of the SimpleDateFormat class and
wondered
if this could be the cause of the issue. It's initialised in
activateOptions:

    public void activateOptions() {
        super.activateOptions();
        if (datePattern != null && fileName != null) {
            now.setTime(System.currentTimeMillis());
            sdf = new SimpleDateFormat(datePattern);
            int type = computeCheckPeriod();
            printPeriodicity(type);
            rc.setType(type);
            File file = new File(fileName);
            scheduledFilename = fileName + sdf.format(new
Date(file.lastModified()));

        } else {
            LogLog.error("Either File or DatePattern options are not set
for
appender [" + name + "].");
        }
    }

and then reused in the rollOver() function:

    /**
     * Rollover the current file to a new file.
     */
    void rollOver() throws IOException {

        /* Compute filename, but only if datePattern is specified */
        if (datePattern == null) {
            errorHandler.error("Missing DatePattern option in
rollOver().");
            return;
        }

        String datedFilename = fileName + sdf.format(now);



Thanks,
Lesley


NOTICE
This e-mail and any attachments are confidential and may contain copyright material of Macquarie Group Limited or third parties. If you are not the intended recipient of this email you should not read, print, re-transmit, store or act in reliance on this e-mail or any attachments, and should destroy all copies of them. Macquarie Group Limited does not guarantee the integrity of any emails or any attached files. The views or opinions expressed are the author's own and may not reflect the views or opinions of Macquarie Group Limited.