Notify listeners on applySnapshot
[controller.git] / opendaylight / md-sal / sal-distributed-datastore / src / main / java / org / opendaylight / controller / cluster / datastore / ShardDataTree.java
1 /*
2  * Copyright (c) 2015 Cisco Systems, Inc. and others.  All rights reserved.
3  *
4  * This program and the accompanying materials are made available under the
5  * terms of the Eclipse Public License v1.0 which accompanies this distribution,
6  * and is available at http://www.eclipse.org/legal/epl-v10.html
7  */
8 package org.opendaylight.controller.cluster.datastore;
9
10 import akka.actor.ActorRef;
11 import akka.util.Timeout;
12 import com.google.common.annotations.VisibleForTesting;
13 import com.google.common.base.Optional;
14 import com.google.common.base.Preconditions;
15 import com.google.common.base.Stopwatch;
16 import com.google.common.base.Verify;
17 import com.google.common.collect.ImmutableList;
18 import com.google.common.collect.ImmutableMap;
19 import com.google.common.collect.ImmutableMap.Builder;
20 import com.google.common.primitives.UnsignedLong;
21 import java.io.File;
22 import java.io.IOException;
23 import java.util.AbstractMap.SimpleEntry;
24 import java.util.ArrayDeque;
25 import java.util.ArrayList;
26 import java.util.Collection;
27 import java.util.HashMap;
28 import java.util.Iterator;
29 import java.util.Map;
30 import java.util.Map.Entry;
31 import java.util.Queue;
32 import java.util.concurrent.ExecutionException;
33 import java.util.concurrent.TimeUnit;
34 import java.util.concurrent.TimeoutException;
35 import java.util.function.UnaryOperator;
36 import javax.annotation.Nonnull;
37 import javax.annotation.concurrent.NotThreadSafe;
38 import org.opendaylight.controller.cluster.access.concepts.LocalHistoryIdentifier;
39 import org.opendaylight.controller.cluster.access.concepts.TransactionIdentifier;
40 import org.opendaylight.controller.cluster.datastore.DataTreeCohortActorRegistry.CohortRegistryCommand;
41 import org.opendaylight.controller.cluster.datastore.ShardDataTreeCohort.State;
42 import org.opendaylight.controller.cluster.datastore.persisted.CommitTransactionPayload;
43 import org.opendaylight.controller.cluster.datastore.persisted.MetadataShardDataTreeSnapshot;
44 import org.opendaylight.controller.cluster.datastore.persisted.ShardDataTreeSnapshot;
45 import org.opendaylight.controller.cluster.datastore.persisted.ShardDataTreeSnapshotMetadata;
46 import org.opendaylight.controller.cluster.datastore.utils.DataTreeModificationOutput;
47 import org.opendaylight.controller.cluster.datastore.utils.PruningDataTreeModification;
48 import org.opendaylight.controller.cluster.raft.protobuff.client.messages.Payload;
49 import org.opendaylight.controller.md.sal.common.api.data.AsyncDataBroker.DataChangeScope;
50 import org.opendaylight.controller.md.sal.common.api.data.AsyncDataChangeListener;
51 import org.opendaylight.controller.md.sal.common.api.data.OptimisticLockFailedException;
52 import org.opendaylight.controller.md.sal.common.api.data.TransactionCommitFailedException;
53 import org.opendaylight.controller.md.sal.dom.api.DOMDataTreeChangeListener;
54 import org.opendaylight.controller.md.sal.dom.store.impl.DataChangeListenerRegistration;
55 import org.opendaylight.yangtools.concepts.Identifier;
56 import org.opendaylight.yangtools.concepts.ListenerRegistration;
57 import org.opendaylight.yangtools.yang.data.api.YangInstanceIdentifier;
58 import org.opendaylight.yangtools.yang.data.api.schema.NormalizedNode;
59 import org.opendaylight.yangtools.yang.data.api.schema.tree.ConflictingModificationAppliedException;
60 import org.opendaylight.yangtools.yang.data.api.schema.tree.DataTreeCandidate;
61 import org.opendaylight.yangtools.yang.data.api.schema.tree.DataTreeCandidateTip;
62 import org.opendaylight.yangtools.yang.data.api.schema.tree.DataTreeCandidates;
63 import org.opendaylight.yangtools.yang.data.api.schema.tree.DataTreeModification;
64 import org.opendaylight.yangtools.yang.data.api.schema.tree.DataTreeSnapshot;
65 import org.opendaylight.yangtools.yang.data.api.schema.tree.DataValidationFailedException;
66 import org.opendaylight.yangtools.yang.data.api.schema.tree.ModificationType;
67 import org.opendaylight.yangtools.yang.data.api.schema.tree.TipProducingDataTree;
68 import org.opendaylight.yangtools.yang.data.api.schema.tree.TreeType;
69 import org.opendaylight.yangtools.yang.data.impl.schema.tree.InMemoryDataTreeFactory;
70 import org.opendaylight.yangtools.yang.model.api.SchemaContext;
71 import org.slf4j.Logger;
72 import org.slf4j.LoggerFactory;
73 import scala.concurrent.duration.Duration;
74
75 /**
76  * Internal shard state, similar to a DOMStore, but optimized for use in the actor system,
77  * e.g. it does not expose public interfaces and assumes it is only ever called from a
78  * single thread.
79  *
80  * This class is not part of the API contract and is subject to change at any time.
81  */
82 @NotThreadSafe
83 public class ShardDataTree extends ShardDataTreeTransactionParent {
84     private static final class CommitEntry {
85         final SimpleShardDataTreeCohort cohort;
86         long lastAccess;
87
88         CommitEntry(final SimpleShardDataTreeCohort cohort, final long now) {
89             this.cohort = Preconditions.checkNotNull(cohort);
90             lastAccess = now;
91         }
92     }
93
94     private static final Timeout COMMIT_STEP_TIMEOUT = new Timeout(Duration.create(5, TimeUnit.SECONDS));
95     private static final Logger LOG = LoggerFactory.getLogger(ShardDataTree.class);
96
97     private final Map<LocalHistoryIdentifier, ShardDataTreeTransactionChain> transactionChains = new HashMap<>();
98     private final DataTreeCohortActorRegistry cohortRegistry = new DataTreeCohortActorRegistry();
99     private final Queue<CommitEntry> pendingTransactions = new ArrayDeque<>();
100     private final ShardDataTreeChangeListenerPublisher treeChangeListenerPublisher;
101     private final ShardDataChangeListenerPublisher dataChangeListenerPublisher;
102     private final Collection<ShardDataTreeMetadata<?>> metadata;
103     private final TipProducingDataTree dataTree;
104     private final String logContext;
105     private final Shard shard;
106     private Runnable runOnPendingTransactionsComplete;
107
108     private SchemaContext schemaContext;
109
110     public ShardDataTree(final Shard shard, final SchemaContext schemaContext, final TipProducingDataTree dataTree,
111             final ShardDataTreeChangeListenerPublisher treeChangeListenerPublisher,
112             final ShardDataChangeListenerPublisher dataChangeListenerPublisher, final String logContext,
113             final ShardDataTreeMetadata<?>... metadata) {
114         this.dataTree = Preconditions.checkNotNull(dataTree);
115         updateSchemaContext(schemaContext);
116
117         this.shard = Preconditions.checkNotNull(shard);
118         this.treeChangeListenerPublisher = Preconditions.checkNotNull(treeChangeListenerPublisher);
119         this.dataChangeListenerPublisher = Preconditions.checkNotNull(dataChangeListenerPublisher);
120         this.logContext = Preconditions.checkNotNull(logContext);
121         this.metadata = ImmutableList.copyOf(metadata);
122     }
123
124     public ShardDataTree(final Shard shard, final SchemaContext schemaContext, final TreeType treeType,
125             final ShardDataTreeChangeListenerPublisher treeChangeListenerPublisher,
126             final ShardDataChangeListenerPublisher dataChangeListenerPublisher, final String logContext) {
127         this(shard, schemaContext, InMemoryDataTreeFactory.getInstance().create(treeType),
128                 treeChangeListenerPublisher, dataChangeListenerPublisher, logContext);
129     }
130
131     @VisibleForTesting
132     public ShardDataTree(final Shard shard, final SchemaContext schemaContext, final TreeType treeType) {
133         this(shard, schemaContext, treeType, new DefaultShardDataTreeChangeListenerPublisher(),
134                 new DefaultShardDataChangeListenerPublisher(), "");
135     }
136
137     String logContext() {
138         return logContext;
139     }
140
141     public TipProducingDataTree getDataTree() {
142         return dataTree;
143     }
144
145     SchemaContext getSchemaContext() {
146         return schemaContext;
147     }
148
149     void updateSchemaContext(final SchemaContext schemaContext) {
150         dataTree.setSchemaContext(schemaContext);
151         this.schemaContext = Preconditions.checkNotNull(schemaContext);
152     }
153
154     /**
155      * Take a snapshot of current state for later recovery.
156      *
157      * @return A state snapshot
158      */
159     @Nonnull ShardDataTreeSnapshot takeStateSnapshot() {
160         final NormalizedNode<?, ?> rootNode = dataTree.takeSnapshot().readNode(YangInstanceIdentifier.EMPTY).get();
161         final Builder<Class<? extends ShardDataTreeSnapshotMetadata<?>>, ShardDataTreeSnapshotMetadata<?>> metaBuilder =
162                 ImmutableMap.builder();
163
164         for (ShardDataTreeMetadata<?> m : metadata) {
165             final ShardDataTreeSnapshotMetadata<?> meta = m.toSnapshot();
166             if (meta != null) {
167                 metaBuilder.put(meta.getType(), meta);
168             }
169         }
170
171         return new MetadataShardDataTreeSnapshot(rootNode, metaBuilder.build());
172     }
173
174     private void applySnapshot(final @Nonnull ShardDataTreeSnapshot snapshot,
175             final UnaryOperator<DataTreeModification> wrapper) throws DataValidationFailedException {
176         final Stopwatch elapsed = Stopwatch.createStarted();
177
178         if (!pendingTransactions.isEmpty()) {
179             LOG.warn("{}: applying state snapshot with pending transactions", logContext);
180         }
181
182         final Map<Class<? extends ShardDataTreeSnapshotMetadata<?>>, ShardDataTreeSnapshotMetadata<?>> snapshotMeta;
183         if (snapshot instanceof MetadataShardDataTreeSnapshot) {
184             snapshotMeta = ((MetadataShardDataTreeSnapshot) snapshot).getMetadata();
185         } else {
186             snapshotMeta = ImmutableMap.of();
187         }
188
189         for (ShardDataTreeMetadata<?> m : metadata) {
190             final ShardDataTreeSnapshotMetadata<?> s = snapshotMeta.get(m.getSupportedType());
191             if (s != null) {
192                 m.applySnapshot(s);
193             } else {
194                 m.reset();
195             }
196         }
197
198         final DataTreeModification mod = wrapper.apply(dataTree.takeSnapshot().newModification());
199         // delete everything first
200         mod.delete(YangInstanceIdentifier.EMPTY);
201
202         final java.util.Optional<NormalizedNode<?, ?>> maybeNode = snapshot.getRootNode();
203         if (maybeNode.isPresent()) {
204             // Add everything from the remote node back
205             mod.write(YangInstanceIdentifier.EMPTY, maybeNode.get());
206         }
207         mod.ready();
208
209         final DataTreeModification unwrapped = unwrap(mod);
210         dataTree.validate(unwrapped);
211         DataTreeCandidateTip candidate = dataTree.prepare(unwrapped);
212         dataTree.commit(candidate);
213         notifyListeners(candidate);
214
215         LOG.debug("{}: state snapshot applied in %s", logContext, elapsed);
216     }
217
218     private PruningDataTreeModification wrapWithPruning(final DataTreeModification delegate) {
219         return new PruningDataTreeModification(delegate, dataTree, schemaContext);
220     }
221
222     private static DataTreeModification unwrap(final DataTreeModification modification) {
223         if (modification instanceof PruningDataTreeModification) {
224             return ((PruningDataTreeModification)modification).delegate();
225         }
226         return modification;
227     }
228
229     /**
230      * Apply a snapshot coming from recovery. This method does not assume the SchemaContexts match and performs data
231      * pruning in an attempt to adjust the state to our current SchemaContext.
232      *
233      * @param snapshot Snapshot that needs to be applied
234      * @throws DataValidationFailedException when the snapshot fails to apply
235      */
236     void applyRecoverySnapshot(final @Nonnull ShardDataTreeSnapshot snapshot) throws DataValidationFailedException {
237         applySnapshot(snapshot, this::wrapWithPruning);
238     }
239
240
241     /**
242      * Apply a snapshot coming from the leader. This method assumes the leader and follower SchemaContexts match and
243      * does not perform any pruning.
244      *
245      * @param snapshot Snapshot that needs to be applied
246      * @throws DataValidationFailedException when the snapshot fails to apply
247      */
248     void applySnapshot(final @Nonnull ShardDataTreeSnapshot snapshot) throws DataValidationFailedException {
249         applySnapshot(snapshot, UnaryOperator.identity());
250     }
251
252     private void applyRecoveryCandidate(final DataTreeCandidate candidate) throws DataValidationFailedException {
253         final PruningDataTreeModification mod = wrapWithPruning(dataTree.takeSnapshot().newModification());
254         DataTreeCandidates.applyToModification(mod, candidate);
255         mod.ready();
256
257         final DataTreeModification unwrapped = mod.delegate();
258         LOG.trace("{}: Applying recovery modification {}", logContext, unwrapped);
259
260         try {
261             dataTree.validate(unwrapped);
262             dataTree.commit(dataTree.prepare(unwrapped));
263         } catch (Exception e) {
264             File file = new File(System.getProperty("karaf.data", "."),
265                     "failed-recovery-payload-" + logContext + ".out");
266             DataTreeModificationOutput.toFile(file, unwrapped);
267             throw new IllegalStateException(String.format(
268                     "%s: Failed to apply recovery payload. Modification data was written to file %s",
269                     logContext, file), e);
270         }
271     }
272
273     /**
274      * Apply a payload coming from recovery. This method does not assume the SchemaContexts match and performs data
275      * pruning in an attempt to adjust the state to our current SchemaContext.
276      *
277      * @param payload Payload
278      * @throws IOException when the snapshot fails to deserialize
279      * @throws DataValidationFailedException when the snapshot fails to apply
280      */
281     void applyRecoveryPayload(final @Nonnull Payload payload) throws IOException, DataValidationFailedException {
282         if (payload instanceof CommitTransactionPayload) {
283             final Entry<TransactionIdentifier, DataTreeCandidate> e = ((CommitTransactionPayload) payload).getCandidate();
284             applyRecoveryCandidate(e.getValue());
285             allMetadataCommittedTransaction(e.getKey());
286         } else if (payload instanceof DataTreeCandidatePayload) {
287             applyRecoveryCandidate(((DataTreeCandidatePayload) payload).getCandidate());
288         } else {
289             LOG.debug("{}: ignoring unhandled payload {}", logContext, payload);
290         }
291     }
292
293     private void applyReplicatedCandidate(final Identifier identifier, final DataTreeCandidate foreign)
294             throws DataValidationFailedException {
295         LOG.debug("{}: Applying foreign transaction {}", logContext, identifier);
296
297         final DataTreeModification mod = dataTree.takeSnapshot().newModification();
298         DataTreeCandidates.applyToModification(mod, foreign);
299         mod.ready();
300
301         LOG.trace("{}: Applying foreign modification {}", logContext, mod);
302         dataTree.validate(mod);
303         final DataTreeCandidate candidate = dataTree.prepare(mod);
304         dataTree.commit(candidate);
305
306         notifyListeners(candidate);
307     }
308
309     /**
310      * Apply a payload coming from the leader, which could actually be us. This method assumes the leader and follower
311      * SchemaContexts match and does not perform any pruning.
312      *
313      * @param identifier Payload identifier as returned from RaftActor
314      * @param payload Payload
315      * @throws IOException when the snapshot fails to deserialize
316      * @throws DataValidationFailedException when the snapshot fails to apply
317      */
318     void applyReplicatedPayload(final Identifier identifier, final Payload payload) throws IOException,
319             DataValidationFailedException {
320         /*
321          * This is a bit more involved than it needs to be due to to the fact we do not want to be touching the payload
322          * if we are the leader and it has originated with us.
323          *
324          * The identifier will only ever be non-null when we were the leader which achieved consensus. Unfortunately,
325          * though, this may not be the case anymore, as we are being called some time afterwards and we may not be
326          * acting in that capacity anymore.
327          *
328          * In any case, we know that this is an entry coming from replication, hence we can be sure we will not observe
329          * pre-Boron state -- which limits the number of options here.
330          */
331         if (payload instanceof CommitTransactionPayload) {
332             if (identifier == null) {
333                 final Entry<TransactionIdentifier, DataTreeCandidate> e = ((CommitTransactionPayload) payload).getCandidate();
334                 applyReplicatedCandidate(e.getKey(), e.getValue());
335                 allMetadataCommittedTransaction(e.getKey());
336             } else {
337                 Verify.verify(identifier instanceof TransactionIdentifier);
338                 payloadReplicationComplete((TransactionIdentifier) identifier);
339             }
340         } else {
341             LOG.warn("{}: ignoring unhandled identifier {} payload {}", logContext, identifier, payload);
342         }
343     }
344
345     private void payloadReplicationComplete(final TransactionIdentifier txId) {
346         final CommitEntry current = pendingTransactions.peek();
347         if (current == null) {
348             LOG.warn("{}: No outstanding transactions, ignoring consensus on transaction {}", logContext, txId);
349             return;
350         }
351
352         if (!current.cohort.getIdentifier().equals(txId)) {
353             LOG.warn("{}: Head of queue is {}, ignoring consensus on transaction {}", logContext,
354                 current.cohort.getIdentifier(), txId);
355             return;
356         }
357
358         finishCommit(current.cohort);
359     }
360
361     private void allMetadataCommittedTransaction(final TransactionIdentifier txId) {
362         for (ShardDataTreeMetadata<?> m : metadata) {
363             m.onTransactionCommitted(txId);
364         }
365     }
366
367     private ShardDataTreeTransactionChain ensureTransactionChain(final LocalHistoryIdentifier localHistoryIdentifier) {
368         ShardDataTreeTransactionChain chain = transactionChains.get(localHistoryIdentifier);
369         if (chain == null) {
370             chain = new ShardDataTreeTransactionChain(localHistoryIdentifier, this);
371             transactionChains.put(localHistoryIdentifier, chain);
372         }
373
374         return chain;
375     }
376
377     ReadOnlyShardDataTreeTransaction newReadOnlyTransaction(final TransactionIdentifier txId) {
378         if (txId.getHistoryId().getHistoryId() == 0) {
379             return new ReadOnlyShardDataTreeTransaction(txId, dataTree.takeSnapshot());
380         }
381
382         return ensureTransactionChain(txId.getHistoryId()).newReadOnlyTransaction(txId);
383     }
384
385     ReadWriteShardDataTreeTransaction newReadWriteTransaction(final TransactionIdentifier txId) {
386         if (txId.getHistoryId().getHistoryId() == 0) {
387             return new ReadWriteShardDataTreeTransaction(ShardDataTree.this, txId, dataTree.takeSnapshot()
388                     .newModification());
389         }
390
391         return ensureTransactionChain(txId.getHistoryId()).newReadWriteTransaction(txId);
392     }
393
394     @VisibleForTesting
395     public void notifyListeners(final DataTreeCandidate candidate) {
396         treeChangeListenerPublisher.publishChanges(candidate, logContext);
397         dataChangeListenerPublisher.publishChanges(candidate, logContext);
398     }
399
400     void notifyOfInitialData(final DataChangeListenerRegistration<AsyncDataChangeListener<YangInstanceIdentifier,
401             NormalizedNode<?, ?>>> listenerReg, final Optional<DataTreeCandidate> currentState) {
402         if (currentState.isPresent()) {
403             ShardDataChangeListenerPublisher localPublisher = dataChangeListenerPublisher.newInstance();
404             localPublisher.registerDataChangeListener(listenerReg.getPath(), listenerReg.getInstance(),
405                     listenerReg.getScope());
406             localPublisher.publishChanges(currentState.get(), logContext);
407         }
408     }
409
410     void notifyOfInitialData(final YangInstanceIdentifier path, final DOMDataTreeChangeListener listener,
411             final Optional<DataTreeCandidate> currentState) {
412         if (currentState.isPresent()) {
413             ShardDataTreeChangeListenerPublisher localPublisher = treeChangeListenerPublisher.newInstance();
414             localPublisher.registerTreeChangeListener(path, listener);
415             localPublisher.publishChanges(currentState.get(), logContext);
416         }
417     }
418
419     void closeAllTransactionChains() {
420         for (ShardDataTreeTransactionChain chain : transactionChains.values()) {
421             chain.close();
422         }
423
424         transactionChains.clear();
425     }
426
427     void closeTransactionChain(final LocalHistoryIdentifier transactionChainId) {
428         final ShardDataTreeTransactionChain chain = transactionChains.remove(transactionChainId);
429         if (chain != null) {
430             chain.close();
431         } else {
432             LOG.debug("{}: Closing non-existent transaction chain {}", logContext, transactionChainId);
433         }
434     }
435
436     Entry<DataChangeListenerRegistration<AsyncDataChangeListener<YangInstanceIdentifier, NormalizedNode<?, ?>>>,
437             Optional<DataTreeCandidate>> registerChangeListener(final YangInstanceIdentifier path,
438                     final AsyncDataChangeListener<YangInstanceIdentifier, NormalizedNode<?, ?>> listener,
439                     final DataChangeScope scope) {
440         final DataChangeListenerRegistration<AsyncDataChangeListener<YangInstanceIdentifier, NormalizedNode<?, ?>>> reg =
441                 dataChangeListenerPublisher.registerDataChangeListener(path, listener, scope);
442
443         return new SimpleEntry<>(reg, readCurrentData());
444     }
445
446     private Optional<DataTreeCandidate> readCurrentData() {
447         final Optional<NormalizedNode<?, ?>> currentState = dataTree.takeSnapshot().readNode(YangInstanceIdentifier.EMPTY);
448         return currentState.isPresent() ? Optional.of(DataTreeCandidates.fromNormalizedNode(
449             YangInstanceIdentifier.EMPTY, currentState.get())) : Optional.<DataTreeCandidate>absent();
450     }
451
452     public Entry<ListenerRegistration<DOMDataTreeChangeListener>, Optional<DataTreeCandidate>> registerTreeChangeListener(
453             final YangInstanceIdentifier path, final DOMDataTreeChangeListener listener) {
454         final ListenerRegistration<DOMDataTreeChangeListener> reg = treeChangeListenerPublisher.registerTreeChangeListener(
455                 path, listener);
456
457         return new SimpleEntry<>(reg, readCurrentData());
458     }
459
460     int getQueueSize() {
461         return pendingTransactions.size();
462     }
463
464     @Override
465     void abortTransaction(final AbstractShardDataTreeTransaction<?> transaction) {
466         // Intentional no-op
467     }
468
469     @Override
470     ShardDataTreeCohort finishTransaction(final ReadWriteShardDataTreeTransaction transaction) {
471         final DataTreeModification snapshot = transaction.getSnapshot();
472         snapshot.ready();
473
474         return createReadyCohort(transaction.getId(), snapshot);
475     }
476
477     public Optional<NormalizedNode<?, ?>> readNode(final YangInstanceIdentifier path) {
478         return dataTree.takeSnapshot().readNode(path);
479     }
480
481     DataTreeSnapshot takeSnapshot() {
482         return dataTree.takeSnapshot();
483     }
484
485     @VisibleForTesting
486     public DataTreeModification newModification() {
487         return dataTree.takeSnapshot().newModification();
488     }
489
490     /**
491      * @deprecated This method violates DataTree containment and will be removed.
492      */
493     @VisibleForTesting
494     @Deprecated
495     public DataTreeCandidate commit(final DataTreeModification modification) throws DataValidationFailedException {
496         modification.ready();
497         dataTree.validate(modification);
498         DataTreeCandidate candidate = dataTree.prepare(modification);
499         dataTree.commit(candidate);
500         return candidate;
501     }
502
503     public Collection<ShardDataTreeCohort> getAndClearPendingTransactions() {
504         Collection<ShardDataTreeCohort> ret = new ArrayList<>(pendingTransactions.size());
505         for(CommitEntry entry: pendingTransactions) {
506             ret.add(entry.cohort);
507         }
508
509         pendingTransactions.clear();
510         return ret;
511     }
512
513     private void processNextTransaction() {
514         while (!pendingTransactions.isEmpty()) {
515             final CommitEntry entry = pendingTransactions.peek();
516             final SimpleShardDataTreeCohort cohort = entry.cohort;
517             final DataTreeModification modification = cohort.getDataTreeModification();
518
519             if(cohort.getState() != State.CAN_COMMIT_PENDING) {
520                 break;
521             }
522
523             LOG.debug("{}: Validating transaction {}", logContext, cohort.getIdentifier());
524             Exception cause;
525             try {
526                 dataTree.validate(modification);
527                 LOG.debug("{}: Transaction {} validated", logContext, cohort.getIdentifier());
528                 cohort.successfulCanCommit();
529                 entry.lastAccess = shard.ticker().read();
530                 return;
531             } catch (ConflictingModificationAppliedException e) {
532                 LOG.warn("{}: Store Tx {}: Conflicting modification for path {}.", logContext, cohort.getIdentifier(),
533                     e.getPath());
534                 cause = new OptimisticLockFailedException("Optimistic lock failed.", e);
535             } catch (DataValidationFailedException e) {
536                 LOG.warn("{}: Store Tx {}: Data validation failed for path {}.", logContext, cohort.getIdentifier(),
537                     e.getPath(), e);
538
539                 // For debugging purposes, allow dumping of the modification. Coupled with the above
540                 // precondition log, it should allow us to understand what went on.
541                 LOG.debug("{}: Store Tx {}: modifications: {} tree: {}", cohort.getIdentifier(), modification, dataTree);
542                 cause = new TransactionCommitFailedException("Data did not pass validation.", e);
543             } catch (Exception e) {
544                 LOG.warn("{}: Unexpected failure in validation phase", logContext, e);
545                 cause = e;
546             }
547
548             // Failure path: propagate the failure, remove the transaction from the queue and loop to the next one
549             pendingTransactions.poll().cohort.failedCanCommit(cause);
550         }
551
552         maybeRunOperationOnPendingTransactionsComplete();
553     }
554
555     void startCanCommit(final SimpleShardDataTreeCohort cohort) {
556         final SimpleShardDataTreeCohort current = pendingTransactions.peek().cohort;
557         if (!cohort.equals(current)) {
558             LOG.debug("{}: Transaction {} scheduled for canCommit step", logContext, cohort.getIdentifier());
559             return;
560         }
561
562         processNextTransaction();
563     }
564
565     private void failPreCommit(final Exception cause) {
566         shard.getShardMBean().incrementFailedTransactionsCount();
567         pendingTransactions.poll().cohort.failedPreCommit(cause);
568         processNextTransaction();
569     }
570
571     void startPreCommit(final SimpleShardDataTreeCohort cohort) {
572         final CommitEntry entry = pendingTransactions.peek();
573         Preconditions.checkState(entry != null, "Attempted to pre-commit of %s when no transactions pending", cohort);
574
575         final SimpleShardDataTreeCohort current = entry.cohort;
576         Verify.verify(cohort.equals(current), "Attempted to pre-commit %s while %s is pending", cohort, current);
577         final DataTreeCandidateTip candidate;
578         try {
579             candidate = dataTree.prepare(cohort.getDataTreeModification());
580         } catch (Exception e) {
581             failPreCommit(e);
582             return;
583         }
584
585         try {
586             cohort.userPreCommit(candidate);
587         } catch (ExecutionException | TimeoutException e) {
588             failPreCommit(e);
589             return;
590         }
591
592         entry.lastAccess = shard.ticker().read();
593         cohort.successfulPreCommit(candidate);
594     }
595
596     private void failCommit(final Exception cause) {
597         shard.getShardMBean().incrementFailedTransactionsCount();
598         pendingTransactions.poll().cohort.failedCommit(cause);
599         processNextTransaction();
600     }
601
602     private void finishCommit(final SimpleShardDataTreeCohort cohort) {
603         final TransactionIdentifier txId = cohort.getIdentifier();
604         final DataTreeCandidate candidate = cohort.getCandidate();
605
606         LOG.debug("{}: Resuming commit of transaction {}", logContext, txId);
607
608         try {
609             dataTree.commit(candidate);
610         } catch (Exception e) {
611             LOG.error("{}: Failed to commit transaction {}", logContext, txId, e);
612             failCommit(e);
613             return;
614         }
615
616         shard.getShardMBean().incrementCommittedTransactionCount();
617         shard.getShardMBean().setLastCommittedTransactionTime(System.currentTimeMillis());
618
619         // FIXME: propagate journal index
620         pendingTransactions.poll().cohort.successfulCommit(UnsignedLong.ZERO);
621
622         LOG.trace("{}: Transaction {} committed, proceeding to notify", logContext, txId);
623         notifyListeners(candidate);
624
625         processNextTransaction();
626     }
627
628     void startCommit(final SimpleShardDataTreeCohort cohort, final DataTreeCandidate candidate) {
629         final CommitEntry entry = pendingTransactions.peek();
630         Preconditions.checkState(entry != null, "Attempted to start commit of %s when no transactions pending", cohort);
631
632         final SimpleShardDataTreeCohort current = entry.cohort;
633         Verify.verify(cohort.equals(current), "Attempted to commit %s while %s is pending", cohort, current);
634
635         if (shard.canSkipPayload() || candidate.getRootNode().getModificationType() == ModificationType.UNMODIFIED) {
636             LOG.debug("{}: No replication required, proceeding to finish commit", logContext);
637             finishCommit(cohort);
638             return;
639         }
640
641         final TransactionIdentifier txId = cohort.getIdentifier();
642         final Payload payload;
643         try {
644             payload = CommitTransactionPayload.create(txId, candidate);
645         } catch (IOException e) {
646             LOG.error("{}: Failed to encode transaction {} candidate {}", logContext, txId, candidate, e);
647             pendingTransactions.poll().cohort.failedCommit(e);
648             return;
649         }
650
651         // Once completed, we will continue via payloadReplicationComplete
652         entry.lastAccess = shard.ticker().read();
653         shard.persistPayload(txId, payload);
654         LOG.debug("{}: Transaction {} submitted to persistence", logContext, txId);
655     }
656
657     void processCohortRegistryCommand(final ActorRef sender, final CohortRegistryCommand message) {
658         cohortRegistry.process(sender, message);
659     }
660
661     ShardDataTreeCohort createReadyCohort(final TransactionIdentifier txId,
662             final DataTreeModification modification) {
663         SimpleShardDataTreeCohort cohort = new SimpleShardDataTreeCohort(this, modification, txId,
664                 cohortRegistry.createCohort(schemaContext, txId, COMMIT_STEP_TIMEOUT));
665         pendingTransactions.add(new CommitEntry(cohort, shard.ticker().read()));
666         return cohort;
667     }
668
669     void checkForExpiredTransactions(final long transactionCommitTimeoutMillis) {
670         final long timeout = TimeUnit.MILLISECONDS.toNanos(transactionCommitTimeoutMillis);
671         final long now = shard.ticker().read();
672         final CommitEntry currentTx = pendingTransactions.peek();
673         if (currentTx != null && currentTx.lastAccess + timeout < now) {
674             LOG.warn("{}: Current transaction {} has timed out after {} ms in state {}", logContext,
675                     currentTx.cohort.getIdentifier(), transactionCommitTimeoutMillis, currentTx.cohort.getState());
676             boolean processNext = true;
677             switch (currentTx.cohort.getState()) {
678                 case CAN_COMMIT_PENDING:
679                     pendingTransactions.poll().cohort.failedCanCommit(new TimeoutException());
680                     break;
681                 case CAN_COMMIT_COMPLETE:
682                     pendingTransactions.poll().cohort.reportFailure(new TimeoutException());
683                     break;
684                 case PRE_COMMIT_PENDING:
685                     pendingTransactions.poll().cohort.failedPreCommit(new TimeoutException());
686                     break;
687                 case PRE_COMMIT_COMPLETE:
688                     // FIXME: this is a legacy behavior problem. Three-phase commit protocol specifies that after we
689                     //        are ready we should commit the transaction, not abort it. Our current software stack does
690                     //        not allow us to do that consistently, because we persist at the time of commit, hence
691                     //        we can end up in a state where we have pre-committed a transaction, then a leader failover
692                     //        occurred ... the new leader does not see the pre-committed transaction and does not have
693                     //        a running timer. To fix this we really need two persistence events.
694                     //
695                     //        The first one, done at pre-commit time will hold the transaction payload. When consensus
696                     //        is reached, we exit the pre-commit phase and start the pre-commit timer. Followers do not
697                     //        apply the state in this event.
698                     //
699                     //        The second one, done at commit (or abort) time holds only the transaction identifier and
700                     //        signals to followers that the state should (or should not) be applied.
701                     //
702                     //        In order to make the pre-commit timer working across failovers, though, we need
703                     //        a per-shard cluster-wide monotonic time, so a follower becoming the leader can accurately
704                     //        restart the timer.
705                     pendingTransactions.poll().cohort.reportFailure(new TimeoutException());
706                     break;
707                 case COMMIT_PENDING:
708                     LOG.warn("{}: Transaction {} is still committing, cannot abort", logContext,
709                         currentTx.cohort.getIdentifier());
710                     currentTx.lastAccess = now;
711                     processNext = false;
712                     return;
713                 case ABORTED:
714                 case COMMITTED:
715                 case FAILED:
716                 case READY:
717                 default:
718                     pendingTransactions.poll();
719             }
720
721             if (processNext) {
722                 processNextTransaction();
723             }
724         }
725     }
726
727     void startAbort(final SimpleShardDataTreeCohort cohort) {
728         final Iterator<CommitEntry> it = pendingTransactions.iterator();
729         if (!it.hasNext()) {
730             LOG.debug("{}: no open transaction while attempting to abort {}", logContext, cohort.getIdentifier());
731             return;
732         }
733
734         // First entry is special, as it may already be committing
735         final CommitEntry first = it.next();
736         if (cohort.equals(first.cohort)) {
737             if (cohort.getState() != State.COMMIT_PENDING) {
738                 LOG.debug("{}: aborted head of queue {} in state {}", logContext, cohort.getIdentifier(),
739                     cohort.getIdentifier());
740                 pendingTransactions.poll();
741                 processNextTransaction();
742             } else {
743                 LOG.warn("{}: transaction {} is committing, skipping abort", logContext, cohort.getIdentifier());
744             }
745
746             return;
747         }
748
749         while (it.hasNext()) {
750             final CommitEntry e = it.next();
751             if (cohort.equals(e.cohort)) {
752                 LOG.debug("{}: aborting queued transaction {}", logContext, cohort.getIdentifier());
753                 it.remove();
754                 return;
755             }
756         }
757
758         LOG.debug("{}: aborted transaction {} not found in the queue", logContext, cohort.getIdentifier());
759     }
760
761     void setRunOnPendingTransactionsComplete(final Runnable operation) {
762         runOnPendingTransactionsComplete = operation;
763         maybeRunOperationOnPendingTransactionsComplete();
764     }
765
766     private void maybeRunOperationOnPendingTransactionsComplete() {
767       if (runOnPendingTransactionsComplete != null && pendingTransactions.isEmpty()) {
768           LOG.debug("{}: Pending transactions complete - running operation {}", logContext,
769                   runOnPendingTransactionsComplete);
770
771           runOnPendingTransactionsComplete.run();
772           runOnPendingTransactionsComplete = null;
773       }
774   }
775 }