X-Git-Url: https://git.opendaylight.org/gerrit/gitweb?p=controller.git;a=blobdiff_plain;f=opendaylight%2Fmd-sal%2Fsal-distributed-datastore%2Fsrc%2Fmain%2Fjava%2Forg%2Fopendaylight%2Fcontroller%2Fcluster%2Fdatastore%2FShard.java;h=9551c800ca003788de3beaf2898e48e4809cf1bb;hp=dea377a810cb73be01cf4c17dab93c4c2b476c1b;hb=18126649bba1cda7b589a4f23b96211562f9e008;hpb=3f2221486de63178fbfbb43508ce9466c0b23b73 diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/Shard.java b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/Shard.java index dea377a810..9551c800ca 100644 --- a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/Shard.java +++ b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/Shard.java @@ -11,10 +11,7 @@ package org.opendaylight.controller.cluster.datastore; import akka.actor.ActorRef; import akka.actor.ActorSelection; import akka.actor.Cancellable; -import akka.actor.PoisonPill; import akka.actor.Props; -import akka.event.Logging; -import akka.event.LoggingAdapter; import akka.japi.Creator; import akka.persistence.RecoveryFailure; import akka.serialization.Serialization; @@ -25,8 +22,6 @@ import com.google.common.collect.Lists; import com.google.common.util.concurrent.FutureCallback; import com.google.common.util.concurrent.Futures; import com.google.common.util.concurrent.ListenableFuture; -import com.google.protobuf.ByteString; -import com.google.protobuf.InvalidProtocolBufferException; import java.io.IOException; import java.util.Collection; import java.util.HashMap; @@ -52,13 +47,12 @@ import org.opendaylight.controller.cluster.datastore.messages.CanCommitTransacti import org.opendaylight.controller.cluster.datastore.messages.CloseTransactionChain; import org.opendaylight.controller.cluster.datastore.messages.CommitTransaction; import org.opendaylight.controller.cluster.datastore.messages.CommitTransactionReply; +import org.opendaylight.controller.cluster.datastore.messages.CreateSnapshot; import org.opendaylight.controller.cluster.datastore.messages.CreateTransaction; import org.opendaylight.controller.cluster.datastore.messages.CreateTransactionReply; import org.opendaylight.controller.cluster.datastore.messages.EnableNotification; import org.opendaylight.controller.cluster.datastore.messages.ForwardedReadyTransaction; import org.opendaylight.controller.cluster.datastore.messages.PeerAddressResolved; -import org.opendaylight.controller.cluster.datastore.messages.ReadData; -import org.opendaylight.controller.cluster.datastore.messages.ReadDataReply; import org.opendaylight.controller.cluster.datastore.messages.ReadyTransactionReply; import org.opendaylight.controller.cluster.datastore.messages.RegisterChangeListener; import org.opendaylight.controller.cluster.datastore.messages.RegisterChangeListenerReply; @@ -66,18 +60,18 @@ import org.opendaylight.controller.cluster.datastore.messages.UpdateSchemaContex import org.opendaylight.controller.cluster.datastore.modification.Modification; import org.opendaylight.controller.cluster.datastore.modification.ModificationPayload; import org.opendaylight.controller.cluster.datastore.modification.MutableCompositeModification; -import org.opendaylight.controller.cluster.datastore.node.NormalizedNodeToNodeCodec; +import org.opendaylight.controller.cluster.datastore.utils.MessageTracker; +import org.opendaylight.controller.cluster.datastore.utils.SerializationUtils; import org.opendaylight.controller.cluster.notifications.RoleChangeNotifier; import org.opendaylight.controller.cluster.raft.RaftActor; import org.opendaylight.controller.cluster.raft.ReplicatedLogEntry; -import org.opendaylight.controller.cluster.raft.base.messages.CaptureSnapshotReply; +import org.opendaylight.controller.cluster.raft.messages.AppendEntriesReply; import org.opendaylight.controller.cluster.raft.protobuff.client.messages.CompositeModificationByteStringPayload; import org.opendaylight.controller.cluster.raft.protobuff.client.messages.CompositeModificationPayload; import org.opendaylight.controller.cluster.raft.protobuff.client.messages.Payload; import org.opendaylight.controller.md.sal.common.api.data.AsyncDataChangeListener; import org.opendaylight.controller.md.sal.dom.store.impl.InMemoryDOMDataStore; import org.opendaylight.controller.md.sal.dom.store.impl.InMemoryDOMDataStoreFactory; -import org.opendaylight.controller.protobuff.messages.common.NormalizedNodeMessages; import org.opendaylight.controller.sal.core.spi.data.DOMStoreThreePhaseCommitCohort; import org.opendaylight.controller.sal.core.spi.data.DOMStoreTransactionChain; import org.opendaylight.controller.sal.core.spi.data.DOMStoreTransactionFactory; @@ -97,6 +91,8 @@ import scala.concurrent.duration.FiniteDuration; */ public class Shard extends RaftActor { + private static final YangInstanceIdentifier DATASTORE_ROOT = YangInstanceIdentifier.builder().build(); + private static final Object TX_COMMIT_TIMEOUT_CHECK_MESSAGE = "txCommitTimeoutCheck"; @VisibleForTesting @@ -105,9 +101,6 @@ public class Shard extends RaftActor { // The state of this Shard private final InMemoryDOMDataStore store; - private final LoggingAdapter LOG = - Logging.getLogger(getContext().system(), this); - /// The name of this shard private final ShardIdentifier name; @@ -124,8 +117,6 @@ public class Shard extends RaftActor { private SchemaContext schemaContext; - private ActorRef createSnapshotTransaction; - private int createSnapshotTransactionCounter; private final ShardCommitCoordinator commitCoordinator; @@ -136,6 +127,8 @@ public class Shard extends RaftActor { private final Optional roleChangeNotifier; + private final MessageTracker appendEntriesReplyTracker; + /** * Coordinates persistence recovery on startup. */ @@ -154,7 +147,7 @@ public class Shard extends RaftActor { this.schemaContext = schemaContext; this.dataPersistenceProvider = (datastoreContext.isPersistent()) ? new PersistentDataProvider() : new NonPersistentRaftDataProvider(); - LOG.info("Shard created : {} persistent : {}", name, datastoreContext.isPersistent()); + LOG.info("Shard created : {}, persistent : {}", name, datastoreContext.isPersistent()); store = InMemoryDOMDataStoreFactory.create(name.toString(), null, datastoreContext.getDataStoreProperties()); @@ -172,13 +165,16 @@ public class Shard extends RaftActor { } commitCoordinator = new ShardCommitCoordinator(TimeUnit.SECONDS.convert(1, TimeUnit.MINUTES), - datastoreContext.getShardTransactionCommitQueueCapacity()); + datastoreContext.getShardTransactionCommitQueueCapacity(), LOG, name.toString()); transactionCommitTimeout = TimeUnit.MILLISECONDS.convert( datastoreContext.getShardTransactionCommitTimeoutInSeconds(), TimeUnit.SECONDS); // create a notifier actor for each cluster member roleChangeNotifier = createRoleChangeNotifier(name.toString()); + + appendEntriesReplyTracker = new MessageTracker(AppendEntriesReply.class, + getRaftActorContext().getConfigParams().getIsolatedCheckIntervalInMillis()); } private static Map mapPeerAddresses( @@ -222,54 +218,63 @@ public class Shard extends RaftActor { @Override public void onReceiveRecover(final Object message) throws Exception { if(LOG.isDebugEnabled()) { - LOG.debug("onReceiveRecover: Received message {} from {}", - message.getClass().toString(), - getSender()); + LOG.debug("{}: onReceiveRecover: Received message {} from {}", persistenceId(), + message.getClass().toString(), getSender()); } if (message instanceof RecoveryFailure){ - LOG.error(((RecoveryFailure) message).cause(), "Recovery failed because of this cause"); + LOG.error("{}: Recovery failed because of this cause", + persistenceId(), ((RecoveryFailure) message).cause()); // Even though recovery failed, we still need to finish our recovery, eg send the // ActorInitialized message and start the txCommitTimeoutCheckSchedule. onRecoveryComplete(); } else { super.onReceiveRecover(message); + if(LOG.isTraceEnabled()) { + appendEntriesReplyTracker.begin(); + } } } @Override public void onReceiveCommand(final Object message) throws Exception { - if(LOG.isDebugEnabled()) { - LOG.debug("onReceiveCommand: Received message {} from {}", message, getSender()); - } - - if(message.getClass().equals(ReadDataReply.SERIALIZABLE_CLASS)) { - handleReadDataReply(message); - } else if (message.getClass().equals(CreateTransaction.SERIALIZABLE_CLASS)) { - handleCreateTransaction(message); - } else if(message instanceof ForwardedReadyTransaction) { - handleForwardedReadyTransaction((ForwardedReadyTransaction)message); - } else if(message.getClass().equals(CanCommitTransaction.SERIALIZABLE_CLASS)) { - handleCanCommitTransaction(CanCommitTransaction.fromSerializable(message)); - } else if(message.getClass().equals(CommitTransaction.SERIALIZABLE_CLASS)) { - handleCommitTransaction(CommitTransaction.fromSerializable(message)); - } else if(message.getClass().equals(AbortTransaction.SERIALIZABLE_CLASS)) { - handleAbortTransaction(AbortTransaction.fromSerializable(message)); - } else if (message.getClass().equals(CloseTransactionChain.SERIALIZABLE_CLASS)){ - closeTransactionChain(CloseTransactionChain.fromSerializable(message)); - } else if (message instanceof RegisterChangeListener) { - registerChangeListener((RegisterChangeListener) message); - } else if (message instanceof UpdateSchemaContext) { - updateSchemaContext((UpdateSchemaContext) message); - } else if (message instanceof PeerAddressResolved) { - PeerAddressResolved resolved = (PeerAddressResolved) message; - setPeerAddress(resolved.getPeerId().toString(), - resolved.getPeerAddress()); - } else if(message.equals(TX_COMMIT_TIMEOUT_CHECK_MESSAGE)) { - handleTransactionCommitTimeoutCheck(); - } else { - super.onReceiveCommand(message); + + MessageTracker.Context context = appendEntriesReplyTracker.received(message); + + if(context.error().isPresent()){ + LOG.trace("{} : AppendEntriesReply failed to arrive at the expected interval {}", persistenceId(), + context.error()); + } + + try { + if (message.getClass().equals(CreateTransaction.SERIALIZABLE_CLASS)) { + handleCreateTransaction(message); + } else if (message instanceof ForwardedReadyTransaction) { + handleForwardedReadyTransaction((ForwardedReadyTransaction) message); + } else if (message.getClass().equals(CanCommitTransaction.SERIALIZABLE_CLASS)) { + handleCanCommitTransaction(CanCommitTransaction.fromSerializable(message)); + } else if (message.getClass().equals(CommitTransaction.SERIALIZABLE_CLASS)) { + handleCommitTransaction(CommitTransaction.fromSerializable(message)); + } else if (message.getClass().equals(AbortTransaction.SERIALIZABLE_CLASS)) { + handleAbortTransaction(AbortTransaction.fromSerializable(message)); + } else if (message.getClass().equals(CloseTransactionChain.SERIALIZABLE_CLASS)) { + closeTransactionChain(CloseTransactionChain.fromSerializable(message)); + } else if (message instanceof RegisterChangeListener) { + registerChangeListener((RegisterChangeListener) message); + } else if (message instanceof UpdateSchemaContext) { + updateSchemaContext((UpdateSchemaContext) message); + } else if (message instanceof PeerAddressResolved) { + PeerAddressResolved resolved = (PeerAddressResolved) message; + setPeerAddress(resolved.getPeerId().toString(), + resolved.getPeerAddress()); + } else if (message.equals(TX_COMMIT_TIMEOUT_CHECK_MESSAGE)) { + handleTransactionCommitTimeoutCheck(); + } else { + super.onReceiveCommand(message); + } + } finally { + context.done(); } } @@ -283,8 +288,8 @@ public class Shard extends RaftActor { if(cohortEntry != null) { long elapsed = System.currentTimeMillis() - cohortEntry.getLastAccessTime(); if(elapsed > transactionCommitTimeout) { - LOG.warning("Current transaction {} has timed out after {} ms - aborting", - cohortEntry.getTransactionID(), transactionCommitTimeout); + LOG.warn("{}: Current transaction {} has timed out after {} ms - aborting", + persistenceId(), cohortEntry.getTransactionID(), transactionCommitTimeout); doAbortTransaction(cohortEntry.getTransactionID(), null); } @@ -294,7 +299,7 @@ public class Shard extends RaftActor { private void handleCommitTransaction(final CommitTransaction commit) { final String transactionID = commit.getTransactionID(); - LOG.debug("Committing transaction {}", transactionID); + LOG.debug("{}: Committing transaction {}", persistenceId(), transactionID); // Get the current in-progress cohort entry in the commitCoordinator if it corresponds to // this transaction. @@ -303,8 +308,8 @@ public class Shard extends RaftActor { // We're not the current Tx - the Tx was likely expired b/c it took too long in // between the canCommit and commit messages. IllegalStateException ex = new IllegalStateException( - String.format("Cannot commit transaction %s - it is not the current transaction", - transactionID)); + String.format("%s: Cannot commit transaction %s - it is not the current transaction", + persistenceId(), transactionID)); LOG.error(ex.getMessage()); shardMBean.incrementFailedTransactionsCount(); getSender().tell(new akka.actor.Status.Failure(ex), getSelf()); @@ -330,9 +335,9 @@ public class Shard extends RaftActor { Shard.this.persistData(getSender(), transactionID, new ModificationPayload(cohortEntry.getModification())); } - } catch (InterruptedException | ExecutionException | IOException e) { - LOG.error(e, "An exception occurred while preCommitting transaction {}", - cohortEntry.getTransactionID()); + } catch (Exception e) { + LOG.error("{} An exception occurred while preCommitting transaction {}", + persistenceId(), cohortEntry.getTransactionID(), e); shardMBean.incrementFailedTransactionsCount(); getSender().tell(new akka.actor.Status.Failure(e), getSelf()); } @@ -360,8 +365,8 @@ public class Shard extends RaftActor { // This really shouldn't happen - it likely means that persistence or replication // took so long to complete such that the cohort entry was expired from the cache. IllegalStateException ex = new IllegalStateException( - String.format("Could not finish committing transaction %s - no CohortEntry found", - transactionID)); + String.format("%s: Could not finish committing transaction %s - no CohortEntry found", + persistenceId(), transactionID)); LOG.error(ex.getMessage()); sender.tell(new akka.actor.Status.Failure(ex), getSelf()); } @@ -369,7 +374,7 @@ public class Shard extends RaftActor { return; } - LOG.debug("Finishing commit for transaction {}", cohortEntry.getTransactionID()); + LOG.debug("{}: Finishing commit for transaction {}", persistenceId(), cohortEntry.getTransactionID()); try { // We block on the future here so we don't have to worry about possibly accessing our @@ -382,24 +387,25 @@ public class Shard extends RaftActor { shardMBean.incrementCommittedTransactionCount(); shardMBean.setLastCommittedTransactionTime(System.currentTimeMillis()); - } catch (InterruptedException | ExecutionException e) { + } catch (Exception e) { sender.tell(new akka.actor.Status.Failure(e), getSelf()); - LOG.error(e, "An exception occurred while committing transaction {}", transactionID); + LOG.error("{}, An exception occurred while committing transaction {}", persistenceId(), + transactionID, e); shardMBean.incrementFailedTransactionsCount(); + } finally { + commitCoordinator.currentTransactionComplete(transactionID, true); } - - commitCoordinator.currentTransactionComplete(transactionID, true); } private void handleCanCommitTransaction(final CanCommitTransaction canCommit) { - LOG.debug("Can committing transaction {}", canCommit.getTransactionID()); + LOG.debug("{}: Can committing transaction {}", persistenceId(), canCommit.getTransactionID()); commitCoordinator.handleCanCommit(canCommit, getSender(), self()); } private void handleForwardedReadyTransaction(ForwardedReadyTransaction ready) { - LOG.debug("Readying transaction {}, client version {}", ready.getTransactionID(), - ready.getTxnClientVersion()); + LOG.debug("{}: Readying transaction {}, client version {}", persistenceId(), + ready.getTransactionID(), ready.getTxnClientVersion()); // This message is forwarded by the ShardTransaction on ready. We cache the cohort in the // commitCoordinator in preparation for the subsequent three phase commit initiated by @@ -414,7 +420,7 @@ public class Shard extends RaftActor { // to provide the compatible behavior. ActorRef replyActorPath = self(); if(ready.getTxnClientVersion() < DataStoreVersions.HELIUM_1_VERSION) { - LOG.debug("Creating BackwardsCompatibleThreePhaseCommitCohort"); + LOG.debug("{}: Creating BackwardsCompatibleThreePhaseCommitCohort", persistenceId()); replyActorPath = getContext().actorOf(BackwardsCompatibleThreePhaseCommitCohort.props( ready.getTransactionID())); } @@ -432,7 +438,7 @@ public class Shard extends RaftActor { void doAbortTransaction(final String transactionID, final ActorRef sender) { final CohortEntry cohortEntry = commitCoordinator.getCohortEntryIfCurrent(transactionID); if(cohortEntry != null) { - LOG.debug("Aborting transaction {}", transactionID); + LOG.debug("{}: Aborting transaction {}", persistenceId(), transactionID); // We don't remove the cached cohort entry here (ie pass false) in case the Tx was // aborted during replication in which case we may still commit locally if replication @@ -454,7 +460,7 @@ public class Shard extends RaftActor { @Override public void onFailure(final Throwable t) { - LOG.error(t, "An exception happened during abort"); + LOG.error("{}: An exception happened during abort", persistenceId(), t); if(sender != null) { sender.tell(new akka.actor.Status.Failure(t), self); @@ -470,27 +476,13 @@ public class Shard extends RaftActor { } else if (getLeader() != null) { getLeader().forward(message, getContext()); } else { - getSender().tell(new akka.actor.Status.Failure(new NoShardLeaderException( - "Could not find shard leader so transaction cannot be created. This typically happens" + + getSender().tell(new akka.actor.Status.Failure(new NoShardLeaderException(String.format( + "Could not find leader for shard %s so transaction cannot be created. This typically happens" + " when the system is coming up or recovering and a leader is being elected. Try again" + - " later.")), getSelf()); + " later.", persistenceId()))), getSelf()); } } - private void handleReadDataReply(final Object message) { - // This must be for install snapshot. Don't want to open this up and trigger - // deSerialization - - self().tell(new CaptureSnapshotReply(ReadDataReply.fromSerializableAsByteString(message)), - self()); - - createSnapshotTransaction = null; - - // Send a PoisonPill instead of sending close transaction because we do not really need - // a response - getSender().tell(PoisonPill.getInstance(), self()); - } - private void closeTransactionChain(final CloseTransactionChain closeTransactionChain) { DOMStoreTransactionChain chain = transactionChains.remove(closeTransactionChain.getTransactionChainId()); @@ -525,7 +517,7 @@ public class Shard extends RaftActor { return getContext().actorOf( ShardTransaction.props(factory.newReadOnlyTransaction(), getSelf(), - schemaContext,datastoreContext, shardMBean, + schemaContext, datastoreContext, shardMBean, transactionId.getRemoteTransactionId(), clientVersion), transactionId.toString()); @@ -578,7 +570,7 @@ public class Shard extends RaftActor { .build(); if(LOG.isDebugEnabled()) { - LOG.debug("Creating transaction : {} ", transactionId); + LOG.debug("{}: Creating transaction : {} ", persistenceId(), transactionId); } ActorRef transactionActor = createTypedTransactionActor(transactionType, transactionId, @@ -603,7 +595,7 @@ public class Shard extends RaftActor { shardMBean.setLastCommittedTransactionTime(System.currentTimeMillis()); } catch (InterruptedException | ExecutionException e) { shardMBean.incrementFailedTransactionsCount(); - LOG.error(e, "Failed to commit"); + LOG.error("{}: Failed to commit", persistenceId(), e); } } @@ -620,14 +612,14 @@ public class Shard extends RaftActor { private void registerChangeListener(final RegisterChangeListener registerChangeListener) { - LOG.debug("registerDataChangeListener for {}", registerChangeListener.getPath()); + LOG.debug("{}: registerDataChangeListener for {}", persistenceId(), registerChangeListener.getPath()); ListenerRegistration>> registration; if(isLeader()) { registration = doChangeListenerRegistration(registerChangeListener); } else { - LOG.debug("Shard is not the leader - delaying registration"); + LOG.debug("{}: Shard is not the leader - delaying registration", persistenceId()); DelayedListenerRegistration delayedReg = new DelayedListenerRegistration(registerChangeListener); @@ -638,8 +630,8 @@ public class Shard extends RaftActor { ActorRef listenerRegistration = getContext().actorOf( DataChangeListenerRegistration.props(registration)); - LOG.debug("registerDataChangeListener sending reply, listenerRegistrationPath = {} ", - listenerRegistration.path()); + LOG.debug("{}: registerDataChangeListener sending reply, listenerRegistrationPath = {} ", + persistenceId(), listenerRegistration.path()); getSender().tell(new RegisterChangeListenerReply(listenerRegistration.path()), getSelf()); } @@ -663,7 +655,7 @@ public class Shard extends RaftActor { AsyncDataChangeListener> listener = new DataChangeListenerProxy(dataChangeListenerPath); - LOG.debug("Registering for path {}", registerChangeListener.getPath()); + LOG.debug("{}: Registering for path {}", persistenceId(), registerChangeListener.getPath()); return store.registerChangeListener(registerChangeListener.getPath(), listener, registerChangeListener.getScope()); @@ -680,7 +672,7 @@ public class Shard extends RaftActor { currentLogRecoveryBatch = Lists.newArrayListWithCapacity(maxBatchSize); if(LOG.isDebugEnabled()) { - LOG.debug("{} : starting log recovery batch with max size {}", persistenceId(), maxBatchSize); + LOG.debug("{}: starting log recovery batch with max size {}", persistenceId(), maxBatchSize); } } @@ -690,40 +682,42 @@ public class Shard extends RaftActor { try { currentLogRecoveryBatch.add(((ModificationPayload) data).getModification()); } catch (ClassNotFoundException | IOException e) { - LOG.error(e, "Error extracting ModificationPayload"); + LOG.error("{}: Error extracting ModificationPayload", persistenceId(), e); } } else if (data instanceof CompositeModificationPayload) { currentLogRecoveryBatch.add(((CompositeModificationPayload) data).getModification()); } else if (data instanceof CompositeModificationByteStringPayload) { currentLogRecoveryBatch.add(((CompositeModificationByteStringPayload) data).getModification()); } else { - LOG.error("Unknown state received {} during recovery", data); + LOG.error("{}: Unknown state received {} during recovery", persistenceId(), data); } } @Override - protected void applyRecoverySnapshot(final ByteString snapshot) { + protected void applyRecoverySnapshot(final byte[] snapshotBytes) { if(recoveryCoordinator == null) { - recoveryCoordinator = new ShardRecoveryCoordinator(persistenceId(), schemaContext); + recoveryCoordinator = new ShardRecoveryCoordinator(persistenceId(), schemaContext, + LOG, name.toString()); } - recoveryCoordinator.submit(snapshot, store.newWriteOnlyTransaction()); + recoveryCoordinator.submit(snapshotBytes, store.newWriteOnlyTransaction()); if(LOG.isDebugEnabled()) { - LOG.debug("{} : submitted recovery sbapshot", persistenceId()); + LOG.debug("{}: submitted recovery sbapshot", persistenceId()); } } @Override protected void applyCurrentLogRecoveryBatch() { if(recoveryCoordinator == null) { - recoveryCoordinator = new ShardRecoveryCoordinator(persistenceId(), schemaContext); + recoveryCoordinator = new ShardRecoveryCoordinator(persistenceId(), schemaContext, + LOG, name.toString()); } recoveryCoordinator.submit(currentLogRecoveryBatch, store.newWriteOnlyTransaction()); if(LOG.isDebugEnabled()) { - LOG.debug("{} : submitted log recovery batch with size {}", persistenceId(), + LOG.debug("{}: submitted log recovery batch with size {}", persistenceId(), currentLogRecoveryBatch.size()); } } @@ -734,7 +728,7 @@ public class Shard extends RaftActor { Collection txList = recoveryCoordinator.getTransactions(); if(LOG.isDebugEnabled()) { - LOG.debug("{} : recovery complete - committing {} Tx's", persistenceId(), txList.size()); + LOG.debug("{}: recovery complete - committing {} Tx's", persistenceId(), txList.size()); } for(DOMStoreWriteTransaction tx: txList) { @@ -743,7 +737,7 @@ public class Shard extends RaftActor { shardMBean.incrementCommittedTransactionCount(); } catch (InterruptedException | ExecutionException e) { shardMBean.incrementFailedTransactionsCount(); - LOG.error(e, "Failed to commit"); + LOG.error("{}: Failed to commit", persistenceId(), e); } } } @@ -773,7 +767,7 @@ public class Shard extends RaftActor { try { applyModificationToState(clientActor, identifier, ((ModificationPayload) data).getModification()); } catch (ClassNotFoundException | IOException e) { - LOG.error(e, "Error extracting ModificationPayload"); + LOG.error("{}: Error extracting ModificationPayload", persistenceId(), e); } } else if (data instanceof CompositeModificationPayload) { @@ -785,8 +779,8 @@ public class Shard extends RaftActor { applyModificationToState(clientActor, identifier, modification); } else { - LOG.error("Unknown state received {} Class loader = {} CompositeNodeMod.ClassLoader = {}", - data, data.getClass().getClassLoader(), + LOG.error("{}: Unknown state received {} Class loader = {} CompositeNodeMod.ClassLoader = {}", + persistenceId(), data, data.getClass().getClassLoader(), CompositeModificationPayload.class.getClassLoader()); } @@ -797,8 +791,8 @@ public class Shard extends RaftActor { private void applyModificationToState(ActorRef clientActor, String identifier, Object modification) { if(modification == null) { LOG.error( - "modification is null - this is very unexpected, clientActor = {}, identifier = {}", - identifier, clientActor != null ? clientActor.path().toString() : null); + "{}: modification is null - this is very unexpected, clientActor = {}, identifier = {}", + persistenceId(), identifier, clientActor != null ? clientActor.path().toString() : null); } else if(clientActor == null) { // There's no clientActor to which to send a commit reply so we must be applying // replicated state from the leader. @@ -824,45 +818,41 @@ public class Shard extends RaftActor { @Override protected void createSnapshot() { - if (createSnapshotTransaction == null) { + // Create a transaction actor. We are really going to treat the transaction as a worker + // so that this actor does not get block building the snapshot. THe transaction actor will + // after processing the CreateSnapshot message. - // Create a transaction. We are really going to treat the transaction as a worker - // so that this actor does not get block building the snapshot - createSnapshotTransaction = createTransaction( + ActorRef createSnapshotTransaction = createTransaction( TransactionProxy.TransactionType.READ_ONLY.ordinal(), "createSnapshot" + ++createSnapshotTransactionCounter, "", DataStoreVersions.CURRENT_VERSION); - createSnapshotTransaction.tell( - new ReadData(YangInstanceIdentifier.builder().build()).toSerializable(), self()); - - } + createSnapshotTransaction.tell(CreateSnapshot.INSTANCE, self()); } @VisibleForTesting @Override - protected void applySnapshot(final ByteString snapshot) { + protected void applySnapshot(final byte[] snapshotBytes) { // Since this will be done only on Recovery or when this actor is a Follower // we can safely commit everything in here. We not need to worry about event notifications // as they would have already been disabled on the follower - LOG.info("Applying snapshot"); + LOG.info("{}: Applying snapshot", persistenceId()); try { DOMStoreWriteTransaction transaction = store.newWriteOnlyTransaction(); - NormalizedNodeMessages.Node serializedNode = NormalizedNodeMessages.Node.parseFrom(snapshot); - NormalizedNode node = new NormalizedNodeToNodeCodec(schemaContext) - .decode(serializedNode); + + NormalizedNode node = SerializationUtils.deserializeNormalizedNode(snapshotBytes); // delete everything first - transaction.delete(YangInstanceIdentifier.builder().build()); + transaction.delete(DATASTORE_ROOT); // Add everything from the remote node back - transaction.write(YangInstanceIdentifier.builder().build(), node); + transaction.write(DATASTORE_ROOT, node); syncCommitTransaction(transaction); - } catch (InvalidProtocolBufferException | InterruptedException | ExecutionException e) { - LOG.error(e, "An exception occurred when applying snapshot"); + } catch (InterruptedException | ExecutionException e) { + LOG.error("{}: An exception occurred when applying snapshot", persistenceId(), e); } finally { - LOG.info("Done applying snapshot"); + LOG.info("{}: Done applying snapshot", persistenceId()); } } @@ -891,8 +881,8 @@ public class Shard extends RaftActor { for(Map.Entry entry : transactionChains.entrySet()){ if(LOG.isDebugEnabled()) { LOG.debug( - "onStateChanged: Closing transaction chain {} because shard {} is no longer the leader", - entry.getKey(), getId()); + "{}: onStateChanged: Closing transaction chain {} because shard {} is no longer the leader", + persistenceId(), entry.getKey(), getId()); } entry.getValue().close(); }