From e3c2aab3d26f7a68fb623524b536abcc3f892b98 Mon Sep 17 00:00:00 2001 From: Simon Brandhof Date: Thu, 4 Dec 2014 23:32:28 +0100 Subject: [PATCH] Add class ProgressLogger to log state of counter at fixed intervals --- .../server/db/migrations/MassUpdate.java | 18 ++- ...dMissingCustomRuleParametersMigration.java | 16 +-- .../PopulateProjectsUuidColumnsMigration.java | 15 +-- .../java/org/sonar/server/es/BulkIndexer.java | 20 ++-- .../server/search/IndexSynchronizer.java | 25 ++-- .../source/index/SourceLineIndexer.java | 6 +- .../org/sonar/server/util/ProgressLogger.java | 107 ++++++++++++++++++ .../org/sonar/server/util/ProgressTask.java | 52 --------- .../sonar/server/util/ProgressLoggerTest.java | 47 ++++++++ 9 files changed, 193 insertions(+), 113 deletions(-) create mode 100644 server/sonar-server/src/main/java/org/sonar/server/util/ProgressLogger.java delete mode 100644 server/sonar-server/src/main/java/org/sonar/server/util/ProgressTask.java create mode 100644 server/sonar-server/src/test/java/org/sonar/server/util/ProgressLoggerTest.java diff --git a/server/sonar-server/src/main/java/org/sonar/server/db/migrations/MassUpdate.java b/server/sonar-server/src/main/java/org/sonar/server/db/migrations/MassUpdate.java index ee9b0a884a3..4c2594dd496 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/db/migrations/MassUpdate.java +++ b/server/sonar-server/src/main/java/org/sonar/server/db/migrations/MassUpdate.java @@ -19,13 +19,11 @@ */ package org.sonar.server.db.migrations; -import org.slf4j.LoggerFactory; import org.sonar.core.persistence.Database; -import org.sonar.server.util.ProgressTask; +import org.sonar.server.util.ProgressLogger; import java.sql.Connection; import java.sql.SQLException; -import java.util.Timer; import java.util.concurrent.atomic.AtomicLong; public class MassUpdate { @@ -42,7 +40,7 @@ public class MassUpdate { private final Database db; private final Connection readConnection, writeConnection; private final AtomicLong counter = new AtomicLong(0L); - private final ProgressTask progressTask = new ProgressTask(counter, LoggerFactory.getLogger("DbMigration")); + private final ProgressLogger progress = ProgressLogger.create(getClass(), counter); private Select select; private Upsert update; @@ -64,7 +62,7 @@ public class MassUpdate { } public MassUpdate rowPluralName(String s) { - this.progressTask.setRowPluralName(s); + this.progress.setPluralLabel(s); return this; } @@ -73,8 +71,7 @@ public class MassUpdate { throw new IllegalStateException("SELECT or UPDATE requests are not defined"); } - Timer timer = new Timer("Db Migration Progress"); - timer.schedule(progressTask, ProgressTask.PERIOD_MS, ProgressTask.PERIOD_MS); + progress.start(); try { select.scroll(new Select.RowHandler() { @Override @@ -90,11 +87,10 @@ public class MassUpdate { } update.close(); - // log the total number of process rows - progressTask.log(); + // log the total number of processed rows + progress.log(); } finally { - timer.cancel(); - timer.purge(); + progress.stop(); } } diff --git a/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v451/AddMissingCustomRuleParametersMigration.java b/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v451/AddMissingCustomRuleParametersMigration.java index 0b82179025e..42fe1bebb96 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v451/AddMissingCustomRuleParametersMigration.java +++ b/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v451/AddMissingCustomRuleParametersMigration.java @@ -24,8 +24,6 @@ import com.google.common.collect.ArrayListMultimap; import com.google.common.collect.HashMultimap; import com.google.common.collect.Iterables; import com.google.common.collect.Multimap; - -import org.slf4j.LoggerFactory; import org.sonar.api.utils.System2; import org.sonar.core.persistence.DbSession; import org.sonar.core.persistence.migration.v45.Migration45Mapper; @@ -33,14 +31,13 @@ import org.sonar.core.persistence.migration.v45.Rule; import org.sonar.core.persistence.migration.v45.RuleParameter; import org.sonar.server.db.DbClient; import org.sonar.server.db.migrations.DatabaseMigration; -import org.sonar.server.util.ProgressTask; +import org.sonar.server.util.ProgressLogger; import javax.annotation.Nullable; import java.util.Collection; import java.util.Date; import java.util.List; -import java.util.Timer; import java.util.concurrent.atomic.AtomicLong; /** @@ -56,7 +53,7 @@ public class AddMissingCustomRuleParametersMigration implements DatabaseMigratio private final System2 system; private final AtomicLong counter = new AtomicLong(0L); - private final ProgressTask progressTask = new ProgressTask(counter, LoggerFactory.getLogger("DbMigration")); + private final ProgressLogger progress = ProgressLogger.create(getClass(), counter); public AddMissingCustomRuleParametersMigration(DbClient db, System2 system) { this.db = db; @@ -65,8 +62,7 @@ public class AddMissingCustomRuleParametersMigration implements DatabaseMigratio @Override public void execute() { - Timer timer = new Timer("Db Migration Progress"); - timer.schedule(progressTask, ProgressTask.PERIOD_MS, ProgressTask.PERIOD_MS); + progress.start(); DbSession session = db.openSession(false); try { @@ -101,12 +97,10 @@ public class AddMissingCustomRuleParametersMigration implements DatabaseMigratio session.commit(); // log the total number of process rows - progressTask.log(); + progress.log(); } finally { session.close(); - - timer.cancel(); - timer.purge(); + progress.stop(); } } diff --git a/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v50/PopulateProjectsUuidColumnsMigration.java b/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v50/PopulateProjectsUuidColumnsMigration.java index 5c7323d8c15..71a6cdc82a0 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v50/PopulateProjectsUuidColumnsMigration.java +++ b/server/sonar-server/src/main/java/org/sonar/server/db/migrations/v50/PopulateProjectsUuidColumnsMigration.java @@ -22,10 +22,8 @@ package org.sonar.server.db.migrations.v50; import com.google.common.base.Splitter; import com.google.common.base.Strings; - import org.apache.ibatis.session.ResultContext; import org.apache.ibatis.session.ResultHandler; -import org.slf4j.LoggerFactory; import org.sonar.api.resources.Scopes; import org.sonar.api.utils.internal.Uuids; import org.sonar.core.persistence.DbSession; @@ -33,11 +31,10 @@ import org.sonar.core.persistence.migration.v50.Component; import org.sonar.core.persistence.migration.v50.Migration50Mapper; import org.sonar.server.db.DbClient; import org.sonar.server.db.migrations.DatabaseMigration; -import org.sonar.server.util.ProgressTask; +import org.sonar.server.util.ProgressLogger; import java.util.List; import java.util.Map; -import java.util.Timer; import java.util.concurrent.atomic.AtomicLong; import static com.google.common.collect.Lists.newArrayList; @@ -52,7 +49,7 @@ public class PopulateProjectsUuidColumnsMigration implements DatabaseMigration { private final DbClient db; private final AtomicLong counter = new AtomicLong(0L); - private final ProgressTask progressTask = new ProgressTask(counter, LoggerFactory.getLogger("DbMigration")); + private final ProgressLogger progress = ProgressLogger.create(getClass(), counter); public PopulateProjectsUuidColumnsMigration(DbClient db) { this.db = db; @@ -60,8 +57,7 @@ public class PopulateProjectsUuidColumnsMigration implements DatabaseMigration { @Override public void execute() { - Timer timer = new Timer("Db Migration Progress"); - timer.schedule(progressTask, ProgressTask.PERIOD_MS, ProgressTask.PERIOD_MS); + progress.start(); final DbSession readSession = db.openSession(false); final DbSession writeSession = db.openSession(true); @@ -82,12 +78,11 @@ public class PopulateProjectsUuidColumnsMigration implements DatabaseMigration { writeSession.commit(); // log the total number of process rows - progressTask.log(); + progress.log(); } finally { readSession.close(); writeSession.close(); - timer.cancel(); - timer.purge(); + progress.stop(); } } diff --git a/server/sonar-server/src/main/java/org/sonar/server/es/BulkIndexer.java b/server/sonar-server/src/main/java/org/sonar/server/es/BulkIndexer.java index 5961a99ca0f..32b76ccd4e4 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/es/BulkIndexer.java +++ b/server/sonar-server/src/main/java/org/sonar/server/es/BulkIndexer.java @@ -21,7 +21,6 @@ package org.sonar.server.es; import com.google.common.base.Preconditions; import com.google.common.collect.Maps; - import org.elasticsearch.action.ActionRequest; import org.elasticsearch.action.admin.indices.settings.get.GetSettingsResponse; import org.elasticsearch.action.admin.indices.settings.put.UpdateSettingsRequestBuilder; @@ -30,12 +29,10 @@ import org.elasticsearch.cluster.metadata.IndexMetaData; import org.elasticsearch.common.unit.ByteSizeUnit; import org.elasticsearch.common.unit.ByteSizeValue; import org.picocontainer.Startable; -import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import org.sonar.server.util.ProgressTask; +import org.sonar.server.util.ProgressLogger; import java.util.Map; -import java.util.Timer; import java.util.concurrent.atomic.AtomicLong; /** @@ -60,12 +57,14 @@ public class BulkIndexer implements Startable { private Map largeInitialSettings = null; private final AtomicLong counter = new AtomicLong(0L); - private final ProgressTask progressTask = new ProgressTask(counter, LoggerFactory.getLogger("BulkIndex")).setRowPluralName("requests"); - private final Timer timer = new Timer("Bulk index progress"); + private final ProgressLogger progress; public BulkIndexer(EsClient client, String indexName) { this.client = client; this.indexName = indexName; + this.progress = new ProgressLogger(String.format("Progress[BulkIndexer[%s]]", indexName), counter, + LoggerFactory.getLogger(BulkIndexer.class)) + .setPluralLabel("requests"); } /** @@ -117,7 +116,8 @@ public class BulkIndexer implements Startable { updateSettings(bulkSettings); } bulkRequest = client.prepareBulk(); - timer.schedule(progressTask, ProgressTask.PERIOD_MS, ProgressTask.PERIOD_MS); + counter.set(0L); + progress.start(); } public void add(ActionRequest request) { @@ -135,11 +135,7 @@ public class BulkIndexer implements Startable { executeBulk(bulkRequest); } - // Log final advancement and reset counter - progressTask.log(); - counter.set(0L); - timer.cancel(); - timer.purge(); + progress.stop(); if (refresh) { client.prepareRefresh(indexName).get(); diff --git a/server/sonar-server/src/main/java/org/sonar/server/search/IndexSynchronizer.java b/server/sonar-server/src/main/java/org/sonar/server/search/IndexSynchronizer.java index f6623cd3717..36ce0c04002 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/search/IndexSynchronizer.java +++ b/server/sonar-server/src/main/java/org/sonar/server/search/IndexSynchronizer.java @@ -33,9 +33,6 @@ import org.sonar.server.source.index.SourceLineIndexer; import java.util.Date; -/** - * @since 4.4 - */ public class IndexSynchronizer { private static final Logger LOG = LoggerFactory.getLogger(IndexSynchronizer.class); @@ -56,34 +53,32 @@ public class IndexSynchronizer { } public void execute() { - /* synchronize all activeRules until we have mng tables in INDEX */ - DbSession session = db.openSession(true); + DbSession session = db.openSession(false); try { synchronize(session, db.ruleDao(), index.get(RuleIndex.class)); synchronize(session, db.activeRuleDao(), index.get(ActiveRuleIndex.class)); synchronize(session, db.activityDao(), index.get(ActivityIndex.class)); - - LOG.info("Indexing issues"); - issueAuthorizationIndexer.index(); - issueIndexer.indexAll(); - - LOG.info("Indexing source files"); - sourceLineIndexer.index(); - session.commit(); } finally { session.close(); } + + LOG.info("Index issues"); + issueAuthorizationIndexer.index(); + issueIndexer.index(); + + LOG.info("Index source files"); + sourceLineIndexer.index(); } void synchronize(DbSession session, Dao dao, Index index) { long count = index.getIndexStat().getDocumentCount(); Date lastSynch = index.getLastSynchronization(); if (count <= 0) { - LOG.info("Initial indexing of {} records", index.getIndexType()); + LOG.info("Index {}s", index.getIndexType()); dao.synchronizeAfter(session); } else { - LOG.info("Synchronizing {} records for updates after {}", index.getIndexType(), lastSynch); + LOG.info("Index {}s for updates after {}", index.getIndexType(), lastSynch); dao.synchronizeAfter(session, lastSynch); } } diff --git a/server/sonar-server/src/main/java/org/sonar/server/source/index/SourceLineIndexer.java b/server/sonar-server/src/main/java/org/sonar/server/source/index/SourceLineIndexer.java index 131fee0d30e..cf00b9dd7fd 100644 --- a/server/sonar-server/src/main/java/org/sonar/server/source/index/SourceLineIndexer.java +++ b/server/sonar-server/src/main/java/org/sonar/server/source/index/SourceLineIndexer.java @@ -104,14 +104,16 @@ public class SourceLineIndexer extends BaseIndexer { public void deleteByFile(String fileUuid) { esClient.prepareDeleteByQuery(SourceLineIndexDefinition.INDEX) .setTypes(SourceLineIndexDefinition.TYPE) - .setQuery(QueryBuilders.filteredQuery(QueryBuilders.matchAllQuery(), FilterBuilders.termFilter(FIELD_FILE_UUID, fileUuid).cache(false))) + .setQuery(QueryBuilders.filteredQuery(QueryBuilders.matchAllQuery(), + FilterBuilders.termFilter(FIELD_FILE_UUID, fileUuid).cache(false))) .get(); } public void deleteByProject(String projectUuid) { esClient.prepareDeleteByQuery(SourceLineIndexDefinition.INDEX) .setTypes(SourceLineIndexDefinition.TYPE) - .setQuery(QueryBuilders.filteredQuery(QueryBuilders.matchAllQuery(), FilterBuilders.termFilter(FIELD_PROJECT_UUID, projectUuid).cache(false))) + .setQuery(QueryBuilders.filteredQuery(QueryBuilders.matchAllQuery(), + FilterBuilders.termFilter(FIELD_PROJECT_UUID, projectUuid).cache(false))) .get(); } } diff --git a/server/sonar-server/src/main/java/org/sonar/server/util/ProgressLogger.java b/server/sonar-server/src/main/java/org/sonar/server/util/ProgressLogger.java new file mode 100644 index 00000000000..97fc702d8b8 --- /dev/null +++ b/server/sonar-server/src/main/java/org/sonar/server/util/ProgressLogger.java @@ -0,0 +1,107 @@ +/* + * SonarQube, open source software quality management tool. + * Copyright (C) 2008-2014 SonarSource + * mailto:contact AT sonarsource DOT com + * + * SonarQube is free software; you can redistribute it and/or + * modify it under the terms of the GNU Lesser General Public + * License as published by the Free Software Foundation; either + * version 3 of the License, or (at your option) any later version. + * + * SonarQube is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * Lesser General Public License for more details. + * + * You should have received a copy of the GNU Lesser General Public License + * along with this program; if not, write to the Free Software Foundation, + * Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. + */ +package org.sonar.server.util; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import java.util.Timer; +import java.util.TimerTask; +import java.util.concurrent.atomic.AtomicLong; + +/** + * Background thread that logs the state of a counter at fixed intervals. + */ +public class ProgressLogger { + + public static final long DEFAULT_PERIOD_MS = 60000L; + + private final Timer timer; + private final LoggerTimerTask task; + private long periodMs = DEFAULT_PERIOD_MS; + + public ProgressLogger(String threadName, AtomicLong counter, Logger logger) { + this.timer = new Timer(threadName); + this.task = new LoggerTimerTask(counter, logger); + } + + public static ProgressLogger create(Class clazz, AtomicLong counter) { + String threadName = String.format("ProgressLogger[%s]", clazz.getSimpleName()); + Logger logger = LoggerFactory.getLogger(clazz); + return new ProgressLogger(threadName, counter, logger); + } + + /** + * Warning, does not check if already started. + */ + public void start() { + // first log after {periodMs} milliseconds + timer.schedule(task, periodMs, periodMs); + } + + public void stop() { + timer.cancel(); + timer.purge(); + } + + /** + * Default is 1 minute + */ + public ProgressLogger setPeriodMs(long l) { + this.periodMs = l; + return this; + } + + public long getPeriodMs() { + return periodMs; + } + + /** + * For example "issues", "measures", ... Default is "rows". + */ + public ProgressLogger setPluralLabel(String s) { + task.pluralLabel = s; + return this; + } + + public String getPluralLabel() { + return task.pluralLabel; + } + + public void log() { + task.run(); + } + + private static class LoggerTimerTask extends TimerTask { + private final AtomicLong counter; + private final Logger logger; + private String pluralLabel = "rows"; + + private LoggerTimerTask(AtomicLong counter, Logger logger) { + this.counter = counter; + this.logger = logger; + } + + @Override + public void run() { + logger.info(String.format("%d %s processed", counter.get(), pluralLabel)); + } + } +} diff --git a/server/sonar-server/src/main/java/org/sonar/server/util/ProgressTask.java b/server/sonar-server/src/main/java/org/sonar/server/util/ProgressTask.java deleted file mode 100644 index 99b9d197c56..00000000000 --- a/server/sonar-server/src/main/java/org/sonar/server/util/ProgressTask.java +++ /dev/null @@ -1,52 +0,0 @@ -/* - * SonarQube, open source software quality management tool. - * Copyright (C) 2008-2014 SonarSource - * mailto:contact AT sonarsource DOT com - * - * SonarQube is free software; you can redistribute it and/or - * modify it under the terms of the GNU Lesser General Public - * License as published by the Free Software Foundation; either - * version 3 of the License, or (at your option) any later version. - * - * SonarQube is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU - * Lesser General Public License for more details. - * - * You should have received a copy of the GNU Lesser General Public License - * along with this program; if not, write to the Free Software Foundation, - * Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. - */ -package org.sonar.server.util; - -import java.util.TimerTask; -import java.util.concurrent.atomic.AtomicLong; - -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -public class ProgressTask extends TimerTask { - private final Logger logger; - public static final long PERIOD_MS = 60000L; - private final AtomicLong counter; - private String rowName = "rows"; - - public ProgressTask(AtomicLong counter, Logger logger) { - this.counter = counter; - this.logger = logger; - } - - public ProgressTask setRowPluralName(String s) { - this.rowName = s; - return this; - } - - @Override - public void run() { - log(); - } - - public void log() { - logger.info(String.format("%d %s processed", counter.get(), rowName)); - } -} diff --git a/server/sonar-server/src/test/java/org/sonar/server/util/ProgressLoggerTest.java b/server/sonar-server/src/test/java/org/sonar/server/util/ProgressLoggerTest.java new file mode 100644 index 00000000000..3f09a1cdf50 --- /dev/null +++ b/server/sonar-server/src/test/java/org/sonar/server/util/ProgressLoggerTest.java @@ -0,0 +1,47 @@ +package org.sonar.server.util; + +import org.junit.Test; +import org.slf4j.Logger; + +import java.util.concurrent.atomic.AtomicLong; + +import static org.fest.assertions.Assertions.assertThat; +import static org.mockito.Mockito.atLeast; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verify; + +public class ProgressLoggerTest { + + @Test(timeout = 1000L) + public void log_at_fixed_intervals() throws Exception { + Logger logger = mock(Logger.class); + AtomicLong counter = new AtomicLong(42L); + ProgressLogger progress = new ProgressLogger("ProgressLoggerTest", counter, logger); + progress.setPeriodMs(1L); + progress.start(); + Thread.sleep(20L); + progress.stop(); + verify(logger, atLeast(1)).info("42 rows processed"); + + // ability to manual log, generally final status + counter.incrementAndGet(); + progress.log(); + verify(logger).info("43 rows processed"); + } + + @Test + public void create() throws Exception { + ProgressLogger progress = ProgressLogger.create(getClass(), new AtomicLong()); + + // default values + assertThat(progress.getPeriodMs()).isEqualTo(60000L); + assertThat(progress.getPluralLabel()).isEqualTo("rows"); + + // override values + progress.setPeriodMs(10L); + progress.setPluralLabel("issues"); + assertThat(progress.getPeriodMs()).isEqualTo(10L); + assertThat(progress.getPluralLabel()).isEqualTo("issues"); + + } +} -- 2.39.5