Skip to content

Commit 278d8d4

Browse files
committed
more unit tests
1 parent 8790812 commit 278d8d4

7 files changed

Lines changed: 140 additions & 40 deletions

File tree

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,22 @@
1+
<?xml version="1.0" encoding="UTF-8" ?>
2+
<!DOCTYPE configuration>
3+
4+
<configuration debug="true">
5+
6+
<appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
7+
<discriminator>
8+
<key>max</key>
9+
<defaultValue>default</defaultValue>
10+
</discriminator>
11+
<maxAppenderCount>5</maxAppenderCount>
12+
<sift>
13+
<appender name="list-${userid}"
14+
class="ch.qos.logback.core.read.ListAppender"/>
15+
</sift>
16+
</appender>
17+
18+
<root level="DEBUG">
19+
<appender-ref ref="SIFT"/>
20+
</root>
21+
22+
</configuration>
Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,23 @@
1+
<?xml version="1.0" encoding="UTF-8" ?>
2+
<!DOCTYPE configuration>
3+
4+
<configuration debug="true">
5+
6+
<appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
7+
8+
<discriminator>
9+
<key>timeout</key>
10+
<defaultValue>smoke</defaultValue>
11+
</discriminator>
12+
<timeout>30000</timeout>
13+
<sift>
14+
<appender name="list-${userid}"
15+
class="ch.qos.logback.core.read.ListAppender"/>
16+
</sift>
17+
</appender>
18+
19+
<root level="DEBUG">
20+
<appender-ref ref="SIFT"/>
21+
</root>
22+
23+
</configuration>

logback-classic/src/test/java/ch/qos/logback/classic/sift/SiftingAppenderTest.java

Lines changed: 46 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@
2222
import ch.qos.logback.core.joran.spi.JoranException;
2323
import ch.qos.logback.core.read.ListAppender;
2424
import ch.qos.logback.core.sift.AppenderTracker;
25+
import ch.qos.logback.core.spi.AbstractComponentTracker;
2526
import ch.qos.logback.core.spi.ComponentTracker;
2627
import ch.qos.logback.core.status.ErrorStatus;
2728
import ch.qos.logback.core.status.StatusChecker;
@@ -32,9 +33,9 @@
3233
import org.slf4j.MDC;
3334

3435
import java.util.List;
35-
import java.util.Set;
3636

3737
import static org.junit.Assert.*;
38+
import static org.junit.Assert.assertEquals;
3839

3940
public class SiftingAppenderTest {
4041

@@ -43,8 +44,9 @@ public class SiftingAppenderTest {
4344
LoggerContext loggerContext = new LoggerContext();
4445
Logger logger = loggerContext.getLogger(this.getClass().getName());
4546
Logger root = loggerContext.getLogger(Logger.ROOT_LOGGER_NAME);
46-
StatusChecker sc = new StatusChecker(loggerContext);
47+
StatusChecker statusChecker = new StatusChecker(loggerContext);
4748
int diff = RandomUtil.getPositiveInt();
49+
int now = 0;
4850

4951
protected void configure(String file) throws JoranException {
5052
JoranConfigurator jc = new JoranConfigurator();
@@ -92,7 +94,7 @@ public void zeroNesting() throws JoranException {
9294
NOPAppender<ILoggingEvent> nopa = (NOPAppender<ILoggingEvent>) appender;
9395
StatusPrinter.printInCaseOfErrorsOrWarnings(loggerContext);
9496

95-
sc.assertContainsMatch(ErrorStatus.ERROR, "No nested appenders found");
97+
statusChecker.assertContainsMatch(ErrorStatus.ERROR, "No nested appenders found");
9698
}
9799

98100
@Test
@@ -106,7 +108,7 @@ public void multipleNesting() throws JoranException {
106108
StatusPrinter.printInCaseOfErrorsOrWarnings(loggerContext);
107109

108110
assertNotNull(listAppender);
109-
sc.assertContainsMatch(ErrorStatus.ERROR,
111+
statusChecker.assertContainsMatch(ErrorStatus.ERROR,
110112
"Only and only one appender can be nested");
111113
}
112114

@@ -160,7 +162,6 @@ public void sessionFinalizationShouldCauseLingering() throws JoranException {
160162
long now = System.currentTimeMillis();
161163
SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
162164
AppenderTracker<ILoggingEvent> tracker = sa.getAppenderTracker();
163-
String key = "a";
164165

165166
assertEquals(1, tracker.allKeys().size());
166167
Appender<ILoggingEvent> appender = tracker.find(mdcVal);
@@ -182,7 +183,6 @@ public void localPropertiesShouldBeVisible() throws JoranException {
182183
configure(SIFT_FOLDER_PREFIX + "propertyPropagation.xml");
183184
MDC.put(mdcKey, mdcVal);
184185
logger.debug(msg);
185-
long timestamp = System.currentTimeMillis();
186186
SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
187187
StringListAppender<ILoggingEvent> listAppender = (StringListAppender<ILoggingEvent>) sa
188188
.getAppenderTracker().find(mdcVal);
@@ -201,7 +201,6 @@ public void propertyDefinedWithinSiftElementShouldBeVisible() throws JoranExcept
201201
configure(SIFT_FOLDER_PREFIX + "propertyDefinedInSiftElement.xml");
202202
MDC.put(mdcKey, mdcVal);
203203
logger.debug(msg);
204-
long timestamp = System.currentTimeMillis();
205204
SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
206205
StringListAppender<ILoggingEvent> listAppender = (StringListAppender<ILoggingEvent>) sa
207206
.getAppenderTracker().find(mdcVal);
@@ -220,7 +219,6 @@ public void compositePropertyShouldCombineWithinAndWithoutSiftElement() throws J
220219
configure(SIFT_FOLDER_PREFIX + "compositeProperty.xml");
221220
MDC.put(mdcKey, mdcVal);
222221
logger.debug(msg);
223-
long timestamp = System.currentTimeMillis();
224222
SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
225223
StringListAppender<ILoggingEvent> listAppender = (StringListAppender<ILoggingEvent>) sa
226224
.getAppenderTracker().find(mdcVal);
@@ -230,5 +228,45 @@ public void compositePropertyShouldCombineWithinAndWithoutSiftElement() throws J
230228
assertEquals(prefix + msg, strList.get(0));
231229
}
232230

231+
@Test
232+
public void maxAppendersCountPropertyShouldBeHonored() throws JoranException {
233+
configure(SIFT_FOLDER_PREFIX + "maxAppenderCount.xml");
234+
int max = 5;
235+
SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
236+
String mdcKey = "max";
237+
for(int i = 0; i <= max; i++) {
238+
MDC.put(mdcKey, "" + (diff + i));
239+
LoggingEvent event = new LoggingEvent("", logger, Level.DEBUG, "max"+i, null, null);
240+
event.setTimeStamp(now);
241+
sa.doAppend(event);
242+
now += AbstractComponentTracker.WAIT_BETWEEN_SUCCESSIVE_REMOVAL_ITERATIONS;
243+
}
244+
AppenderTracker<ILoggingEvent> tracker = sa.getAppenderTracker();
245+
assertEquals(max, tracker.allKeys().size());
246+
assertNull(tracker.find("" + (diff + 0)));
247+
for(int i = 1; i <= max; i++) {
248+
assertNotNull(tracker.find("" + (diff + i)));
249+
}
250+
}
251+
252+
@Test
253+
public void timeoutPropertyShouldBeHonored() throws JoranException, InterruptedException {
254+
configure(SIFT_FOLDER_PREFIX + "timeout.xml");
255+
long timeout = 30*1000;
256+
SiftingAppender sa = (SiftingAppender) root.getAppender("SIFT");
257+
258+
LoggingEvent event = new LoggingEvent("", logger, Level.DEBUG, "timeout", null, null);
259+
event.setTimeStamp(now);
260+
sa.doAppend(event);
261+
262+
AppenderTracker<ILoggingEvent> tracker = sa.getAppenderTracker();
263+
264+
assertEquals(1, tracker.getComponentCount());
265+
266+
now += timeout+1;
267+
tracker.removeStaleComponents(now);
268+
assertEquals(0, tracker.getComponentCount());
269+
statusChecker.assertIsErrorFree();
270+
}
233271

234272
}

logback-core/src/main/java/ch/qos/logback/core/sift/AppenderTracker.java

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -65,7 +65,6 @@ protected Appender<E> buildComponent(String key) {
6565
return appender;
6666
}
6767

68-
6968
private NOPAppender<E> buildNOPAppender(String key) {
7069
if (nopaWarningCount < CoreConstants.MAX_ERROR_COUNT) {
7170
nopaWarningCount++;

logback-core/src/main/java/ch/qos/logback/core/spi/AbstractComponentTracker.java

Lines changed: 18 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,11 @@ abstract public class AbstractComponentTracker<C> implements ComponentTracker<C>
3535
// Components in lingering state last 10 seconds
3636
final public static long LINGERING_TIMEOUT = 10 * CoreConstants.MILLIS_IN_ONE_SECOND;
3737

38+
/**
39+
* The minimum amount of time that has to elapse between successive removal iterations.
40+
*/
41+
final public static long WAIT_BETWEEN_SUCCESSIVE_REMOVAL_ITERATIONS = CoreConstants.MILLIS_IN_ONE_SECOND;
42+
3843
protected int maxComponents = DEFAULT_MAX_COMPONENTS;
3944
protected long timeout = DEFAULT_TIMEOUT;
4045

@@ -104,7 +109,6 @@ public synchronized C find(String key) {
104109
else return entry.component;
105110
}
106111

107-
108112
/**
109113
* {@inheritDoc}
110114
*
@@ -127,6 +131,18 @@ public synchronized C getOrCreate(String key, long timestamp) {
127131
return entry.component;
128132
}
129133

134+
/**
135+
* Mark component identified by 'key' as having reached its end-of-life.
136+
*
137+
* @param key
138+
*/
139+
public void endOfLife(String key) {
140+
Entry entry = liveMap.remove(key);
141+
if (entry == null)
142+
return;
143+
lingerersMap.put(key, entry);
144+
}
145+
130146
/**
131147
* Clear (and detach) components which are stale. Components which have not
132148
* been accessed for more than a user-specified duration are deemed stale.
@@ -185,17 +201,14 @@ public boolean isSlatedForRemoval(Entry<C> entry, long timestamp) {
185201
}
186202
};
187203

188-
189-
190204
private boolean isTooSoonForRemovalIteration(long now) {
191-
if (lastCheck + CoreConstants.MILLIS_IN_ONE_SECOND > now) {
205+
if (lastCheck + WAIT_BETWEEN_SUCCESSIVE_REMOVAL_ITERATIONS > now) {
192206
return true;
193207
}
194208
lastCheck = now;
195209
return false;
196210
}
197211

198-
199212
private boolean isEntryStale(Entry<C> entry, long now) {
200213
// stopped or improperly started appenders are considered stale
201214
// see also http://jira.qos.ch/browse/LBCLASSIC-316
@@ -226,18 +239,6 @@ public Collection<C> allComponents() {
226239
return allComponents;
227240
}
228241

229-
/**
230-
* Mark component identified by 'key' as having reached its end-of-life.
231-
*
232-
* @param key
233-
*/
234-
public void endOfLife(String key) {
235-
Entry entry = liveMap.remove(key);
236-
if (entry == null)
237-
return;
238-
lingerersMap.put(key, entry);
239-
}
240-
241242
public long getTimeout() {
242243
return timeout;
243244
}
@@ -254,9 +255,6 @@ public void setMaxComponents(int maxComponents) {
254255
this.maxComponents = maxComponents;
255256
}
256257

257-
258-
259-
260258
// ================================================================
261259
private interface RemovalPredicator<C> {
262260
boolean isSlatedForRemoval(Entry<C> entry, long timestamp);

logback-core/src/main/java/ch/qos/logback/core/spi/ComponentTracker.java

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,9 @@
2222
/**
2323
* Interface for tracking various components by key. Components which have not
2424
* been accessed for more than a user-specified duration are deemed stale and
25-
* removed.
25+
* removed. Components can also be explicitly marked as having reached their
26+
* {@link #endOfLife(String)} in which case they will linger for a few seconds
27+
* and then be removed.
2628
*
2729
* @author Tommy Becker
2830
* @author Ceki Gulcu
@@ -32,7 +34,6 @@
3234
*/
3335
public interface ComponentTracker<C> {
3436

35-
3637
/**
3738
* The default timeout duration is 30 minutes
3839
*/

logback-core/src/test/java/ch/qos/logback/core/sift/AppenderTrackerTest.java

Lines changed: 28 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -14,20 +14,22 @@
1414
package ch.qos.logback.core.sift;
1515

1616
import ch.qos.logback.core.Appender;
17+
import ch.qos.logback.core.Context;
18+
import ch.qos.logback.core.ContextBase;
1719
import ch.qos.logback.core.joran.spi.JoranException;
20+
import ch.qos.logback.core.read.ListAppender;
1821
import ch.qos.logback.core.testUtil.RandomUtil;
1922
import org.junit.Before;
2023
import org.junit.Test;
2124

22-
import ch.qos.logback.core.Context;
23-
import ch.qos.logback.core.ContextBase;
24-
import ch.qos.logback.core.read.ListAppender;
25-
2625
import java.util.ArrayList;
2726
import java.util.List;
2827

2928
import static org.junit.Assert.*;
3029

30+
/**
31+
* Relatively straightforward unit tests for AppenderTracker.
32+
*/
3133
public class AppenderTrackerTest {
3234

3335
Context context = new ContextBase();
@@ -50,33 +52,49 @@ public void removeStaleComponentsShouldNotBomb() {
5052
@Test
5153
public void findingTheInexistentShouldNotBomb() {
5254
assertNull(appenderTracker.find(key));
53-
now += AppenderTracker.DEFAULT_TIMEOUT + 1000;
55+
now += AppenderTracker.DEFAULT_TIMEOUT + 1;
5456
appenderTracker.removeStaleComponents(now);
5557
assertNull(appenderTracker.find(key));
5658
}
5759

5860
@Test
5961
public void smoke() {
60-
appenderTracker.getOrCreate(key, now);
61-
Appender<Object> a = appenderTracker.find(key);
62+
Appender<Object> a = appenderTracker.getOrCreate(key, now);
6263
assertTrue(a.isStarted());
63-
now += AppenderTracker.DEFAULT_TIMEOUT + 1000;
64+
now += AppenderTracker.DEFAULT_TIMEOUT + 1;
6465
appenderTracker.removeStaleComponents(now);
6566
assertFalse(a.isStarted());
6667
assertNull(appenderTracker.find(key));
6768
}
6869

6970
@Test
70-
public void endOfLivedItemsShouldBeRemovedAfterLingeringTimeout() {
71+
public void endOfLivedAppendersShouldBeRemovedAfterLingeringTimeout() {
72+
Appender a = appenderTracker.getOrCreate(key, now);
73+
appenderTracker.endOfLife(key);
74+
now += AppenderTracker.LINGERING_TIMEOUT + 1;
75+
appenderTracker.removeStaleComponents(now);
76+
assertFalse(a.isStarted());
77+
a = appenderTracker.find(key);
78+
assertNull(a);
79+
}
80+
81+
@Test
82+
public void endOfLivedAppenderShouldBeAvailableDuringLingeringPeriod() {
7183
Appender a = appenderTracker.getOrCreate(key, now);
7284
appenderTracker.endOfLife(key);
85+
// clean
86+
appenderTracker.removeStaleComponents(now);
87+
Appender lingering = appenderTracker.getOrCreate(key, now);
88+
assertTrue(lingering.isStarted());
89+
assertTrue(a == lingering);
7390
now += AppenderTracker.LINGERING_TIMEOUT + 1;
7491
appenderTracker.removeStaleComponents(now);
7592
assertFalse(a.isStarted());
7693
a = appenderTracker.find(key);
7794
assertNull(a);
7895
}
7996

97+
8098
@Test
8199
public void trackerShouldHonorMaxComponentsParameter() {
82100
List<Appender<Object>> appenderList = new ArrayList<Appender<Object>>();
@@ -120,6 +138,7 @@ public void trackerShouldHonorTimeoutParameter() {
120138
assertTrue(appenderList.get(i).isStarted());
121139
}
122140
}
141+
123142
// ======================================================================
124143
static class ListAppenderFactory implements AppenderFactory<Object> {
125144

0 commit comments

Comments
 (0)