*/
package org.sonar.server.computation.log;
+import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.sift.MDCBasedDiscriminator;
import ch.qos.logback.classic.sift.SiftingAppender;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.Appender;
+import ch.qos.logback.core.sift.AppenderTracker;
+import ch.qos.logback.core.util.Duration;
import com.google.common.annotations.VisibleForTesting;
import com.google.common.base.Optional;
import java.io.File;
import org.apache.commons.io.filefilter.FileFilterUtils;
import org.apache.log4j.MDC;
import org.sonar.api.config.Settings;
+import org.sonar.process.LogbackHelper;
import org.sonar.process.ProcessProperties;
import org.sonar.process.Props;
import org.sonar.server.computation.queue.CeTask;
import static com.google.common.base.Preconditions.checkArgument;
+import static com.google.common.base.Preconditions.checkState;
import static com.google.common.collect.FluentIterable.from;
import static com.google.common.collect.Lists.newArrayList;
import static java.lang.String.format;
*/
public class CeLogging {
+ private static final long TIMEOUT_2_MINUTES = 1000 * 60 * 2L;
+ private static final String CE_APPENDER_NAME = "ce";
+ // using 0L as timestamp when retrieving appender to stop it will make it instantly eligible for removal
+ private static final long STOPPING_TRACKER_TIMESTAMP = 0L;
+
@VisibleForTesting
static final String MDC_LOG_PATH = "ceLogPath";
public static final String MAX_LOGS_PROPERTY = "sonar.ce.maxLogsPerTask";
+ private final LogbackHelper helper = new LogbackHelper();
private final File logsDir;
private final Settings settings;
MDC.remove(MDC_LOG_PATH);
if (relativePath != null) {
+ stopAppender(relativePath);
purgeDir(new File(logsDir, relativePath).getParentFile());
}
}
+ private void stopAppender(String relativePath) {
+ Appender<ILoggingEvent> appender = helper.getRootContext().getLogger(Logger.ROOT_LOGGER_NAME).getAppender(CE_APPENDER_NAME);
+ checkState(appender instanceof SiftingAppender, "Appender with name %s is null or not a SiftingAppender", CE_APPENDER_NAME);
+ AppenderTracker<ILoggingEvent> ceAppender = ((SiftingAppender) appender).getAppenderTracker();
+ ceAppender.getOrCreate(relativePath, STOPPING_TRACKER_TIMESTAMP).stop();
+ }
+
@VisibleForTesting
void purgeDir(File dir) {
if (dir.exists()) {
siftingAppender.setContext(ctx);
siftingAppender.setDiscriminator(mdcDiscriminator);
siftingAppender.setAppenderFactory(new CeFileAppenderFactory(logsDir));
- siftingAppender.setName("ce");
+ siftingAppender.setName(CE_APPENDER_NAME);
+ siftingAppender.setTimeout(new Duration(TIMEOUT_2_MINUTES));
siftingAppender.start();
return siftingAppender;
}
*/
package org.sonar.server.computation.log;
+import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.sift.SiftingAppender;
import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.Appender;
import ch.qos.logback.core.filter.Filter;
+import ch.qos.logback.core.joran.spi.JoranException;
import com.google.common.base.Optional;
import java.io.File;
import java.io.IOException;
+import java.util.Collection;
import java.util.List;
import org.apache.commons.io.FileUtils;
+import org.junit.After;
+import org.junit.Before;
import org.junit.Rule;
import org.junit.Test;
import org.junit.rules.ExpectedException;
import org.junit.rules.TemporaryFolder;
+import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.sonar.api.config.Settings;
+import org.sonar.process.LogbackHelper;
import org.sonar.process.ProcessProperties;
import org.sonar.server.computation.queue.CeTask;
import static java.lang.String.format;
import static org.assertj.core.api.Assertions.assertThat;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.when;
+import static org.sonar.server.computation.log.CeLogging.MDC_LOG_PATH;
public class CeLoggingTest {
@Rule
public ExpectedException expectedException = ExpectedException.none();
-
@Rule
public TemporaryFolder temp = new TemporaryFolder();
+ private LogbackHelper helper = new LogbackHelper();
+ private File dataDir;
+
+ @Before
+ public void setUp() throws Exception {
+ this.dataDir = temp.newFolder();
+ }
+
+ @After
+ public void resetLogback() throws JoranException {
+ helper.resetFromXml("/logback-test.xml");
+ }
+
+ @After
+ public void cleanMDC() throws Exception {
+ MDC.clear();
+ }
+
@Test
public void getFile() throws IOException {
- File dataDir = temp.newFolder();
Settings settings = newSettings(dataDir, 10);
CeLogging underTest = new CeLogging(settings);
}
@Test
- public void use_MDC_to_store_path_to_in_progress_task_logs() throws IOException {
- CeLogging underTest = new CeLogging(newSettings(temp.newFolder(), 5));
+ public void initForTask_adds_path_of_ce_log_file_in_MDC() throws IOException {
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 5));
+
+ CeTask task = createCeTask("TYPE1", "U1");
+ underTest.initForTask(task);
+ assertThat(MDC.get(MDC_LOG_PATH)).isNotEmpty().isEqualTo(LogFileRef.from(task).getRelativePath());
+ }
+
+ @Test
+ public void clearForTask_throws_ISE_if_CE_appender_is_not_configured() throws IOException {
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 5));
+
+ CeTask task = createCeTask("TYPE1", "U1");
+ underTest.initForTask(task);
+
+ expectedException.expect(IllegalStateException.class);
+ expectedException.expectMessage("Appender with name ce is null or not a SiftingAppender");
+
+ underTest.clearForTask();
+ }
+
+ @Test
+ public void clearForTask_throws_ISE_if_CE_appender_is_not_a_SiftingAppender() throws IOException {
+ Appender<ILoggingEvent> mockCeAppender = mock(Appender.class);
+ when(mockCeAppender.getName()).thenReturn("ce");
+ helper.getRootContext().getLogger(Logger.ROOT_LOGGER_NAME).addAppender(mockCeAppender);
+
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 5));
+
+ CeTask task = createCeTask("TYPE1", "U1");
+ underTest.initForTask(task);
+
+ expectedException.expect(IllegalStateException.class);
+ expectedException.expectMessage("Appender with name ce is null or not a SiftingAppender");
+
+ underTest.clearForTask();
+ }
+
+ @Test
+ public void clearForTask_clears_MDC() throws IOException {
+ setupCeAppender();
- CeTask task = new CeTask.Builder().setType("TYPE1").setUuid("U1").build();
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 5));
+
+ CeTask task = createCeTask("TYPE1", "U1");
underTest.initForTask(task);
- assertThat(MDC.get(CeLogging.MDC_LOG_PATH)).isNotEmpty().isEqualTo(LogFileRef.from(task).getRelativePath());
+ assertThat(MDC.get(MDC_LOG_PATH)).isNotEmpty().isEqualTo(LogFileRef.from(task).getRelativePath());
+
+ underTest.clearForTask();
+ assertThat(MDC.get(MDC_LOG_PATH)).isNull();
+ }
+
+ @Test
+ public void cleanForTask_stops_only_appender_for_MDC_value() throws IOException {
+ Logger rootLogger = setupCeAppender();
+
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 5));
+
+ // init MDC
+ underTest.initForTask(createCeTask("TYPE1", "U1"));
+ verifyNoAppender(rootLogger);
+
+ // logging will create and start the appender
+ LoggerFactory.getLogger(getClass()).info("some log!");
+ verifyAllAppenderStarted(rootLogger, 1);
+
+ // init MDC and create appender for another task
+ // (in the same thread, which should not happen, but it's good enough for our test)
+ CeTask ceTask = createCeTask("TYPE1", "U2");
+ underTest.initForTask(ceTask);
+ LoggerFactory.getLogger(getClass()).info("some other log!");
+ verifyAllAppenderStarted(rootLogger, 2);
+
+ // stop appender which is currently referenced in MDC
underTest.clearForTask();
- assertThat(MDC.get(CeLogging.MDC_LOG_PATH)).isNull();
+
+ Appender appender = verifySingleAppenderIsStopped(rootLogger, 2);
+ assertThat(appender.getName()).isEqualTo("ce-" + LogFileRef.from(ceTask).getRelativePath());
}
@Test
public void delete_oldest_files_of_same_directory_to_keep_only_max_allowed_files() throws IOException {
- File dir = temp.newFolder();
for (int i = 1; i <= 5; i++) {
- File file = new File(dir, format("U%d.log", i));
+ File file = new File(dataDir, format("U%d.log", i));
FileUtils.touch(file);
// see javadoc: "all platforms support file-modification times to the nearest second,
// but some provide more precision" --> increment by second, not by millisecond
file.setLastModified(1_450_000_000_000L + i * 1000);
}
- assertThat(dir.listFiles()).hasSize(5);
+ assertThat(dataDir.listFiles()).hasSize(5);
// keep 3 files in each dir
- CeLogging underTest = new CeLogging(newSettings(dir, 3));
- underTest.purgeDir(dir);
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 3));
+ underTest.purgeDir(dataDir);
- assertThat(dir.listFiles()).hasSize(3);
- assertThat(dir.listFiles()).extracting("name")
+ assertThat(dataDir.listFiles()).hasSize(3);
+ assertThat(dataDir.listFiles()).extracting("name")
.containsOnly("U3.log", "U4.log", "U5.log");
}
@Test
public void do_not_delete_files_if_dir_has_less_files_than_max_allowed() throws IOException {
- File dir = temp.newFolder();
- FileUtils.touch(new File(dir, "U1.log"));
+ FileUtils.touch(new File(dataDir, "U1.log"));
- CeLogging underTest = new CeLogging(newSettings(dir, 5));
- underTest.purgeDir(dir);
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 5));
+ underTest.purgeDir(dataDir);
- assertThat(dir.listFiles()).extracting("name").containsOnly("U1.log");
+ assertThat(dataDir.listFiles()).extracting("name").containsOnly("U1.log");
}
@Test
public void do_not_keep_any_logs() throws IOException {
- File dir = temp.newFolder();
- FileUtils.touch(new File(dir, "U1.log"));
+ FileUtils.touch(new File(dataDir, "U1.log"));
- CeLogging underTest = new CeLogging(newSettings(temp.newFolder(), 0));
- underTest.purgeDir(dir);
+ CeLogging underTest = new CeLogging(newSettings(dataDir, 0));
+ underTest.purgeDir(dataDir);
- assertThat(dir.listFiles()).isEmpty();
+ assertThat(dataDir.listFiles()).isEmpty();
}
@Test
expectedException.expect(IllegalArgumentException.class);
expectedException.expectMessage("Property sonar.ce.maxLogsPerTask must be positive. Got: -1");
- Settings settings = newSettings(temp.newFolder(), -1);
+ Settings settings = newSettings(dataDir, -1);
CeLogging logging = new CeLogging(settings);
- logging.purgeDir(temp.newFolder());
+ logging.purgeDir(dataDir);
}
@Test
public void createConfiguration() throws Exception {
- File logsDir = temp.newFolder();
- SiftingAppender siftingAppender = CeLogging.createAppenderConfiguration(new LoggerContext(), logsDir);
+ SiftingAppender siftingAppender = CeLogging.createAppenderConfiguration(new LoggerContext(), dataDir);
// filter on CE logs
List<Filter<ILoggingEvent>> filters = siftingAppender.getCopyOfAttachedFiltersList();
assertThat(filters).hasSize(1);
assertThat(filters.get(0)).isInstanceOf(CeLogAcceptFilter.class);
- assertThat(siftingAppender.getDiscriminator().getKey()).isEqualTo(CeLogging.MDC_LOG_PATH);
+ assertThat(siftingAppender.getDiscriminator().getKey()).isEqualTo(MDC_LOG_PATH);
+ assertThat(siftingAppender.getTimeout().getMilliseconds()).isEqualTo(1000 * 60 * 2);
+ }
+
+ private Logger setupCeAppender() {
+ Logger rootLogger = helper.getRootContext().getLogger(Logger.ROOT_LOGGER_NAME);
+ rootLogger.addAppender(CeLogging.createAppenderConfiguration(helper.getRootContext(), dataDir));
+ return rootLogger;
+ }
+
+ private void verifyNoAppender(Logger rootLogger) {
+ Collection<Appender<ILoggingEvent>> allAppenders = getAllAppenders(rootLogger);
+ assertThat(allAppenders).isEmpty();
+ }
+
+ private void verifyAllAppenderStarted(Logger rootLogger, int expectedSize) {
+ Collection<Appender<ILoggingEvent>> allAppenders = getAllAppenders(rootLogger);
+ assertThat(allAppenders).hasSize(expectedSize);
+ for (Appender<ILoggingEvent> appender : allAppenders) {
+ assertThat(appender.isStarted()).isTrue();
+ }
+ }
+
+ private Appender verifySingleAppenderIsStopped(Logger rootLogger, int expectedSize) {
+ Collection<Appender<ILoggingEvent>> allAppenders = getAllAppenders(rootLogger);
+ assertThat(allAppenders).hasSize(expectedSize);
+ Appender res = null;
+ for (Appender<ILoggingEvent> appender : allAppenders) {
+ if (!appender.isStarted()) {
+ assertThat(res).describedAs("More than one appender found stopped").isNull();
+ res = appender;
+ }
+ }
+ assertThat(res).describedAs("There should be one stopped appender").isNotNull();
+ return res;
+ }
+
+ private Collection<Appender<ILoggingEvent>> getAllAppenders(Logger rootLogger) {
+ Appender<ILoggingEvent> ceAppender = rootLogger.getAppender("ce");
+ assertThat(ceAppender).isInstanceOf(SiftingAppender.class);
+ return ((SiftingAppender) ceAppender).getAppenderTracker().allComponents();
}
private static Settings newSettings(File dataDir, int maxLogs) {
settings.setProperty(CeLogging.MAX_LOGS_PROPERTY, maxLogs);
return settings;
}
+
+ private static CeTask createCeTask(String type, String uuid) {
+ return new CeTask.Builder().setType(type).setUuid(uuid).build();
+ }
}
projects / sonarqube.git / commitdiff