SOLR-10130 Serious performance degradation in Solr 6.4.1 due to the

new metrics collection.
This commit is contained in:
Andrzej Bialecki 2017-02-15 14:55:48 +01:00
parent 787a388ec8
commit b6f49dc1fb
5 changed files with 198 additions and 71 deletions

View File

@ -205,6 +205,28 @@ Other Changes
* SOLR-9890: factor out ShardResultTransformerUtils.[un]marshSortValue methods
(Judith Silverman, Christine Poerschke)
================== 6.4.2 ==================
Consult the LUCENE_CHANGES.txt file for additional, low level, changes in this release.
Versions of Major Components
---------------------
Apache Tika 1.13
Carrot2 3.15.0
Velocity 1.7 and Velocity Tools 2.0
Apache UIMA 2.3.1
Apache ZooKeeper 3.4.6
Jetty 9.3.14.v20161028
Detailed Change List
----------------------
Bug Fixes
----------------------
* SOLR-10130: Serious performance degradation in Solr 6.4.1 due to the new metrics collection.
Default settings in solrconfig.xml /config/indexConfig/metrics have been changed to turn off
IndexWriter and Directory level metrics collection. (ab, ishan)
================== 6.4.1 ==================
Consult the LUCENE_CHANGES.txt file for additional, low level, changes in this release.

View File

@ -40,6 +40,7 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
private final String registry;
private final DirectoryFactory in;
private boolean directoryDetails = false;
private boolean directoryTotals = false;
public MetricsDirectoryFactory(SolrMetricManager metricManager, String registry, DirectoryFactory in) {
this.metricManager = metricManager;
@ -54,9 +55,12 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
/**
* Currently the following arguments are supported:
* <ul>
* <li><code>directoryDetails</code> - (optional bool) when true then additional detailed metrics
* <li><code>directory</code> - (optional bool, default false) when true then coarse-grained metrics will be collected.</li>
* <li><code>directoryDetails</code> - (optional bool, default false) when true then additional detailed metrics
* will be collected. These include eg. IO size histograms and per-file counters and histograms</li>
* </ul>
* NOTE: please be aware that collecting even coarse-grained metrics can have significant performance impact
* (see SOLR-10130).
* @param args init args
*/
@Override
@ -66,12 +70,21 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
if (args == null) {
return;
}
Boolean td = args.getBooleanArg("directory");
if (td != null) {
directoryTotals = td;
} else {
directoryTotals = false;
}
Boolean dd = args.getBooleanArg("directoryDetails");
if (dd != null) {
directoryDetails = dd;
} else {
directoryDetails = false;
}
if (directoryDetails) {
directoryTotals = true;
}
}
/**
@ -107,7 +120,7 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
@Override
protected Directory create(String path, LockFactory lockFactory, DirContext dirContext) throws IOException {
Directory dir = in.create(path, lockFactory, dirContext);
return new MetricsDirectory(metricManager, registry, dir, directoryDetails);
return new MetricsDirectory(metricManager, registry, dir, directoryTotals, directoryDetails);
}
@Override
@ -196,7 +209,7 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
if (dir instanceof MetricsDirectory) {
return dir;
} else {
return new MetricsDirectory(metricManager, registry, dir, directoryDetails);
return new MetricsDirectory(metricManager, registry, dir, directoryTotals, directoryDetails);
}
}
@ -263,21 +276,31 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
private final Meter totalWrites;
private final Histogram totalWriteSizes;
private final boolean directoryDetails;
private final boolean directoryTotals;
private final String PREFIX = SolrInfoMBean.Category.DIRECTORY.toString() + ".";
public MetricsDirectory(SolrMetricManager metricManager, String registry, Directory in, boolean directoryDetails) throws IOException {
public MetricsDirectory(SolrMetricManager metricManager, String registry, Directory in, boolean directoryTotals,
boolean directoryDetails) throws IOException {
super(in);
this.metricManager = metricManager;
this.registry = registry;
this.in = in;
this.directoryDetails = directoryDetails;
this.totalReads = metricManager.meter(registry, "reads", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
this.totalWrites = metricManager.meter(registry, "writes", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
if (directoryDetails) {
this.totalReadSizes = metricManager.histogram(registry, "readSizes", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
this.totalWriteSizes = metricManager.histogram(registry, "writeSizes", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
this.directoryTotals = directoryTotals;
if (directoryTotals) {
this.totalReads = metricManager.meter(registry, "reads", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
this.totalWrites = metricManager.meter(registry, "writes", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
if (directoryDetails) {
this.totalReadSizes = metricManager.histogram(registry, "readSizes", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
this.totalWriteSizes = metricManager.histogram(registry, "writeSizes", SolrInfoMBean.Category.DIRECTORY.toString(), "total");
} else {
this.totalReadSizes = null;
this.totalWriteSizes = null;
}
} else {
this.totalReads = null;
this.totalWrites = null;
this.totalReadSizes = null;
this.totalWriteSizes = null;
}
@ -312,6 +335,9 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
@Override
public IndexOutput createOutput(String name, IOContext context) throws IOException {
IndexOutput output = in.createOutput(name, context);
if (!directoryTotals) {
return output;
}
if (output != null) {
return new MetricsOutput(totalWrites, totalWriteSizes, metricManager, registry, getMetricName(name, true), output);
} else {
@ -322,6 +348,9 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
@Override
public IndexOutput createTempOutput(String prefix, String suffix, IOContext context) throws IOException {
IndexOutput output = in.createTempOutput(prefix, suffix, context);
if (!directoryTotals) {
return output;
}
if (output != null) {
return new MetricsOutput(totalWrites, totalWriteSizes, metricManager, registry, getMetricName(TEMP, true), output);
} else {
@ -332,6 +361,9 @@ public class MetricsDirectoryFactory extends DirectoryFactory implements SolrCor
@Override
public IndexInput openInput(String name, IOContext context) throws IOException {
IndexInput input = in.openInput(name, context);
if (!directoryTotals) {
return input;
}
if (input != null) {
return new MetricsInput(totalReads, totalReadSizes, metricManager, registry, getMetricName(name, false), input);
} else {

View File

@ -71,25 +71,26 @@ public class SolrIndexWriter extends IndexWriter {
// metrics
private long majorMergeDocs = 512 * 1024;
private final Timer majorMerge;
private final Timer minorMerge;
private final Meter majorMergedDocs;
private final Meter majorDeletedDocs;
private final Counter mergeErrors;
private final Meter flushMeter; // original counter is package-private in IndexWriter
private final boolean mergeDetails;
private Timer majorMerge;
private Timer minorMerge;
private Meter majorMergedDocs;
private Meter majorDeletedDocs;
private Counter mergeErrors;
private Meter flushMeter; // original counter is package-private in IndexWriter
private boolean mergeTotals = false;
private boolean mergeDetails = false;
private final AtomicInteger runningMajorMerges = new AtomicInteger();
private final Gauge<Integer> runningMajorMergesGauge;
private Gauge<Integer> runningMajorMergesGauge;
private final AtomicInteger runningMinorMerges = new AtomicInteger();
private final Gauge<Integer> runningMinorMergesGauge;
private Gauge<Integer> runningMinorMergesGauge;
private final AtomicInteger runningMajorMergesSegments = new AtomicInteger();
private final Gauge<Integer> runningMajorMergesSegmentsGauge;
private Gauge<Integer> runningMajorMergesSegmentsGauge;
private final AtomicInteger runningMinorMergesSegments = new AtomicInteger();
private final Gauge<Integer> runningMinorMergesSegmentsGauge;
private Gauge<Integer> runningMinorMergesSegmentsGauge;
private final AtomicLong runningMajorMergesDocs = new AtomicLong();
private final Gauge<Long> runningMajorMergesDocsGauge;
private Gauge<Long> runningMajorMergesDocsGauge;
private final AtomicLong runningMinorMergesDocs = new AtomicLong();
private final Gauge<Long> runningMinorMergesDocsGauge;
private Gauge<Long> runningMinorMergesDocsGauge;
public static SolrIndexWriter create(SolrCore core, String name, String path, DirectoryFactory directoryFactory, boolean create, IndexSchema schema, SolrIndexConfig config, IndexDeletionPolicy delPolicy, Codec codec) throws IOException {
@ -116,18 +117,7 @@ public class SolrIndexWriter extends IndexWriter {
numOpens.incrementAndGet();
log.debug("Opened Writer " + name);
// no metrics
minorMerge = null;
majorMerge = null;
mergeErrors = null;
majorMergedDocs = null;
majorDeletedDocs = null;
runningMinorMergesGauge = null;
runningMinorMergesDocsGauge = null;
runningMinorMergesSegmentsGauge = null;
runningMajorMergesGauge = null;
runningMajorMergesDocsGauge = null;
runningMajorMergesSegmentsGauge = null;
flushMeter = null;
mergeTotals = false;
mergeDetails = false;
}
@ -144,22 +134,6 @@ public class SolrIndexWriter extends IndexWriter {
numOpens.incrementAndGet();
SolrMetricManager metricManager = core.getCoreDescriptor().getCoreContainer().getMetricManager();
String registry = core.getCoreMetricManager().getRegistryName();
minorMerge = metricManager.timer(registry, "minor", SolrInfoMBean.Category.INDEX.toString(), "merge");
majorMerge = metricManager.timer(registry, "major", SolrInfoMBean.Category.INDEX.toString(), "merge");
mergeErrors = metricManager.counter(registry, "errors", SolrInfoMBean.Category.INDEX.toString(), "merge");
runningMajorMergesGauge = () -> runningMajorMerges.get();
runningMinorMergesGauge = () -> runningMinorMerges.get();
runningMajorMergesDocsGauge = () -> runningMajorMergesDocs.get();
runningMinorMergesDocsGauge = () -> runningMinorMergesDocs.get();
runningMajorMergesSegmentsGauge = () -> runningMajorMergesSegments.get();
runningMinorMergesSegmentsGauge = () -> runningMinorMergesSegments.get();
metricManager.register(registry, runningMajorMergesGauge, true, "running", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
metricManager.register(registry, runningMinorMergesGauge, true, "running", SolrInfoMBean.Category.INDEX.toString(), "merge", "minor");
metricManager.register(registry, runningMajorMergesDocsGauge, true, "running.docs", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
metricManager.register(registry, runningMinorMergesDocsGauge, true, "running.docs", SolrInfoMBean.Category.INDEX.toString(), "merge", "minor");
metricManager.register(registry, runningMajorMergesSegmentsGauge, true, "running.segments", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
metricManager.register(registry, runningMinorMergesSegmentsGauge, true, "running.segments", SolrInfoMBean.Category.INDEX.toString(), "merge", "minor");
flushMeter = metricManager.meter(registry, "flush", SolrInfoMBean.Category.INDEX.toString());
if (config.metricsInfo != null && config.metricsInfo.initArgs != null) {
Object v = config.metricsInfo.initArgs.get("majorMergeDocs");
if (v != null) {
@ -169,23 +143,41 @@ public class SolrIndexWriter extends IndexWriter {
log.warn("Invalid 'majorMergeDocs' argument, using default 512k", e);
}
}
Boolean Totals = config.metricsInfo.initArgs.getBooleanArg("merge");
Boolean Details = config.metricsInfo.initArgs.getBooleanArg("mergeDetails");
if (Details != null) {
mergeDetails = Details;
} else {
mergeDetails = false;
}
if (Totals != null) {
mergeTotals = Totals;
} else {
mergeTotals = false;
}
if (mergeDetails) {
mergeTotals = true; // override
majorMergedDocs = metricManager.meter(registry, "docs", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
majorDeletedDocs = metricManager.meter(registry, "deletedDocs", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
} else {
majorMergedDocs = null;
majorDeletedDocs = null;
}
} else {
mergeDetails = false;
majorMergedDocs = null;
majorDeletedDocs = null;
if (mergeTotals) {
minorMerge = metricManager.timer(registry, "minor", SolrInfoMBean.Category.INDEX.toString(), "merge");
majorMerge = metricManager.timer(registry, "major", SolrInfoMBean.Category.INDEX.toString(), "merge");
mergeErrors = metricManager.counter(registry, "errors", SolrInfoMBean.Category.INDEX.toString(), "merge");
runningMajorMergesGauge = () -> runningMajorMerges.get();
runningMinorMergesGauge = () -> runningMinorMerges.get();
runningMajorMergesDocsGauge = () -> runningMajorMergesDocs.get();
runningMinorMergesDocsGauge = () -> runningMinorMergesDocs.get();
runningMajorMergesSegmentsGauge = () -> runningMajorMergesSegments.get();
runningMinorMergesSegmentsGauge = () -> runningMinorMergesSegments.get();
metricManager.register(registry, runningMajorMergesGauge, true, "running", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
metricManager.register(registry, runningMinorMergesGauge, true, "running", SolrInfoMBean.Category.INDEX.toString(), "merge", "minor");
metricManager.register(registry, runningMajorMergesDocsGauge, true, "running.docs", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
metricManager.register(registry, runningMinorMergesDocsGauge, true, "running.docs", SolrInfoMBean.Category.INDEX.toString(), "merge", "minor");
metricManager.register(registry, runningMajorMergesSegmentsGauge, true, "running.segments", SolrInfoMBean.Category.INDEX.toString(), "merge", "major");
metricManager.register(registry, runningMinorMergesSegmentsGauge, true, "running.segments", SolrInfoMBean.Category.INDEX.toString(), "merge", "minor");
flushMeter = metricManager.meter(registry, "flush", SolrInfoMBean.Category.INDEX.toString());
}
}
}
@ -205,6 +197,10 @@ public class SolrIndexWriter extends IndexWriter {
// we override this method to collect metrics for merges.
@Override
public void merge(MergePolicy.OneMerge merge) throws IOException {
if (!mergeTotals) {
super.merge(merge);
return;
}
long deletedDocs = 0;
long totalNumDocs = merge.totalNumDocs();
for (SegmentCommitInfo info : merge.segments) {
@ -251,7 +247,7 @@ public class SolrIndexWriter extends IndexWriter {
@Override
protected void doAfterFlush() throws IOException {
if (flushMeter != null) { // this is null when writer is used only for snapshot cleanup
flushMeter.mark();
flushMeter.mark(); // or if mergeTotals == false
}
super.doAfterFlush();
}

View File

@ -29,8 +29,10 @@
<indexConfig>
<metrics>
<bool name="directoryDetails">${solr.tests.directoryDetails:false}</bool>
<bool name="mergeDetails">${solr.tests.mergeDetails:false}</bool>
<bool name="directory">${solr.tests.metrics.directory:false}</bool>
<bool name="directoryDetails">${solr.tests.metrics.directoryDetails:false}</bool>
<bool name="merge">${solr.tests.metrics.merge:false}</bool>
<bool name="mergeDetails">${solr.tests.metrics.mergeDetails:false}</bool>
</metrics>
<!-- intentionally set very low values here to trigger multiple flushes and merges.
DO NOT USE THESE ABSURD VALUES IN PRODUCTION. -->

View File

@ -26,7 +26,7 @@ import com.codahale.metrics.Timer;
import org.apache.solr.SolrTestCaseJ4;
import org.apache.solr.common.SolrInputDocument;
import org.apache.solr.request.SolrQueryRequest;
import org.junit.BeforeClass;
import org.junit.After;
import org.junit.Test;
/**
@ -34,15 +34,12 @@ import org.junit.Test;
*/
public class SolrIndexMetricsTest extends SolrTestCaseJ4 {
@BeforeClass
public static void beforeClass() throws Exception {
System.setProperty("solr.tests.mergeDetails", "true");
System.setProperty("solr.tests.directoryDetails", "true");
initCore("solrconfig-indexmetrics.xml", "schema.xml");
@After
public void afterMethod() throws Exception {
deleteCore();
}
@Test
public void testIndexMetrics() throws Exception {
private void addDocs() throws Exception {
SolrQueryRequest req = lrf.makeRequest();
UpdateHandler uh = req.getCore().getUpdateHandler();
AddUpdateCommand add = new AddUpdateCommand(req);
@ -54,10 +51,86 @@ public class SolrIndexMetricsTest extends SolrTestCaseJ4 {
uh.addDoc(add);
}
uh.commit(new CommitUpdateCommand(req, false));
MetricRegistry registry = h.getCoreContainer().getMetricManager().registry(h.getCore().getCoreMetricManager().getRegistryName());
assertNotNull(registry);
// make sure all merges are finished
h.reload();
}
@Test
public void testIndexMetricsNoDetails() throws Exception {
System.setProperty("solr.tests.metrics.merge", "true");
System.setProperty("solr.tests.metrics.mergeDetails", "false");
System.setProperty("solr.tests.metrics.directory", "true");
System.setProperty("solr.tests.metrics.directoryDetails", "false");
initCore("solrconfig-indexmetrics.xml", "schema.xml");
addDocs();
MetricRegistry registry = h.getCoreContainer().getMetricManager().registry(h.getCore().getCoreMetricManager().getRegistryName());
assertNotNull(registry);
Map<String, Metric> metrics = registry.getMetrics();
assertEquals(10, metrics.entrySet().stream().filter(e -> e.getKey().startsWith("INDEX")).count());
assertEquals(2, metrics.entrySet().stream().filter(e -> e.getKey().startsWith("DIRECTORY")).count());
// check basic index meters
Timer timer = (Timer)metrics.get("INDEX.merge.minor");
assertTrue("minorMerge: " + timer.getCount(), timer.getCount() >= 3);
timer = (Timer)metrics.get("INDEX.merge.major");
assertEquals("majorMerge: " + timer.getCount(), 0, timer.getCount());
// check detailed meters
assertNull((Meter)metrics.get("INDEX.merge.major.docs"));
Meter meter = (Meter)metrics.get("INDEX.flush");
assertTrue("flush: " + meter.getCount(), meter.getCount() > 10);
// check basic directory meters
meter = (Meter)metrics.get("DIRECTORY.total.reads");
assertTrue("totalReads", meter.getCount() > 0);
meter = (Meter)metrics.get("DIRECTORY.total.writes");
assertTrue("totalWrites", meter.getCount() > 0);
// check detailed meters
Histogram histogram = (Histogram)metrics.get("DIRECTORY.total.readSizes");
assertNull("readSizes", histogram);
histogram = (Histogram)metrics.get("DIRECTORY.total.writeSizes");
assertNull("writeSizes", histogram);
meter = (Meter)metrics.get("DIRECTORY.segments.writes");
assertNull("segmentsWrites", meter);
histogram = (Histogram)metrics.get("DIRECTORY.segments.writeSizes");
assertNull("segmentsWriteSizes", histogram);
}
@Test
public void testIndexNoMetrics() throws Exception {
System.setProperty("solr.tests.metrics.merge", "false");
System.setProperty("solr.tests.metrics.mergeDetails", "false");
System.setProperty("solr.tests.metrics.directory", "false");
System.setProperty("solr.tests.metrics.directoryDetails", "false");
initCore("solrconfig-indexmetrics.xml", "schema.xml");
addDocs();
MetricRegistry registry = h.getCoreContainer().getMetricManager().registry(h.getCore().getCoreMetricManager().getRegistryName());
assertNotNull(registry);
Map<String, Metric> metrics = registry.getMetrics();
assertEquals(0, metrics.entrySet().stream().filter(e -> e.getKey().startsWith("INDEX")).count());
// this is variable, depending on the codec and the number of created files
assertEquals(0, metrics.entrySet().stream().filter(e -> e.getKey().startsWith("DIRECTORY")).count());
}
@Test
public void testIndexMetricsWithDetails() throws Exception {
System.setProperty("solr.tests.metrics.merge", "false"); // test mergeDetails override too
System.setProperty("solr.tests.metrics.mergeDetails", "true");
System.setProperty("solr.tests.metrics.directory", "false");
System.setProperty("solr.tests.metrics.directoryDetails", "true");
initCore("solrconfig-indexmetrics.xml", "schema.xml");
addDocs();
MetricRegistry registry = h.getCoreContainer().getMetricManager().registry(h.getCore().getCoreMetricManager().getRegistryName());
assertNotNull(registry);
Map<String, Metric> metrics = registry.getMetrics();
@ -70,8 +143,10 @@ public class SolrIndexMetricsTest extends SolrTestCaseJ4 {
assertTrue("minorMerge: " + timer.getCount(), timer.getCount() >= 3);
timer = (Timer)metrics.get("INDEX.merge.major");
assertEquals("majorMerge: " + timer.getCount(), 0, timer.getCount());
// check detailed meters
Meter meter = (Meter)metrics.get("INDEX.merge.major.docs");
assertEquals("majorMergeDocs: " + meter.getCount(), 0, meter.getCount());
meter = (Meter)metrics.get("INDEX.flush");
assertTrue("flush: " + meter.getCount(), meter.getCount() > 10);
@ -80,11 +155,11 @@ public class SolrIndexMetricsTest extends SolrTestCaseJ4 {
assertTrue("totalReads", meter.getCount() > 0);
meter = (Meter)metrics.get("DIRECTORY.total.writes");
assertTrue("totalWrites", meter.getCount() > 0);
// check detailed meters
Histogram histogram = (Histogram)metrics.get("DIRECTORY.total.readSizes");
assertTrue("readSizes", histogram.getCount() > 0);
histogram = (Histogram)metrics.get("DIRECTORY.total.writeSizes");
assertTrue("writeSizes", histogram.getCount() > 0);
// check detailed meters
meter = (Meter)metrics.get("DIRECTORY.segments.writes");
assertTrue("segmentsWrites", meter.getCount() > 0);
histogram = (Histogram)metrics.get("DIRECTORY.segments.writeSizes");