This is an automated email from the ASF dual-hosted git repository. asf-gitbox-commits pushed a commit to branch branch_10_1 in repository https://gitbox.apache.org/repos/asf/solr.git
commit 295bd6c57efde8fc140d22092e0dbbc905c5ee02 Author: David Smiley <[email protected]> AuthorDate: Wed Oct 7 17:59:34 2026 -0400 SOLR-18124: Trace RecoveryStrategy with a span and events (#4961) Co-authored-by: Claude Opus 5.5 <[email protected]> (cherry picked from commit 709d65ec2f72ea393e30a3bc38c69ef51c0b2b36) (cherry picked from commit 5087d328a6a62e05089d814344187d770649ca3a) --- .../org/apache/solr/cloud/RecoveryStrategy.java | 54 +++++++++++++++++++++- 1 file changed, 53 insertions(+), 1 deletion(-) diff --git a/solr/core/src/java/org/apache/solr/cloud/RecoveryStrategy.java b/solr/core/src/java/org/apache/solr/cloud/RecoveryStrategy.java index 64b288ab6ad..38a0d8a0d1e 100644 --- a/solr/core/src/java/org/apache/solr/cloud/RecoveryStrategy.java +++ b/solr/core/src/java/org/apache/solr/cloud/RecoveryStrategy.java @@ -16,6 +16,9 @@ */ package org.apache.solr.cloud; +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.api.trace.Span; import java.io.Closeable; import java.io.IOException; import java.lang.invoke.MethodHandles; @@ -68,6 +71,7 @@ import org.apache.solr.util.RTimer; import org.apache.solr.util.RefCounted; import org.apache.solr.util.SolrPluginUtils; import org.apache.solr.util.plugin.NamedListInitializedPlugin; +import org.apache.solr.util.tracing.TraceUtils; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -103,6 +107,10 @@ public class RecoveryStrategy implements Runnable, Closeable { private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); + private static final AttributeKey<String> LEADER_ATTR = AttributeKey.stringKey("leader"); + private static final AttributeKey<Long> RETRY_ATTR = AttributeKey.longKey("retry"); + private static final AttributeKey<Boolean> SUCCESS_ATTR = AttributeKey.booleanKey("success"); + private int waitForUpdatesWithStaleStatePauseMilliSeconds = Integer.getInteger("solr.cloud.wait-for-updates-with-stale-state-pause", 2500); private int maxRetries = 500; @@ -131,6 +139,9 @@ public class RecoveryStrategy implements Runnable, Closeable { private CoreDescriptor coreDescriptor; + /** Recorded on the trace span; null until recovery reaches a terminal state. */ + private String outcome; + protected RecoveryStrategy( CoreContainer cc, CoreDescriptor cd, RecoveryListener recoveryListener) { this.cc = cc; @@ -205,6 +216,7 @@ public class RecoveryStrategy implements Runnable, Closeable { private final void recoveryFailed(final ZkController zkController, final CoreDescriptor cd) throws Exception { log.error("Recovery failed - I give up."); + setOutcome("failed"); try { zkController.publish(cd, Replica.State.RECOVERY_FAILED); } finally { @@ -230,6 +242,7 @@ public class RecoveryStrategy implements Runnable, Closeable { final String leaderCore = URLUtil.extractCoreFromCoreUrl(getReplicateLeaderUrl(leaderprops)); log.info("Attempting to replicate from core [{}] on node [{}].", leaderCore, leaderBaseUrl); + Span.current().addEvent("replicate"); // send commit if replica could be a leader if (replicaType.leaderEligible) { @@ -323,15 +336,33 @@ public class RecoveryStrategy implements Runnable, Closeable { log.info("Starting recovery process. recoveringAfterStartup={}", recoveringAfterStartup); final RTimer timer = new RTimer(); - try { + final Span span = + TraceUtils.getGlobalTracer() + .spanBuilder("recovery") + .setAttribute(TraceUtils.TAG_DB, coreName) + .setAttribute("recovery.afterStartup", recoveringAfterStartup) + .startSpan(); + try (var scope = span.makeCurrent()) { + assert scope != null; // prevent javac warning about scope being unused doRecovery(core); } catch (InterruptedException e) { Thread.currentThread().interrupt(); log.error("interrupted", e); + span.recordException(e); throw new ZooKeeperException(SolrException.ErrorCode.SERVER_ERROR, "", e); } catch (Exception e) { log.error("", e); + span.recordException(e); throw new ZooKeeperException(SolrException.ErrorCode.SERVER_ERROR, "", e); + } finally { + if (outcome == null && isClosed()) { + outcome = "closed"; + } + if (outcome != null) { + span.setAttribute("recovery.outcome", outcome); + } + span.setAttribute("recovery.retries", retries); + span.end(); } if (log.isInfoEnabled()) { @@ -348,8 +379,10 @@ public class RecoveryStrategy implements Runnable, Closeable { this.coreDescriptor = core.getCoreDescriptor(); if (this.coreDescriptor.getCloudDescriptor().getReplicaType().requireTransactionLog) { + Span.current().setAttribute("recovery.strategy", "syncOrReplicate"); doSyncOrReplicateRecovery(core); } else { + Span.current().setAttribute("recovery.strategy", "replicateOnly"); doReplicateOnlyRecovery(core); } } @@ -373,6 +406,7 @@ public class RecoveryStrategy implements Runnable, Closeable { zkStateReader.getLeaderRetry(cloudDesc.getCollectionName(), cloudDesc.getShardId()); final String leaderUrl = leader.getCoreUrl(); final String ourUrl = ZkCoreNodeProps.getCoreUrl(baseUrl, coreName); + Span.current().addEvent("leaderFound", Attributes.of(LEADER_ATTR, leaderUrl)); // TODO: We can probably delete most of this code if we say this strategy can only be used // for pull replicas @@ -385,6 +419,7 @@ public class RecoveryStrategy implements Runnable, Closeable { // we are now the leader - no one else must have been suitable log.warn("We have not yet recovered - but we are now the leader!"); log.info("Finished recovery process."); + setOutcome("becameLeader"); zkController.publish(this.coreDescriptor, Replica.State.ACTIVE); return; } @@ -435,6 +470,7 @@ public class RecoveryStrategy implements Runnable, Closeable { zkController.startReplicationFromLeader(coreName, false); } log.info("Registering as Active after recovery."); + Span.current().addEvent("publishActive"); try { zkController.publish(this.coreDescriptor, Replica.State.ACTIVE); } catch (Exception e) { @@ -443,6 +479,7 @@ public class RecoveryStrategy implements Runnable, Closeable { } if (successfulRecovery) { + setOutcome("recovered"); close = true; recoveryListener.recovered(); } @@ -476,6 +513,7 @@ public class RecoveryStrategy implements Runnable, Closeable { } log.error("Recovery failed - trying again... ({})", retries); + Span.current().addEvent("retry", Attributes.of(RETRY_ATTR, (long) retries)); retries++; if (retries >= maxRetries) { @@ -613,6 +651,7 @@ public class RecoveryStrategy implements Runnable, Closeable { log.info("RecoveryStrategy has been closed"); break; } + Span.current().addEvent("leaderFound", Attributes.of(LEADER_ATTR, leader.getCoreUrl())); boolean isLeader = leader.getCoreUrl().equals(ourUrl); if (isLeader && !cloudDesc.isLeader()) { @@ -622,11 +661,13 @@ public class RecoveryStrategy implements Runnable, Closeable { // we are now the leader - no one else must have been suitable log.warn("We have not yet recovered - but we are now the leader!"); log.info("Finished recovery process."); + setOutcome("becameLeader"); zkController.publish(this.coreDescriptor, Replica.State.ACTIVE); return; } log.info("Begin buffering updates. core=[{}]", coreName); + Span.current().addEvent("bufferUpdates"); // recalling buffer updates will drop the old buffer tlog ulog.bufferUpdates(); @@ -683,11 +724,13 @@ public class RecoveryStrategy implements Runnable, Closeable { } // System.out.println("Attempting to PeerSync from " + leaderUrl // + " i am:" + zkController.getNodeName()); + Span.current().addEvent("peerSync"); boolean syncSuccess; try (PeerSyncWithLeader peerSyncWithLeader = new PeerSyncWithLeader(core, leader.getCoreUrl(), ulog.getNumRecordsToKeep())) { syncSuccess = peerSyncWithLeader.sync(recentVersions).isSuccess(); } + Span.current().addEvent("peerSyncDone", Attributes.of(SUCCESS_ATTR, syncSuccess)); if (syncSuccess) { SolrQueryRequest req = new SolrQueryRequestBase(core, new ModifiableSolrParams()); // force open a new searcher @@ -747,6 +790,7 @@ public class RecoveryStrategy implements Runnable, Closeable { } finally { if (successfulRecovery) { log.info("Registering as Active after recovery."); + Span.current().addEvent("publishActive"); try { if (replicaType.replicateFromLeader) { zkController.startReplicationFromLeader(coreName, true); @@ -758,6 +802,7 @@ public class RecoveryStrategy implements Runnable, Closeable { } if (successfulRecovery) { + setOutcome("recovered"); close = true; recoveryListener.recovered(); } @@ -863,8 +908,10 @@ public class RecoveryStrategy implements Runnable, Closeable { log.info("No replay needed."); } else { log.info("Replaying buffered documents."); + Span.current().addEvent("replay"); // wait for replay RecoveryInfo report = future.get(); + Span.current().addEvent("replayDone", Attributes.of(SUCCESS_ATTR, !report.failed)); if (report.failed) { log.error("Replay failed"); throw new SolrException(ErrorCode.SERVER_ERROR, "Replay failed"); @@ -900,6 +947,11 @@ public class RecoveryStrategy implements Runnable, Closeable { } } + private void setOutcome(String outcome) { + this.outcome = outcome; + Span.current().addEvent(outcome); + } + public final boolean isClosed() { return close || cc.isShutDown(); }
