Add more logging for the apply object REST-API Introduce a lot more logging when the invocation of the apply object REST-API fails, so that the Gerrit admin can have more insights on the cause of the failures. Change-Id: I923896be72375df70a84cdd23d86e25635c88477
diff --git a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/ReplicationQueue.java b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/ReplicationQueue.java index cfe01e2..0ce125d 100644 --- a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/ReplicationQueue.java +++ b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/ReplicationQueue.java
@@ -15,6 +15,7 @@ package com.googlesource.gerrit.plugins.replication.pull; import com.google.auto.value.AutoValue; +import com.google.common.base.Stopwatch; import com.google.common.collect.Queues; import com.google.gerrit.entities.Project; import com.google.gerrit.entities.Project.NameKey; @@ -245,6 +246,12 @@ try { Optional<RevisionData> revisionData = revisionReader.read(project, objectId, refName); + repLog.info( + "RevisionData is {} for {}:{}", + revisionData.map(RevisionData::toString).orElse("ABSENT"), + project, + refName); + if (revisionData.isPresent()) { return ((source) -> callSendObject(source, project, refName, isDelete, revisionData.get(), state)); @@ -274,27 +281,56 @@ try { URIish uri = new URIish(apiUrl); FetchApiClient fetchClient = fetchClientFactory.create(source); - + repLog.info( + "Pull replication REST API apply object to {} for {}:{} - {}", + apiUrl, + project, + refName, + revision); + Stopwatch apiTimer = Stopwatch.createStarted(); HttpResult result = fetchClient.callSendObject(project, refName, isDelete, revision, uri); + repLog.info( + "Pull replication REST API apply object to {} COMPLETED for {}:{} - {}, HTTP Result:" + + " {} - time:{} ms", + apiUrl, + project, + refName, + revision, + result, + apiTimer.elapsed(TimeUnit.MILLISECONDS)); + if (isProjectMissing(result, project) && source.isCreateMissingRepositories()) { result = initProject(project, uri, fetchClient, result); + repLog.info("Missing project {} created, HTTP Result:{}", project, result); } + if (!result.isSuccessful()) { - repLog.warn( - String.format( - "Pull replication rest api apply object call failed. Endpoint url: %s, reason:%s", - apiUrl, result.getMessage().orElse("unknown"))); if (result.isParentObjectMissing()) { throw new MissingParentObjectException( project, refName, source.getRemoteConfigName()); } } } catch (URISyntaxException e) { + repLog.warn( + "Pull replication REST API apply object to {} *FAILED* for {}:{} - {}", + apiUrl, + project, + refName, + revision, + e); stateLog.error(String.format("Cannot parse pull replication api url:%s", apiUrl), state); } catch (IOException e) { + repLog.warn( + "Pull replication REST API apply object to {} *FAILED* for {}:{} - {}", + apiUrl, + project, + refName, + revision, + e); stateLog.error( String.format( - "Exception during the pull replication fetch rest api call. Endpoint url:%s, message:%s", + "Exception during the pull replication fetch rest api call. Endpoint url:%s," + + " message:%s", apiUrl, e.getMessage()), e, state); @@ -326,7 +362,8 @@ } catch (Exception e) { stateLog.error( String.format( - "Exception during the pull replication fetch rest api call. Endpoint url:%s, message:%s", + "Exception during the pull replication fetch rest api call. Endpoint url:%s," + + " message:%s", apiUrl, e.getMessage()), e, state);
diff --git a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectAction.java b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectAction.java index f83cadb..442f585 100644 --- a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectAction.java +++ b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectAction.java
@@ -14,6 +14,8 @@ package com.googlesource.gerrit.plugins.replication.pull.api; +import static com.googlesource.gerrit.plugins.replication.pull.PullReplicationLogger.repLog; + import com.google.common.base.Strings; import com.google.gerrit.extensions.restapi.AuthException; import com.google.gerrit.extensions.restapi.BadRequestException; @@ -60,25 +62,68 @@ throw new BadRequestException("Ref-update refname cannot be null or empty"); } + repLog.info( + "Apply object API from {} for {}:{} - {}", + resource.getNameKey(), + input.getLabel(), + input.getRefName(), + input.getRevisionData()); + if (Objects.isNull(input.getRevisionData())) { deleteRefCommand.deleteRef(resource.getNameKey(), input.getRefName(), input.getLabel()); + repLog.info( + "Apply object API - REF DELETED - from {} for {}:{} - {}", + resource.getNameKey(), + input.getLabel(), + input.getRefName(), + input.getRevisionData()); return Response.created(input); } try { input.validate(); } catch (IllegalArgumentException e) { - throw new BadRequestException("Ref-update with invalid input: " + e.getMessage(), e); + BadRequestException bre = + new BadRequestException("Ref-update with invalid input: " + e.getMessage(), e); + repLog.error( + "Apply object API *FAILED* from {} for {}:{} - {}", + input.getLabel(), + resource.getNameKey(), + input.getRefName(), + input.getRevisionData(), + bre); + throw bre; } command.applyObject( resource.getNameKey(), input.getRefName(), input.getRevisionData(), input.getLabel()); return Response.created(input); } catch (MissingParentObjectException e) { + repLog.error( + "Apply object API *FAILED* from {} for {}:{} - {}", + input.getLabel(), + resource.getNameKey(), + input.getRefName(), + input.getRevisionData(), + e); throw new ResourceConflictException(e.getMessage(), e); } catch (NumberFormatException | IOException e) { + repLog.error( + "Apply object API *FAILED* from {} for {}:{} - {}", + input.getLabel(), + resource.getNameKey(), + input.getRefName(), + input.getRevisionData(), + e); throw RestApiException.wrap(e.getMessage(), e); } catch (RefUpdateException e) { + repLog.error( + "Apply object API *FAILED* from {} for {}:{} - {}", + input.getLabel(), + resource.getNameKey(), + input.getRefName(), + input.getRevisionData(), + e); throw new UnprocessableEntityException(e.getMessage()); } }
diff --git a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectCommand.java b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectCommand.java index 276aa16..ff231d8 100644 --- a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectCommand.java +++ b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/ApplyObjectCommand.java
@@ -73,7 +73,7 @@ Project.NameKey name, String refName, RevisionData revisionData, String sourceLabel) throws IOException, RefUpdateException, MissingParentObjectException { - repLog.info("Apply object from {} for project {}, ref name {}", sourceLabel, name, refName); + repLog.info("Apply object from {} for {}:{} - {}", sourceLabel, name, refName, revisionData); Timer1.Context<String> context = metrics.start(sourceLabel); RefUpdateState refUpdateState = applyObject.apply(name, new RefSpec(refName), revisionData); long elapsed = NANOSECONDS.toMillis(context.stop());
diff --git a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionData.java b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionData.java index bcd4e05..9c33d07 100644 --- a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionData.java +++ b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionData.java
@@ -43,4 +43,15 @@ public List<RevisionObjectData> getBlobs() { return blobs; } + + @Override + public String toString() { + return "{" + + (commitObject != null ? "commitObject=" + commitObject : "") + + " " + + (treeObject != null ? "treeObject=" + treeObject : "") + + " " + + (blobs != null && !blobs.isEmpty() ? "blobs=" + blobs : "") + + "}"; + } }
diff --git a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionObjectData.java b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionObjectData.java index 02ba06c..0962717 100644 --- a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionObjectData.java +++ b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/api/data/RevisionObjectData.java
@@ -15,6 +15,7 @@ package com.googlesource.gerrit.plugins.replication.pull.api.data; import java.util.Base64; +import org.eclipse.jgit.lib.Constants; public class RevisionObjectData { private final Integer type; @@ -32,4 +33,18 @@ public byte[] getContent() { return Base64.getDecoder().decode(content); } + + @Override + public String toString() { + switch (type) { + case Constants.OBJ_BLOB: + return "BLOB"; + case Constants.OBJ_COMMIT: + return "COMMIT"; + case Constants.OBJ_TREE: + return "TREE"; + default: + return "type:" + type; + } + } }
diff --git a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/client/HttpResult.java b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/client/HttpResult.java index bd164df..3efcacf 100644 --- a/src/main/java/com/googlesource/gerrit/plugins/replication/pull/client/HttpResult.java +++ b/src/main/java/com/googlesource/gerrit/plugins/replication/pull/client/HttpResult.java
@@ -47,4 +47,11 @@ public boolean isParentObjectMissing() { return responseCode == SC_CONFLICT; } + + @Override + public String toString() { + return isSuccessful() + ? "OK" + : "FAILED" + ", status=" + responseCode + message.map(s -> " '" + s + "'").orElse(""); + } }