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());
 }
示例#2
0
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());
  }
}
示例#8
0
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");
 }
示例#11
0
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&uuml;lc&uuml;
 * @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());
    }
  }
}