Skip to content

Commit 9d77a0a

Browse files
committed
Fix broken throttler flush for v0.11.1.
1 parent dca3f8a commit 9d77a0a

File tree

5 files changed

+52
-4
lines changed

5 files changed

+52
-4
lines changed

CHANGELOG.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,10 @@
1414
limitations under the License.
1515
-->
1616

17+
### (2022-10-04) v0.11.1
18+
19+
- Earlier throttler fix has introduced a bug. The buffer cursor is not reset correctly and caused duplicates in logged events. (Thanks to [Khaled Bakhtiari](https://github.com/ec84b4) for the report.)
20+
1721
### (2022-09-02) v0.11.0
1822

1923
- Flush remaining events in the buffer after interrupting the throttler.

README.md

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -246,9 +246,10 @@ F.A.Q.
246246
Contributors
247247
============
248248

249+
- [Boris Faniuk](https://github.com//bfanyuk)
250+
- [Khaled Bakhtiari](https://github.com/ec84b4)
249251
- [t9t](https://github.com/t9t)
250252
- [Yaroslav Skopets](https://github.com/yskopets)
251-
- [Boris Faniuk](https://github.com/bfanyuk)
252253

253254
# License
254255

appender/src/main/java/com/vlkan/log4j2/redis/appender/RedisThrottler.java

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -219,6 +219,7 @@ private void flush(long waitPeriodNanos) throws InterruptedException {
219219
LOGGER.debug("{} background task is pushing last {} events that didn't fit into the batch", logPrefix, batchIndex);
220220
byte[][] subBatch = Arrays.copyOfRange(batch, 0, batchIndex);
221221
push(subBatch);
222+
batchIndex = 0;
222223
}
223224

224225
}

appender/src/test/java/com/vlkan/log4j2/redis/appender/RedisAppenderTest.java

Lines changed: 43 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -75,16 +75,56 @@ void appended_messages_should_be_persisted() {
7575
logger.log(expectedLogMessage.level, expectedLogMessage.message);
7676
}
7777

78+
// Verify the logging.
79+
verifyLogging(expectedLogMessages, expectedMessageCount, expectedMessageCount);
80+
81+
}
82+
83+
@Test
84+
void throttler_should_not_flush_same_content_twice() {
85+
86+
// Create the logger.
87+
LOGGER.debug("creating the logger");
88+
Logger logger = loggerContextExtension
89+
.getLoggerContext()
90+
.getLogger(RedisAppenderTest.class.getCanonicalName());
91+
92+
// Verify that batch size is greater than 1 so that we can observe a partially filled batch push.
93+
Assertions.assertThat(RedisAppenderTestConfig.THROTTLER_BATCH_SIZE).isGreaterThan(1);
94+
95+
// Log the 1st message.
96+
RedisTestMessage[] expectedLogMessages1 = RedisTestMessage.createRandomArray(1);
97+
logger.log(expectedLogMessages1[0].level, expectedLogMessages1[0].message);
98+
99+
// Verify the 1st message persistence.
100+
verifyLogging(expectedLogMessages1, 1, 1);
101+
102+
// Log the 1st message.
103+
RedisTestMessage[] expectedLogMessages2 = RedisTestMessage.createRandomArray(1);
104+
logger.log(expectedLogMessages2[0].level, expectedLogMessages2[0].message);
105+
106+
// Verify the 1st message persistence.
107+
verifyLogging(expectedLogMessages2, 2, 2);
108+
109+
}
110+
111+
private void verifyLogging(
112+
RedisTestMessage[] expectedLogMessages,
113+
int expectedTotalEventCount,
114+
int expectedRedisPushSuccessCount) {
115+
78116
// Verify the amount of persisted messages.
79117
Jedis jedis = redisClientExtension.getClient();
80118
LOGGER.debug("waiting for the logged messages to be persisted");
119+
int expectedMessageCount = expectedLogMessages.length;
81120
Awaitility
82121
.await()
83122
.pollDelay(Duration.ofMillis(100))
84123
.atMost(Duration.ofSeconds(10))
85124
.until(() -> {
86125
long persistedMessageCount = jedis.llen(RedisAppenderTestConfig.REDIS_KEY);
87-
return persistedMessageCount == expectedLogMessages.length;
126+
Assertions.assertThat(persistedMessageCount).isLessThanOrEqualTo(expectedMessageCount);
127+
return persistedMessageCount == expectedMessageCount;
88128
});
89129

90130
// Verify the content of persisted messages.
@@ -115,12 +155,12 @@ void appended_messages_should_be_persisted() {
115155
.getAppender(RedisAppenderTestConfig.LOG4J2_APPENDER_NAME);
116156
Assertions.assertThat(appender).isInstanceOf(RedisAppender.class);
117157
RedisThrottlerJmxBean jmxBean = ((RedisAppender) appender).getJmxBean();
118-
Assertions.assertThat(jmxBean.getTotalEventCount()).isEqualTo(expectedMessageCount);
158+
Assertions.assertThat(jmxBean.getTotalEventCount()).isEqualTo(expectedTotalEventCount);
119159
Assertions.assertThat(jmxBean.getIgnoredEventCount()).isEqualTo(0);
120160
Assertions.assertThat(jmxBean.getEventRateLimitFailureCount()).isEqualTo(0);
121161
Assertions.assertThat(jmxBean.getByteRateLimitFailureCount()).isEqualTo(0);
122162
Assertions.assertThat(jmxBean.getUnavailableBufferSpaceFailureCount()).isEqualTo(0);
123-
Assertions.assertThat(jmxBean.getRedisPushSuccessCount()).isEqualTo(expectedMessageCount);
163+
Assertions.assertThat(jmxBean.getRedisPushSuccessCount()).isEqualTo(expectedRedisPushSuccessCount);
124164
Assertions.assertThat(jmxBean.getRedisPushFailureCount()).isEqualTo(0);
125165

126166
}

appender/src/test/java/com/vlkan/log4j2/redis/appender/RedisAppenderTestConfig.java

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,4 +34,6 @@ enum RedisAppenderTestConfig {;
3434

3535
static final String LOG4J2_APPENDER_NAME = "REDIS";
3636

37+
static final int THROTTLER_BATCH_SIZE = 10;
38+
3739
}

0 commit comments

Comments
 (0)