Repository: logging-log4j2 Updated Branches: refs/heads/master c262a53d1 -> bd0693983
LOG4J2-1680 Make TimeFilter garbage-free Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/bd069398 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/bd069398 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/bd069398 Branch: refs/heads/master Commit: bd06939833185c2fc38bfc2ec6afc15384b36e76 Parents: c262a53 Author: rpopma <[email protected]> Authored: Sun Nov 13 21:41:48 2016 +0900 Committer: rpopma <[email protected]> Committed: Sun Nov 13 21:41:48 2016 +0900 ---------------------------------------------------------------------- .../logging/log4j/core/filter/TimeFilter.java | 139 +++++++++++++++++-- log4j-core/src/test/resources/gcFreeLogging.xml | 4 + .../resources/gcFreeMixedSyncAsyncLogging.xml | 4 + src/changes/changes.xml | 7 +- src/site/xdoc/manual/garbagefree.xml | 4 +- 5 files changed, 142 insertions(+), 16 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/bd069398/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/TimeFilter.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/TimeFilter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/TimeFilter.java index 123cb6c..4c09161 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/TimeFilter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/filter/TimeFilter.java @@ -21,12 +21,16 @@ import java.text.SimpleDateFormat; import java.util.Calendar; import java.util.TimeZone; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.Marker; import org.apache.logging.log4j.core.Filter; import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.Logger; import org.apache.logging.log4j.core.config.Node; import org.apache.logging.log4j.core.config.plugins.Plugin; import org.apache.logging.log4j.core.config.plugins.PluginAttribute; import org.apache.logging.log4j.core.config.plugins.PluginFactory; +import org.apache.logging.log4j.message.Message; /** * Filters events that fall within a specified time period in each day. @@ -62,6 +66,9 @@ public final class TimeFilter extends AbstractFilter { */ private final TimeZone timezone; + private long midnightToday; + private long midnightTomorrow; + private TimeFilter(final long start, final long end, final TimeZone tz, final Result onMatch, final Result onMismatch) { @@ -69,21 +76,131 @@ public final class TimeFilter extends AbstractFilter { this.start = start; this.end = end; timezone = tz; + initMidnight(start); + } + + /** + * Initializes the midnight boundaries to midnight in the specified time zone. + * @param now a time in milliseconds since the epoch, used to pinpoint the current date + */ + void initMidnight(final long now) { + final Calendar calendar = Calendar.getInstance(timezone); + calendar.setTimeInMillis(now); + calendar.set(Calendar.HOUR_OF_DAY, 0); + calendar.set(Calendar.MINUTE, 0); + calendar.set(Calendar.SECOND, 0); + calendar.set(Calendar.MILLISECOND, 0); + midnightToday = calendar.getTimeInMillis(); + + calendar.add(Calendar.DATE, 1); + midnightTomorrow = calendar.getTimeInMillis(); + } + + /** + * Package-protected for tests. + * + * @param currentTimeMillis the time to compare with the boundaries. May re-initialize the cached midnight + * boundary values. + * @return the action to perform + */ + Result filter(final long currentTimeMillis) { + if (currentTimeMillis >= midnightTomorrow || currentTimeMillis < midnightToday) { + initMidnight(currentTimeMillis); + } + return currentTimeMillis >= midnightToday + start && currentTimeMillis <= midnightToday + end // + ? onMatch // within window + : onMismatch; } @Override public Result filter(final LogEvent event) { - final Calendar calendar = Calendar.getInstance(timezone); - calendar.setTimeInMillis(event.getTimeMillis()); - // - // get apparent number of milliseconds since midnight - // (ignores extra or missing hour on daylight time changes). - // - final long apparentOffset = calendar.get(Calendar.HOUR_OF_DAY) * HOUR_MS + - calendar.get(Calendar.MINUTE) * MINUTE_MS + - calendar.get(Calendar.SECOND) * SECOND_MS + - calendar.get(Calendar.MILLISECOND); - return apparentOffset >= start && apparentOffset < end ? onMatch : onMismatch; + return filter(event.getTimeMillis()); + } + + private Result filter() { + return Result.NEUTRAL; + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final Message msg, + final Throwable t) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final Object msg, + final Throwable t) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object... params) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2, final Object p3) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2, final Object p3, final Object p4) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5, + final Object p6) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5, + final Object p6, final Object p7) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5, + final Object p6, final Object p7, final Object p8) { + return filter(); + } + + @Override + public Result filter(final Logger logger, final Level level, final Marker marker, final String msg, + final Object p0, final Object p1, final Object p2, final Object p3, final Object p4, final Object p5, + final Object p6, final Object p7, final Object p8, final Object p9) { + return filter(); } @Override http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/bd069398/log4j-core/src/test/resources/gcFreeLogging.xml ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/resources/gcFreeLogging.xml b/log4j-core/src/test/resources/gcFreeLogging.xml index 2c92e8c..0e17663 100644 --- a/log4j-core/src/test/resources/gcFreeLogging.xml +++ b/log4j-core/src/test/resources/gcFreeLogging.xml @@ -18,18 +18,21 @@ <KeyValuePair key="id" value="Login"/> <KeyValuePair key="id" value="Logout"/> </StructuredDataFilter> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> </Filters> <Appenders> <Console name="Console" target="SYSTEM_OUT"> <PatternLayout pattern="%p %c{1.} [%t] %X{aKey} %X %m%ex%n" /> </Console> <File name="File" fileName="target/gcfreefile.log" bufferedIO="false"> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> <PatternLayout> <Pattern>%d{DEFAULT}{UTC} %r %sn %markerSimpleName %maxLen{%marker}{10} %equals{%markerSimpleName}{test}{substitute} %p %c{1.} [%t] %m%n %highlight{%style{%d}{bright,cyan} %p %c{1.} [%t] %m%n}</Pattern> </PatternLayout> </File> <RollingFile name="RollingFile" fileName="target/gcfreeRollingFile.log" filePattern="target/gcfree-%d{MM-dd-yy-HH-mm-ss}.log.gz"> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> <PatternLayout> <Pattern>%d{yyyy-MM-dd'T'HH:mm:ss,SSS}{UTC} %r %sn %markerSimpleName %maxLen{%marker}{10} %p %c{1.} [%t] %m%n %highlight{%style{%d}{bright,cyan} %p %c{1.} [%t] %m%n}</Pattern> </PatternLayout> @@ -38,6 +41,7 @@ </Policies> </RollingFile> <RandomAccessFile name="RandomAccessFile" fileName="target/gcfreeRAF.log" immediateFlush="false" append="false"> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> <PatternLayout> <Pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSS}{UTC} %r %sn %markerSimpleName %maxLen{%marker}{10} %p %c{1.} [%t] %X{aKey} %m %ex%n %highlight{%style{%d}{bright,cyan} %p %c{1.} [%t] %X{aKey} %m %ex%n}</Pattern> </PatternLayout> http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/bd069398/log4j-core/src/test/resources/gcFreeMixedSyncAsyncLogging.xml ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/resources/gcFreeMixedSyncAsyncLogging.xml b/log4j-core/src/test/resources/gcFreeMixedSyncAsyncLogging.xml index 24d1c90..b9ea5b2 100644 --- a/log4j-core/src/test/resources/gcFreeMixedSyncAsyncLogging.xml +++ b/log4j-core/src/test/resources/gcFreeMixedSyncAsyncLogging.xml @@ -18,18 +18,21 @@ <KeyValuePair key="id" value="Login"/> <KeyValuePair key="id" value="Logout"/> </StructuredDataFilter> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> </Filters> <Appenders> <Console name="Console" target="SYSTEM_OUT"> <PatternLayout pattern="%p %c{1.} [%t] %X{aKey} %X %m%ex%n" /> </Console> <File name="File" fileName="target/gcfreefileMixed.log" bufferedIO="false"> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> <PatternLayout> <Pattern>%d{yyyy-MM-dd'T'HH:mm:ss,SSS}{UTC} %r %sn %markerSimpleName %maxLen{%marker}{10} %equals{%markerSimpleName}{test}{substitute} %p %c{1.} [%t] %m%n %highlight{%style{%d}{bright,cyan} %p %c{1.} [%t] %m%n}</Pattern> </PatternLayout> </File> <RollingFile name="RollingFile" fileName="target/gcfreeRollingFileMixed.log" filePattern="target/gcfree-%d{MM-dd-yy-HH-mm-ss}.log.gz"> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> <PatternLayout> <Pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSS}{UTC} %r %sn %markerSimpleName %maxLen{%marker}{10} %p %c{1.} [%t] %m%n %highlight{%style{%d}{bright,cyan} %p %c{1.} [%t] %m%n}</Pattern> </PatternLayout> @@ -38,6 +41,7 @@ </Policies> </RollingFile> <RandomAccessFile name="RandomAccessFile" fileName="target/gcfreeRAFMixed.log" immediateFlush="false" append="false"> + <TimeFilter start="05:00:00" end="05:30:00" onMatch="ACCEPT" onMismatch="NEUTRAL"/> <PatternLayout> <Pattern>%d{DEFAULT}{UTC} %r %sn %markerSimpleName %maxLen{%marker}{10} %p %c{1.} [%t] %X{aKey} %m %ex%n %highlight{%style{%d}{bright,cyan} %p %c{1.} [%t] %X{aKey} %m %ex%n}</Pattern> </PatternLayout> http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/bd069398/src/changes/changes.xml ---------------------------------------------------------------------- diff --git a/src/changes/changes.xml b/src/changes/changes.xml index a86116f..155ff8f 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -30,6 +30,9 @@ <action issue="LOG4J2-1685" dev="mikes" type="fix" due-to="Raman Gupta"> Option 'disableAnsi' in PatternLayout to unconditionally disable ANSI escape codes. </action> + <action issue="LOG4J2-1680" dev="rpopma" type="fix"> + (GC) Avoid allocating temporary objects in TimeFilter. + </action> <action issue="LOG4J2-1679" dev="rpopma" type="fix"> (GC) Avoid allocating temporary objects in StructuredDataFilter. </action> @@ -137,10 +140,10 @@ </action> <action issue="LOG4J2-1703" dev="ggregory" type="add"> Add a Builder to MemoryMappedFileAppender and deprecate MemoryMappedFileAppender.createAppender(). - </action> + </action> <action issue="LOG4J2-1704" dev="ggregory" type="add"> Add a Builder to RollingRandomAccessFileAppender and deprecate RollingRandomAccessFileAppender.createAppender(). - </action> + </action> </release> <release version="2.7" date="2016-10-02" description="GA Release 2.7"> <action issue="LOG4J2-1618" dev="rpopma" type="fix" due-to="Raman Gupta"> http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/bd069398/src/site/xdoc/manual/garbagefree.xml ---------------------------------------------------------------------- diff --git a/src/site/xdoc/manual/garbagefree.xml b/src/site/xdoc/manual/garbagefree.xml index 5aca9e8..6af1a6c 100644 --- a/src/site/xdoc/manual/garbagefree.xml +++ b/src/site/xdoc/manual/garbagefree.xml @@ -173,10 +173,8 @@ <li>StructuredDataFilter (garbage free since 2.8)</li> <li>ThreadContextMapFilter (garbage free since 2.8)</li> <li>ThresholdFilter (garbage free since 2.8)</li> + <li>TimeFilter (garbage free since 2.8)</li> </ul> - <p>Currently the other filter implementations allocate temporary objects during steady state logging. - We expect to be able to make the following filters garbage-free in a subsequent release: - TimeFilter.</p> <p> Other filters like BurstFilter, RegexFilter and ScriptFilter are not trivial to make garbage free, and there is currently no plan to change them.
