You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by er...@apache.org on 2018/09/01 03:45:17 UTC
[1/2] lucene-solr:branch_7x: SOLR-12055: Enable async logging by
default
Repository: lucene-solr
Updated Branches:
refs/heads/branch_7x 91c9068ba -> 3483086f9
SOLR-12055: Enable async logging by default
(cherry picked from commit 8e75f393b31c0ffae9a7187474efe382b5011601)
Project: http://git-wip-us.apache.org/repos/asf/lucene-solr/repo
Commit: http://git-wip-us.apache.org/repos/asf/lucene-solr/commit/0464be8c
Tree: http://git-wip-us.apache.org/repos/asf/lucene-solr/tree/0464be8c
Diff: http://git-wip-us.apache.org/repos/asf/lucene-solr/diff/0464be8c
Branch: refs/heads/branch_7x
Commit: 0464be8cec8143687a34dd9bdf69567c7fb06522
Parents: 91c9068
Author: Erick Erickson <Er...@gmail.com>
Authored: Fri Aug 31 20:39:05 2018 -0700
Committer: Erick Erickson <Er...@gmail.com>
Committed: Fri Aug 31 20:40:58 2018 -0700
----------------------------------------------------------------------
solr/core/src/test-files/log4j2.xml | 12 +--
.../apache/solr/handler/RequestLoggingTest.java | 2 -
.../org/apache/solr/logging/TestLogWatcher.java | 80 ++++++++++----------
solr/server/resources/log4j2-console.xml | 8 +-
solr/server/resources/log4j2.xml | 30 ++++----
5 files changed, 63 insertions(+), 69 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/0464be8c/solr/core/src/test-files/log4j2.xml
----------------------------------------------------------------------
diff --git a/solr/core/src/test-files/log4j2.xml b/solr/core/src/test-files/log4j2.xml
index 7d0ebf7..5447843 100644
--- a/solr/core/src/test-files/log4j2.xml
+++ b/solr/core/src/test-files/log4j2.xml
@@ -27,13 +27,13 @@
</Console>
</Appenders>
<Loggers>
- <Logger name="org.apache.zookeeper" level="WARN"/>
- <Logger name="org.apache.hadoop" level="WARN"/>
- <Logger name="org.apache.directory" level="WARN"/>
- <Logger name="org.apache.solr.hadoop" level="INFO"/>
+ <AsyncLogger name="org.apache.zookeeper" level="WARN"/>
+ <AsyncLogger name="org.apache.hadoop" level="WARN"/>
+ <AsyncLogger name="org.apache.directory" level="WARN"/>
+ <AsyncLogger name="org.apache.solr.hadoop" level="INFO"/>
- <Root level="INFO">
+ <AsyncRoot level="INFO">
<AppenderRef ref="STDERR"/>
- </Root>
+ </AsyncRoot>
</Loggers>
</Configuration>
http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/0464be8c/solr/core/src/test/org/apache/solr/handler/RequestLoggingTest.java
----------------------------------------------------------------------
diff --git a/solr/core/src/test/org/apache/solr/handler/RequestLoggingTest.java b/solr/core/src/test/org/apache/solr/handler/RequestLoggingTest.java
index 17b5429..0e8a7a9 100644
--- a/solr/core/src/test/org/apache/solr/handler/RequestLoggingTest.java
+++ b/solr/core/src/test/org/apache/solr/handler/RequestLoggingTest.java
@@ -48,7 +48,6 @@ public class RequestLoggingTest extends SolrTestCaseJ4 {
@Before
public void setupAppender() {
LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
- LoggerConfig config = ctx.getConfiguration().getLoggerConfig("RequestLoggingTest");
writer = new StringWriter();
appender = WriterAppender.createAppender(
@@ -58,7 +57,6 @@ public class RequestLoggingTest extends SolrTestCaseJ4 {
.build(),
null, writer, "RequestLoggingTest", false, true);
appender.start();
-
}
@Test
http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/0464be8c/solr/core/src/test/org/apache/solr/logging/TestLogWatcher.java
----------------------------------------------------------------------
diff --git a/solr/core/src/test/org/apache/solr/logging/TestLogWatcher.java b/solr/core/src/test/org/apache/solr/logging/TestLogWatcher.java
index 6f7987f..9548363 100644
--- a/solr/core/src/test/org/apache/solr/logging/TestLogWatcher.java
+++ b/solr/core/src/test/org/apache/solr/logging/TestLogWatcher.java
@@ -16,6 +16,7 @@
*/
package org.apache.solr.logging;
+import org.apache.solr.SolrTestCaseJ4;
import org.apache.solr.common.SolrDocument;
import org.apache.solr.common.SolrDocumentList;
import org.junit.Before;
@@ -26,55 +27,50 @@ import org.slf4j.LoggerFactory;
import java.lang.invoke.MethodHandles;
import java.util.concurrent.atomic.AtomicBoolean;
-import static org.junit.Assert.assertEquals;
-import static org.junit.Assert.assertTrue;
-
-public class TestLogWatcher {
+public class TestLogWatcher extends SolrTestCaseJ4 {
private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
private LogWatcherConfig config;
@Before
- public void setUp() {
- config = new LogWatcherConfig(true, null, null, 50);
+ public void before() {
+ config = new LogWatcherConfig(true, null, "INFO", 1);
}
+ // Create several log watchers and ensure that new messages go to the new watcher.
@Test
public void testLog4jWatcher() {
- LogWatcher watcher = LogWatcher.newRegisteredLogWatcher(config, null);
-
- assertEquals(watcher.getLastEvent(), -1);
-
- log.warn("This is a test message");
-
- assertTrue(watcher.getLastEvent() > -1);
-
- SolrDocumentList events = watcher.getHistory(-1, new AtomicBoolean());
- assertEquals(events.size(), 1);
-
- SolrDocument event = events.get(0);
- assertEquals(event.get("logger"), "org.apache.solr.logging.TestLogWatcher");
- assertEquals(event.get("message"), "This is a test message");
-
+ LogWatcher watcher = null;
+ int lim = random().nextInt(3) + 2;
+ for (int idx = 0; idx < lim; ++idx) {
+ String msg = "This is a test message: " + idx;
+ watcher = LogWatcher.newRegisteredLogWatcher(config, null);
+
+ // First ensure there's nothing in the new watcher.
+ assertEquals(-1, watcher.getLastEvent());
+
+ // Now log a message and ensure that the new watcher sees it.
+ log.warn(msg);
+
+ // Loop to give the logger time to process the async message and notify the new watcher.
+ boolean foundMsg = false;
+ long last = -1;
+ // In local testing this loop usually succeeds 1-2 tries.
+ for (int msgIdx = 0; msgIdx < 100; ++msgIdx) {
+ // Returns an empty (but non-null) list even if there are no messages yet.
+ SolrDocumentList events = watcher.getHistory(-1, new AtomicBoolean());
+ for (SolrDocument doc : events) {
+ if (doc.get("message").equals(msg)) {
+ foundMsg = true;
+ break;
+ }
+ }
+ try {
+ Thread.sleep(10);
+ } catch (InterruptedException ie) {
+ ;
+ }
+ }
+ assertTrue("Should have found message " + msg + " in loop: " + idx, foundMsg);
+ }
}
-
- // This seems weird to do the same thing twice, this is valid. We need to test whether listeners are replaced....
- @Test
- public void testLog4jWatcherRepeat() {
- LogWatcher watcher = LogWatcher.newRegisteredLogWatcher(config, null);
-
- assertEquals(watcher.getLastEvent(), -1);
-
- log.warn("This is a test message");
-
- assertTrue(watcher.getLastEvent() > -1);
-
- SolrDocumentList events = watcher.getHistory(-1, new AtomicBoolean());
- assertEquals(events.size(), 1);
-
- SolrDocument event = events.get(0);
- assertEquals(event.get("logger"), "org.apache.solr.logging.TestLogWatcher");
- assertEquals(event.get("message"), "This is a test message");
-
- }
-
}
http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/0464be8c/solr/server/resources/log4j2-console.xml
----------------------------------------------------------------------
diff --git a/solr/server/resources/log4j2-console.xml b/solr/server/resources/log4j2-console.xml
index f32f4c1..698227b 100644
--- a/solr/server/resources/log4j2-console.xml
+++ b/solr/server/resources/log4j2-console.xml
@@ -29,11 +29,11 @@
</Console>
</Appenders>
<Loggers>
- <Logger name="org.apache.zookeeper" level="WARN"/>
- <Logger name="org.apache.hadoop" level="WARN"/>
+ <AsyncLogger name="org.apache.zookeeper" level="WARN"/>
+ <AsyncLogger name="org.apache.hadoop" level="WARN"/>
- <Root level="INFO">
+ <AsyncRoot level="INFO">
<AppenderRef ref="STDERR"/>
- </Root>
+ </AsyncRoot>
</Loggers>
</Configuration>
http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/0464be8c/solr/server/resources/log4j2.xml
----------------------------------------------------------------------
diff --git a/solr/server/resources/log4j2.xml b/solr/server/resources/log4j2.xml
index 17bcf4c..d9c05d8 100644
--- a/solr/server/resources/log4j2.xml
+++ b/solr/server/resources/log4j2.xml
@@ -27,8 +27,8 @@
</PatternLayout>
</Console>
- <RollingFile
- name="RollingFile"
+ <RollingRandomAccessFile
+ name="MainLogFile"
fileName="${sys:solr.log.dir}/solr.log"
filePattern="${sys:solr.log.dir}/solr.log.%i" >
<PatternLayout>
@@ -41,10 +41,10 @@
<SizeBasedTriggeringPolicy size="32 MB"/>
</Policies>
<DefaultRolloverStrategy max="10"/>
- </RollingFile>
+ </RollingRandomAccessFile>
- <RollingFile
- name="SlowFile"
+ <RollingRandomAccessFile
+ name="SlowLogFile"
fileName="${sys:solr.log.dir}/solr_slow_requests.log"
filePattern="${sys:solr.log.dir}/solr_slow_requests.log.%i" >
<PatternLayout>
@@ -57,20 +57,20 @@
<SizeBasedTriggeringPolicy size="32 MB"/>
</Policies>
<DefaultRolloverStrategy max="10"/>
- </RollingFile>
+ </RollingRandomAccessFile>
</Appenders>
<Loggers>
- <Logger name="org.apache.hadoop" level="warn"/>
- <Logger name="org.apache.solr.update.LoggingInfoStream" level="off"/>
- <Logger name="org.apache.zookeeper" level="warn"/>
- <Logger name="org.apache.solr.core.SolrCore.SlowRequest" level="info" additivity="false">
- <AppenderRef ref="SlowFile"/>
- </Logger>
+ <AsyncLogger name="org.apache.hadoop" level="warn"/>
+ <AsyncLogger name="org.apache.solr.update.LoggingInfoStream" level="off"/>
+ <AsyncLogger name="org.apache.zookeeper" level="warn"/>
+ <AsyncLogger name="org.apache.solr.core.SolrCore.SlowRequest" level="info" additivity="false">
+ <AppenderRef ref="SlowLogFile"/>
+ </AsyncLogger>
- <Root level="info">
- <AppenderRef ref="RollingFile"/>
+ <AsyncRoot level="info">
+ <AppenderRef ref="MainLogFile"/>
<AppenderRef ref="STDOUT"/>
- </Root>
+ </AsyncRoot>
</Loggers>
</Configuration>
[2/2] lucene-solr:branch_7x: SOLR-12055: Last patch had the entry in
the wrong place in CHANGES.txt
Posted by er...@apache.org.
SOLR-12055: Last patch had the entry in the wrong place in CHANGES.txt
(cherry picked from commit e7b449534344baf09f4824ad322f9a1e53300620)
Project: http://git-wip-us.apache.org/repos/asf/lucene-solr/repo
Commit: http://git-wip-us.apache.org/repos/asf/lucene-solr/commit/3483086f
Tree: http://git-wip-us.apache.org/repos/asf/lucene-solr/tree/3483086f
Diff: http://git-wip-us.apache.org/repos/asf/lucene-solr/diff/3483086f
Branch: refs/heads/branch_7x
Commit: 3483086f9cade648b97fc3dc77ea8dd7d7e32790
Parents: 0464be8
Author: Erick Erickson <Er...@gmail.com>
Authored: Fri Aug 31 20:43:26 2018 -0700
Committer: Erick Erickson <Er...@gmail.com>
Committed: Fri Aug 31 20:45:11 2018 -0700
----------------------------------------------------------------------
solr/CHANGES.txt | 6 ++++++
1 file changed, 6 insertions(+)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/lucene-solr/blob/3483086f/solr/CHANGES.txt
----------------------------------------------------------------------
diff --git a/solr/CHANGES.txt b/solr/CHANGES.txt
index 8eb92e6..c4452ce 100644
--- a/solr/CHANGES.txt
+++ b/solr/CHANGES.txt
@@ -45,6 +45,12 @@ Upgrade Notes
WINDOWS USERS: This JIRA corrects a bug in the start scripts that put example logs under ...\server, solr.log is
now under ...\example. (Erick Erickson)
+* SOLR-12055: Enable async logging by default. This change improves throughput for logging. This opens
+ up a small window where log messages could possibly be lost. If this is unacceptable, switching back to synchronous
+ logging can be done by changing the log4j2.xml files, no internal Solr code changed to make async logging the default.
+ (Erick Erickson)
+
+
New Features
----------------------