void writeToFile(File file, String contents) throws IOException {
FileWriter fw = new FileWriter(file);
fw.write(contents);
fw.close();
// on linux changes to last modified are not propagated if the
// time stamp is near the previous time stamp hence the random delta
file.setLastModified(System.currentTimeMillis() + RandomUtil.getPositiveInt());
}
public class MDCConverterTest {
LoggerContext lc;
MDCConverter converter;
int diff = RandomUtil.getPositiveInt();
@Before
public void setUp() throws Exception {
lc = new LoggerContext();
converter = new MDCConverter();
converter.start();
MDC.clear();
}
@After
public void tearDown() throws Exception {
lc = null;
converter.stop();
converter = null;
MDC.clear();
}
@Test
public void testConvertWithOneEntry() {
String k = "MDCConverterTest_k" + diff;
String v = "MDCConverterTest_v" + diff;
MDC.put(k, v);
ILoggingEvent le = createLoggingEvent();
String result = converter.convert(le);
assertEquals(k + "=" + v, result);
}
@Test
public void testConvertWithMultipleEntries() {
MDC.put("testKey", "testValue");
MDC.put("testKey2", "testValue2");
ILoggingEvent le = createLoggingEvent();
String result = converter.convert(le);
boolean isConform = result.matches("testKey2?=testValue2?, testKey2?=testValue2?");
assertTrue(result + " is not conform", isConform);
}
private ILoggingEvent createLoggingEvent() {
return new LoggingEvent(
this.getClass().getName(),
lc.getLogger(Logger.ROOT_LOGGER_NAME),
Level.DEBUG,
"test message",
null,
null);
}
}
@Test
public void tException() throws InterruptedException {
int port = RandomUtil.getRandomServerPort();
MockSyslogServer mockServer = new MockSyslogServer(21, port);
mockServer.start();
// give MockSyslogServer head start
Thread.sleep(100);
LoggerContext lc = new LoggerContext();
lc.setName("test");
SyslogAppender sa = new SyslogAppender();
sa.setContext(lc);
sa.setSyslogHost("localhost");
sa.setFacility("MAIL");
sa.setPort(port);
sa.setSuffixPattern("[%thread] %logger %msg");
sa.start();
assertTrue(sa.isStarted());
String loggerName = this.getClass().getName();
Logger logger = lc.getLogger(loggerName);
logger.addAppender(sa);
String logMsg = "hello";
String exMsg = "just testing";
Exception ex = new Exception(exMsg);
logger.debug(logMsg, ex);
// StatusPrinter.print(lc.getStatusManager());
// wait max 2 seconds for mock server to finish. However, it should
// much sooner than that.
mockServer.join(8000);
assertTrue(mockServer.isFinished());
// message + 20 lines of stacktrace
assertEquals(21, mockServer.getMessageList().size());
// int i = 0;
// for (String line: mockServer.msgList) {
// System.out.println(i++ + ": " + line);
// }
String msg = mockServer.getMessageList().get(0);
String expected = "<" + (SyslogConstants.LOG_MAIL + SyslogConstants.DEBUG_SEVERITY) + ">";
assertTrue(msg.startsWith(expected));
String expectedPrefix = "<\\d{2}>\\w{3} \\d{2} \\d{2}(:\\d{2}){2} [\\w.-]* ";
String threadName = Thread.currentThread().getName();
String regex = expectedPrefix + "\\[" + threadName + "\\] " + loggerName + " " + logMsg;
checkRegexMatch(msg, regex);
}
public class LevelChangePropagatorTest {
int rand = RandomUtil.getPositiveInt();
LoggerContext loggerContext = new LoggerContext();
LevelChangePropagator levelChangePropagator = new LevelChangePropagator();
@Before
public void setUp() {
levelChangePropagator.setContext(loggerContext);
loggerContext.addListener(levelChangePropagator);
}
void checkLevelChange(String loggerName, Level level) {
Logger logger = loggerContext.getLogger(loggerName);
logger.setLevel(level);
java.util.logging.Logger julLogger = JULHelper.asJULLogger(logger);
java.util.logging.Level julLevel = JULHelper.asJULLevel(level);
assertEquals(julLevel, julLogger.getLevel());
}
@Test
public void smoke() {
checkLevelChange("a", Level.INFO);
checkLevelChange("a.b", Level.DEBUG);
}
@Test
public void root() {
checkLevelChange(Logger.ROOT_LOGGER_NAME, Level.TRACE);
}
// see http://jira.qos.ch/browse/LBCLASSIC-256
@Test
public void gc() {
Logger logger = loggerContext.getLogger("gc" + rand);
logger.setLevel(Level.INFO);
// invoke GC so that the relevant julLogger can be garbage collected.
System.gc();
java.util.logging.Logger julLogger = JULHelper.asJULLogger(logger);
java.util.logging.Level julLevel = JULHelper.asJULLevel(Level.INFO);
assertEquals(julLevel, julLogger.getLevel());
}
}
@Test
public void basic() throws InterruptedException {
int port = RandomUtil.getRandomServerPort();
MockSyslogServer mockServer = new MockSyslogServer(1, port);
mockServer.start();
// give MockSyslogServer head start
Thread.sleep(100);
LoggerContext lc = new LoggerContext();
lc.setName("test");
SyslogAppender sa = new SyslogAppender();
sa.setContext(lc);
sa.setSyslogHost("localhost");
sa.setFacility("MAIL");
sa.setPort(port);
sa.setSuffixPattern("[%thread] %logger %msg");
sa.start();
assertTrue(sa.isStarted());
String loggerName = this.getClass().getName();
Logger logger = lc.getLogger(loggerName);
logger.addAppender(sa);
String logMsg = "hello";
logger.debug(logMsg);
// wait max 2 seconds for mock server to finish. However, it should
// much sooner than that.
mockServer.join(8000);
assertTrue(mockServer.isFinished());
assertEquals(1, mockServer.getMessageList().size());
String msg = mockServer.getMessageList().get(0);
String threadName = Thread.currentThread().getName();
String expected = "<" + (SyslogConstants.LOG_MAIL + SyslogConstants.DEBUG_SEVERITY) + ">";
assertTrue(msg.startsWith(expected));
String first = "<\\d{2}>\\w{3} \\d{2} \\d{2}(:\\d{2}){2} [\\w.-]* ";
checkRegexMatch(msg, first + "\\[" + threadName + "\\] " + loggerName + " " + logMsg);
}
@Test
public void withMissingTargetDir() throws Exception {
String testId = "missingTargetDir";
initRFA(rfa1, testId2FileName(testId));
int secondDiff = RandomUtil.getPositiveInt();
String randomTargetDir = CoreTestConstants.OUTPUT_DIR_PREFIX + secondDiff + '/';
System.out.println("randomOutputDir" + randomOutputDir);
System.out.println("randomTargetDir" + randomTargetDir);
initTRBP(
rfa1,
tbrp1,
randomTargetDir + testId + "-%d{" + DATE_PATTERN_WITH_SECONDS + "}",
currentTime);
addExpectedFileName_ByDate(randomTargetDir, testId, getDateOfCurrentPeriodsStart(), false);
incCurrentTime(1100);
tbrp1.timeBasedFileNamingAndTriggeringPolicy.setCurrentTime(currentTime);
for (int i = 0; i < 3; i++) {
rfa1.doAppend("Hello---" + i);
addExpectedFileNamedIfItsTime_ByDate(randomTargetDir, testId, false);
incCurrentTime(500);
tbrp1.timeBasedFileNamingAndTriggeringPolicy.setCurrentTime(currentTime);
}
massageExpectedFilesToCorresponToCurrentTarget("missingTargetDir.log");
int i = 0;
for (String fn : expectedFilenameList) {
System.out.println("expectedFile=" + fn);
assertTrue(
Compare.compare(
fn, CoreTestConstants.TEST_SRC_PREFIX + "witness/rolling/tbr-test5." + i++));
}
}
public class SMTPAppender_GreenTest {
static final String HEADER = "HEADER\n";
static final String FOOTER = "FOOTER\n";
static final String DEFAULT_PATTERN = "%-4relative %mdc [%thread] %-5level %class - %msg%n";
static final boolean SYNCHRONOUS = false;
static final boolean ASYNCHRONOUS = true;
int port = RandomUtil.getRandomServerPort();
// GreenMail cannot be static. As a shared server induces race conditions
GreenMail greenMailServer;
SMTPAppender smtpAppender;
LoggerContext loggerContext = new LoggerContext();
Logger logger = loggerContext.getLogger(this.getClass());
@Before
public void setUp() throws Exception {
OnConsoleStatusListener.addNewInstanceToContext(loggerContext);
MDC.clear();
ServerSetup serverSetup = new ServerSetup(port, "localhost", ServerSetup.PROTOCOL_SMTP);
greenMailServer = new GreenMail(serverSetup);
greenMailServer.start();
// give the server a head start
if (EnvUtilForTests.isRunningOnSlowJenkins()) {
Thread.sleep(2000);
} else {
Thread.sleep(50);
}
}
@After
public void tearDown() throws Exception {
greenMailServer.stop();
}
void buildSMTPAppender(String subject, boolean synchronicity) throws Exception {
smtpAppender = new SMTPAppender();
smtpAppender.setContext(loggerContext);
smtpAppender.setName("smtp");
smtpAppender.setFrom("*****@*****.**");
smtpAppender.setSMTPHost("localhost");
smtpAppender.setSMTPPort(port);
smtpAppender.setSubject(subject);
smtpAppender.addTo("*****@*****.**");
smtpAppender.setAsynchronousSending(synchronicity);
}
private Layout<ILoggingEvent> buildPatternLayout(String pattern) {
PatternLayout layout = new PatternLayout();
layout.setContext(loggerContext);
layout.setFileHeader(HEADER);
layout.setOutputPatternAsHeader(false);
layout.setPattern(pattern);
layout.setFileFooter(FOOTER);
layout.start();
return layout;
}
private Layout<ILoggingEvent> buildHTMLLayout() {
HTMLLayout layout = new HTMLLayout();
layout.setContext(loggerContext);
layout.setPattern("%level%class%msg");
layout.start();
return layout;
}
private void waitForServerToReceiveEmails(int emailCount) throws InterruptedException {
greenMailServer.waitForIncomingEmail(5000, emailCount);
}
private MimeMultipart verifyAndExtractMimeMultipart(String subject)
throws MessagingException, IOException, InterruptedException {
int oldCount = 0;
int expectedEmailCount = 1;
// wait for the server to receive the messages
waitForServerToReceiveEmails(expectedEmailCount);
MimeMessage[] mma = greenMailServer.getReceivedMessages();
assertNotNull(mma);
assertEquals(expectedEmailCount, mma.length);
MimeMessage mm = mma[oldCount];
// http://jira.qos.ch/browse/LBCLASSIC-67
assertEquals(subject, mm.getSubject());
return (MimeMultipart) mm.getContent();
}
void waitUntilEmailIsSent() throws InterruptedException {
loggerContext.getExecutorService().shutdown();
loggerContext.getExecutorService().awaitTermination(1000, TimeUnit.MILLISECONDS);
}
@Test
public void synchronousSmoke() throws Exception {
String subject = "synchronousSmoke";
buildSMTPAppender(subject, SYNCHRONOUS);
smtpAppender.setLayout(buildPatternLayout(DEFAULT_PATTERN));
smtpAppender.start();
logger.addAppender(smtpAppender);
logger.debug("hello");
logger.error("en error", new Exception("an exception"));
MimeMultipart mp = verifyAndExtractMimeMultipart(subject);
String body = GreenMailUtil.getBody(mp.getBodyPart(0));
assertTrue(body.startsWith(HEADER.trim()));
assertTrue(body.endsWith(FOOTER.trim()));
}
@Test
public void asynchronousSmoke() throws Exception {
String subject = "asynchronousSmoke";
buildSMTPAppender(subject, ASYNCHRONOUS);
smtpAppender.setLayout(buildPatternLayout(DEFAULT_PATTERN));
smtpAppender.start();
logger.addAppender(smtpAppender);
logger.debug("hello");
logger.error("en error", new Exception("an exception"));
waitUntilEmailIsSent();
MimeMultipart mp = verifyAndExtractMimeMultipart(subject);
String body = GreenMailUtil.getBody(mp.getBodyPart(0));
assertTrue(body.startsWith(HEADER.trim()));
assertTrue(body.endsWith(FOOTER.trim()));
}
// See also http://jira.qos.ch/browse/LOGBACK-734
@Test
public void callerDataShouldBeCorrectlySetWithAsynchronousSending() throws Exception {
String subject = "LOGBACK-734";
buildSMTPAppender("LOGBACK-734", ASYNCHRONOUS);
smtpAppender.setLayout(buildPatternLayout(DEFAULT_PATTERN));
smtpAppender.setIncludeCallerData(true);
smtpAppender.start();
logger.addAppender(smtpAppender);
logger.debug("LOGBACK-734");
logger.error("callerData", new Exception("ShouldBeCorrectlySetWithAsynchronousSending"));
waitUntilEmailIsSent();
MimeMultipart mp = verifyAndExtractMimeMultipart(subject);
String body = GreenMailUtil.getBody(mp.getBodyPart(0));
assertTrue(
"actual [" + body + "]",
body.contains("DEBUG " + this.getClass().getName() + " - LOGBACK-734"));
}
// lost MDC
@Test
public void LBCLASSIC_104() throws Exception {
String subject = "LBCLASSIC_104";
buildSMTPAppender(subject, SYNCHRONOUS);
smtpAppender.setAsynchronousSending(false);
smtpAppender.setLayout(buildPatternLayout(DEFAULT_PATTERN));
smtpAppender.start();
logger.addAppender(smtpAppender);
MDC.put("key", "val");
logger.debug("LBCLASSIC_104");
MDC.clear();
logger.error("en error", new Exception("test"));
MimeMultipart mp = verifyAndExtractMimeMultipart(subject);
String body = GreenMailUtil.getBody(mp.getBodyPart(0));
assertTrue(body.startsWith(HEADER.trim()));
System.out.println(body);
assertTrue(body.contains("key=val"));
assertTrue(body.endsWith(FOOTER.trim()));
}
@Test
public void html() throws Exception {
String subject = "html";
buildSMTPAppender(subject, SYNCHRONOUS);
smtpAppender.setAsynchronousSending(false);
smtpAppender.setLayout(buildHTMLLayout());
smtpAppender.start();
logger.addAppender(smtpAppender);
logger.debug("html");
logger.error("en error", new Exception("an exception"));
MimeMultipart mp = verifyAndExtractMimeMultipart(subject);
// verifyAndExtractMimeMultipart strict adherence to xhtml1-strict.dtd
SAXReader reader = new SAXReader();
reader.setValidation(true);
reader.setEntityResolver(new XHTMLEntityResolver());
byte[] messageBytes = getAsByteArray(mp.getBodyPart(0).getInputStream());
ByteArrayInputStream bais = new ByteArrayInputStream(messageBytes);
try {
reader.read(bais);
} catch (DocumentException de) {
System.out.println("incoming message:");
System.out.println(new String(messageBytes));
throw de;
}
}
private byte[] getAsByteArray(InputStream inputStream) throws IOException {
ByteArrayOutputStream baos = new ByteArrayOutputStream();
byte[] buffer = new byte[1024];
int n = -1;
while ((n = inputStream.read(buffer)) != -1) {
baos.write(buffer, 0, n);
}
return baos.toByteArray();
}
private void configure(String file) throws JoranException {
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(loggerContext);
loggerContext.putProperty("port", "" + port);
jc.doConfigure(file);
}
@Test
public void testCustomEvaluator() throws Exception {
configure(ClassicTestConstants.JORAN_INPUT_PREFIX + "smtp/customEvaluator.xml");
logger.debug("test");
String msg2 = "CustomEvaluator";
logger.debug(msg2);
logger.debug("invisible");
waitUntilEmailIsSent();
MimeMultipart mp =
verifyAndExtractMimeMultipart(
"testCustomEvaluator " + this.getClass().getName() + " - " + msg2);
String body = GreenMailUtil.getBody(mp.getBodyPart(0));
assertEquals("testCustomEvaluator", body);
}
@Test
public void testCustomBufferSize() throws Exception {
configure(ClassicTestConstants.JORAN_INPUT_PREFIX + "smtp/customBufferSize.xml");
logger.debug("invisible1");
logger.debug("invisible2");
String msg = "hello";
logger.error(msg);
waitUntilEmailIsSent();
MimeMultipart mp =
verifyAndExtractMimeMultipart(
"testCustomBufferSize " + this.getClass().getName() + " - " + msg);
String body = GreenMailUtil.getBody(mp.getBodyPart(0));
assertEquals(msg, body);
}
// this test fails intermittently on Jenkins.
@Test
public void testMultipleTo() throws Exception {
buildSMTPAppender("testMultipleTo", SYNCHRONOUS);
smtpAppender.setLayout(buildPatternLayout(DEFAULT_PATTERN));
// buildSMTPAppender() already added one destination address
smtpAppender.addTo("Test <*****@*****.**>, [email protected]");
smtpAppender.start();
logger.addAppender(smtpAppender);
logger.debug("testMultipleTo hello");
logger.error("testMultipleTo en error", new Exception("an exception"));
Thread.yield();
int expectedEmailCount = 3;
waitForServerToReceiveEmails(expectedEmailCount);
MimeMessage[] mma = greenMailServer.getReceivedMessages();
assertNotNull(mma);
assertEquals(expectedEmailCount, mma.length);
}
// http://jira.qos.ch/browse/LBCLASSIC-221
@Test
public void bufferShouldBeResetBetweenMessages() throws Exception {
buildSMTPAppender("bufferShouldBeResetBetweenMessages", SYNCHRONOUS);
smtpAppender.setLayout(buildPatternLayout(DEFAULT_PATTERN));
smtpAppender.start();
logger.addAppender(smtpAppender);
String msg0 = "hello zero";
logger.debug(msg0);
logger.error("error zero");
String msg1 = "hello one";
logger.debug(msg1);
logger.error("error one");
Thread.yield();
int oldCount = 0;
int expectedEmailCount = oldCount + 2;
waitForServerToReceiveEmails(expectedEmailCount);
MimeMessage[] mma = greenMailServer.getReceivedMessages();
assertNotNull(mma);
assertEquals(expectedEmailCount, mma.length);
MimeMessage mm0 = mma[oldCount];
MimeMultipart content0 = (MimeMultipart) mm0.getContent();
String body0 = GreenMailUtil.getBody(content0.getBodyPart(0));
MimeMessage mm1 = mma[oldCount + 1];
MimeMultipart content1 = (MimeMultipart) mm1.getContent();
String body1 = GreenMailUtil.getBody(content1.getBodyPart(0));
// second body should not contain content from first message
assertFalse(body1.contains(msg0));
}
@Test
public void multiLineSubjectTruncatedAtFirstNewLine() throws Exception {
String line1 = "line 1 of subject";
String subject = line1 + "\nline 2 of subject\n";
buildSMTPAppender(subject, ASYNCHRONOUS);
smtpAppender.setLayout(buildPatternLayout(DEFAULT_PATTERN));
smtpAppender.start();
logger.addAppender(smtpAppender);
logger.debug("hello");
logger.error("en error", new Exception("an exception"));
Thread.yield();
waitUntilEmailIsSent();
waitForServerToReceiveEmails(1);
MimeMessage[] mma = greenMailServer.getReceivedMessages();
assertEquals(1, mma.length);
assertEquals(line1, mma[0].getSubject());
}
}
public class ConditionalTest {
LoggerContext context = new LoggerContext();
Logger root = context.getLogger(Logger.ROOT_LOGGER_NAME);
int diff = RandomUtil.getPositiveInt();
String randomOutputDir = CoreTestConstants.OUTPUT_DIR_PREFIX + diff + "/";
@Before
public void setUp() throws UnknownHostException {
context.setName("c" + diff);
context.putProperty("randomOutputDir", randomOutputDir);
}
@After
public void tearDown() {
StatusPrinter.printIfErrorsOccured(context);
}
void configure(String file) throws JoranException {
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(context);
jc.doConfigure(file);
}
@SuppressWarnings("rawtypes")
@Test
public void conditionalConsoleApp_IF_THEN_True()
throws JoranException, IOException, InterruptedException {
InetAddress localhost = InetAddress.getLocalHost();
System.out.println(
"In conditionalConsoleApp_IF_THEN_True, canonicalHostName=\""
+ localhost.getCanonicalHostName()
+ "] and hostNmae=\""
+ localhost.getHostName()
+ "\"");
context.putProperty("aHost", localhost.getHostName());
String configFileAsStr =
ClassicTestConstants.JORAN_INPUT_PREFIX + "conditional/conditionalConsoleApp.xml";
configure(configFileAsStr);
FileAppender fileAppender = (FileAppender) root.getAppender("FILE");
assertNotNull(fileAppender);
ConsoleAppender consoleAppender = (ConsoleAppender) root.getAppender("CON");
assertNotNull(consoleAppender);
StatusChecker checker = new StatusChecker(context);
checker.assertIsErrorFree();
}
@SuppressWarnings("rawtypes")
@Test
public void conditionalConsoleApp_IF_THEN_False()
throws JoranException, IOException, InterruptedException {
String configFileAsStr =
ClassicTestConstants.JORAN_INPUT_PREFIX + "conditional/conditionalConsoleApp.xml";
configure(configFileAsStr);
FileAppender fileAppender = (FileAppender) root.getAppender("FILE");
assertNotNull(fileAppender);
ConsoleAppender consoleAppender = (ConsoleAppender) root.getAppender("CON");
assertNull(consoleAppender);
StatusChecker checker = new StatusChecker(context);
checker.assertIsErrorFree();
}
@SuppressWarnings("rawtypes")
@Test
public void conditionalConsoleApp_IF_THEN_ELSE()
throws JoranException, IOException, InterruptedException {
String configFileAsStr =
ClassicTestConstants.JORAN_INPUT_PREFIX + "conditional/conditionalConsoleApp_ELSE.xml";
configure(configFileAsStr);
FileAppender fileAppender = (FileAppender) root.getAppender("FILE");
assertNotNull(fileAppender);
ConsoleAppender consoleAppender = (ConsoleAppender) root.getAppender("CON");
assertNull(consoleAppender);
ListAppender listAppender = (ListAppender) root.getAppender("LIST");
assertNotNull(listAppender);
// StatusPrinter.printIfErrorsOccured(context);
StatusChecker checker = new StatusChecker(context);
checker.assertIsErrorFree();
}
@Test
public void conditionalInclusionWithExistingFile()
throws JoranException, IOException, InterruptedException {
String configFileAsStr =
ClassicTestConstants.JORAN_INPUT_PREFIX + "conditional/conditionalIncludeExistingFile.xml";
configure(configFileAsStr);
ConsoleAppender consoleAppender = (ConsoleAppender) root.getAppender("CON");
assertNotNull(consoleAppender);
StatusChecker checker = new StatusChecker(context);
checker.assertIsErrorFree();
}
@Test
public void conditionalInclusionWithInexistentFile()
throws JoranException, IOException, InterruptedException {
String configFileAsStr =
ClassicTestConstants.JORAN_INPUT_PREFIX
+ "conditional/conditionalIncludeInexistentFile.xml";
configure(configFileAsStr);
ConsoleAppender consoleAppender = (ConsoleAppender) root.getAppender("CON");
assertNull(consoleAppender);
StatusChecker checker = new StatusChecker(context);
checker.assertIsErrorFree();
}
}
public class DBAppenderHSQLTest {
LoggerContext lc;
Logger logger;
DBAppender appender;
DriverManagerConnectionSource connectionSource;
DBAppenderHSQLTestFixture dbAppenderHSQLTestFixture;
int diff = RandomUtil.getPositiveInt();
@Before
public void setUp() throws SQLException {
dbAppenderHSQLTestFixture = new DBAppenderHSQLTestFixture();
dbAppenderHSQLTestFixture.setUp();
lc = new LoggerContext();
lc.setName("default");
logger = lc.getLogger("root");
appender = new DBAppender();
appender.setName("DB");
appender.setContext(lc);
connectionSource = new DriverManagerConnectionSource();
connectionSource.setContext(lc);
connectionSource.setDriverClass(DBAppenderHSQLTestFixture.HSQLDB_DRIVER_CLASS);
connectionSource.setUrl(dbAppenderHSQLTestFixture.url);
connectionSource.setUser(dbAppenderHSQLTestFixture.user);
connectionSource.setPassword(dbAppenderHSQLTestFixture.password);
connectionSource.start();
appender.setConnectionSource(connectionSource);
appender.start();
}
@After
public void tearDown() throws SQLException {
logger = null;
lc = null;
appender = null;
connectionSource = null;
dbAppenderHSQLTestFixture.tearDown();
}
@Test
public void testAppendLoggingEvent() throws SQLException {
ILoggingEvent event = createLoggingEvent();
appender.append(event);
StatusPrinter.printInCaseOfErrorsOrWarnings(lc);
Statement stmt = connectionSource.getConnection().createStatement();
ResultSet rs = null;
rs = stmt.executeQuery("SELECT * FROM logging_event");
if (rs.next()) {
assertEquals(event.getTimeStamp(), rs.getLong(DBAppender.TIMESTMP_INDEX));
assertEquals(event.getFormattedMessage(), rs.getString(DBAppender.FORMATTED_MESSAGE_INDEX));
assertEquals(event.getLoggerName(), rs.getString(DBAppender.LOGGER_NAME_INDEX));
assertEquals(event.getLevel().toString(), rs.getString(DBAppender.LEVEL_STRING_INDEX));
assertEquals(event.getThreadName(), rs.getString(DBAppender.THREAD_NAME_INDEX));
assertEquals(
DBHelper.computeReferenceMask(event), rs.getShort(DBAppender.REFERENCE_FLAG_INDEX));
assertEquals(String.valueOf(diff), rs.getString(DBAppender.ARG0_INDEX));
StackTraceElement callerData = event.getCallerData()[0];
assertEquals(callerData.getFileName(), rs.getString(DBAppender.CALLER_FILENAME_INDEX));
assertEquals(callerData.getClassName(), rs.getString(DBAppender.CALLER_CLASS_INDEX));
assertEquals(callerData.getMethodName(), rs.getString(DBAppender.CALLER_METHOD_INDEX));
} else {
fail("No row was inserted in the database");
}
rs.close();
stmt.close();
}
@Test
public void testAppendThrowable() throws SQLException {
ILoggingEvent event = createLoggingEvent();
appender.append(event);
Statement stmt = connectionSource.getConnection().createStatement();
ResultSet rs = null;
rs = stmt.executeQuery("SELECT * FROM LOGGING_EVENT_EXCEPTION where EVENT_ID = 0");
rs.next();
String expected = "java.lang.Exception: test Ex";
String firstLine = rs.getString(3);
assertTrue(
"[" + firstLine + "] does not match [" + expected + "]", firstLine.contains(expected));
int i = 0;
while (rs.next()) {
expected = event.getThrowableProxy().getStackTraceElementProxyArray()[i].toString();
String st = rs.getString(3);
assertTrue("[" + st + "] does not match [" + expected + "]", st.contains(expected));
i++;
}
assertTrue(i != 0);
rs.close();
stmt.close();
}
@Test
public void testContextInfo() throws SQLException {
lc.putProperty("testKey1", "testValue1");
MDC.put("k" + diff, "v" + diff);
ILoggingEvent event = createLoggingEvent();
appender.append(event);
Statement stmt = connectionSource.getConnection().createStatement();
ResultSet rs = null;
rs = stmt.executeQuery("SELECT * FROM LOGGING_EVENT_PROPERTY WHERE EVENT_ID = 0");
Map<String, String> map = appender.mergePropertyMaps(event);
System.out.println("ma.size=" + map.size());
int i = 0;
while (rs.next()) {
String key = rs.getString(2);
assertEquals(map.get(key), rs.getString(3));
i++;
}
assertTrue(map.size() != 0);
assertEquals(map.size(), i);
rs.close();
stmt.close();
}
@Test
public void testAppendMultipleEvents() throws SQLException {
for (int i = 0; i < 10; i++) {
ILoggingEvent event = createLoggingEvent();
appender.append(event);
}
Statement stmt = connectionSource.getConnection().createStatement();
ResultSet rs = null;
rs = stmt.executeQuery("SELECT * FROM logging_event");
int count = 0;
while (rs.next()) {
count++;
}
assertEquals(10, count);
rs.close();
stmt.close();
}
private ILoggingEvent createLoggingEvent() {
return new LoggingEvent(
this.getClass().getName(),
logger,
Level.DEBUG,
"test message",
new Exception("test Ex"),
new Integer[] {diff});
}
}
File makeRandomJarFile() {
File outputDir = new File(CoreTestConstants.OUTPUT_DIR_PREFIX);
outputDir.mkdirs();
int randomPart = RandomUtil.getPositiveInt();
return new File(CoreTestConstants.OUTPUT_DIR_PREFIX + "foo-" + randomPart + ".jar");
}
public class FileAppenderPerf {
static String msgLong = "ABCDEGHIJKLMNOPQRSTUVWXYZabcdeghijklmnopqrstuvwxyz1234567890";
static long LEN = 100 * 1000;
static int DIFF = RandomUtil.getPositiveInt() % 1000;
static String FILENAME;
static LoggerContext buildLoggerContext(String filename, boolean safetyMode) {
LoggerContext loggerContext = new LoggerContext();
FileAppender<ILoggingEvent> fa = new FileAppender<ILoggingEvent>();
PatternLayoutEncoder patternLayout = new PatternLayoutEncoder();
patternLayout.setPattern("%5p %c - %m%n");
patternLayout.setContext(loggerContext);
patternLayout.start();
fa.setEncoder(patternLayout);
fa.setFile(filename);
fa.setAppend(false);
fa.setPrudent(safetyMode);
fa.setContext(loggerContext);
fa.start();
ch.qos.logback.classic.Logger root = loggerContext.getLogger(Logger.ROOT_LOGGER_NAME);
root.addAppender(fa);
return loggerContext;
}
static void usage(String msg) {
System.err.println(msg);
System.err.println("Usage: java " + FileAppenderPerf.class.getName() + " filename");
System.exit(1);
}
public static void main(String[] argv) throws Exception {
if (argv.length > 1) {
usage("Wrong number of arguments.");
}
if (argv.length == 0) {
FILENAME = DIFF + "";
} else {
FILENAME = argv[0];
}
perfCase(false);
perfCase(true);
}
static void perfCase(boolean safetyMode) throws Exception {
LoggerContext lc = buildLoggerContext(FILENAME + "-" + safetyMode + ".log", safetyMode);
Logger logger = lc.getLogger(FileAppenderPerf.class);
long start = System.nanoTime();
for (int i = 0; i < LEN; i++) {
logger.debug(msgLong + " " + i);
}
// in microseconds
double durationPerLog = (System.nanoTime() - start) / (LEN * 1000.0);
lc.stop();
System.out.println(
"Average duration of "
+ (durationPerLog)
+ " microseconds per log. Prudent mode="
+ safetyMode);
System.out.println("------------------------------------------------");
}
}
/**
* @author Ceki Gülcü
* @author Torsten Juergeleit
*/
public class AsyncAppenderTest {
String thisClassName = this.getClass().getName();
LoggerContext context = new LoggerContext();
AsyncAppender asyncAppender = new AsyncAppender();
ListAppender<ILoggingEvent> listAppender = new ListAppender<ILoggingEvent>();
OnConsoleStatusListener onConsoleStatusListener = new OnConsoleStatusListener();
LoggingEventBuilderInContext builder =
new LoggingEventBuilderInContext(
context, thisClassName, UnsynchronizedAppenderBase.class.getName());
int diff = RandomUtil.getPositiveInt();
@Before
public void setUp() {
onConsoleStatusListener.setContext(context);
context.getStatusManager().add(onConsoleStatusListener);
onConsoleStatusListener.start();
asyncAppender.setContext(context);
listAppender.setContext(context);
listAppender.setName("list");
listAppender.start();
}
@Test
public void eventWasPreparedForDeferredProcessing() {
asyncAppender.addAppender(listAppender);
asyncAppender.start();
String k = "k" + diff;
MDC.put(k, "v");
asyncAppender.doAppend(builder.build(diff));
MDC.clear();
asyncAppender.stop();
assertFalse(asyncAppender.isStarted());
// check the event
assertEquals(1, listAppender.list.size());
ILoggingEvent e = listAppender.list.get(0);
// check that MDC values were correctly retained
assertEquals("v", e.getMDCPropertyMap().get(k));
assertFalse(e.hasCallerData());
}
@Test
public void settingIncludeCallerDataPropertyCausedCallerDataToBeIncluded() {
asyncAppender.addAppender(listAppender);
asyncAppender.setIncludeCallerData(true);
asyncAppender.start();
asyncAppender.doAppend(builder.build(diff));
asyncAppender.stop();
// check the event
assertEquals(1, listAppender.list.size());
ILoggingEvent e = listAppender.list.get(0);
assertTrue(e.hasCallerData());
StackTraceElement ste = e.getCallerData()[0];
assertEquals(thisClassName, ste.getClassName());
}
}
public class MultiThreadedRollingTest {
static final int NUM_THREADS = 10;
static final int TOTAL_DURATION = 600;
RunnableWithCounterAndDone[] runnableArray;
Encoder<Object> encoder;
Context context = new ContextBase();
static String VERIFY_SH = "verify.sh";
int diff = RandomUtil.getPositiveInt();
String outputDirStr = CoreTestConstants.OUTPUT_DIR_PREFIX + "multi-" + diff + "/";
RollingFileAppender<Object> rfa = new RollingFileAppender<Object>();
String pathToBash = Env.getPathToBash();
OutputStream scriptOS;
@Before
public void setUp() throws Exception {
encoder = new EchoEncoder<Object>();
File outputDir = new File(outputDirStr);
outputDir.mkdirs();
System.out.println("Output dir [" + outputDirStr + "]");
scriptOS = openScript();
rfa.setName("rolling");
rfa.setEncoder(encoder);
rfa.setContext(context);
rfa.setFile(outputDirStr + "output.log");
}
void close(OutputStream os) {
if (os != null) {
try {
os.close();
} catch (IOException e) {
}
}
}
@After
public void tearDown() throws Exception {
rfa.stop();
}
public void setUpTimeBasedTriggeringPolicy(RollingFileAppender<Object> rfa) {
String datePattern = "yyyy-MM-dd'T'HH_mm_ss_SSS";
TimeBasedRollingPolicy tbrp = new TimeBasedRollingPolicy();
tbrp.setFileNamePattern(outputDirStr + "test-%d{" + datePattern + "}");
tbrp.setContext(context);
tbrp.setParent(rfa);
tbrp.start();
rfa.setRollingPolicy(tbrp);
rfa.start();
}
public void setUpSizeBasedTriggeringPolicy(RollingFileAppender<Object> rfa) {
SizeBasedTriggeringPolicy<Object> zbtp = new SizeBasedTriggeringPolicy<Object>();
zbtp.setContext(context);
zbtp.setMaxFileSize("100KB");
zbtp.start();
rfa.setTriggeringPolicy(zbtp);
FixedWindowRollingPolicy fwrp = new FixedWindowRollingPolicy();
fwrp.setContext(context);
fwrp.setFileNamePattern(outputDirStr + "test-%i.log");
fwrp.setMaxIndex(20);
fwrp.setMinIndex(0);
fwrp.setParent(rfa);
fwrp.start();
rfa.setRollingPolicy(fwrp);
rfa.start();
}
RunnableWithCounterAndDone[] buildRunnableArray(boolean withDelay) {
RunnableWithCounterAndDone[] runnableArray = new RunnableWithCounterAndDone[NUM_THREADS];
for (int i = 0; i < NUM_THREADS; i++) {
runnableArray[i] = new RFARunnable(i, rfa, withDelay);
}
return runnableArray;
}
OutputStream openScript() throws IOException {
return new FileOutputStream(outputDirStr + VERIFY_SH);
}
@Test
public void multiThreadedTimedBased() throws InterruptedException, IOException {
setUpTimeBasedTriggeringPolicy(rfa);
executeHarness(TOTAL_DURATION, false);
printScriptForTimeBased();
verify();
}
int testFileCount() {
File outputDir = new File(outputDirStr);
FilenameFilter filter =
new FilenameFilter() {
public boolean accept(File dir, String name) {
if (name.matches("test-\\d{1,2}.log")) {
return true;
}
return false;
}
};
File[] files = outputDir.listFiles(filter);
return files.length;
}
void verify() throws IOException, InterruptedException {
close(scriptOS);
// no point in this test if we don't have bash
if (pathToBash == null) {
return;
}
ProcessBuilder pb = new ProcessBuilder();
pb.command(pathToBash, VERIFY_SH);
pb.directory(new File(outputDirStr));
Process process = pb.start();
process.waitFor();
int exitCode = process.exitValue();
assertEquals(SUCCESSFUL_EXIT_CODE, exitCode);
System.out.println("External script based verification returned with exit code " + exitCode);
}
@Test
public void multiThreadedSizeBased() throws InterruptedException, IOException {
setUpSizeBasedTriggeringPolicy(rfa);
// on a fast machine with a fast hard disk, if the tests runs for too
// long the MAX_WINDOW_SIZE is reached, resulting in data loss which
// we cannot test for.
executeHarness(TOTAL_DURATION, true);
int numFiles = testFileCount();
printScriptForSizeBased(numFiles);
verify();
}
private void printScriptHeader(String type) throws IOException {
out("# ====================================================");
out("# A script to check the exactness of the output ");
out("# produced by " + type + " test");
out("# ====================================================");
out("# ");
}
private void printCommonScriptCore() throws IOException {
out("");
out("for t in $(seq 0 1 " + (NUM_THREADS - 1) + ")");
out("do");
out(" echo \"Testing results of thread $t\"");
out(" grep \"$t \" aggregated | cut -d ' ' -f 2 > ${t}-sample");
out(" for j in $(seq 1 1 ${end[$t]}); do echo $j; done > ${t}-witness");
out(" diff -q -w ${t}-sample ${t}-witness;");
out(" res=$?");
out(" if [ $res != \"0\" ]; then");
out(" echo \"FAILED for $t\"");
out(" exit " + FAILURE_EXIT_CODE);
out(" fi");
out("done");
out("");
out("exit " + SUCCESSFUL_EXIT_CODE);
}
private void printScriptForTimeBased() throws IOException {
printScriptHeader("TimeBased");
for (int i = 0; i < NUM_THREADS; i++) {
out("end[" + i + "]=" + this.runnableArray[i].getCounter());
}
out("");
out("rm aggregated");
out("cat test* output.log >> aggregated");
printCommonScriptCore();
}
private void printScriptForSizeBased(int numfiles) throws IOException {
printScriptHeader("SizeBased");
for (int i = 0; i < NUM_THREADS; i++) {
out("end[" + i + "]=" + this.runnableArray[i].getCounter());
}
out("");
out("rm aggregated");
out("for i in $(seq " + (numfiles - 1) + " -1 0); do cat test-$i.log >> aggregated; done");
out("cat output.log >> aggregated");
out("");
printCommonScriptCore();
}
private void out(String msg) throws IOException {
scriptOS.write(msg.getBytes());
scriptOS.write("\n".getBytes());
}
private void executeHarness(int duration, boolean withDelay) throws InterruptedException {
MultiThreadedHarness multiThreadedHarness = new MultiThreadedHarness(duration);
this.runnableArray = buildRunnableArray(withDelay);
multiThreadedHarness.execute(runnableArray);
StatusChecker checker = new StatusChecker(context.getStatusManager());
if (!checker.isErrorFree(0)) {
StatusPrinter.print(context);
fail("errors reported");
}
}
long diff(long start) {
return System.currentTimeMillis() - start;
}
static class RFARunnable extends RunnableWithCounterAndDone {
RollingFileAppender<Object> rfa;
int id;
boolean withInducedDelay;
RFARunnable(int id, RollingFileAppender<Object> rfa, boolean withInducedDelay) {
this.id = id;
this.rfa = rfa;
this.withInducedDelay = withInducedDelay;
}
public void run() {
while (!isDone()) {
counter++;
rfa.doAppend(id + " " + counter);
if ((counter % 64 == 0) && withInducedDelay) {
try {
Thread.sleep(10);
} catch (InterruptedException e) {
}
}
}
}
}
}
public class ReconfigureOnChangeTaskTest {
static final int THREAD_COUNT = 5;
int diff = RandomUtil.getPositiveInt();
// the space in the file name mandated by
// http://jira.qos.ch/browse/LBCORE-119
static final String SCAN1_FILE_AS_STR = JORAN_INPUT_PREFIX + "roct/scan 1.xml";
static final String G_SCAN1_FILE_AS_STR = JORAN_INPUT_PREFIX + "roct/scan 1.groovy";
static final String SCAN_LOGBACK_474_FILE_AS_STR =
JORAN_INPUT_PREFIX + "roct/scan_logback_474.xml";
static final String INCLUSION_SCAN_TOPLEVEL0_AS_STR =
JORAN_INPUT_PREFIX + "roct/inclusion/topLevel0.xml";
static final String INCLUSION_SCAN_TOP_BY_RESOURCE_AS_STR =
JORAN_INPUT_PREFIX + "roct/inclusion/topByResource.xml";
static final String INCLUSION_SCAN_INNER0_AS_STR =
JORAN_INPUT_PREFIX + "roct/inclusion/inner0.xml";
static final String INCLUSION_SCAN_INNER1_AS_STR = "target/test-classes/asResource/inner1.xml";
LoggerContext loggerContext = new LoggerContext();
Logger logger = loggerContext.getLogger(this.getClass());
StatusChecker statusChecker = new StatusChecker(loggerContext);
@BeforeClass
public static void classSetup() {
FileTestUtil.makeTestOutputDir();
}
void configure(File file) throws JoranException {
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(loggerContext);
jc.doConfigure(file);
}
void configure(InputStream is) throws JoranException {
JoranConfigurator jc = new JoranConfigurator();
jc.setContext(loggerContext);
jc.doConfigure(is);
}
void gConfigure(File file) throws JoranException {
GafferConfigurator gc = new GafferConfigurator(loggerContext);
gc.run(file);
}
@Test(timeout = 4000L)
public void checkBasicLifecyle() throws JoranException, IOException, InterruptedException {
File file = new File(SCAN1_FILE_AS_STR);
configure(file);
List<File> fileList = getConfigurationWatchList(loggerContext);
assertThatListContainsFile(fileList, file);
checkThatTaskHasRan();
checkThatTaskCanBeStopped();
}
@Test(timeout = 4000L)
public void checkBasicLifecyleWithGaffer()
throws JoranException, IOException, InterruptedException {
File file = new File(G_SCAN1_FILE_AS_STR);
gConfigure(file);
List<File> fileList = getConfigurationWatchList(loggerContext);
assertThatListContainsFile(fileList, file);
checkThatTaskHasRan();
checkThatTaskCanBeStopped();
}
private void checkThatTaskCanBeStopped() {
ScheduledFuture<?> future = loggerContext.getScheduledFutures().get(0);
loggerContext.stop();
assertTrue(future.isCancelled());
}
private void checkThatTaskHasRan() throws InterruptedException {
waitForReconfigureOnChangeTaskToRun();
}
List<File> getConfigurationWatchList(LoggerContext context) {
ConfigurationWatchList configurationWatchList =
ConfigurationWatchListUtil.getConfigurationWatchList(loggerContext);
return configurationWatchList.getCopyOfFileWatchList();
}
@Test(timeout = 4000L)
public void scanWithFileInclusion() throws JoranException, IOException, InterruptedException {
File topLevelFile = new File(INCLUSION_SCAN_TOPLEVEL0_AS_STR);
File innerFile = new File(INCLUSION_SCAN_INNER0_AS_STR);
configure(topLevelFile);
List<File> fileList = getConfigurationWatchList(loggerContext);
assertThatListContainsFile(fileList, topLevelFile);
assertThatListContainsFile(fileList, innerFile);
checkThatTaskHasRan();
checkThatTaskCanBeStopped();
}
@Test(timeout = 4000L)
public void scanWithResourceInclusion() throws JoranException, IOException, InterruptedException {
File topLevelFile = new File(INCLUSION_SCAN_TOP_BY_RESOURCE_AS_STR);
File innerFile = new File(INCLUSION_SCAN_INNER1_AS_STR);
configure(topLevelFile);
List<File> fileList = getConfigurationWatchList(loggerContext);
assertThatListContainsFile(fileList, topLevelFile);
assertThatListContainsFile(fileList, innerFile);
}
// See also http://jira.qos.ch/browse/LOGBACK-338
@Test(timeout = 4000L)
public void reconfigurationIsNotPossibleInTheAbsenceOfATopFile()
throws IOException, JoranException, InterruptedException {
String configurationStr =
"<configuration scan=\"true\" scanPeriod=\"50 millisecond\"><include resource=\"asResource/inner1.xml\"/></configuration>";
configure(new ByteArrayInputStream(configurationStr.getBytes("UTF-8")));
ConfigurationWatchList configurationWatchList =
ConfigurationWatchListUtil.getConfigurationWatchList(loggerContext);
assertNull(configurationWatchList);
// assertNull(configurationWatchList.getMainURL());
statusChecker.containsMatch(Status.WARN, "Due to missing top level");
StatusPrinter.print(loggerContext);
ReconfigureOnChangeTask roct = getRegisteredReconfigureTask();
assertNull(roct);
assertEquals(0, loggerContext.getScheduledFutures().size());
}
@Test(timeout = 3000L)
public void fallbackToSafe_FollowedByRecovery()
throws IOException, JoranException, InterruptedException {
String path =
CoreTestConstants.OUTPUT_DIR_PREFIX
+ "reconfigureOnChangeConfig_fallbackToSafe-"
+ diff
+ ".xml";
File topLevelFile = new File(path);
writeToFile(
topLevelFile,
"<configuration scan=\"true\" scanPeriod=\"5 millisecond\"><root level=\"ERROR\"/></configuration> ");
configure(topLevelFile);
CountDownLatch changeDetectedLatch = waitForReconfigurationToBeDone(null);
ReconfigureOnChangeTask oldRoct = getRegisteredReconfigureTask();
assertNotNull(oldRoct);
writeToFile(
topLevelFile,
"<configuration scan=\"true\" scanPeriod=\"5 millisecond\">\n"
+ " <root></configuration>");
changeDetectedLatch.await();
statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
loggerContext.getStatusManager().clear();
CountDownLatch secondDoneLatch = waitForReconfigurationToBeDone(oldRoct);
writeToFile(
topLevelFile,
"<configuration scan=\"true\" scanPeriod=\"5 millisecond\"><root level=\"ERROR\"/></configuration> ");
secondDoneLatch.await();
StatusPrinter.print(loggerContext);
statusChecker.assertIsErrorFree();
statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
}
@Test(timeout = 4000L)
public void fallbackToSafeWithIncludedFile_FollowedByRecovery()
throws IOException, JoranException, InterruptedException, ExecutionException {
String topLevelFileAsStr =
CoreTestConstants.OUTPUT_DIR_PREFIX + "reconfigureOnChangeConfig_top-" + diff + ".xml";
String innerFileAsStr =
CoreTestConstants.OUTPUT_DIR_PREFIX + "reconfigureOnChangeConfig_inner-" + diff + ".xml";
File topLevelFile = new File(topLevelFileAsStr);
writeToFile(
topLevelFile,
"<configuration xdebug=\"true\" scan=\"true\" scanPeriod=\"5 millisecond\"><include file=\""
+ innerFileAsStr
+ "\"/></configuration> ");
File innerFile = new File(innerFileAsStr);
writeToFile(innerFile, "<included><root level=\"ERROR\"/></included> ");
configure(topLevelFile);
CountDownLatch doneLatch = waitForReconfigurationToBeDone(null);
ReconfigureOnChangeTask oldRoct = getRegisteredReconfigureTask();
assertNotNull(oldRoct);
writeToFile(innerFile, "<included>\n<root>\n</included>");
doneLatch.await();
statusChecker.assertContainsMatch(Status.WARN, FALLING_BACK_TO_SAFE_CONFIGURATION);
statusChecker.assertContainsMatch(Status.INFO, RE_REGISTERING_PREVIOUS_SAFE_CONFIGURATION);
loggerContext.getStatusManager().clear();
CountDownLatch secondDoneLatch = waitForReconfigurationToBeDone(oldRoct);
writeToFile(innerFile, "<included><root level=\"ERROR\"/></included> ");
secondDoneLatch.await();
StatusPrinter.print(loggerContext);
statusChecker.assertIsErrorFree();
statusChecker.containsMatch(DETECTED_CHANGE_IN_CONFIGURATION_FILES);
}
private ReconfigureOnChangeTask getRegisteredReconfigureTask() {
return (ReconfigureOnChangeTask) loggerContext.getObject(RECONFIGURE_ON_CHANGE_TASK);
}
class RunMethodInvokedListener extends ReconfigureOnChangeTaskListener {
CountDownLatch countDownLatch;
RunMethodInvokedListener(CountDownLatch countDownLatch) {
this.countDownLatch = countDownLatch;
}
@Override
public void enteredRunMethod() {
countDownLatch.countDown();
}
};
class ChangeDetectedListener extends ReconfigureOnChangeTaskListener {
CountDownLatch countDownLatch;
ChangeDetectedListener(CountDownLatch countDownLatch) {
this.countDownLatch = countDownLatch;
}
@Override
public void changeDetected() {
countDownLatch.countDown();
}
};
class ReconfigurationDoneListener extends ReconfigureOnChangeTaskListener {
CountDownLatch countDownLatch;
ReconfigurationDoneListener(CountDownLatch countDownLatch) {
this.countDownLatch = countDownLatch;
}
@Override
public void doneReconfiguring() {
countDownLatch.countDown();
}
};
private ReconfigureOnChangeTask waitForReconfigureOnChangeTaskToRun()
throws InterruptedException {
ReconfigureOnChangeTask roct = null;
while (roct == null) {
roct = getRegisteredReconfigureTask();
Thread.yield();
}
CountDownLatch countDownLatch = new CountDownLatch(1);
roct.addListener(new RunMethodInvokedListener(countDownLatch));
countDownLatch.await();
return roct;
}
private CountDownLatch waitForReconfigurationToBeDone(ReconfigureOnChangeTask oldTask)
throws InterruptedException {
ReconfigureOnChangeTask roct = oldTask;
while (roct == oldTask) {
roct = getRegisteredReconfigureTask();
Thread.yield();
}
CountDownLatch countDownLatch = new CountDownLatch(1);
roct.addListener(new ReconfigurationDoneListener(countDownLatch));
return countDownLatch;
}
private RunnableWithCounterAndDone[] buildRunnableArray(File configFile, UpdateType updateType) {
RunnableWithCounterAndDone[] rArray = new RunnableWithCounterAndDone[THREAD_COUNT];
rArray[0] = new Updater(configFile, updateType);
for (int i = 1; i < THREAD_COUNT; i++) {
rArray[i] = new LoggingRunnable(logger);
}
return rArray;
}
// check for deadlocks
@Test(timeout = 4000L)
public void scan_LOGBACK_474() throws JoranException, IOException, InterruptedException {
loggerContext.setName("scan_LOGBACK_474");
File file = new File(SCAN_LOGBACK_474_FILE_AS_STR);
// StatusListenerConfigHelper.addOnConsoleListenerInstance(loggerContext, new
// OnConsoleStatusListener());
configure(file);
// ReconfigureOnChangeTask roct = waitForReconfigureOnChangeTaskToRun();
int expectedResets = 2;
Harness harness = new Harness(expectedResets);
RunnableWithCounterAndDone[] runnableArray = buildRunnableArray(file, UpdateType.TOUCH);
harness.execute(runnableArray);
loggerContext.getStatusManager().add(new InfoStatus("end of execution ", this));
StatusPrinter.print(loggerContext);
checkResetCount(expectedResets);
}
private void assertThatListContainsFile(List<File> fileList, File file) {
// conversion to absolute file seems to work nicely
assertTrue(fileList.contains(file.getAbsoluteFile()));
}
private void checkResetCount(int expected) {
StatusChecker checker = new StatusChecker(loggerContext);
checker.assertIsErrorFree();
int effectiveResets = checker.matchCount(CoreConstants.RESET_MSG_PREFIX);
assertEquals(expected, effectiveResets);
// String failMsg = "effective=" + effectiveResets + ", expected=" + expected;
//
// there might be more effective resets than the expected amount
// since the harness may be sleeping while a reset occurs
// assertTrue(failMsg, expected <= effectiveResets && (expected + 2) >= effectiveResets);
}
void addInfo(String msg, Object o) {
loggerContext.getStatusManager().add(new InfoStatus(msg, o));
}
enum UpdateType {
TOUCH,
MALFORMED,
MALFORMED_INNER
}
void writeToFile(File file, String contents) throws IOException {
FileWriter fw = new FileWriter(file);
fw.write(contents);
fw.close();
// on linux changes to last modified are not propagated if the
// time stamp is near the previous time stamp hence the random delta
file.setLastModified(System.currentTimeMillis() + RandomUtil.getPositiveInt());
}
class Harness extends AbstractMultiThreadedHarness {
int changeCountLimit;
Harness(int changeCount) {
this.changeCountLimit = changeCount;
}
public void waitUntilEndCondition() throws InterruptedException {
ReconfigureOnChangeTaskTest.this.addInfo(
"Entering " + this.getClass() + ".waitUntilEndCondition()", this);
int changeCount = 0;
ReconfigureOnChangeTask lastRoct = null;
CountDownLatch countDownLatch = null;
while (changeCount < changeCountLimit) {
ReconfigureOnChangeTask roct =
(ReconfigureOnChangeTask) loggerContext.getObject(RECONFIGURE_ON_CHANGE_TASK);
if (lastRoct != roct && roct != null) {
lastRoct = roct;
countDownLatch = new CountDownLatch(1);
roct.addListener(new ChangeDetectedListener(countDownLatch));
} else if (countDownLatch != null) {
countDownLatch.await();
countDownLatch = null;
changeCount++;
}
Thread.yield();
}
ReconfigureOnChangeTaskTest.this.addInfo(
"*****Exiting " + this.getClass() + ".waitUntilEndCondition()", this);
}
}
class Updater extends RunnableWithCounterAndDone {
File configFile;
UpdateType updateType;
// it actually takes time for Windows to propagate file modification changes
// values below 100 milliseconds can be problematic the same propagation
// latency occurs in Linux but is even larger (>600 ms)
// final static int DEFAULT_SLEEP_BETWEEN_UPDATES = 60;
int sleepBetweenUpdates = 100;
Updater(File configFile, UpdateType updateType) {
this.configFile = configFile;
this.updateType = updateType;
}
Updater(File configFile) {
this(configFile, UpdateType.TOUCH);
}
public void run() {
while (!isDone()) {
try {
Thread.sleep(sleepBetweenUpdates);
} catch (InterruptedException e) {
}
if (isDone()) {
ReconfigureOnChangeTaskTest.this.addInfo("Exiting Updater.run()", this);
return;
}
counter++;
ReconfigureOnChangeTaskTest.this.addInfo("Touching [" + configFile + "]", this);
switch (updateType) {
case TOUCH:
touchFile();
break;
case MALFORMED:
try {
malformedUpdate();
} catch (IOException e) {
e.printStackTrace();
fail("malformedUpdate failed");
}
break;
case MALFORMED_INNER:
try {
malformedInnerUpdate();
} catch (IOException e) {
e.printStackTrace();
fail("malformedInnerUpdate failed");
}
}
}
ReconfigureOnChangeTaskTest.this.addInfo("Exiting Updater.run()", this);
}
private void malformedUpdate() throws IOException {
writeToFile(
configFile,
"<configuration scan=\"true\" scanPeriod=\"50 millisecond\">\n"
+ " <root level=\"ERROR\">\n"
+ "</configuration>");
}
private void malformedInnerUpdate() throws IOException {
writeToFile(configFile, "<included>\n" + " <root>\n" + "</included>");
}
void touchFile() {
configFile.setLastModified(System.currentTimeMillis());
}
}
}