Author: chetanm
Date: Fri Nov 18 12:25:15 2016
New Revision: 1770371
URL: http://svn.apache.org/viewvc?rev=1770371&view=rev
Log:
OAK-4836 - Avoid excessive logging in case of corrupt index or mis-configured
index defnition
Adding BadIndexTracker which tracks bad indexes and controls access to them
Added:
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTracker.java
(with props)
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTrackerTest.java
(with props)
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/VirtualTicker.java
(with props)
Modified:
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTracker.java
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTrackerTest.java
Added:
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTracker.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTracker.java?rev=1770371&view=auto
==============================================================================
---
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTracker.java
(added)
+++
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTracker.java
Fri Nov 18 12:25:15 2016
@@ -0,0 +1,158 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.apache.jackrabbit.oak.plugins.index.lucene;
+
+import java.util.Map;
+import java.util.Set;
+import java.util.concurrent.TimeUnit;
+
+import com.google.common.base.Stopwatch;
+import com.google.common.base.Throwables;
+import com.google.common.base.Ticker;
+import com.google.common.collect.Maps;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+class BadIndexTracker {
+ /**
+ * Time interval in millis after which a bad index would be accessed again
+ * to check if it has been fixed
+ */
+ private static final long DEFAULT_RECHECK_INTERVAL =
TimeUnit.MINUTES.toMillis(15);
+
+ private final Logger log = LoggerFactory.getLogger(getClass());
+ private final Map<String, BadIndexInfo> badIndexes =
Maps.newConcurrentMap();
+ private final long recheckIntervalMillis;
+ private Ticker ticker = Ticker.systemTicker();
+ private int indexerCycleCount;
+
+ public BadIndexTracker() {
+ this(DEFAULT_RECHECK_INTERVAL);
+ }
+
+ public BadIndexTracker(long recheckIntervalMillis) {
+ this.recheckIntervalMillis = recheckIntervalMillis;
+ log.info("Bad Index recheck interval set to {} seconds",
+ TimeUnit.MILLISECONDS.toSeconds(recheckIntervalMillis));
+ }
+
+ public void markGoodIndexes(Set<String> updatedIndexPaths) {
+ indexerCycleCount++;
+ for (String indexPath : updatedIndexPaths) {
+ markGoodIndex(indexPath);
+ }
+ }
+
+ public void markGoodIndex(String indexPath) {
+ BadIndexInfo info = badIndexes.remove(indexPath);
+ if (info != null) {
+ log.info("Index [{}] which was not working {} is found to be
healthy again",
+ indexPath, info.getStats());
+ }
+ }
+
+ public void markBadIndex(String path, Throwable e) {
+ BadIndexInfo badIndex = badIndexes.get(path);
+ if (badIndex == null) {
+ badIndexes.put(path, new BadIndexInfo(path, e));
+ log.error("Could not access the Lucene index at [{}]", path, e);
+ } else {
+ badIndex.failedAccess(e);
+ log.error("Could not access the Lucene index at [{}] . {}",
+ path, badIndex.getStats(), e);
+ }
+ }
+
+ public boolean isIgnoredBadIndex(String path) {
+ BadIndexInfo badIdx = badIndexes.get(path);
+ if (badIdx == null) {
+ return false;
+ }
+ return !badIdx.tryAgain();
+ }
+
+ public Set<String> getIndexPaths() {
+ return badIndexes.keySet();
+ }
+
+ public long getRecheckIntervalMillis() {
+ return recheckIntervalMillis;
+ }
+
+ BadIndexInfo getInfo(String indexPath){
+ return badIndexes.get(indexPath);
+ }
+
+ void setTicker(Ticker ticker) {
+ this.ticker = ticker;
+ }
+
+ class BadIndexInfo {
+ final String path;
+ final int lastIndexerCycleCount = indexerCycleCount;
+ private final Stopwatch created = Stopwatch.createStarted(ticker);
+ private final Stopwatch watch = Stopwatch.createStarted(ticker);
+ private String exception;
+ private int accessCount;
+ private int failedAccessCount;
+
+ public BadIndexInfo(String path, Throwable e) {
+ this.path = path;
+ this.exception = Throwables.getStackTraceAsString(e);
+ }
+
+ public boolean tryAgain() {
+ accessCount++;
+
+ if (watch.elapsed(TimeUnit.MILLISECONDS) > recheckIntervalMillis) {
+ watch.reset().start();
+ return true;
+ }
+
+ if (log.isDebugEnabled()) {
+ log.debug("Ignoring index [{}] which is not working correctly
{}", path, getStats());
+ }
+ return false;
+ }
+
+ public String getStats() {
+ return String.format("since %s ,%d indexing cycles, accessed %d
times",
+ created, getCycleCount(), accessCount);
+ }
+
+ public int getFailedAccessCount() {
+ return failedAccessCount;
+ }
+
+ public int getAccessCount() {
+ return accessCount;
+ }
+
+ private int getCycleCount() {
+ return indexerCycleCount - lastIndexerCycleCount;
+ }
+
+ public void failedAccess(Throwable e) {
+ failedAccessCount++;
+ exception = Throwables.getStackTraceAsString(e);
+ }
+ }
+
+}
Propchange:
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTracker.java
------------------------------------------------------------------------------
svn:eol-style = native
Modified:
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTracker.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTracker.java?rev=1770371&r1=1770370&r2=1770371&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTracker.java
(original)
+++
jackrabbit/oak/trunk/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTracker.java
Fri Nov 18 12:25:15 2016
@@ -37,6 +37,7 @@ import java.util.Set;
import javax.annotation.CheckForNull;
import javax.annotation.Nullable;
+import com.google.common.collect.Sets;
import org.apache.jackrabbit.oak.commons.PathUtils;
import org.apache.jackrabbit.oak.plugins.index.lucene.hybrid.NRTIndexFactory;
import
org.apache.jackrabbit.oak.plugins.index.lucene.reader.DefaultIndexReaderFactory;
@@ -64,6 +65,7 @@ public class IndexTracker {
private final LuceneIndexReaderFactory readerFactory;
private final NRTIndexFactory nrtFactory;
+ private final BadIndexTracker badIndexTracker = new BadIndexTracker();
private NodeState root = EMPTY_NODE;
@@ -116,10 +118,12 @@ public class IndexTracker {
Map<String, IndexNode> original = indices;
final Map<String, IndexNode> updates = newHashMap();
- List<Editor> editors = newArrayListWithCapacity(original.size());
- for (Map.Entry<String, IndexNode> entry : original.entrySet()) {
- final String path = entry.getKey();
+ Set<String> indexPaths = Sets.newHashSet();
+ indexPaths.addAll(original.keySet());
+ indexPaths.addAll(badIndexTracker.getIndexPaths());
+ List<Editor> editors = newArrayListWithCapacity(indexPaths.size());
+ for (final String path : indexPaths) {
editors.add(new SubtreeEditor(new DefaultEditor() {
@Override
public void leave(NodeState before, NodeState after) {
@@ -144,6 +148,8 @@ public class IndexTracker {
.putAll(filterValues(updates, notNull()))
.build();
+ badIndexTracker.markGoodIndexes(updates.keySet());
+
//This might take some time as close need to acquire the
//write lock which might be held by current running searches
//Given that Tracker is now invoked from a BackgroundObserver
@@ -151,7 +157,9 @@ public class IndexTracker {
for (String path : updates.keySet()) {
IndexNode index = original.get(path);
try {
- index.close();
+ if (index != null) {
+ index.close();
+ }
} catch (IOException e) {
log.error("Failed to close Lucene index at " + path, e);
}
@@ -187,6 +195,10 @@ public class IndexTracker {
return indices.keySet();
}
+ BadIndexTracker getBadIndexTracker() {
+ return badIndexTracker;
+ }
+
private synchronized IndexNode findIndexNode(String path) {
// Retry the lookup from acquireIndexNode now that we're
// synchronized. The acquire() call is guaranteed to succeed
@@ -197,6 +209,10 @@ public class IndexTracker {
return index;
}
+ if (badIndexTracker.isIgnoredBadIndex(path)){
+ return null;
+ }
+
NodeState node = root;
for (String name : PathUtils.elements(path)) {
node = node.getChildNode(name);
@@ -211,15 +227,18 @@ public class IndexTracker {
.putAll(indices)
.put(path, index)
.build();
+ badIndexTracker.markGoodIndex(path);
return index;
}
} else if (node.exists()) {
log.warn("Cannot open Lucene Index at path {} as the index is
not of type {}", path, TYPE_LUCENE);
}
- } catch (IOException e) {
- log.error("Could not access the Lucene index at " + path, e);
+ } catch (Throwable e) {
+ badIndexTracker.markBadIndex(path, e);
}
return null;
}
+
+
}
Added:
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTrackerTest.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTrackerTest.java?rev=1770371&view=auto
==============================================================================
---
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTrackerTest.java
(added)
+++
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTrackerTest.java
Fri Nov 18 12:25:15 2016
@@ -0,0 +1,75 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.apache.jackrabbit.oak.plugins.index.lucene;
+
+import java.util.Collections;
+import java.util.concurrent.TimeUnit;
+
+import org.junit.Test;
+
+import static org.hamcrest.Matchers.hasItem;
+import static org.junit.Assert.*;
+
+public class BadIndexTrackerTest {
+
+ private VirtualTicker ticker = new VirtualTicker();
+ private BadIndexTracker tracker = new BadIndexTracker();
+
+ @Test
+ public void basics() throws Exception{
+ tracker.markBadIndex("foo", new Exception());
+ assertThat(tracker.getIndexPaths(), hasItem("foo"));
+
+ assertTrue(tracker.isIgnoredBadIndex("foo"));
+
+ tracker.markGoodIndex("foo");
+ assertFalse(tracker.isIgnoredBadIndex("foo"));
+ }
+
+ @Test
+ public void updatedIndexesMakesGood() throws Exception{
+ tracker.markBadIndex("foo", new Exception());
+ assertTrue(tracker.isIgnoredBadIndex("foo"));
+
+ tracker.markGoodIndexes(Collections.singleton("foo"));
+ assertFalse(tracker.isIgnoredBadIndex("foo"));
+ }
+
+ @Test
+ public void recheckDelay() throws Exception{
+ tracker = new BadIndexTracker(100);
+ tracker.setTicker(ticker);
+ tracker.markBadIndex("foo", new Exception());
+ ticker.addTime(50, TimeUnit.MILLISECONDS);
+
+ assertTrue(tracker.isIgnoredBadIndex("foo"));
+
+ ticker.addTime(30, TimeUnit.MILLISECONDS);
+ assertTrue(tracker.isIgnoredBadIndex("foo"));
+
+ //Now cross the threshold
+ ticker.addTime(30, TimeUnit.MILLISECONDS);
+ assertFalse(tracker.isIgnoredBadIndex("foo"));
+
+ //However index is still considered bad
+ assertThat(tracker.getIndexPaths(), hasItem("foo"));
+ }
+
+}
\ No newline at end of file
Propchange:
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/BadIndexTrackerTest.java
------------------------------------------------------------------------------
svn:eol-style = native
Modified:
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTrackerTest.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTrackerTest.java?rev=1770371&r1=1770370&r2=1770371&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTrackerTest.java
(original)
+++
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/IndexTrackerTest.java
Fri Nov 18 12:25:15 2016
@@ -19,19 +19,31 @@
package org.apache.jackrabbit.oak.plugins.index.lucene;
+import java.util.Collections;
+import java.util.concurrent.TimeUnit;
+
import com.google.common.collect.ImmutableSet;
+import org.apache.jackrabbit.oak.api.Type;
+import org.apache.jackrabbit.oak.commons.PathUtils;
import org.apache.jackrabbit.oak.plugins.index.IndexUpdateProvider;
+import org.apache.jackrabbit.oak.plugins.memory.ArrayBasedBlob;
+import org.apache.jackrabbit.oak.plugins.memory.PropertyStates;
import org.apache.jackrabbit.oak.spi.commit.CommitInfo;
import org.apache.jackrabbit.oak.spi.commit.EditorHook;
import org.apache.jackrabbit.oak.spi.state.NodeBuilder;
import org.apache.jackrabbit.oak.spi.state.NodeState;
+import
org.apache.jackrabbit.oak.plugins.index.lucene.BadIndexTracker.BadIndexInfo;
import org.junit.Test;
import static
org.apache.jackrabbit.oak.plugins.index.IndexConstants.INDEX_DEFINITIONS_NAME;
import static
org.apache.jackrabbit.oak.plugins.index.lucene.util.LuceneIndexHelper.newLucenePropertyIndexDefinition;
import static
org.apache.jackrabbit.oak.plugins.nodetype.write.InitialContent.INITIAL_CONTENT;
import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.assertNull;
+import static org.junit.Assert.assertTrue;
+@SuppressWarnings("UnusedAssignment")
public class IndexTrackerTest {
private static final EditorHook HOOK = new EditorHook(
new IndexUpdateProvider(
@@ -69,4 +81,99 @@ public class IndexTrackerTest {
assertEquals(0, tracker.getIndexNodePaths().size());
}
+ @Test
+ public void badIndexAccess() throws Exception{
+ createIndex("foo");
+
+ //1. Create and populate index
+ NodeState before = builder.getNodeState();
+ builder.setProperty("foo", "bar");
+ NodeState after = builder.getNodeState();
+
+ NodeState indexed = HOOK.processCommit(before, after,
CommitInfo.EMPTY);
+ tracker.update(indexed);
+
+ IndexNode indexNode = tracker.acquireIndexNode("/oak:index/foo");
+ indexNode.release();
+
+ assertTrue(tracker.getBadIndexTracker().getIndexPaths().isEmpty());
+
+ //2. Corrupt the index
+ builder = indexed.builder();
+ indexed = corruptIndex("/oak:index/foo");
+
+ //3. Recreate the tracker as we cannot push corrupt index in existing
tracker
+ //As diffAndUpdate would fail and existing IndexNode would not be
changed
+ tracker = new IndexTracker();
+ tracker.update(indexed);
+
+ VirtualTicker ticker = new VirtualTicker();
+ tracker.getBadIndexTracker().setTicker(ticker);
+
+ indexNode = tracker.acquireIndexNode("/oak:index/foo");
+
+ //Index must be corrupted hence it must be null
+ assertNull(indexNode);
+
assertTrue(tracker.getBadIndexTracker().getIndexPaths().contains("/oak:index/foo"));
+
+ BadIndexInfo badIdxInfo =
tracker.getBadIndexTracker().getInfo("/oak:index/foo");
+ assertNotNull(badIdxInfo);
+ assertEquals(0, badIdxInfo.getAccessCount());
+
+ //Try to access again
+ indexNode = tracker.acquireIndexNode("/oak:index/foo");
+ assertEquals(1, badIdxInfo.getAccessCount());
+ assertEquals(0, badIdxInfo.getFailedAccessCount());
+
+ indexNode = tracker.acquireIndexNode("/oak:index/foo");
+ assertEquals(2, badIdxInfo.getAccessCount());
+ assertEquals(0, badIdxInfo.getFailedAccessCount());
+
+ //5. Move clock forward
+ ticker.addTime(tracker.getBadIndexTracker().getRecheckIntervalMillis()
+ 1, TimeUnit.MILLISECONDS);
+
+ //Now index access must be attempted again
+ indexNode = tracker.acquireIndexNode("/oak:index/foo");
+ assertEquals(3, badIdxInfo.getAccessCount());
+ assertEquals(1, badIdxInfo.getFailedAccessCount());
+
+ //6. Now lets reindex to fix the corruption
+ builder = indexed.builder();
+ before = indexed;
+ after = reindex("/oak:index/foo");
+
+ indexed = HOOK.processCommit(before, after, CommitInfo.EMPTY);
+ tracker.update(indexed);
+
+ //7. Now indexNode should be accessible
+ indexNode = tracker.acquireIndexNode("/oak:index/foo");
+ assertNotNull(indexNode);
+
+ //And this index would not be considered bad
+ badIdxInfo = tracker.getBadIndexTracker().getInfo("/oak:index/foo");
+ assertNull(badIdxInfo);
+ }
+
+ private NodeState corruptIndex(String indexPath) {
+ NodeBuilder dir = TestUtil.child(builder, PathUtils.concat(indexPath,
":data"));
+ for (String name : dir.getChildNodeNames()){
+ if (!"segments.gen".equals(name)){
+
dir.getChildNode(name).setProperty(PropertyStates.createProperty("jcr:data",
Collections
+ .singletonList(new ArrayBasedBlob("foo".getBytes())),
Type.BINARIES));
+ }
+ }
+ return builder.getNodeState();
+ }
+
+ private NodeState reindex(String indexPath){
+ NodeBuilder dir = TestUtil.child(builder, indexPath);
+ dir.setProperty("reindex", true);
+ return builder.getNodeState();
+ }
+
+ private void createIndex(String propName){
+ NodeBuilder index = builder.child(INDEX_DEFINITIONS_NAME);
+ newLucenePropertyIndexDefinition(index, propName,
ImmutableSet.of(propName), null);
+ }
+
}
\ No newline at end of file
Added:
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/VirtualTicker.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/VirtualTicker.java?rev=1770371&view=auto
==============================================================================
---
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/VirtualTicker.java
(added)
+++
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/VirtualTicker.java
Fri Nov 18 12:25:15 2016
@@ -0,0 +1,41 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+package org.apache.jackrabbit.oak.plugins.index.lucene;
+
+import java.util.concurrent.TimeUnit;
+
+import com.google.common.base.Ticker;
+
+public class VirtualTicker extends Ticker{
+ private long time;
+
+ @Override
+ public long read() {
+ return time;
+ }
+
+ public void setTime(long time, TimeUnit unit){
+ this.time = unit.toNanos(time);
+ }
+
+ public void addTime(long delta, TimeUnit unit){
+ this.time += unit.toNanos(delta);
+ }
+}
Propchange:
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/VirtualTicker.java
------------------------------------------------------------------------------
svn:eol-style = native
