IOException,
InterruptedException,
MasterSyncException {
long messageProcessingStartTime = System.nanoTime();
InputWireRecord wireRecord = entry.getWireRecord();
LogEntry logEntry = wireRecord.getLogEntry();
/*
* Sanity check that the replication stream is in sequence. We want to
* forestall any possible corruption from replaying invalid entries.
*/
if (!wireRecord.getVLSN().follows(lastReplayedVLSN)) {
throw new EnvironmentFailureException
(repImpl,
EnvironmentFailureReason.UNEXPECTED_STATE,
"Rep stream not sequential. Current VLSN: " +
lastReplayedVLSN +
" next log entry VLSN: " + wireRecord.getVLSN());
}
if (logger.isLoggable(Level.FINEST)) {
LoggerUtils.finest(logger, repImpl, "Replaying " + wireRecord);
}
ReplayTxn repTxn = getReplayTxn(logEntry.getTransactionId());
updateReplicaSequences(logEntry);
byte entryType = wireRecord.getEntryType();
lastReplayedVLSN = wireRecord.getVLSN();
final RepNode repNode = repImpl.getRepNode();
try {
if (LogEntryType.LOG_TXN_COMMIT.equalsType(entryType)) {
Protocol.Commit commitEntry = (Protocol.Commit) entry;
boolean needsAck = commitEntry.getNeedsAck();
SyncPolicy syncPolicy =
needsAck ?
commitEntry.getReplicaSyncPolicy() :
noAckSyncPolicy;
if (logger.isLoggable(Level.FINE)) {
if (needsAck) {
LoggerUtils.fine(logger, repImpl,
"Replay: got commit for txn=" +
repTxn.getId() +
", ack needed, replica sync policy=" +
syncPolicy +
" vlsn=" +
lastReplayedVLSN);
} else {
LoggerUtils.fine(logger, repImpl,
"Replay: got commit for txn=" +
repTxn.getId() + " ack not needed" +
" vlsn=" +
lastReplayedVLSN);
}
}
TxnCommit masterCommit = (TxnCommit) logEntry.getMainItem();
if (needsAck) {
/*
* Only wait if the replica is not lagging and the
* durability requires it.
*/
repNode.getVLSNFreezeLatch().awaitThaw();
repNode.getMasterStatus().assertSync();
}
repTxn.commit(syncPolicy,
new ReplicationContext(lastReplayedVLSN),
masterCommit.getMasterNodeId());
Timestamp commitTime = masterCommit.getTime();
lastReplayedTxn = new TxnInfo(lastReplayedVLSN,
commitTime.getTime());
/* Respond to the feeder. */
long commitNanos = System.nanoTime() -
messageProcessingStartTime;
updateCommitStats(needsAck, syncPolicy, commitNanos);
if (commitNanos > ackTimeoutLogThresholdInNanos &&
logger.isLoggable(Level.INFO)) {
LoggerUtils.info
(logger, repImpl,
"Replay commit time: " + (commitNanos / 1000000) +
" ms exceeded log threshold: " +
(ackTimeoutLogThresholdInNanos / 1000000));
}
if (needsAck) {
protocol.write(protocol.new Ack(repTxn.getId()),
namedChannel);
}
/*
* The group refresh and recalculation can be expensive, since
* it may require a database read. Do it after the ack.
*/
if (repTxn.getRepGroupDbChange() && canRefreshGroup(repTxn)) {
repNode.refreshCachedGroup();
repNode.recalculateGlobalCBVLSN();
}
nElapsedTxnTime.add(repTxn.elapsedTime());
} else if (LogEntryType.LOG_TXN_ABORT.equalsType(entryType)) {
nAborts.increment();
TxnAbort masterAbort = (TxnAbort) logEntry.getMainItem();
ReplicationContext abortContext =
new ReplicationContext(wireRecord.getVLSN());
if (logger.isLoggable(Level.FINEST)) {
LoggerUtils.finest(logger, repImpl,
"abort called for " + repTxn.getId() +
" masterId=" +
masterAbort.getMasterNodeId() +
" repContext=" + abortContext);
}
repTxn.abort(abortContext, masterAbort.getMasterNodeId());
if (repTxn.getRepGroupDbChange() && canRefreshGroup(repTxn)) {
/*
* Refresh is the safe thing to do on an abort, since a
* refresh may have been held back from an earlier commit
* due to this active transaction.
*/
repNode.refreshCachedGroup();
}
nElapsedTxnTime.add(repTxn.elapsedTime());
} else if (LogEntryType.LOG_NAMELN_TRANSACTIONAL.
equalsType(entryType)) {
repNode.getReplica().clearDbTreeCache();
nNameLNs.increment();
applyNameLN(repTxn, wireRecord);
} else {
nLNs.increment();
/* A data operation. */
assert wireRecord.getLogEntry() instanceof LNLogEntry;
applyLN(repTxn, wireRecord);
}
/* Remember the last VLSN applied by this txn. */
repTxn.setLastAppliedVLSN(lastReplayedVLSN);
} catch (DatabaseException e) {