September 2011 - logback-dev

[JIRA] Created: (LBCLASSIC-290) performance issue
by Roman Kosenko (JIRA) 04 Sep '11

04 Sep '11

performance issue ----------------- Key: LBCLASSIC-290 URL: http://jira.qos.ch/browse/LBCLASSIC-290 Project: logback-classic Issue Type: Improvement Components: Other Affects Versions: 0.9.29 Reporter: Roman Kosenko Assignee: Logback dev list In the ch.qos.logback.classic.Logger there is a comment related to filterAndLog_0_Or3Plus, filterAndLog_1, filterAndLog_2: /** * The next methods are not merged into one because of the time we gain by not * creating a new Object[] with the params. This reduces the cost of not * logging by about 20 nanoseconds. */ But if we use at least one "TurboFilter" then "new Object[]" is called twice in filterAndLog_1 & filterAndLog_2 (because of LoggerContext.getTurboFilterChainDecision_1 & LoggerContext.getTurboFilterChainDecision_2). So in this case you don't receive advantage of splitting, even more - merged version will be faster. And methods LoggerContext.getTurboFilterChainDecision_0_3OrMore, LoggerContext.getTurboFilterChainDecision_1, LoggerContext.getTurboFilterChainDecision_2 can be merged in one without any performance penalty. -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

[JIRA] Created: (LBCORE-79) FixedWindowRollingPolicy performs compression on the logging thread
by Szel Zoltan (JIRA) 02 Sep '11

02 Sep '11

FixedWindowRollingPolicy performs compression on the logging thread ------------------------------------------------------------------- Key: LBCORE-79 URL: http://jira.qos.ch/browse/LBCORE-79 Project: logback-core Issue Type: Improvement Components: Rolling Affects Versions: 0.9.13 Reporter: Szel Zoltan Assignee: Logback dev list Hi, the FixedWindowRollingPolicy performs the compression on the logging thread which can bring the application to halt, when compressing large files. Please consider modifing the FixedWindowRollingPolicy to perform the operation on a background thread as requested in LBCORE-48. Regards, Zoltan Szel -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

2 2

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch, master, updated. v_0.9.29-21-g6f27356
by git-noreply＠pixie.qos.ch 01 Sep '11

01 Sep '11

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via 6f2735660d8c650b7be9e682c2fe85764592a340 (commit) from f47630842482beb41d38cc1c45a96088f09bcd82 (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=6f2735660d8c650b7be9e682… http://github.com/ceki/logback/commit/6f2735660d8c650b7be9e682c2fe85764592a… commit 6f2735660d8c650b7be9e682c2fe85764592a340 Author: Ceki Gulcu <ceki(a)qos.ch> Date: Thu Sep 1 23:55:30 2011 +0200 ongoing work on LBCORE-147 diff --git a/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java b/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java index 34b2c5d..ba67c65 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java +++ b/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java @@ -134,4 +134,9 @@ public class CoreConstants { public static int BYTES_PER_INT = 4; public static final int MILLIS_IN_ONE_SECOND = 1000; + public static final int MILLIS_IN_ONE_MINUTE = MILLIS_IN_ONE_SECOND*60; + public static final int MILLIS_IN_ONE_HOUR = MILLIS_IN_ONE_MINUTE*60; + public static final int MILLIS_IN_ONE_DAY = MILLIS_IN_ONE_HOUR*24; + public static final int MILLIS_IN_ONE_WEEK = MILLIS_IN_ONE_DAY*7; + } diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/DefaultTimeBasedFileNamingAndTriggeringPolicy.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/DefaultTimeBasedFileNamingAndTriggeringPolicy.java index 02edf85..49101f8 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/DefaultTimeBasedFileNamingAndTriggeringPolicy.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/DefaultTimeBasedFileNamingAndTriggeringPolicy.java @@ -17,6 +17,7 @@ import java.io.File; import java.util.Date; import ch.qos.logback.core.rolling.helper.DefaultArchiveRemover; +import ch.qos.logback.core.rolling.helper.TimeBasedArchiveRemover; /** * @@ -30,7 +31,7 @@ public class DefaultTimeBasedFileNamingAndTriggeringPolicy<E> extends @Override public void start() { super.start(); - archiveRemover = new DefaultArchiveRemover(tbrp.fileNamePattern, rc); + archiveRemover = new TimeBasedArchiveRemover(tbrp.fileNamePattern, rc, getCurrentTime()); archiveRemover.setContext(context); started = true; } diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP.java index bda2ad2..0c2c44a 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/SizeAndTimeBasedFNATP.java @@ -35,7 +35,7 @@ public class SizeAndTimeBasedFNATP<E> extends // in super.start() super.start(); - archiveRemover = new SizeAndTimeBasedArchiveRemover(tbrp.fileNamePattern, rc); + archiveRemover = new SizeAndTimeBasedArchiveRemover(tbrp.fileNamePattern, rc, getCurrentTime()); archiveRemover.setContext(context); // we need to get the correct value of currentPeriodsCounter. diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java index 2238dc5..b1690ad 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedFileNamingAndTriggeringPolicyBase.java @@ -30,7 +30,7 @@ abstract public class TimeBasedFileNamingAndTriggeringPolicyBase<E> extends protected String elapsedPeriodsFileName; protected RollingCalendar rc; - protected long currentTime = -1; + protected long artificialCurrentTime = -1; protected Date dateInCurrentPeriod = null; protected long nextCheck; @@ -95,13 +95,13 @@ abstract public class TimeBasedFileNamingAndTriggeringPolicyBase<E> extends } public void setCurrentTime(long timeInMillis) { - currentTime = timeInMillis; + artificialCurrentTime = timeInMillis; } public long getCurrentTime() { // if time is forced return the time set by user - if (currentTime >= 0) { - return currentTime; + if (artificialCurrentTime >= 0) { + return artificialCurrentTime; } else { return System.currentTimeMillis(); } diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/DefaultArchiveRemover.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/DefaultArchiveRemover.java index dedf85f..7fbcf50 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/DefaultArchiveRemover.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/DefaultArchiveRemover.java @@ -20,21 +20,25 @@ import ch.qos.logback.core.pattern.Converter; import ch.qos.logback.core.pattern.LiteralConverter; import ch.qos.logback.core.spi.ContextAwareBase; -public class DefaultArchiveRemover extends ContextAwareBase implements +abstract public class DefaultArchiveRemover extends ContextAwareBase implements ArchiveRemover { final FileNamePattern fileNamePattern; final RollingCalendar rc; int periodOffsetForDeletionTarget; final boolean parentClean; + long lastHeartBeat; public DefaultArchiveRemover(FileNamePattern fileNamePattern, - RollingCalendar rc) { + RollingCalendar rc, long currentTime) { this.fileNamePattern = fileNamePattern; this.rc = rc; this.parentClean = computeParentCleaningFlag(fileNamePattern); + this.lastHeartBeat = currentTime; } + + boolean computeParentCleaningFlag(FileNamePattern fileNamePattern) { DateTokenConverter dtc = fileNamePattern.getDateTokenConverter(); // if the date pattern has a /, then we need parent cleaning @@ -68,17 +72,8 @@ public class DefaultArchiveRemover extends ContextAwareBase implements return false; } - public void clean(Date now) { - Date date2delete = rc.getRelativeDate(now, periodOffsetForDeletionTarget); - String filename = fileNamePattern.convert(date2delete); - File file2Delete = new File(filename); - if (file2Delete.exists() && file2Delete.isFile()) { - file2Delete.delete(); - addInfo("deleting " + file2Delete); - if (parentClean) { - removeFolderIfEmpty(file2Delete.getParentFile(), 0); - } - } + void removeFolderIfEmpty(File dir) { + removeFolderIfEmpty(dir, 0); } /** @@ -89,7 +84,7 @@ public class DefaultArchiveRemover extends ContextAwareBase implements * @param dir * @param depth */ - void removeFolderIfEmpty(File dir, int depth) { + private void removeFolderIfEmpty(File dir, int depth) { // we should never go more than 3 levels higher if (depth >= 3) { return; diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java index b0b2e51..cd6850c 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java @@ -20,6 +20,7 @@ import java.util.GregorianCalendar; import java.util.Locale; import java.util.TimeZone; +import ch.qos.logback.core.CoreConstants; import ch.qos.logback.core.spi.ContextAwareBase; /** @@ -27,9 +28,8 @@ import ch.qos.logback.core.spi.ContextAwareBase; * {@link ch.qos.logback.core.rolling.TimeBasedRollingPolicy } or similar * timed-based rolling policies. Given a periodicity type and the current time, * it computes the start of the next interval (i.e. the triggering date). - * + * * @author Ceki Gülcü - * */ public class RollingCalendar extends GregorianCalendar { @@ -38,7 +38,7 @@ public class RollingCalendar extends GregorianCalendar { // The gmtTimeZone is used only in computeCheckPeriod() method. static final TimeZone GMT_TIMEZONE = TimeZone.getTimeZone("GMT"); - PeriodicityType type = PeriodicityType.ERRONEOUS; + PeriodicityType periodicityType = PeriodicityType.ERRONEOUS; public RollingCalendar() { super(); @@ -49,11 +49,15 @@ public class RollingCalendar extends GregorianCalendar { } public void init(String datePattern) { - type = computePeriodicity(datePattern); + periodicityType = computePeriodicityType(datePattern); + } + + private void setPeriodicityType(PeriodicityType periodicityType) { + this.periodicityType = periodicityType; } - private void setType(PeriodicityType type) { - this.type = type; + public PeriodicityType getPeriodicityType() { + return periodicityType; } public long getNextTriggeringMillis(Date now) { @@ -68,9 +72,9 @@ public class RollingCalendar extends GregorianCalendar { // 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). - public PeriodicityType computePeriodicity(String datePattern) { + public PeriodicityType computePeriodicityType(String datePattern) { RollingCalendar rollingCalendar = new RollingCalendar(GMT_TIMEZONE, Locale - .getDefault()); + .getDefault()); // set sate to 1970-01-01 00:00:00 GMT Date epoch = new Date(0); @@ -82,7 +86,7 @@ public class RollingCalendar extends GregorianCalendar { // in GMT String r0 = simpleDateFormat.format(epoch); - rollingCalendar.setType(i); + rollingCalendar.setPeriodicityType(i); Date next = new Date(rollingCalendar.getNextTriggeringMillis(epoch)); String r1 = simpleDateFormat.format(next); @@ -98,98 +102,136 @@ public class RollingCalendar extends GregorianCalendar { } public void printPeriodicity(ContextAwareBase cab) { - switch (type) { - case TOP_OF_MILLISECOND: - cab.addInfo("Roll-over every millisecond."); - break; + switch (periodicityType) { + case TOP_OF_MILLISECOND: + cab.addInfo("Roll-over every millisecond."); + break; + + case TOP_OF_SECOND: + cab.addInfo("Roll-over every second."); + break; - case TOP_OF_SECOND: - cab.addInfo("Roll-over every second."); - break; + case TOP_OF_MINUTE: + cab.addInfo("Roll-over every minute."); + break; - case TOP_OF_MINUTE: - cab.addInfo("Roll-over every minute."); - break; + case TOP_OF_HOUR: + cab.addInfo("Roll-over at the top of every hour."); + break; - case TOP_OF_HOUR: - cab.addInfo("Roll-over at the top of every hour."); - break; + case HALF_DAY: + cab.addInfo("Roll-over at midday and midnight."); + break; - case HALF_DAY: - cab.addInfo("Roll-over at midday and midnight."); - break; + case TOP_OF_DAY: + cab.addInfo("Roll-over at midnight."); + break; - case TOP_OF_DAY: - cab.addInfo("Roll-over at midnight."); - break; + case TOP_OF_WEEK: + cab.addInfo("Rollover at the start of week."); + break; - case TOP_OF_WEEK: - cab.addInfo("Rollover at the start of week."); - break; + case TOP_OF_MONTH: + cab.addInfo("Rollover at start of every month."); + break; - case TOP_OF_MONTH: - cab.addInfo("Rollover at start of every month."); - break; + default: + cab.addInfo("Unknown periodicity."); + } + } - default: - cab.addInfo("Unknown periodicity."); + public int periodsElapsed(long start, long end) { + if (start > end) + throw new IllegalArgumentException("Start cannot come before end"); + + long diff = end - start; + switch (periodicityType) { + + case TOP_OF_MILLISECOND: + return (int) diff; + case TOP_OF_SECOND: + return (int) diff / CoreConstants.MILLIS_IN_ONE_SECOND; + case TOP_OF_MINUTE: + return (int) diff / CoreConstants.MILLIS_IN_ONE_MINUTE; + case TOP_OF_HOUR: + return (int) diff / CoreConstants.MILLIS_IN_ONE_HOUR; + case TOP_OF_DAY: + return (int) diff / CoreConstants.MILLIS_IN_ONE_DAY; + case TOP_OF_WEEK: + return (int) diff / CoreConstants.MILLIS_IN_ONE_WEEK; + case TOP_OF_MONTH: + return diffInMonths(start, end); + default: + throw new IllegalStateException("Unknown periodicity type."); } } + public static int diffInMonths(Long startTime, Long endTime) { + if (startTime > endTime) + throw new IllegalArgumentException("startTime cannot be larger than endTime"); + Calendar startCal = Calendar.getInstance(); + startCal.setTimeInMillis(startTime); + Calendar endCal = Calendar.getInstance(); + endCal.setTimeInMillis(endTime); + int yearDiff = endCal.get(Calendar.YEAR) - startCal.get(Calendar.YEAR); + int monthDiff = endCal.get(Calendar.MONTH) - startCal.get(Calendar.MONTH); + return yearDiff * 12 + monthDiff; + } + public Date getRelativeDate(Date now, int periods) { this.setTime(now); - switch (type) { - case TOP_OF_MILLISECOND: - this.add(Calendar.MILLISECOND, periods); - break; - - case TOP_OF_SECOND: - this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.SECOND, periods); - break; - - case TOP_OF_MINUTE: - this.set(Calendar.SECOND, 0); - this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.MINUTE, periods); - break; - - case TOP_OF_HOUR: - this.set(Calendar.MINUTE, 0); - this.set(Calendar.SECOND, 0); - this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.HOUR_OF_DAY, periods); - break; - - case TOP_OF_DAY: - this.set(Calendar.HOUR_OF_DAY, 0); - this.set(Calendar.MINUTE, 0); - this.set(Calendar.SECOND, 0); - this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.DATE, periods); - break; - - case TOP_OF_WEEK: - this.set(Calendar.DAY_OF_WEEK, getFirstDayOfWeek()); - this.set(Calendar.HOUR_OF_DAY, 0); - this.set(Calendar.MINUTE, 0); - this.set(Calendar.SECOND, 0); - this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.WEEK_OF_YEAR, periods); - break; - - case TOP_OF_MONTH: - this.set(Calendar.DATE, 1); - this.set(Calendar.HOUR_OF_DAY, 0); - this.set(Calendar.MINUTE, 0); - this.set(Calendar.SECOND, 0); - this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.MONTH, periods); - break; - - default: - throw new IllegalStateException("Unknown periodicity type."); + switch (periodicityType) { + case TOP_OF_MILLISECOND: + this.add(Calendar.MILLISECOND, periods); + break; + + case TOP_OF_SECOND: + this.set(Calendar.MILLISECOND, 0); + this.add(Calendar.SECOND, periods); + break; + + case TOP_OF_MINUTE: + this.set(Calendar.SECOND, 0); + this.set(Calendar.MILLISECOND, 0); + this.add(Calendar.MINUTE, periods); + break; + + case TOP_OF_HOUR: + this.set(Calendar.MINUTE, 0); + this.set(Calendar.SECOND, 0); + this.set(Calendar.MILLISECOND, 0); + this.add(Calendar.HOUR_OF_DAY, periods); + break; + + case TOP_OF_DAY: + this.set(Calendar.HOUR_OF_DAY, 0); + this.set(Calendar.MINUTE, 0); + this.set(Calendar.SECOND, 0); + this.set(Calendar.MILLISECOND, 0); + this.add(Calendar.DATE, periods); + break; + + case TOP_OF_WEEK: + this.set(Calendar.DAY_OF_WEEK, getFirstDayOfWeek()); + this.set(Calendar.HOUR_OF_DAY, 0); + this.set(Calendar.MINUTE, 0); + this.set(Calendar.SECOND, 0); + this.set(Calendar.MILLISECOND, 0); + this.add(Calendar.WEEK_OF_YEAR, periods); + break; + + case TOP_OF_MONTH: + this.set(Calendar.DATE, 1); + this.set(Calendar.HOUR_OF_DAY, 0); + this.set(Calendar.MINUTE, 0); + this.set(Calendar.SECOND, 0); + this.set(Calendar.MILLISECOND, 0); + this.add(Calendar.MONTH, periods); + break; + + default: + throw new IllegalStateException("Unknown periodicity type."); } return getTime(); diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/SizeAndTimeBasedArchiveRemover.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/SizeAndTimeBasedArchiveRemover.java index 810c301..1bb90d4 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/SizeAndTimeBasedArchiveRemover.java +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/SizeAndTimeBasedArchiveRemover.java @@ -19,11 +19,10 @@ import java.util.Date; public class SizeAndTimeBasedArchiveRemover extends DefaultArchiveRemover { public SizeAndTimeBasedArchiveRemover(FileNamePattern fileNamePattern, - RollingCalendar rc) { - super(fileNamePattern, rc); + RollingCalendar rc, long currentTime) { + super(fileNamePattern, rc, currentTime); } - @Override public void clean(Date now) { Date dateOfPeriodToClean = rc.getRelativeDate(now, periodOffsetForDeletionTarget); @@ -31,8 +30,11 @@ public class SizeAndTimeBasedArchiveRemover extends DefaultArchiveRemover { String stemRegex = FileFilterUtil.afterLastSlash(regex); File archive0 = new File(fileNamePattern.convertMultipleArguments( dateOfPeriodToClean, 0)); + // in case the file has no directory part, i.e. if it's written into the + // user's current directory. + archive0 = archive0.getAbsoluteFile(); - File parentDir = archive0.getParentFile(); + File parentDir = archive0.getAbsoluteFile().getParentFile(); File[] matchingFileArray = FileFilterUtil.filesInFolderMatchingStemRegex( parentDir, stemRegex); @@ -41,7 +43,7 @@ public class SizeAndTimeBasedArchiveRemover extends DefaultArchiveRemover { } if (parentClean) { - removeFolderIfEmpty(parentDir, 0); + removeFolderIfEmpty(parentDir); } } diff --git a/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/TimeBasedArchiveRemover.java b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/TimeBasedArchiveRemover.java new file mode 100644 index 0000000..01ff76e --- /dev/null +++ b/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/TimeBasedArchiveRemover.java @@ -0,0 +1,57 @@ +/** + * Logback: the reliable, generic, fast and flexible logging framework. + * Copyright (C) 1999-2011, QOS.ch. All rights reserved. + * + * This program and the accompanying materials are dual-licensed under + * either the terms of the Eclipse Public License v1.0 as published by + * the Eclipse Foundation + * + * or (per the licensee's choosing) + * + * under the terms of the GNU Lesser General Public License version 2.1 + * as published by the Free Software Foundation. + */ +package ch.qos.logback.core.rolling.helper; + +import java.io.File; +import java.util.Date; + +import ch.qos.logback.core.pattern.Converter; +import ch.qos.logback.core.pattern.LiteralConverter; +import ch.qos.logback.core.spi.ContextAwareBase; +import org.codehaus.groovy.tools.shell.util.NoExitSecurityManager; + +public class TimeBasedArchiveRemover extends DefaultArchiveRemover { + + public TimeBasedArchiveRemover(FileNamePattern fileNamePattern, + RollingCalendar rc, long currentTime) { + super(fileNamePattern, rc, currentTime); + } + + + public void clean(Date now) { + long nowInMillis = now.getTime(); + int periodsElapsed = rc.periodsElapsed(lastHeartBeat, nowInMillis); + if(periodsElapsed < 1) { + addWarn("Unexpected periodsElapsed value "+periodsElapsed); + periodsElapsed = 1; + } + lastHeartBeat = nowInMillis; + for(int i=0; i < periodsElapsed; i++) { + cleanByPeriodOffset(now, periodOffsetForDeletionTarget-i); + } + } + + protected void cleanByPeriodOffset(Date now, int periodOffset) { + Date date2delete = rc.getRelativeDate(now, periodOffset); + String filename = fileNamePattern.convert(date2delete); + File file2Delete = new File(filename); + if (file2Delete.exists() && file2Delete.isFile()) { + file2Delete.delete(); + addInfo("deleting " + file2Delete); + if (parentClean) { + removeFolderIfEmpty(file2Delete.getParentFile()); + } + } + } +} diff --git a/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java b/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java index 8d20a87..dda9a1f 100644 --- a/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java +++ b/logback-core/src/test/java/ch/qos/logback/core/rolling/PackageTest.java @@ -18,7 +18,7 @@ import org.junit.runners.Suite; @RunWith(Suite.class) @Suite.SuiteClasses({RenameUtilTest.class, SizeBasedRolling_STest.class, - TimeBasedRolling_STest.class, TimeBasedRollingWithArchiveRemovalTest.class, + TimeBasedRolling_STest.class, TimeBasedRollingWithArchiveRemoval_STest.class, MultiThreadedRollingTest.class, SizeAndTimeBasedFNATP_STest.class, RollingFileAppenderTest.class, diff --git a/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java b/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java index 97c84f2..8b44ac1 100644 --- a/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java +++ b/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java @@ -35,31 +35,31 @@ public class RollingCalendarTest extends TestCase { { RollingCalendar rc = new RollingCalendar(); assertEquals(PeriodicityType.TOP_OF_SECOND, rc - .computePeriodicity("yyyy-MM-dd_HH_mm_ss")); + .computePeriodicityType("yyyy-MM-dd_HH_mm_ss")); } { RollingCalendar rc = new RollingCalendar(); assertEquals(PeriodicityType.TOP_OF_MINUTE, rc - .computePeriodicity("yyyy-MM-dd_HH_mm")); + .computePeriodicityType("yyyy-MM-dd_HH_mm")); } { RollingCalendar rc = new RollingCalendar(); assertEquals(PeriodicityType.TOP_OF_HOUR, rc - .computePeriodicity("yyyy-MM-dd_HH")); + .computePeriodicityType("yyyy-MM-dd_HH")); } { RollingCalendar rc = new RollingCalendar(); assertEquals(PeriodicityType.TOP_OF_DAY, rc - .computePeriodicity("yyyy-MM-dd")); + .computePeriodicityType("yyyy-MM-dd")); } { RollingCalendar rc = new RollingCalendar(); assertEquals(PeriodicityType.TOP_OF_MONTH, rc - .computePeriodicity("yyyy-MM")); + .computePeriodicityType("yyyy-MM")); } } diff --git a/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRollingWithArchiveRemoval_STest.scala b/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRollingWithArchiveRemoval_STest.scala index 13bbac2..a1e99a6 100644 --- a/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRollingWithArchiveRemoval_STest.scala +++ b/logback-core/src/test/scala/ch/qos/logback/core/rolling/TimeBasedRollingWithArchiveRemoval_STest.scala @@ -1,14 +1,19 @@ package ch.qos.logback.core.rolling -import org.junit.{Before, Test} import ch.qos.logback.core.{Context, ContextBase} import ch.qos.logback.core.testUtil.RandomUtil -import ch.qos.logback.core.util.CoreTestConstants +import helper.RollingCalendar import org.junit.Assert._ import ch.qos.logback.core.encoder.EchoEncoder import java.util.concurrent.TimeUnit import java.io.{FileFilter, File} import collection.mutable.ListBuffer +import java.util.Calendar +import ch.qos.logback.core.util.{StatusPrinter, CoreTestConstants} +import ch.qos.logback.core.CoreConstants._ +import java.util.regex.{Matcher, Pattern} +import scala.collection.mutable.{Set, HashSet} +import org.junit.{Ignore, Before, Test} /** * Created by IntelliJ IDEA. @@ -23,6 +28,8 @@ class TimeBasedRollingWithArchiveRemoval_STest { var encoder: EchoEncoder[AnyRef] = new EchoEncoder[AnyRef] val MONTHLY_DATE_PATTERN: String = "yyyy-MM" + val MONTHLY_CROLOLOG_DATE_PATTERN: String = "yyyy/MM" + final val DAILY_CROLOLOG_DATE_PATTERN: String = "yyyy/MM/dd" val MILLIS_IN_MINUTE: Long = 60 * 1000 val MILLIS_IN_HOUR: Long = 60 * MILLIS_IN_MINUTE @@ -52,6 +59,77 @@ class TimeBasedRollingWithArchiveRemoval_STest { check(expectedCountWithoutFolders(20)) } + @Test def monthlyRolloverOverManyPeriods { + System.out.println("randomOutputDir=" + randomOutputDir) + slashCount = computeSlashCount(MONTHLY_CROLOLOG_DATE_PATTERN) + var numPeriods: Int = 40 + var maxHistory: Int = 2 + + val (startTime, endTime) = doRollover(randomOutputDir + "/%d{" + MONTHLY_CROLOLOG_DATE_PATTERN + "}/clean.txt.zip", MILLIS_IN_MONTH, maxHistory, numPeriods) + val differenceInMonths = RollingCalendar.diffInMonths(startTime, endTime) + var indexOfStartPeriod: Int = Calendar.getInstance.get(Calendar.MONTH) + val withExtraFolder = extraFolder(differenceInMonths, 12, indexOfStartPeriod, maxHistory) + StatusPrinter.print(context) + check(expectedCountWithFolders(2, withExtraFolder)) + } + + @Test def dailyRollover { + slashCount = computeSlashCount(DAILY_DATE_PATTERN) + doRollover(randomOutputDir + "clean-%d{" + DAILY_DATE_PATTERN + "}.txt.zip", MILLIS_IN_DAY, 5, 5 * 3) + check(expectedCountWithoutFolders(5)) + } + + @Test def dailyCronologRollover { + slashCount = computeSlashCount(DAILY_CROLOLOG_DATE_PATTERN) + doRollover(randomOutputDir + "/%d{" + DAILY_CROLOLOG_DATE_PATTERN + "}/clean.txt.zip", MILLIS_IN_DAY, 8, 8 * 3) + var expectedDirMin: Int = 9 + slashCount + var expectDirMax: Int = expectedDirMin + 1 + 1 + expectedFileAndDirCount(9, expectedDirMin, expectDirMax) + } + + @Test def dailySizeBasedRollover { + var sizeAndTimeBasedFNATP: SizeAndTimeBasedFNATP[AnyRef] = new SizeAndTimeBasedFNATP[AnyRef] + sizeAndTimeBasedFNATP.setMaxFileSize("10000") + tbfnatp = sizeAndTimeBasedFNATP + slashCount = computeSlashCount(DAILY_DATE_PATTERN) + doRollover(randomOutputDir + "/%d{" + DAILY_DATE_PATTERN + "}-clean.%i.zip", MILLIS_IN_DAY, 5, 5 * 4) + checkPatternCompliance(5 + 1 + slashCount, "\\d{4}-\\d{2}-\\d{2}-clean(\\.\\d)(.zip)?") + } + + @Test def dailyChronologSizeBasedRollover { + var sizeAndTimeBasedFNATP: SizeAndTimeBasedFNATP[AnyRef] = new SizeAndTimeBasedFNATP[AnyRef] + sizeAndTimeBasedFNATP.setMaxFileSize("10000") + tbfnatp = sizeAndTimeBasedFNATP + slashCount = 1 + doRollover(randomOutputDir + "/%d{" + DAILY_DATE_PATTERN + "}/clean.%i.zip", MILLIS_IN_DAY, 5, 5 * 4) + checkDirPatternCompliance(6) + } + + + // this test requires changing the current working directory which is impossible in Java + @Ignore + @Test def dailyChronologSizeBasedRolloverWhenLogFilenameDoesNotContainDirectory: Unit = { + var sizeAndTimeBasedFNATP: SizeAndTimeBasedFNATP[AnyRef] = new SizeAndTimeBasedFNATP[AnyRef] + sizeAndTimeBasedFNATP.setMaxFileSize("10000") + tbfnatp = sizeAndTimeBasedFNATP + slashCount = 1 + doRollover("clean.%d{" + DAILY_DATE_PATTERN + "}.%i.zip", MILLIS_IN_DAY, 5, 5 * 4) + checkDirPatternCompliance(6) + } + + def extraFolder(numPeriods: Int, periodsPerEra: Int, beginPeriod: Int, maxHistory: Int): Boolean = { + var valueOfLastMonth: Int = ((beginPeriod) + numPeriods) % periodsPerEra + return (valueOfLastMonth < maxHistory) + } + + def expectedCountWithFolders(maxHistory: Int, extraFolder: Boolean): Int = { + val numLogFiles = (maxHistory + 1) + val numLogFilesAndFolders = numLogFiles*2 + var result: Int = numLogFilesAndFolders + slashCount + if (extraFolder) result += 1 + result + } + def addTime(currentTime: Long, timeToWait: Long): Long = { return currentTime + timeToWait } @@ -62,8 +140,9 @@ class TimeBasedRollingWithArchiveRemoval_STest { } } - def doRollover(fileNamePattern: String, periodDurationInMillis: Long, maxHistory: Int, simulatedNumberOfPeriods: Int): Unit = { + def doRollover(fileNamePattern: String, periodDurationInMillis: Long, maxHistory: Int, simulatedNumberOfPeriods: Int): (Long, Long) = { var currentTime: Long = System.currentTimeMillis + val startTime = currentTime var rfa: RollingFileAppender[AnyRef] = new RollingFileAppender[AnyRef] rfa.setContext(context) rfa.setEncoder(encoder) @@ -90,46 +169,89 @@ class TimeBasedRollingWithArchiveRemoval_STest { } waitForCompression(tbrp) rfa.stop + (startTime, tbrp.timeBasedFileNamingAndTriggeringPolicy.getCurrentTime) } def expectedCountWithoutFolders(maxHistory: Int): Int = { return maxHistory + 1 } - def findFoldersInFolderRecursively(dir: File, fileList: ListBuffer[File]) { - if (dir.isDirectory) { - var `match` : Array[File] = dir.listFiles(new FileFilter { - def accept(f: File): Boolean = { - return f.isDirectory - } - }) - for (f <- `match`) { - fileList += f - findFoldersInFolderRecursively(f, fileList) - } - } - } - def findAllInFolderRecursivelyByStringContains(dir: File, fileList: ListBuffer[File], pattern: String): Unit = { + def genericFindMatching(matchFunc: (File, String) => Boolean, dir: File, fileList: ListBuffer[File], pattern: String = null, includeDirs: Boolean = false) { if (dir.isDirectory) { var `match` : Array[File] = dir.listFiles(new FileFilter { def accept(f: File): Boolean = { - return (f.isDirectory || f.getName.contains(pattern)) + return f.isDirectory() || matchFunc(f, pattern) } }) for (f <- `match`) { - fileList += f if (f.isDirectory) { - findAllInFolderRecursivelyByStringContains(f, fileList, pattern) - } + if (includeDirs) fileList += f + genericFindMatching(matchFunc, f, fileList, pattern, includeDirs) + } else + fileList += f } } } + def findAllFoldersInFolderRecursively(dir: File, fileList: ListBuffer[File]) { + genericFindMatching((f, p) => false, dir, fileList, null, true); + } + + def findAllDirsOrStringContainsFilesRecursively(dir: File, fileList: ListBuffer[File], pattern: String): Unit = { + genericFindMatching((f, pattern) => (f.getName.contains(pattern)), dir, fileList, pattern, true) + } + + def findFilesInFolderRecursivelyByPatterMatch(dir: File, fileList: ListBuffer[File], pattern: String): Unit = { + genericFindMatching((f, p) => f.getName.matches(pattern), dir, fileList, pattern); + } + + + def expectedFileAndDirCount(expectedFileAndDirCount: Int, expectedDirCountMin: Int, expectedDirCountMax: Int): Unit = { + var dir: File = new File(randomOutputDir) + var fileList = new ListBuffer[File] + findFilesInFolderRecursivelyByPatterMatch(dir, fileList, "clean") + var dirList = new ListBuffer[File] + findAllFoldersInFolderRecursively(dir, dirList) + assertTrue("expectedDirCountMin=" + expectedDirCountMin + ", expectedDirCountMax=" + expectedDirCountMax + " actual value=" + dirList.size, expectedDirCountMin <= dirList.size && dirList.size <= expectedDirCountMax) + } + def check(expectedCount: Int): Unit = { var dir: File = new File(randomOutputDir) val fileList = new ListBuffer[File] - findAllInFolderRecursivelyByStringContains(dir, fileList, "clean") + findAllDirsOrStringContainsFilesRecursively(dir, fileList, "clean") assertEquals(expectedCount, fileList.size) } + + def groupByClass(fileList: ListBuffer[File], regex: String): Set[String] = { + var p: Pattern = Pattern.compile(regex) + val set = new HashSet[String] + for (f <- fileList) { + var n: String = f.getName + var m: Matcher = p.matcher(n) + m.matches + var begin: Int = m.start(1) + var reduced: String = n.substring(0, begin) + set.add(reduced) + } + return set + } + + def checkPatternCompliance(expectedClassCount: Int, regex: String) { + var dir: File = new File(randomOutputDir) + var fileList = new ListBuffer[File] + findFilesInFolderRecursivelyByPatterMatch(dir, fileList, regex) + var set: Set[String] = groupByClass(fileList, regex) + assertEquals(expectedClassCount, set.size) + } + + def checkDirPatternCompliance(expectedClassCount: Int): Unit = { + var dir: File = new File(randomOutputDir) + var fileList = new ListBuffer[File] + findAllFoldersInFolderRecursively(dir, fileList) + for (f <- fileList) { + assertTrue(f.list.length >= 1) + } + assertEquals(expectedClassCount, fileList.size) + } } \ No newline at end of file diff --git a/logback-site/src/site/pages/documentation.html b/logback-site/src/site/pages/documentation.html index cb27a5f..fac7f4e 100644 --- a/logback-site/src/site/pages/documentation.html +++ b/logback-site/src/site/pages/documentation.html @@ -77,6 +77,11 @@ <ul> <li><a + href="http://webtide.intalio.com/2011/08/sifting-logs-in-jetty-with-logback/">Sifting + Logs in Jetty with Logback</a> by Joakim Erdfelt + </li> + + <li><a href="http://www.nalinmakar.com/2010/07/28/logging-tests-to-separate-files/">Logging tests to separate files</a> by Nalin Makar</li> diff --git a/pom.xml b/pom.xml index b9791dc..417aa20 100755 --- a/pom.xml +++ b/pom.xml @@ -33,7 +33,7 @@ <slf4j.version>1.6.1</slf4j.version> <junit.version>4.8.2</junit.version> <janino.version>2.5.10</janino.version> - <scala.version>2.9.0</scala.version> + <scala.version>2.9.1</scala.version> <groovy.version>1.7.6</groovy.version> <surefire.version>2.6</surefire.version> <consolePlugin.version>1.1.0</consolePlugin.version> ----------------------------------------------------------------------- Summary of changes: .../java/ch/qos/logback/core/CoreConstants.java | 5 + ...aultTimeBasedFileNamingAndTriggeringPolicy.java | 3 +- .../core/rolling/SizeAndTimeBasedFNATP.java | 2 +- ...TimeBasedFileNamingAndTriggeringPolicyBase.java | 8 +- .../core/rolling/helper/DefaultArchiveRemover.java | 23 +-- .../core/rolling/helper/RollingCalendar.java | 216 ++++++++++++-------- .../helper/SizeAndTimeBasedArchiveRemover.java | 12 +- .../rolling/helper/TimeBasedArchiveRemover.java | 57 +++++ .../ch/qos/logback/core/rolling/PackageTest.java | 2 +- .../core/rolling/helper/RollingCalendarTest.java | 10 +- .../TimeBasedRollingWithArchiveRemoval_STest.scala | 166 +++++++++++++-- logback-site/src/site/pages/documentation.html | 5 + pom.xml | 2 +- 13 files changed, 370 insertions(+), 141 deletions(-) create mode 100644 logback-core/src/main/java/ch/qos/logback/core/rolling/helper/TimeBasedArchiveRemover.java hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0