public void ProcessedLogicalRecord(LogicalLogRecord record)
{
if (record.FlushException != null)
{
FabricEvents.Events.ProcessedLogicalRecordSkip(
this.tracer.Type,
(int)this.roleContextDrainState.DrainingStream,
record.Psn.PSN);
return;
}
var outstandingNumberOfRecordsBeingProcessed =
Interlocked.Decrement(ref this.numberOfLogicalRecordsBeingProcessed);
Utility.Assert(
outstandingNumberOfRecordsBeingProcessed >= 0,
"outstandingNumberOfRecordsBeingProcessed {0} >= 0",
outstandingNumberOfRecordsBeingProcessed);
if (outstandingNumberOfRecordsBeingProcessed == 0)
{
this.logicalRecordsProcessingTcs.SetResult(record);
}
FabricEvents.Events.ProcessedLogicalRecord(this.tracer.Type, (int)this.roleContextDrainState.DrainingStream, record.Psn.PSN);
record.CompletedProcessing(null);
return;
}
private void StartLoggingOnSecondary(LogicalLogRecord record)
{
switch (record.RecordType)
{
case LogRecordType.BeginTransaction:
case LogRecordType.Operation:
case LogRecordType.EndTransaction:
case LogRecordType.Backup:
var bufferedRecordsSizeBytes = this.replicatedLogManager.AppendWithoutReplication(
record,
this.transactionManager);
if (bufferedRecordsSizeBytes > this.replicatorSettings.PublicSettings.MaxRecordSizeInKB * 1024)
{
this.replicatedLogManager.LogManager.FlushAsync("InitiateLogicalRecordProcessingOnSecondary BufferedRecordsSize: " + bufferedRecordsSizeBytes).IgnoreExceptionVoid();
}
break;
case LogRecordType.Barrier:
this.checkpointManager.AppendBarrierOnSecondary(record as BarrierLogRecord);
break;
case LogRecordType.UpdateEpoch:
this.CopiedUpdateEpoch((UpdateEpochLogRecord)record);
break;
default:
Utility.CodingError("Unexpected record type {0}", record.RecordType);
break;
}
this.checkpointManager.InsertPhysicalRecordsIfNecessaryOnSecondary(this.copiedUptoLsn, this.roleContextDrainState.DrainingStream, record);
}
private long Append(
LogicalLogRecord record,
TransactionManager transactionsManager,
bool isPrimary)
{
long bufferedBytes = 0;
TransactionLogRecord txLogRecord = record as TransactionLogRecord;
TaskCompletionSource <object> lsnOrderingTcsToSignal = null;
if (txLogRecord != null)
{
Utility.Assert(transactionsManager != null, "transactionsManager should not be null in AppendOnPrimary");
transactionsManager.CreateTransactionState(this.CurrentLogTailEpoch, txLogRecord);
}
lock (this.lsnOrderingLock)
{
bufferedBytes = LsnOrderingInsert(record, isPrimary, out lsnOrderingTcsToSignal);
}
if (lsnOrderingTcsToSignal != null)
{
// Do this outside the lock above and also after setting the this.lsnorderingtcs to NULL as this set result can end up invoking a completion to run on the same thread,
// which ends up invoking another call to Append. This happened in a unit test on the UpdateEpoch code path on primary
bool result = lsnOrderingTcsToSignal.TrySetResult(null);
Utility.Assert(result == true, "ReplicatedLogManager: failed to set result on lsn ordering tcs");
}
return(bufferedBytes);
}
private async Task LogLogicalRecordOnSecondaryAsync(LogicalLogRecord record)
{
var recordLsn = record.Lsn;
if ((recordLsn < this.replicatedLogManager.CurrentLogTailLsn) ||
((recordLsn == this.replicatedLogManager.CurrentLogTailLsn) && ((record is UpdateEpochLogRecord) == false)))
{
ProcessDuplicateRecord(record);
return;
}
this.StartLoggingOnSecondary(record);
if (this.replicatedLogManager.LogManager.ShouldThrottleWrites)
{
FabricEvents.Events.Warning(this.tracer.Type, "Blocking secondary pump due to pending flush cache size");
await this.replicatedLogManager.LogManager.WaitForPendingRecordsToFlush().ConfigureAwait(false);
FabricEvents.Events.Warning(this.tracer.Type, "Continuing secondary pump as flush cache is purged");
}
var barrierRecord = record as BarrierLogRecord;
if (barrierRecord != null &&
roleContextDrainState.DrainingStream != DrainingStream.CopyStream)
{
// Only invoke this method on barrier boundaries and only on active replication stream.
// copy stream will continue pumping and the pending checkpoint during full copy will only complete when we finish pumping all copy operations
// if we stop pumping, we will hit a deadlock since checkpoint waits for copy pump completion and only on copy pump completion do we complete the checkpoint
await this.checkpointManager.BlockSecondaryPumpIfNeeded(barrierRecord.LastStableLsn).ConfigureAwait(false);
}
}
public long ReplicateAndLog(
LogicalLogRecord record,
TransactionManager transactionsManager)
{
Replicate(record);
return(Append(record, transactionsManager, isPrimary: true));
}
private void Replicate(LogicalLogRecord record)
{
Utility.Assert(
record.Lsn <= LogicalSequenceNumber.ZeroLsn && record.RecordType != LogRecordType.UpdateEpoch,
"Record Lsn not <=0 during Replicate or record is update epoch. It is {0} for type {1}",
record.Lsn, record.RecordType);
if (RoleContextDrainState.ReplicaRole != ReplicaRole.Primary ||
RoleContextDrainState.IsClosing)
{
throw new FabricNotPrimaryException();
}
// 1. The binary writer is taken before replication
// 2. It is released immediately if replication failed (see catch block)
// 3. If replication is accepted, it is released after the log record is flushed in flushedrecordscallback
// This is because the same memory buffers are re-used to write to disk as well to avoid double serialization of logical data
var bw = this.replicationSerializationBinaryWritersPool.Take();
var operationData = record.ToOperationData(bw);
#if DEBUG
ValidateOperationData(operationData, "Replicate data " + record.RecordType);
#endif
long sequenceNumber;
try
{
this.OnOperationAcceptance();
// Use the local variable as the member can be set to null
var replicatorTask = this.fabricReplicator.ReplicateAsync(
operationData,
CancellationToken.None,
out sequenceNumber);
record.ReplicatorTask = replicatorTask;
record.Lsn = new LogicalSequenceNumber(sequenceNumber);
if (sequenceNumber == 0)
{
Utility.Assert(replicatorTask.IsFaulted == true, "replicatorTask.IsFaulted == true");
record.InvalidateReplicatedDataBuffers(this.replicationSerializationBinaryWritersPool);
this.ThrowReplicationException(record, replicatorTask.Exception);
}
}
catch (Exception e)
{
record.InvalidateReplicatedDataBuffers(this.replicationSerializationBinaryWritersPool);
OnOperationAcceptanceException();
this.ThrowReplicationException(record, e);
}
}
public void ThrowReplicationException(LogicalLogRecord record, Exception e)
{
int innerHResult = 0;
var flattenedException = Utility.FlattenException(e, out innerHResult);
Exception notPrimaryException = flattenedException as FabricNotPrimaryException;
var transientException = flattenedException as FabricTransientException;
var cancelException = flattenedException as OperationCanceledException;
var closedException = flattenedException as FabricObjectClosedException;
var tooLargeException = flattenedException as FabricReplicationOperationTooLargeException;
var isExpected = notPrimaryException != null || transientException != null || cancelException != null ||
closedException != null || tooLargeException != null;
var message =
string.Format(
CultureInfo.InvariantCulture,
"ProcessReplicationException" + Environment.NewLine
+ " Replication exception. Type: {0} Message: {1} HResult: 0x{2:X8}" + Environment.NewLine
+ " Log record. Type: {3} LSN: {4}" + Environment.NewLine,
flattenedException.GetType().ToString(),
flattenedException.Message,
flattenedException.HResult != 0 ? flattenedException.HResult : innerHResult,
record.RecordType,
record.Lsn.LSN);
if (isExpected)
{
if (this.lastWarningExceptionTraceOnPrimary.ElapsedMilliseconds > PrimaryWarningExceptionTraceIntervalMs)
{
this.lastWarningExceptionTraceOnPrimary.Restart();
FabricEvents.Events.Warning(this.tracer.Type, message);
}
}
else if (!this.RoleContextDrainState.IsClosing)
{
FabricEvents.Events.Error(this.tracer.Type, message);
this.RoleContextDrainState.ReportPartitionFault();
}
if (closedException != null)
{
throw new FabricNotPrimaryException();
}
else
{
throw flattenedException;
}
}
private void InitiateLogicalRecordProcessingOnPrimary(LogicalLogRecord record)
{
this.checkpointManager.ThrowIfThrottled(record);
long bufferedRecordsSizeBytes = 0;
switch (record.RecordType)
{
case LogRecordType.BeginTransaction:
case LogRecordType.Operation:
case LogRecordType.EndTransaction:
bufferedRecordsSizeBytes = this.replicatedLogManager.ReplicateAndLog(record, this);
break;
default:
Utility.CodingError("Unexpected record type {0} in InitiateLogicalRecordProcessingOnPrimary", record.RecordType);
break;
}
var addedIndexingRecord = false;
var addedTruncateHeadRecord = false;
this.checkpointManager.InsertPhysicalRecordsIfNecessary(out addedIndexingRecord, out addedTruncateHeadRecord);
if (record.IsLatencySensitiveRecord == true || addedTruncateHeadRecord)
{
this.checkpointManager.RequestGroupCommit();
}
else if (bufferedRecordsSizeBytes > this.flushAtBufferedBytes)
{
{
// If there is lot of buffered data, issue a flush
var t =
this.replicatedLogManager.LogManager.FlushAsync(
"InitiateLogicalLogRecordProcessing BufferedRecordsSize: " + bufferedRecordsSizeBytes);
}
}
return;
}
private long InsertBufferedRecordCallerHoldsLock(
LogicalLogRecord record,
bool isPrimary,
out long pendingCount)
{
pendingCount = -1;
var result = LogManager.PhysicalLogWriter.InsertBufferedRecord(record);
UpdateEpochLogRecord updateEpochRecord = record as UpdateEpochLogRecord;
Utility.Assert(
(this.CurrentLogTailLsn + 1) == record.Lsn || (updateEpochRecord != null && updateEpochRecord.Lsn == this.CurrentLogTailLsn),
"(this.currentLogTailLsn + 1) {0} == record.LastLogicalSequenceNumber {1}. RecordType {2}",
this.CurrentLogTailLsn + 1,
record.Lsn,
record.RecordType);
if (updateEpochRecord == null)
{
// Increment tail lsn only on appending a logical record that is NOT an update epoch
++this.CurrentLogTailLsn;
}
if (isPrimary)
{
pendingCount = OnOperationLogInitiationCallerHoldsLock();
}
var barrierRecord = record as BarrierLogRecord;
if (barrierRecord != null)
{
this.OnBarrierBufferedCallerHoldsLock(barrierRecord, isPrimary);
}
return(result);
}
public void Unlock(LogicalLogRecord record)
{
Utility.Assert(record.IsApplied == true, "record.IsApplied == true");
Utility.Assert(this.recoveredOrCopiedCheckpointLsn.Value != LogicalSequenceNumber.InvalidLsn, "recoveredOrCopiedCheckpointLsn must not be -1");
// If flush fails, the records are processed immediately, after which the processing can complete (before waiting for unlocks)
if (record.FlushException == null)
{
Utility.Assert(
roleContextDrainState.DrainingStream != DrainingStream.Invalid,
"this.DrainingStream != DrainingStream.Invalid during unlock for record lsn:{0} psn:{1}",
record.Lsn, record.Psn);
}
BeginTransactionOperationLogRecord beginTransactionRecord;
try
{
OperationLogRecord operationRecord;
switch (record.RecordType)
{
case LogRecordType.BeginTransaction:
beginTransactionRecord = (BeginTransactionOperationLogRecord)record;
if (beginTransactionRecord.IsSingleOperationTransaction)
{
if (beginTransactionRecord.Lsn > this.recoveredOrCopiedCheckpointLsn.Value)
{
var operationContext = beginTransactionRecord.ResetOperationContext();
if (operationContext != null)
{
this.stateManager.Unlock(operationContext);
}
}
this.FireCommitNotification((ITransaction)beginTransactionRecord.Transaction);
}
break;
case LogRecordType.Operation:
operationRecord = (OperationLogRecord)record;
if (operationRecord.Transaction.IsAtomicOperation == true)
{
if (operationRecord.Lsn > this.recoveredOrCopiedCheckpointLsn.Value)
{
var operationContext = operationRecord.ResetOperationContext();
if (operationContext != null)
{
this.stateManager.Unlock(operationContext);
}
}
}
break;
case LogRecordType.EndTransaction:
var endTransactionRecord = (EndTransactionLogRecord)record;
if (endTransactionRecord.Lsn > this.recoveredOrCopiedCheckpointLsn.Value)
{
TransactionLogRecord transactionRecord = endTransactionRecord;
do
{
transactionRecord = transactionRecord.ParentTransactionRecord;
beginTransactionRecord = transactionRecord as BeginTransactionOperationLogRecord;
} while (beginTransactionRecord == null);
Utility.Assert(
(beginTransactionRecord != null) &&
(LogRecord.IsInvalidRecord(beginTransactionRecord) == false),
"(beginTransactionRecord != null) && (TransactionLogRecord.IsInvalidRecord(beginTransactionRecord) == false)");
var operationContext = beginTransactionRecord.ResetOperationContext();
if (operationContext != null)
{
this.stateManager.Unlock(operationContext);
}
transactionRecord = beginTransactionRecord;
do
{
transactionRecord = transactionRecord.ChildTransactionRecord;
Utility.Assert(
(transactionRecord != null) &&
(LogRecord.IsInvalidRecord(transactionRecord) == false),
"(transactionRecord != null) && (TransactionLogRecord.IsInvalidRecord(transactionRecord) == false)");
if (transactionRecord == endTransactionRecord)
{
break;
}
operationRecord = (OperationLogRecord)transactionRecord;
operationContext = operationRecord.ResetOperationContext();
if (operationContext != null)
{
this.stateManager.Unlock(operationContext);
}
} while (true);
}
else
{
TransactionLogRecord transactionRecord = endTransactionRecord;
do
{
var parentRecord = transactionRecord.ParentTransactionRecord;
if (parentRecord == null)
{
break;
}
transactionRecord = parentRecord;
} while (true);
Utility.Assert(
(endTransactionRecord.IsEnlistedTransaction == false) ||
(transactionRecord is BeginTransactionOperationLogRecord),
"(endTransactionRecord.IsEnlistedTransaction {0} == false) || "
+ "(transactionRecord is BeginTransactionLogRecord {1})",
endTransactionRecord.IsEnlistedTransaction, transactionRecord.RecordType);
if (transactionRecord != endTransactionRecord)
{
do
{
transactionRecord = transactionRecord.ChildTransactionRecord;
Utility.Assert(
(transactionRecord != null) &&
(LogRecord.IsInvalidRecord(transactionRecord) == false),
"(transactionRecord != null) && (TransactionLogRecord.IsInvalidRecord(transactionRecord) == false)");
if (transactionRecord == endTransactionRecord)
{
break;
}
} while (true);
}
}
if (endTransactionRecord.IsCommitted == true)
{
this.FireCommitNotification((ITransaction)endTransactionRecord.Transaction);
}
break;
case LogRecordType.Backup:
var backupLogRecord = (BackupLogRecord)record;
Utility.Assert(backupManager != null, "Backupmanager must not be null in UnlockCallbackManager");
backupManager.LastCompletedBackupLogRecord = backupLogRecord;
break;
default:
Utility.CodingError("Unexpected record type {0}", record.RecordType);
break;
}
}
catch (Exception e)
{
this.ProcessServiceException("Unlockcallback", record, e);
}
this.ProcessedLogicalRecord(record);
return;
}
private long LsnOrderingInsert(
LogicalLogRecord record,
bool isPrimary,
out TaskCompletionSource <object> lsnOrderingTcsToSignal)
{
var recordLsn = record.Lsn;
long pendingCount = -1;
var i = 0;
lsnOrderingTcsToSignal = null;
// First every update epoch record on full copy secondary has UpdateEpoch(0,0)
Utility.Assert(
recordLsn > LogicalSequenceNumber.ZeroLsn || record.RecordType == LogRecordType.UpdateEpoch,
"recordLsn > LogicalSequenceNumber.ZeroLsn || record.RecordType == LogRecordType.UpdateEpoch");
if (recordLsn > (this.CurrentLogTailLsn + 1))
{
for (i = this.lsnOrderingQueue.Count - 1; i >= 0; i--)
{
if (recordLsn > this.lsnOrderingQueue[i].Lsn)
{
this.lsnOrderingQueue.Insert(i + 1, record);
break;
}
}
if (i == -1)
{
this.lsnOrderingQueue.Insert(0, record);
}
return(-1);
}
var result = InsertBufferedRecordCallerHoldsLock(record, isPrimary, out pendingCount);
for (i = 0; i < this.lsnOrderingQueue.Count; i++)
{
recordLsn = this.lsnOrderingQueue[i].Lsn;
if (recordLsn > (this.CurrentLogTailLsn + 1))
{
break;
}
record = this.lsnOrderingQueue[i];
result = InsertBufferedRecordCallerHoldsLock(record, isPrimary, out pendingCount);
}
this.lsnOrderingQueue.RemoveRange(0, i);
if (pendingCount == 0 &&
this.lsnOrderingQueue.Count == 0 &&
this.lsnOrderingTcs != null)
{
lsnOrderingTcsToSignal = this.lsnOrderingTcs;
this.lsnOrderingTcs = null;
}
return(result);
}
public long AppendWithoutReplication(
LogicalLogRecord record,
TransactionManager transactionsManager)
{
return(Append(record, transactionsManager, false));
}