internal LoggingReplicatorCopyStream(
ReplicatedLogManager replicatedLogManager,
IStateManager stateManager,
CheckpointManager checkpointManager,
Func <LogicalSequenceNumber, Task> waitForLogFlushUptoLsn,
long replicaId,
LogicalSequenceNumber uptoLsn,
IOperationDataStream copyContext,
ITracer tracer)
{
this.stateManager = stateManager;
this.checkpointManager = checkpointManager;
this.replicatedLogManager = replicatedLogManager;
this.replicaId = replicaId;
this.waitForLogFlushUptoLsn = waitForLogFlushUptoLsn;
this.uptoLsn = uptoLsn;
this.copyContext = copyContext;
this.targetReplicaId = 0;
this.targetProgressVector = null;
this.targetLogHeadEpoch = LogicalSequenceNumber.InvalidEpoch;
this.targetLogHeadLsn = LogicalSequenceNumber.InvalidLsn;
this.currentTargetLsn = LogicalSequenceNumber.InvalidLsn;
this.copyStage = CopyStage.CopyMetadata;
this.copyStateStream = null;
this.copiedRecordNumber = 0;
this.sourceStartingLsn = LogicalSequenceNumber.InvalidLsn;
this.targetStartingLsn = LogicalSequenceNumber.InvalidLsn;
this.logRecordsToCopy = null;
this.beginCheckpointRecord = null;
this.bw = new BinaryWriter(new MemoryStream());
this.isDisposed = false;
this.tracer = tracer;
}
/// <summary>
/// Append end checkpoint record
/// </summary>
public void EndCheckpoint(BeginCheckpointLogRecord lastInProgressCheckpointRecord)
{
lock (lsnOrderingLock)
{
EndCheckpointCallerHoldsLock(lastInProgressCheckpointRecord);
}
}
internal EndCheckpointLogRecord(LogRecordType recordType, ulong recordPosition, long lsn)
: base(recordType, recordPosition, lsn)
{
Utility.Assert(recordType == LogRecordType.EndCheckpoint, "recordType == LogRecordType.EndCheckpoint");
this.lastCompletedBeginCheckpointRecordOffset = InvalidPhysicalRecordOffset;
this.lastCompletedBeginCheckpointRecord = BeginCheckpointLogRecord.InvalidBeginCheckpointLogRecord;
}
/// <summary>
/// Creates or finds the log stream.
/// If being created either initializes the log with default log records or records from backup log.
/// </summary>
/// <param name="openMode">Open mode of the replica.</param>
/// <returns>Task that represents the asynchronous open operation.</returns>
internal async Task <PhysicalLogReader> OpenAsync(ReplicaOpenMode openMode)
{
// TODO: Anurag: do we plumb c.token up?
this.LogicalLog = await this.CreateLogFileAsync(openMode == ReplicaOpenMode.New, CancellationToken.None).ConfigureAwait(false);
var logLogLength = this.LogicalLog.Length;
if (logLogLength <= sizeof(int))
{
// No usable content in the log
if (this.LogicalLog.WritePosition > 0)
{
await this.LogicalLog.TruncateTail(0, CancellationToken.None).ConfigureAwait(false);
// Remove all contents and reset write cursor back to 0
Utility.Assert(this.LogicalLog.Length == 0, "this.logicalLog.Length == 0");
Utility.Assert(this.LogicalLog.WritePosition == 0, "this.logicalLog.WritePosition == 0");
}
using (
var logWriter = new PhysicalLogWriter(
this.LogicalLog,
this.emptyCallbackManager,
this.Tracer,
this.MaxWriteCacheSizeInMB,
this.IncomingBytesRateCounterWriter,
this.LogFlushBytesRateCounterWriter,
this.BytesPerFlushCounterWriter,
this.AvgFlushLatencyCounterWriter,
this.AvgSerializationLatencyCounterWriter,
false))
{
var zeroIndexRecord = IndexingLogRecord.CreateZeroIndexingLogRecord();
logWriter.InsertBufferedRecord(zeroIndexRecord);
logWriter.InsertBufferedRecord(UpdateEpochLogRecord.CreateZeroUpdateEpochLogRecord());
var zeroBeginCheckpointRecord =
BeginCheckpointLogRecord.CreateZeroBeginCheckpointLogRecord();
logWriter.InsertBufferedRecord(zeroBeginCheckpointRecord);
logWriter.InsertBufferedRecord(BarrierLogRecord.CreateOneBarrierLogRecord());
var oneEndCheckpointRecord =
EndCheckpointLogRecord.CreateOneEndCheckpointLogRecord(
zeroBeginCheckpointRecord,
zeroIndexRecord);
logWriter.InsertBufferedRecord(oneEndCheckpointRecord);
var endCompleteCheckpointRecord =
new CompleteCheckpointLogRecord(
LogicalSequenceNumber.OneLsn,
zeroIndexRecord,
oneEndCheckpointRecord);
logWriter.InsertBufferedRecord(endCompleteCheckpointRecord);
await logWriter.FlushAsync("OpenAsync").ConfigureAwait(false);
// This additional await is required to ensure the log record was indeed flushed.
// Without this, the flushasync could succeed, but the log record flush could have failed due to a write error
await endCompleteCheckpointRecord.AwaitFlush().ConfigureAwait(false);
}
}
return(new PhysicalLogReader(this));
}
internal static void Assert(bool condition, string format, BeginCheckpointLogRecord param1, LogRecord param2)
{
if (condition == false)
{
var failFastMessage = string.Format(System.Globalization.CultureInfo.InvariantCulture, format, param1, param2);
FailFast(failFastMessage);
// AMW - Force break into debugger for ease of debugging
Debugger.Break();
}
}
/// <summary>
/// Append end checkpoint record
/// </summary>
private void EndCheckpointCallerHoldsLock(BeginCheckpointLogRecord lastInProgressCheckpointRecord)
{
Utility.Assert(lastInProgressCheckpointRecord != null, "this.lastInProgressCheckpointRecord != null");
this.LastCompletedEndCheckpointRecord =
new EndCheckpointLogRecord(
lastInProgressCheckpointRecord,
this.CurrentLogHeadRecord,
this.CurrentLogTailLsn,
this.LastLinkedPhysicalRecord);
this.LastLinkedPhysicalRecord = this.LastCompletedEndCheckpointRecord;
this.LogManager.PhysicalLogWriter.InsertBufferedRecord(this.LastCompletedEndCheckpointRecord);
}
/// <summary>
/// Process the begin checkpoint log record.
/// </summary>
/// <param name="beginCheckpointLogRecord">The begin checkpoint record to be processed.</param>
/// <param name="isRecoverableRecord">Is this a recoverable record.</param>
private void ProcessLogRecord(BeginCheckpointLogRecord beginCheckpointLogRecord, out bool isRecoverableRecord)
{
isRecoverableRecord = true;
if (Mode.Recovery == this.mode)
{
Utility.Assert(
beginCheckpointLogRecord.RecordPosition <= this.recoveredLastCompletedBeginCheckpointRecord.RecordPosition ||
this.LastCompletedEndCheckpointRecord != null,
BeginCheckpointProcessingAssertMessage,
beginCheckpointLogRecord.RecordPosition, this.recoveredLastCompletedBeginCheckpointRecord.RecordPosition);
}
else
{
Utility.Assert(
LogRecord.InvalidRecordPosition == beginCheckpointLogRecord.RecordPosition,
"LogRecord.INVALID_RECORD_POSITION == beginCheckpointLogRecord.RecordPosition ({0})",
beginCheckpointLogRecord);
}
var failedBarrierCheck = true;
beginCheckpointLogRecord.EarliestPendingTransaction =
this.TransactionsMap.GetEarliestPendingTransaction(
beginCheckpointLogRecord.Lsn.LSN,
out failedBarrierCheck);
Utility.Assert(failedBarrierCheck == false, "failedBarrierCheck == false during recovery");
if (Mode.Recovery == this.mode)
{
if (beginCheckpointLogRecord.RecordPosition
== this.recoveredLastCompletedBeginCheckpointRecord.RecordPosition)
{
Utility.Assert(
this.CurrentLogTailEpoch == this.ProgressVector.LastProgressVectorEntry.Epoch,
"this.currentLogTailEpoch == this.progressVector.LastProgressVectorEntry.Epoch");
Utility.Assert(
this.CurrentLogTailEpoch == beginCheckpointLogRecord.ProgressVector.LastProgressVectorEntry.Epoch,
"this.currentLogTailEpoch == beginCheckpointRecord.ProgressVector.LastProgressVectorEntry.Epoch");
this.LastInProgressCheckpointRecord = beginCheckpointLogRecord;
}
}
else
{
this.LastInProgressCheckpointRecord = beginCheckpointLogRecord;
}
}
internal EndCheckpointLogRecord(
BeginCheckpointLogRecord lastCompletedBeginCheckpointRecord,
IndexingLogRecord logHeadRecord,
LogicalSequenceNumber lsn,
PhysicalLogRecord linkedPhysicalRecord)
: base(LogRecordType.EndCheckpoint, logHeadRecord, lsn, linkedPhysicalRecord)
{
this.lastCompletedBeginCheckpointRecordOffset = InvalidPhysicalRecordOffset;
this.lastStableLsn = lastCompletedBeginCheckpointRecord.LastStableLsn;
this.lastCompletedBeginCheckpointRecord = lastCompletedBeginCheckpointRecord;
Utility.Assert(
this.lastStableLsn >= this.lastCompletedBeginCheckpointRecord.Lsn,
"this.lastStableLsn >= this.lastCompletedBeginCheckpointRecord.LastLogicalSequenceNumber. Last stable lsn is : {0} and last completed checkpoint record is {1}",
this.lastStableLsn.LSN, this.lastCompletedBeginCheckpointRecord.Lsn.LSN);
this.UpdateApproximateDiskSize();
}
internal override bool FreePreviousLinksLowerThanPsn(PhysicalSequenceNumber newHeadPsn)
{
bool ret = base.FreePreviousLinksLowerThanPsn(newHeadPsn);
if ((this.lastCompletedBeginCheckpointRecord != null) &&
(this.lastCompletedBeginCheckpointRecord.Psn < newHeadPsn))
{
Utility.Assert(
this.lastCompletedBeginCheckpointRecordOffset != InvalidPhysicalRecordOffset,
"this.lastCompletedBeginCheckpointRecordOffset != PhysicalLogRecord.INVALID_PHYSICAL_RECORD_OFFSET");
this.lastCompletedBeginCheckpointRecord = this.lastCompletedBeginCheckpointRecordOffset == 0
? null
: BeginCheckpointLogRecord.InvalidBeginCheckpointLogRecord;
return(true);
}
return(ret);
}
public void Reuse(
ProgressVector progressVector,
EndCheckpointLogRecord lastCompletedEndCheckpointRecord,
BeginCheckpointLogRecord lastInProgressBeginCheckpointRecord,
PhysicalLogRecord lastLinkedPhysicalRecord,
InformationLogRecord lastInformationRecord,
IndexingLogRecord currentLogHeadRecord,
Epoch tailEpoch,
LogicalSequenceNumber tailLsn)
{
this.LastInProgressCheckpointRecord = lastInProgressBeginCheckpointRecord;
Utility.Assert(this.LastInProgressCheckpointRecord == null, "ReInitialize of ReplicatedLogManager must have null in progress checkpoint");
this.LastInProgressTruncateHeadRecord = null;
this.ProgressVector = progressVector;
this.LastCompletedEndCheckpointRecord = lastCompletedEndCheckpointRecord;
this.LastLinkedPhysicalRecord = lastLinkedPhysicalRecord;
this.CurrentLogHeadRecord = currentLogHeadRecord;
this.LastInformationRecord = lastInformationRecord;
this.CurrentLogTailEpoch = tailEpoch;
this.CurrentLogTailLsn = tailLsn;
}
/// <summary>
/// Initializes a new instance of the LogRecordsMap class for recovery.
/// </summary>
/// <param name="startingLogicalSequenceNumber"></param>
/// <param name="transactionsMap"></param>
/// <param name="currentLogTailEpoch"></param>
/// <param name="lastStableLsn"></param>
/// <param name="progressVector"></param>
/// <param name="recoveredLastCompletedBeginCheckpointRecord"></param>
/// <param name="tracer"></param>
/// <param name="recoveredLastEndCheckpointRecord"></param>
public LogRecordsMap(
LogicalSequenceNumber startingLogicalSequenceNumber,
TransactionMap transactionsMap,
Epoch currentLogTailEpoch,
LogicalSequenceNumber lastStableLsn,
ProgressVector progressVector,
BeginCheckpointLogRecord recoveredLastCompletedBeginCheckpointRecord,
ITracer tracer,
EndCheckpointLogRecord recoveredLastEndCheckpointRecord)
{
this.mode = Mode.Recovery;
this.LastLogicalSequenceNumber = startingLogicalSequenceNumber;
this.TransactionsMap = transactionsMap;
this.CurrentLogTailEpoch = currentLogTailEpoch;
this.LastStableLsn = lastStableLsn;
this.LastPhysicalRecord = PhysicalLogRecord.InvalidPhysicalLogRecord;
this.ProgressVector = progressVector;
this.recoveredLastCompletedBeginCheckpointRecord = recoveredLastCompletedBeginCheckpointRecord;
this.tracer = tracer;
this.recoveredLastEndCheckpointRecord = recoveredLastEndCheckpointRecord;
}
internal static EndCheckpointLogRecord CreateOneEndCheckpointLogRecord(
BeginCheckpointLogRecord lastCompletedBeginCheckpointRecord,
IndexingLogRecord logHeadRecord)
{
return(new EndCheckpointLogRecord(lastCompletedBeginCheckpointRecord, logHeadRecord));
}
private EndCheckpointLogRecord(
BeginCheckpointLogRecord lastCompletedBeginCheckpointRecord,
IndexingLogRecord logHeadRecord)
: this(lastCompletedBeginCheckpointRecord, logHeadRecord, LogicalSequenceNumber.OneLsn, null)
{
}
private static LogRecord ReadRecord(BinaryReader br, ulong recordPosition, bool isPhysicalRead)
{
LogRecord record;
var lsn = LogicalSequenceNumber.InvalidLsn.LSN;
LogRecordType recordType;
// Metadata section.
var startingPosition = br.BaseStream.Position;
var sizeOfSection = br.ReadInt32();
var endPosition = startingPosition + sizeOfSection;
// Read Logical Metadata
recordType = (LogRecordType)br.ReadUInt32();
switch (recordType)
{
case LogRecordType.BeginTransaction:
record = new BeginTransactionOperationLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.Operation:
record = new OperationLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.EndTransaction:
record = new EndTransactionLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.Barrier:
record = new BarrierLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.UpdateEpoch:
record = new UpdateEpochLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.Backup:
record = new BackupLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.BeginCheckpoint:
record = new BeginCheckpointLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.EndCheckpoint:
record = new EndCheckpointLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.Indexing:
record = new IndexingLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.TruncateHead:
record = new TruncateHeadLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.TruncateTail:
record = new TruncateTailLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.Information:
record = new InformationLogRecord(recordType, recordPosition, lsn);
break;
case LogRecordType.CompleteCheckpoint:
record = new CompleteCheckpointLogRecord(recordType, recordPosition, lsn);
break;
default:
Utility.CodingError("Unexpected record type {0}", recordType);
return(null);
}
record.lsn = new LogicalSequenceNumber(br.ReadInt64());
// Jump to the end of the section ignoring fields that are not understood.
Utility.Assert(endPosition >= br.BaseStream.Position, "Could not have read more than section size.");
br.BaseStream.Position = endPosition;
record.Read(br, isPhysicalRead);
return(record);
}
private async Task DrainCopyStreamAsync(
IOperationStream copyStream,
IOperation operation,
BeginCheckpointLogRecord copiedCheckpointRecord,
bool renamedCopyLogSuccessfully)
{
FabricEvents.Events.DrainStart(this.tracer.Type, "Copy stream: RenamedCopyLogSuccessfully: " + renamedCopyLogSuccessfully);
var lastCopiedRecord = LogicalLogRecord.InvalidLogicalLogRecord;
long copiedRecordNumber = 0, acksOutstanding = 1;
TaskCompletionSource <object> allOperationsAckedTcs = new TaskCompletionSource <object>();
try
{
if (operation != null)
{
this.roleContextDrainState.OnDrainCopy();
do
{
var data = operation.Data;
#if DEBUG
ReplicatedLogManager.ValidateOperationData(data, "DrainCopyStreamAsync LSN: " + operation.SequenceNumber);
#endif
lastCopiedRecord = (LogicalLogRecord)LogRecord.FromOperationData(data);
await this.LogLogicalRecordOnSecondaryAsync(lastCopiedRecord).ConfigureAwait(false);
// After successfully appending the record into the buffer, increment the outstanding ack count
var acksRemaining = Interlocked.Increment(ref acksOutstanding);
FabricEvents.Events.DrainCopyReceive(
this.tracer.Type,
copiedRecordNumber,
lastCopiedRecord.RecordType.ToString(),
lastCopiedRecord.Lsn.LSN,
acksRemaining);
++copiedRecordNumber;
if (this.replicatorSettings.PublicSettings.MaxCopyQueueSize / 2 <= acksRemaining)
{
FabricEvents.Events.DrainCopyFlush(
this.tracer.Type,
copiedRecordNumber,
lastCopiedRecord.Lsn.LSN,
acksRemaining);
this.replicatedLogManager.LogManager.FlushAsync("DrainCopyStream.IsFull").IgnoreExceptionVoid();
}
var capturedOperation = operation;
var capturedRecord = lastCopiedRecord;
if (copiedCheckpointRecord == null)
{
copiedCheckpointRecord = this.replicatedLogManager.LastInProgressCheckpointRecord;
if (copiedCheckpointRecord != null)
{
Utility.Assert(
copiedCheckpointRecord.Lsn == this.recoveredOrCopiedCheckpointLsn.Value,
"copiedCheckpointRecordLsn {0} == recoveredOrCopiedCheckpointLsn {1}",
copiedCheckpointRecord.Lsn,
this.recoveredOrCopiedCheckpointLsn.Value);
}
}
// If pumped the last operation in the copy stream (indicated by copiedUptoLsn), rename the copy log if this was a full copy
// as we are guranteed that the replica has all the data needed to be promoted to an active secondary and we could not have lost any state
if (copiedCheckpointRecord != null &&
copiedCheckpointRecord != BeginCheckpointLogRecord.InvalidBeginCheckpointLogRecord &&
lastCopiedRecord.Lsn == this.copiedUptoLsn &&
renamedCopyLogSuccessfully == false) // Copied UE record could have same LSN, so this condition is needed
{
await this.checkpointManager.CompleteFirstCheckpointOnIdleAndRenameLog(copiedCheckpointRecord, this.copiedUptoLsn.LSN).ConfigureAwait(false);
renamedCopyLogSuccessfully = true;
}
lastCopiedRecord.AwaitFlush().ContinueWith(
async task =>
{
var acksPending = Interlocked.Decrement(ref acksOutstanding);
if (task.Exception != null)
{
// Signal the drain completion task if needed
if (acksPending == 0)
{
allOperationsAckedTcs.TrySetResult(null);
}
return;
}
capturedOperation.Acknowledge();
Utility.Assert(acksPending >= 0, "acksPending {0} >= 0", acksPending);
if (acksPending == 0)
{
allOperationsAckedTcs.TrySetResult(null);
}
FabricEvents.Events.DrainCopyNoise(
this.tracer.Type,
capturedRecord.Lsn.LSN,
acksPending);
await capturedRecord.AwaitApply().ConfigureAwait(false);
}).IgnoreExceptionVoid();
var drainTask = copyStream.GetOperationAsync(CancellationToken.None);
if (drainTask.IsCompleted == false)
{
// GopalK: Currently, we cannot wait for copy to finish because copy might get
// abandoned if the primary fails and the product waits for pending
// copy operations to get acknowledged before electing a new primary
this.replicatedLogManager.LogManager.FlushAsync("DrainCopyStream.IsEmpty").IgnoreExceptionVoid();
await drainTask.ConfigureAwait(false);
}
operation = drainTask.GetAwaiter().GetResult();
} while (operation != null);
}
}
// This finally block ensures that before we continue, we cancel the first full copy checkpoint during full build
// Without having this, it is possible that the above code throws out of this method and any lifecycle API like close might get stuck because
// there is a pending checkpoint that is not yet fully processed
finally
{
// If the pump prematurely finishes for any reason, it means the copy log cannot be renamed
if (copiedCheckpointRecord != null &&
copiedCheckpointRecord != BeginCheckpointLogRecord.InvalidBeginCheckpointLogRecord &&
renamedCopyLogSuccessfully == false)
{
await this.checkpointManager.CancelFirstCheckpointOnIdleDueToIncompleteCopy(copiedCheckpointRecord, this.copiedUptoLsn.LSN);
}
}
await this.replicatedLogManager.FlushInformationRecordAsync(
InformationEvent.CopyFinished,
closeLog : false,
flushInitiator : "DrainCopyStream.IsFinished").ConfigureAwait(false);
// Awaiting processing of this record,
// ensures that all operations in the copystream must have been applied Before we complete the drainComplationTcs.
await this.replicatedLogManager.LastInformationRecord.AwaitProcessing().ConfigureAwait(false);
await this.recordsProcessor.WaitForLogicalRecordsProcessingAsync().ConfigureAwait(false);
var acksOpen = Interlocked.Decrement(ref acksOutstanding);
Utility.Assert(acksOpen >= 0, "acksOpen {0} >= 0", acksOpen);
if (acksOpen != 0)
{
// wait for all the callbacks above to finish running and acknowleding
await allOperationsAckedTcs.Task.ConfigureAwait(false);
}
Utility.Assert(acksOutstanding == 0, "acksOutstanding == 0");
#if !DotNetCoreClr
// These are new events defined in System.Fabric, existing CoreCLR apps would break
// if these events are refernced as it wont be found. As CoreCLR apps carry System.Fabric
// along with application
// This is just a mitigation for now. Actual fix being tracked via bug# 11614507
FabricEvents.Events.DrainCompleted(
this.tracer.Type,
"Copy",
"Completed",
copiedRecordNumber,
(uint)lastCopiedRecord.RecordType,
lastCopiedRecord.Lsn.LSN,
lastCopiedRecord.Psn.PSN,
lastCopiedRecord.RecordPosition);
#endif
}
public void Insert_BeginCheckpoint(BeginCheckpointLogRecord record)
{
Utility.Assert(this.LastInProgressCheckpointRecord == null, "Inprogress checkpoint must be null");
this.LastInProgressCheckpointRecord = record;
this.LogManager.PhysicalLogWriter.InsertBufferedRecord(record);
}
