You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Paul <pp...@yahoo.com> on 2012/02/13 17:14:38 UTC
log4j rollover in est timezone not working as expected
Initially I setup log4j to rollover at midnight using the default machine (linux) timezone which is GMT and everything worked correctly. I could see the timestamps before and after rollover were correct. I then changed the time output to be in EST (log4j extras) but the rollover still happens at midnight GMT or 5 hours too early. How can I get both time display and rollover to work the same based on EST?
This is my current test property file:
log4j.appender.appender1=org.apache.log4j.DailyRollingFileAppender
log4j.appender.appender1.File=report.log
log4j.appender.appender1.layout=org.apache.log4j.EnhancedPatternLayout
log4j.appender.appender1.layout.conversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS}{EST} [%p] %c:%L - %m%n
log4j.appender.appender1.DatePattern = '.'yyyy-MM-dd-HH-mm
When I look in the log file I can see the entries are in EST - so far so good. But when I look at the last entry before rollover, I see:
INFO 2012-02-09 18:56:06 ...
so, we have a rollover around 7pm EST or midnight GMT but I want the rollover to happen at midnight EST or 5 hours later. Right now the day boundaries are showing across two files which makes troubleshooting application errors more difficult.
BTW, I'm using the 1.2.16 log4j binary and 1.1 extras.
thanks, Paul.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
AW: AW: log4j rollover in est timezone not working as expected
Posted by Stadelmann Josef <jo...@axa-winterthur.ch>.
Hi Paul,
the other hard way would be you develop what is missing on the current
DailyRollingFileAppender, develop to support what you want, develop a I18N interface.
I think it is somehow an architectural fault. MY own view.
The core of the time calculations are all done in GMT to form a common work basis. That's very OK.
as the core does all kind of calculations, including triggering events etc.
But all around that core an I18N-IO-Interface, should nicely support local language and cultures.
But that does certainly not yet exist, maybe you are the one to provide it.
Josef
-----Ursprüngliche Nachricht-----
Von: Paul [mailto:ppage4@yahoo.com]
Gesendet: Donnerstag, 16. Februar 2012 17:48
An: Log4J Users List
Betreff: Re: AW: log4j rollover in est timezone not working as expected
Thanks Josef for the information. The ExternallyRolledFileAppender class looks interesting so I may try to use that. It would be nice if there was a way to trigger a rollover internally w/out having to resort to sockets and possibly an extra thread. In other words just create a separate thread which sleeps until midnight EST, and then trigger the rollover and then go back to sleep for 24 hours.
Paul.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: AW: log4j rollover in est timezone not working as expected
Posted by Paul <pp...@yahoo.com>.
Thanks Josef for the information. The ExternallyRolledFileAppender class looks interesting so I may try to use that. It would be nice if there was a way to trigger a rollover internally w/out having to resort to sockets and possibly an extra thread. In other words just create a separate thread which sleeps until midnight EST, and then trigger the rollover and then go back to sleep for 24 hours.
Paul.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
AW: log4j rollover in est timezone not working as expected
Posted by Stadelmann Josef <jo...@axa-winterthur.ch>.
Hi Paul,
I am not an expert on log4j, but use it and frequently build it from sources.
So I found the following in code which might get you some light into shadow.
This is at the DailyRollingFileAppender.java
DailyRollingFileAppender extends {@link FileAppender} so that the
underlying file is rolled over at a user chosen frequency.
DailyRollingFileAppender has been observed to exhibit
synchronization issues and data loss. The log4j extras
companion includes alternatives which should be considered
for new deployments and which are discussed in the documentation
for org.apache.log4j.rolling.RollingFileAppender.
below is first the DailyRollingFileAppender.java (3 methods)
a.) to understand, "what triggers the rollover?"
/**
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);
// It is too early to roll over because we are still within the
// bounds of the current interval. Rollover will occur once the
// next interval is reached.
if (scheduledFilename.equals(datedFilename)) {
return;
}
// close current file, and rename it to datedFilename
this.closeFile();
File target = new File(scheduledFilename);
if (target.exists()) {
target.delete();
}
File file = new File(fileName);
boolean result = file.renameTo(target);
if(result) {
LogLog.debug(fileName +" -> "+ scheduledFilename);
} else {
LogLog.error("Failed to rename ["+fileName+"] to ["+scheduledFilename+"].");
}
try {
// This will also close the file. This is OK since multiple
// close operations are safe.
this.setFile(fileName, true, this.bufferedIO, this.bufferSize);
}
catch(IOException e) {
errorHandler.error("setFile("+fileName+", true) call failed.");
}
scheduledFilename = datedFilename;
}
b.) how is the computation done? "all in GMT starting at epoch"
// This method computes the roll over period by looping over the
// periods, starting with the shortest, and stopping when the r0 is
// different from from r1, where r0 is the epoch formatted according
// the datePattern (supplied by the user) and r1 is the
// epoch+nextMillis(i) formatted according to datePattern. All date
// formatting is done in GMT and not local format because the test
// logic is based on comparisons relative to 1970-01-01 00:00:00
// GMT (the epoch).
int computeCheckPeriod() {
RollingCalendar rollingCalendar = new RollingCalendar(gmtTimeZone, Locale.getDefault());
// set sate to 1970-01-01 00:00:00 GMT
Date epoch = new Date(0);
if(datePattern != null) {
for(int i = TOP_OF_MINUTE; i <= TOP_OF_MONTH; i++) {
SimpleDateFormat simpleDateFormat = new SimpleDateFormat(datePattern);
simpleDateFormat.setTimeZone(gmtTimeZone); // do all date formatting in GMT
String r0 = simpleDateFormat.format(epoch);
rollingCalendar.setType(i);
Date next = new Date(rollingCalendar.getNextCheckMillis(epoch));
String r1 = simpleDateFormat.format(next);
//System.out.println("Type = "+i+", r0 = "+r0+", r1 = "+r1);
if(r0 != null && r1 != null && !r0.equals(r1)) {
return i;
}
}
}
return TOP_OF_TROUBLE; // Deliberately head for trouble...
}
be aware that rollingCalendar is a helper to computeCheckPeriod to help in calculating the next intervall
b.)what adds to the scheduledFilename which plays a major role to trigger the rolover
Also this mightbe of help/insight to you. What is returned in sdf? below.
Because sdf forms part of the new scheduledFilename. And because the rollover
takes place when the currentFilename matches the scheduledFilename.
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 printPeriodicity() will for sure never printout what you are looking for.
i.e. 5 hours after midnight.
void printPeriodicity(int type) {
switch(type) {
case TOP_OF_MINUTE:
LogLog.debug("Appender ["+name+"] to be rolled every minute.");
break;
case TOP_OF_HOUR:
LogLog.debug("Appender ["+name
+"] to be rolled on top of every hour.");
break;
case HALF_DAY:
LogLog.debug("Appender ["+name
+"] to be rolled at midday and midnight.");
break;
case TOP_OF_DAY:
LogLog.debug("Appender ["+name
+"] to be rolled at midnight.");
break;
case TOP_OF_WEEK:
LogLog.debug("Appender ["+name
+"] to be rolled at start of week.");
break;
case TOP_OF_MONTH:
LogLog.debug("Appender ["+name
+"] to be rolled at start of every month.");
break;
default:
LogLog.warn("Unknown periodicity for appender ["+name+"].");
}
}
My mind, take down sources down from
$ svn co http://svn.apache.org/repos/asf/logging/log4j/trunk log4j
and invest some time executing the
/**
Exhaustive test of the DailyRollingFileAppender compute algorithm.
@author Ceki Gülcü
@author Curt Arnold
*/
public class DRFATestCase extends TestCase {
so look at DRFATestCase.java
I think what you want could work if we master to add an offset to get a new scheduledFilename
in example to rollover at GMT+5h, this will definitly trigger the rollover at GMT+5h.
But reagarding the pattern to format the events I can not make any statements.
Maybe a other idea:
What you can think of is: forget the DailyRollingFileAppender.java and
look at log4j code for ExternallyRolledFileAppender.java
This file appender listens on a socket given in the pattern,
and it will rollover when it receives a signal from the Roller.java
apps which can be remotely. So your apps controls the rollover()
/**
A simple application to send roll over messages to a potentially
remote {@link ExternallyRolledFileAppender}.
<p>It takes two arguments, the <code>host_name</code> and
<code>port_number</code> where the
<code>ExternallyRolledFileAppender</code> is listening.
@author Ceki Gülcü
@since version 0.9.0 */
regards
Josef
-----Ursprüngliche Nachricht-----
Von: Paul [mailto:ppage4@yahoo.com]
Gesendet: Montag, 13. Februar 2012 17:15
An: log4j-user@logging.apache.org
Betreff: log4j rollover in est timezone not working as expected
Initially I setup log4j to rollover at midnight using the default machine (linux) timezone which is GMT and everything worked correctly. I could see the timestamps before and after rollover were correct. I then changed the time output to be in EST (log4j extras) but the rollover still happens at midnight GMT or 5 hours too early. How can I get both time display and rollover to work the same based on EST?
This is my current test property file:
log4j.appender.appender1=org.apache.log4j.DailyRollingFileAppender
log4j.appender.appender1.File=report.log
log4j.appender.appender1.layout=org.apache.log4j.EnhancedPatternLayout
log4j.appender.appender1.layout.conversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS}{EST} [%p] %c:%L - %m%n
log4j.appender.appender1.DatePattern = '.'yyyy-MM-dd-HH-mm
When I look in the log file I can see the entries are in EST - so far so good. But when I look at the last entry before rollover, I see:
INFO 2012-02-09 18:56:06 ...
so, we have a rollover around 7pm EST or midnight GMT but I want the rollover to happen at midnight EST or 5 hours later. Right now the day boundaries are showing across two files which makes troubleshooting application errors more difficult.
BTW, I'm using the 1.2.16 log4j binary and 1.1 extras.
thanks, Paul.
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org