Provide structured information on staleness to help debugging edge cases

On googlesource.com we see a large number of changes that are stale
continously, even after reindexing.

This commit provides more structured information about the reason for
staleness to aid further debugging.

The alternative to this commit is just use logging at the point where we
previously returned a boolean result. Using a structured response will
also allow the tests to be more specific about the staleness reason in
the future. Boolean results and logging-before-return also has the
drawback that it's easy to forget the log statement when modifying code.

Change-Id: I898c2f28bcb3d8b56ee1cfe6928f7b3b2684bb6c
This commit is contained in:
Patrick Hiesel
2019-11-06 11:40:43 +01:00
parent 12bba9f6e3
commit 3ac377d598
12 changed files with 205 additions and 110 deletions

View File

@@ -0,0 +1,39 @@
// Copyright (C) 2019 The Android Open Source Project
//
// Licensed 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 com.google.gerrit.server.index;
import com.google.auto.value.AutoValue;
import java.util.Optional;
/** Structured result of a staleness check. */
@AutoValue
public abstract class StalenessCheckResult {
public static StalenessCheckResult notStale() {
return new AutoValue_StalenessCheckResult(false, Optional.empty());
}
public static StalenessCheckResult stale(String reason) {
return new AutoValue_StalenessCheckResult(true, Optional.of(reason));
}
public static StalenessCheckResult stale(String reason, Object... args) {
return stale(String.format(reason, args));
}
public abstract boolean isStale();
public abstract Optional<String> reason();
}

View File

@@ -23,6 +23,7 @@ import com.google.gerrit.extensions.events.AccountIndexedListener;
import com.google.gerrit.index.Index;
import com.google.gerrit.server.account.AccountCache;
import com.google.gerrit.server.account.AccountState;
import com.google.gerrit.server.index.StalenessCheckResult;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
@@ -116,7 +117,9 @@ public class AccountIndexerImpl implements AccountIndexer {
@Override
public boolean reindexIfStale(Account.Id id) {
try {
if (stalenessChecker.isStale(id)) {
StalenessCheckResult stalenessCheckResult = stalenessChecker.check(id);
if (stalenessCheckResult.isStale()) {
logger.atInfo().log("Reindexing stale document %s", stalenessCheckResult);
index(id);
return true;
}

View File

@@ -35,6 +35,7 @@ import com.google.gerrit.server.config.AllUsersName;
import com.google.gerrit.server.config.AllUsersNameProvider;
import com.google.gerrit.server.git.GitRepositoryManager;
import com.google.gerrit.server.index.IndexUtils;
import com.google.gerrit.server.index.StalenessCheckResult;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import java.io.IOException;
@@ -87,16 +88,16 @@ public class StalenessChecker {
this.indexConfig = indexConfig;
}
public boolean isStale(Account.Id id) throws IOException {
public StalenessCheckResult check(Account.Id id) throws IOException {
AccountIndex i = indexes.getSearchIndex();
if (i == null) {
// No index; caller couldn't do anything if it is stale.
return false;
return StalenessCheckResult.notStale();
}
if (!i.getSchema().hasField(AccountField.REF_STATE)
|| !i.getSchema().hasField(AccountField.EXTERNAL_ID_STATE)) {
// Index version not new enough for this check.
return false;
return StalenessCheckResult.notStale();
}
boolean useLegacyNumericFields = i.getSchema().useLegacyNumericFields();
@@ -112,7 +113,11 @@ public class StalenessChecker {
Ref ref = repo.exactRef(RefNames.refsUsers(id));
// Stale if the account actually exists.
return ref != null;
if (ref == null) {
return StalenessCheckResult.notStale();
}
return StalenessCheckResult.stale(
"Document missing in index, but found %s in the repo", ref);
}
}
@@ -124,8 +129,9 @@ public class StalenessChecker {
e.getKey().get().equals(AllUsersNameProvider.DEFAULT) ? allUsersName : e.getKey();
try (Repository repo = repoManager.openRepository(repoName)) {
if (!e.getValue().match(repo)) {
// Ref was modified since the account was indexed.
return true;
return StalenessCheckResult.stale(
"Ref was modified since the account was indexed (%s != %s)",
e.getValue(), repo.exactRef(e.getValue().ref()));
}
}
}
@@ -134,17 +140,22 @@ public class StalenessChecker {
ListMultimap<ObjectId, ObjectId> extIdStates =
parseExternalIdStates(result.get().getValue(AccountField.EXTERNAL_ID_STATE));
if (extIdStates.size() != extIds.size()) {
// External IDs of the account were modified since the account was indexed.
return true;
return StalenessCheckResult.stale(
"External IDs of the account were modified since the account was indexed. (%s != %s)",
extIdStates.size(), extIds.size());
}
for (ExternalId extId : extIds) {
if (!extIdStates.containsKey(extId.key().sha1())) {
return StalenessCheckResult.stale("External ID missing: %s", extId.key().sha1());
}
if (!extIdStates.containsEntry(extId.key().sha1(), extId.blobId())) {
// External IDs of the account were modified since the account was indexed.
return true;
return StalenessCheckResult.stale(
"External ID has unexpected value. (%s != %s)",
extIdStates.get(extId.key().sha1()), extId.blobId());
}
}
return false;
return StalenessCheckResult.notStale();
}
public static ListMultimap<ObjectId, ObjectId> parseExternalIdStates(

View File

@@ -28,6 +28,7 @@ import com.google.gerrit.extensions.events.ChangeIndexedListener;
import com.google.gerrit.index.Index;
import com.google.gerrit.server.config.GerritServerConfig;
import com.google.gerrit.server.index.IndexExecutor;
import com.google.gerrit.server.index.StalenessCheckResult;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
@@ -432,7 +433,9 @@ public class ChangeIndexer {
public Boolean callImpl() throws Exception {
remove();
try {
if (stalenessChecker.isStale(id)) {
StalenessCheckResult stalenessCheckResult = stalenessChecker.check(id);
if (stalenessCheckResult.isStale()) {
logger.atInfo().log("Reindexing stale document %s", stalenessCheckResult);
indexImpl(changeDataFactory.create(project, id));
return true;
}

View File

@@ -35,6 +35,7 @@ import com.google.gerrit.extensions.restapi.Url;
import com.google.gerrit.index.IndexConfig;
import com.google.gerrit.index.RefState;
import com.google.gerrit.server.git.GitRepositoryManager;
import com.google.gerrit.server.index.StalenessCheckResult;
import com.google.gerrit.server.query.change.ChangeData;
import com.google.inject.Inject;
import com.google.inject.Singleton;
@@ -68,27 +69,28 @@ public class StalenessChecker {
this.indexConfig = indexConfig;
}
public boolean isStale(Change.Id id) {
public StalenessCheckResult check(Change.Id id) {
ChangeIndex i = indexes.getSearchIndex();
if (i == null) {
return false; // No index; caller couldn't do anything if it is stale.
return StalenessCheckResult
.notStale(); // No index; caller couldn't do anything if it is stale.
}
if (!i.getSchema().hasField(ChangeField.REF_STATE)
|| !i.getSchema().hasField(ChangeField.REF_STATE_PATTERN)) {
return false; // Index version not new enough for this check.
return StalenessCheckResult.notStale(); // Index version not new enough for this check.
}
Optional<ChangeData> result =
i.get(id, IndexedChangeQuery.createOptions(indexConfig, 0, 1, FIELDS));
if (!result.isPresent()) {
return true; // Not in index, but caller wants it to be.
return StalenessCheckResult.stale("Document %s missing from index", id);
}
ChangeData cd = result.get();
return isStale(repoManager, id, parseStates(cd), parsePatterns(cd));
return check(repoManager, id, parseStates(cd), parsePatterns(cd));
}
@UsedAt(UsedAt.Project.GOOGLE)
public static boolean isStale(
public static StalenessCheckResult check(
GitRepositoryManager repoManager,
Change.Id id,
SetMultimap<Project.NameKey, RefState> states,
@@ -97,7 +99,7 @@ public class StalenessChecker {
}
@VisibleForTesting
static boolean refsAreStale(
static StalenessCheckResult refsAreStale(
GitRepositoryManager repoManager,
Change.Id id,
SetMultimap<Project.NameKey, RefState> states,
@@ -105,12 +107,13 @@ public class StalenessChecker {
Set<Project.NameKey> projects = Sets.union(states.keySet(), patterns.keySet());
for (Project.NameKey p : projects) {
if (refsAreStale(repoManager, id, p, states, patterns)) {
return true;
StalenessCheckResult result = refsAreStale(repoManager, id, p, states, patterns);
if (result.isStale()) {
return result;
}
}
return false;
return StalenessCheckResult.notStale();
}
private SetMultimap<Project.NameKey, RefState> parseStates(ChangeData cd) {
@@ -136,7 +139,7 @@ public class StalenessChecker {
return result;
}
private static boolean refsAreStale(
private static StalenessCheckResult refsAreStale(
GitRepositoryManager repoManager,
Change.Id id,
Project.NameKey project,
@@ -146,18 +149,22 @@ public class StalenessChecker {
Set<RefState> states = allStates.get(project);
for (RefState state : states) {
if (!state.match(repo)) {
return true;
return StalenessCheckResult.stale(
"Ref states don't match for document %s (%s != %s)",
id, state, repo.exactRef(state.ref()));
}
}
for (RefStatePattern pattern : allPatterns.get(project)) {
if (!pattern.match(repo, states)) {
return true;
return StalenessCheckResult.stale(
"Ref patterns don't match for document %s. Pattern: %s States: %s",
id, pattern, states);
}
}
return false;
return StalenessCheckResult.notStale();
} catch (IOException e) {
logger.atWarning().withCause(e).log("error checking staleness of %s in %s", id, project);
return true;
return StalenessCheckResult.stale("Exceptions while processing document %s", e.getMessage());
}
}

View File

@@ -23,6 +23,7 @@ import com.google.gerrit.extensions.events.GroupIndexedListener;
import com.google.gerrit.index.Index;
import com.google.gerrit.server.account.GroupCache;
import com.google.gerrit.server.group.InternalGroup;
import com.google.gerrit.server.index.StalenessCheckResult;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
@@ -116,7 +117,9 @@ public class GroupIndexerImpl implements GroupIndexer {
@Override
public boolean reindexIfStale(AccountGroup.UUID uuid) {
try {
if (stalenessChecker.isStale(uuid)) {
StalenessCheckResult stalenessCheckResult = stalenessChecker.check(uuid);
if (stalenessCheckResult.isStale()) {
logger.atInfo().log("Reindexing stale document %s", stalenessCheckResult);
index(uuid);
return true;
}

View File

@@ -21,6 +21,7 @@ import com.google.gerrit.index.IndexConfig;
import com.google.gerrit.index.query.FieldBundle;
import com.google.gerrit.server.config.AllUsersName;
import com.google.gerrit.server.git.GitRepositoryManager;
import com.google.gerrit.server.index.StalenessCheckResult;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import java.io.IOException;
@@ -59,10 +60,11 @@ public class StalenessChecker {
this.allUsers = allUsers;
}
public boolean isStale(AccountGroup.UUID uuid) throws IOException {
public StalenessCheckResult check(AccountGroup.UUID uuid) throws IOException {
GroupIndex i = indexes.getSearchIndex();
if (i == null) {
return false; // No index; caller couldn't do anything if it is stale.
// No index; caller couldn't do anything if it is stale.
return StalenessCheckResult.notStale();
}
Optional<FieldBundle> result =
@@ -73,14 +75,23 @@ public class StalenessChecker {
Ref ref = repo.exactRef(RefNames.refsGroups(uuid));
// Stale if the group actually exists.
return ref != null;
if (ref == null) {
return StalenessCheckResult.notStale();
}
return StalenessCheckResult.stale(
"Document missing in index, but found %s in the repo", ref);
}
}
try (Repository repo = repoManager.openRepository(allUsers)) {
Ref ref = repo.exactRef(RefNames.refsGroups(uuid));
ObjectId head = ref == null ? ObjectId.zeroId() : ref.getObjectId();
return !head.equals(ObjectId.fromString(result.get().getValue(GroupField.REF_STATE), 0));
ObjectId idFromIndex = ObjectId.fromString(result.get().getValue(GroupField.REF_STATE), 0);
if (head.equals(idFromIndex)) {
return StalenessCheckResult.notStale();
}
return StalenessCheckResult.stale(
"Document has unexpected ref state (%s != %s)", head, idFromIndex);
}
}
}

View File

@@ -27,6 +27,7 @@ import com.google.gerrit.index.project.ProjectField;
import com.google.gerrit.index.project.ProjectIndex;
import com.google.gerrit.index.project.ProjectIndexCollection;
import com.google.gerrit.index.query.FieldBundle;
import com.google.gerrit.server.index.StalenessCheckResult;
import com.google.gerrit.server.project.ProjectCache;
import com.google.inject.Inject;
import java.util.Optional;
@@ -47,17 +48,18 @@ public class StalenessChecker {
this.indexConfig = indexConfig;
}
public boolean isStale(Project.NameKey project) {
public StalenessCheckResult check(Project.NameKey project) {
ProjectData projectData = projectCache.get(project).toProjectData();
ProjectIndex i = indexes.getSearchIndex();
if (i == null) {
return false; // No index; caller couldn't do anything if it is stale.
return StalenessCheckResult
.notStale(); // No index; caller couldn't do anything if it is stale.
}
Optional<FieldBundle> result =
i.getRaw(project, QueryOptions.create(indexConfig, 0, 1, FIELDS));
if (!result.isPresent()) {
return true;
return StalenessCheckResult.stale("Document %s missing from index", project);
}
SetMultimap<Project.NameKey, RefState> indexedRefStates =
@@ -73,6 +75,10 @@ public class StalenessChecker {
p.getProject().getNameKey(),
RefState.create(RefNames.REFS_CONFIG, p.getProject().getConfigRefState())));
return !currentRefStates.equals(indexedRefStates);
if (currentRefStates.equals(indexedRefStates)) {
return StalenessCheckResult.notStale();
}
return StalenessCheckResult.stale(
"Document has unexpected ref states (%s != %s)", currentRefStates, indexedRefStates);
}
}

View File

@@ -3010,7 +3010,7 @@ public class AccountIT extends AbstractDaemonTest {
// Newly created account is not stale.
AccountInfo accountInfo = gApi.accounts().create(name("foo")).get();
Account.Id accountId = Account.id(accountInfo._accountId);
assertThat(stalenessChecker.isStale(accountId)).isFalse();
assertThat(stalenessChecker.check(accountId).isStale()).isFalse();
// Manually updating the user ref makes the index document stale.
String userRef = RefNames.refsUsers(accountId);
@@ -3078,11 +3078,11 @@ public class AccountIT extends AbstractDaemonTest {
// has to happen directly on the accounts cache because AccountCacheImpl triggers a reindex for
// the account.
accountsCache.invalidate(accountId);
assertThat(stalenessChecker.isStale(accountId)).isTrue();
assertThat(stalenessChecker.check(accountId).isStale()).isTrue();
// Reindex fixes staleness
accountIndexer.index(accountId);
assertThat(stalenessChecker.isStale(accountId)).isFalse();
assertThat(stalenessChecker.check(accountId).isStale()).isFalse();
}
@Test

View File

@@ -1265,7 +1265,7 @@ public class GroupsIT extends AbstractDaemonTest {
// Newly created group is not stale
GroupInfo groupInfo = gApi.groups().create(name("foo")).get();
AccountGroup.UUID groupUuid = AccountGroup.uuid(groupInfo.id);
assertThat(stalenessChecker.isStale(groupUuid)).isFalse();
assertThat(stalenessChecker.check(groupUuid).isStale()).isFalse();
// Manual update makes index document stale
String groupRef = RefNames.refsGroups(groupUuid);
@@ -1406,11 +1406,11 @@ public class GroupsIT extends AbstractDaemonTest {
private void assertStaleGroupAndReindex(AccountGroup.UUID groupUuid) throws IOException {
// Evict group from cache to be sure that we use the index state for staleness checks.
groupCache.evict(groupUuid);
assertThat(stalenessChecker.isStale(groupUuid)).isTrue();
assertThat(stalenessChecker.check(groupUuid).isStale()).isTrue();
// Reindex fixes staleness
groupIndexer.index(groupUuid);
assertThat(stalenessChecker.isStale(groupUuid)).isFalse();
assertThat(stalenessChecker.check(groupUuid).isStale()).isFalse();
}
private void pushToGroupBranchForReviewAndSubmit(

View File

@@ -83,19 +83,19 @@ public class ProjectIndexerIT extends AbstractDaemonTest {
@Test
public void stalenessChecker_currentProject_notStale() throws Exception {
assertThat(stalenessChecker.isStale(project)).isFalse();
assertThat(stalenessChecker.check(project).isStale()).isFalse();
}
@Test
public void stalenessChecker_currentProjectUpdates_isStale() throws Exception {
updateProjectConfigWithoutIndexUpdate(project);
assertThat(stalenessChecker.isStale(project)).isTrue();
assertThat(stalenessChecker.check(project).isStale()).isTrue();
}
@Test
public void stalenessChecker_parentProjectUpdates_isStale() throws Exception {
updateProjectConfigWithoutIndexUpdate(allProjects);
assertThat(stalenessChecker.isStale(project)).isTrue();
assertThat(stalenessChecker.check(project).isStale()).isTrue();
}
@Test
@@ -106,10 +106,10 @@ public class ProjectIndexerIT extends AbstractDaemonTest {
u.getConfig().getProject().setParentName(p1);
u.save();
}
assertThat(stalenessChecker.isStale(project)).isFalse();
assertThat(stalenessChecker.check(project).isStale()).isFalse();
updateProjectConfigWithoutIndexUpdate(p1, c -> c.getProject().setParentName(p2));
assertThat(stalenessChecker.isStale(project)).isTrue();
assertThat(stalenessChecker.check(project).isStale()).isTrue();
}
private void updateProjectConfigWithoutIndexUpdate(Project.NameKey project) throws Exception {

View File

@@ -168,7 +168,8 @@ public class StalenessCheckerTest {
ImmutableSetMultimap.of(
P1, RefState.create(ref1, id1.name()),
P2, RefState.create(ref2, id2.name())),
ImmutableListMultimap.of()))
ImmutableListMultimap.of())
.isStale())
.isFalse();
// Wrong ref value.
@@ -179,7 +180,8 @@ public class StalenessCheckerTest {
ImmutableSetMultimap.of(
P1, RefState.create(ref1, SHA1),
P2, RefState.create(ref2, id2.name())),
ImmutableListMultimap.of()))
ImmutableListMultimap.of())
.isStale())
.isTrue();
// Swapped repos.
@@ -190,7 +192,8 @@ public class StalenessCheckerTest {
ImmutableSetMultimap.of(
P1, RefState.create(ref1, id2.name()),
P2, RefState.create(ref2, id1.name())),
ImmutableListMultimap.of()))
ImmutableListMultimap.of())
.isStale())
.isTrue();
// Two refs in same repo, not stale.
@@ -204,7 +207,8 @@ public class StalenessCheckerTest {
ImmutableSetMultimap.of(
P1, RefState.create(ref1, id1.name()),
P1, RefState.create(ref3, id3.name())),
ImmutableListMultimap.of()))
ImmutableListMultimap.of())
.isStale())
.isFalse();
// Ignore ref not mentioned.
@@ -213,7 +217,8 @@ public class StalenessCheckerTest {
repoManager,
C,
ImmutableSetMultimap.of(P1, RefState.create(ref1, id1.name())),
ImmutableListMultimap.of()))
ImmutableListMultimap.of())
.isStale())
.isFalse();
// One ref wrong.
@@ -224,7 +229,8 @@ public class StalenessCheckerTest {
ImmutableSetMultimap.of(
P1, RefState.create(ref1, id1.name()),
P1, RefState.create(ref3, SHA1)),
ImmutableListMultimap.of()))
ImmutableListMultimap.of())
.isStale())
.isTrue();
}
@@ -239,7 +245,8 @@ public class StalenessCheckerTest {
repoManager,
C,
ImmutableSetMultimap.of(P1, RefState.create(ref1, id1.name())),
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/heads/*"))))
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/heads/*")))
.isStale())
.isFalse();
// Now ref2 matches pattern, so stale unless ref2 is present in state map.
@@ -250,7 +257,8 @@ public class StalenessCheckerTest {
repoManager,
C,
ImmutableSetMultimap.of(P1, RefState.create(ref1, id1.name())),
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/heads/*"))))
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/heads/*")))
.isStale())
.isTrue();
assertThat(
refsAreStale(
@@ -259,7 +267,8 @@ public class StalenessCheckerTest {
ImmutableSetMultimap.of(
P1, RefState.create(ref1, id1.name()),
P1, RefState.create(ref2, id2.name())),
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/heads/*"))))
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/heads/*")))
.isStale())
.isFalse();
}
@@ -275,7 +284,8 @@ public class StalenessCheckerTest {
repoManager,
C,
ImmutableSetMultimap.of(P1, RefState.create(ref1, id1.name())),
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/*/foo"))))
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/*/foo")))
.isStale())
.isFalse();
// Now ref2 matches pattern, so stale unless ref2 is present in state map.
@@ -286,7 +296,8 @@ public class StalenessCheckerTest {
repoManager,
C,
ImmutableSetMultimap.of(P1, RefState.create(ref1, id1.name())),
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/*/foo"))))
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/*/foo")))
.isStale())
.isTrue();
assertThat(
refsAreStale(
@@ -295,7 +306,8 @@ public class StalenessCheckerTest {
ImmutableSetMultimap.of(
P1, RefState.create(ref1, id1.name()),
P1, RefState.create(ref3, id3.name())),
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/*/foo"))))
ImmutableListMultimap.of(P1, RefStatePattern.create("refs/*/foo")))
.isStale())
.isFalse();
}