diff --git a/solr/CHANGES.txt b/solr/CHANGES.txt index 7d30c0c3ad4..797acfc3d53 100644 --- a/solr/CHANGES.txt +++ b/solr/CHANGES.txt @@ -100,11 +100,6 @@ 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 ---------------------- @@ -322,12 +317,8 @@ Bug Fixes * SOLR-12704: Guard AddSchemaFieldsUpdateProcessorFactory against null field names and field values. (Steve Rowe, Varun Thacker) -* SOLR-12728: RequestLoggingTest fails on occasion, not reproducible (Erick Erickson) - * SOLR-12733: SolrMetricReporterTest failure (Erick Erickson, David Smiley) -* SOLR-12732: TestLogWatcher failure on Jenkins (Erick Erickson) - Optimizations ---------------------- diff --git a/solr/core/src/test-files/log4j2.xml b/solr/core/src/test-files/log4j2.xml index 544784322d3..7d0ebf7a497 100644 --- a/solr/core/src/test-files/log4j2.xml +++ b/solr/core/src/test-files/log4j2.xml @@ -27,13 +27,13 @@ - - - - + + + + - + - + 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 ae08e9a09d9..e203e808928 100644 --- a/solr/core/src/test/org/apache/solr/handler/RequestLoggingTest.java +++ b/solr/core/src/test/org/apache/solr/handler/RequestLoggingTest.java @@ -48,15 +48,17 @@ 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( PatternLayout .newBuilder() .withPattern("%-5p [%t]: %m%n") - .build(), + .build(), null, writer, "RequestLoggingTest", false, true); appender.start(); + } @Test @@ -73,7 +75,7 @@ public class RequestLoggingTest extends SolrTestCaseJ4 { public void testLogBeforeExecute(Logger logger) { Level level = logger.getLevel(); - + LoggerContext ctx = (LoggerContext) LogManager.getContext(false); LoggerConfig config = ctx.getConfiguration().getLoggerConfig(logger.getName()); config.setLevel(Level.DEBUG); @@ -82,23 +84,10 @@ public class RequestLoggingTest extends SolrTestCaseJ4 { try { assertQ(req("q", "*:*")); - Matcher matcher = null; - boolean foundDebugMsg = false; - String output = ""; - for (int msgIdx = 0; msgIdx < 100; ++msgIdx) { - output = writer.toString(); - matcher = Pattern.compile("DEBUG.*q=\\*:\\*.*").matcher(output); - if (matcher.find()) { - foundDebugMsg = true; - break; - } - try { - Thread.sleep(10); - } catch (InterruptedException ie) { - ; - } - } - assertTrue("Should have found debug-level message. Found " + output, foundDebugMsg); + + String output = writer.toString(); + Matcher matcher = Pattern.compile("DEBUG.*q=\\*:\\*.*").matcher(output); + assertTrue(matcher.find()); final String group = matcher.group(); final String msg = "Should not have post query information"; assertFalse(msg, group.contains("hits")); 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 a93a11bec6f..6f7987f084f 100644 --- a/solr/core/src/test/org/apache/solr/logging/TestLogWatcher.java +++ b/solr/core/src/test/org/apache/solr/logging/TestLogWatcher.java @@ -16,7 +16,6 @@ */ 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; @@ -27,63 +26,55 @@ import org.slf4j.LoggerFactory; import java.lang.invoke.MethodHandles; import java.util.concurrent.atomic.AtomicBoolean; -public class TestLogWatcher extends SolrTestCaseJ4 { +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertTrue; + +public class TestLogWatcher { private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); private LogWatcherConfig config; @Before - public void before() { - config = new LogWatcherConfig(true, null, "INFO", 1); + public void setUp() { + config = new LogWatcherConfig(true, null, null, 50); } - // Create several log watchers and ensure that new messages go to the new watcher. @Test public void testLog4jWatcher() { - LogWatcher watcher; - 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); + LogWatcher watcher = LogWatcher.newRegisteredLogWatcher(config, null); - // First ensure there's nothing in the new watcher. + assertEquals(watcher.getLastEvent(), -1); - // Every time you put a message in the queue, you wait for it to come out _before_ creating - // a new watcher so it should be fine. - if (looper(watcher, null) == false) { - fail("There should be no messages when a new watcher finally gets registered! In loop: " + idx); - } + log.warn("This is a test message"); - // Now log a message and ensure that the new watcher sees it. - log.warn(msg); + 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"); - // Loop to give the logger time to process the async message and notify the new watcher. - if (looper(watcher, msg) == false) { - fail("Should have found message " + msg + ". In loop: " + idx); - } - } } - private boolean looper(LogWatcher watcher, String msg) { - // In local testing this loop usually succeeds 1-2 tries. - boolean success = false; - boolean testingNew = msg == null; - for (int msgIdx = 0; msgIdx < 100 && success == false; ++msgIdx) { - if (testingNew) { // check that there are no entries registered for the watcher - success = watcher.getLastEvent() == -1; - } else { // check that the expected message is there. - // 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)) { - success = true; - } - } - } - try { - Thread.sleep(10); - } catch (InterruptedException ie) { - ; - } - } - return success; + + // 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"); + } + } diff --git a/solr/server/resources/log4j2-console.xml b/solr/server/resources/log4j2-console.xml index 698227b46d6..f32f4c142e2 100644 --- a/solr/server/resources/log4j2-console.xml +++ b/solr/server/resources/log4j2-console.xml @@ -29,11 +29,11 @@ - - + + - + - + diff --git a/solr/server/resources/log4j2.xml b/solr/server/resources/log4j2.xml index d9c05d8b468..17bcf4c007a 100644 --- a/solr/server/resources/log4j2.xml +++ b/solr/server/resources/log4j2.xml @@ -27,8 +27,8 @@ - @@ -41,10 +41,10 @@ - + - @@ -57,20 +57,20 @@ - + - - - - - - + + + + + + - - + + - +