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; }
public void Open( RecoveredOrCopiedCheckpointLsn recoveredOrCopiedCheckpointLsn, RoleContextDrainState roleContextDrainState, OperationProcessor recordsProcessor, IStateReplicator fabricReplicator, IBackupManager backupManager, CheckpointManager checkpointManager, TransactionManager transactionManager, ReplicatedLogManager replicatedLogManager, IStateManager stateManager, TransactionalReplicatorSettings replicatorSettings, RecoveryManager recoveryManager, ITracer tracer) { this.recoveredOrCopiedCheckpointLsn = recoveredOrCopiedCheckpointLsn; this.recoveryManager = recoveryManager; this.replicatorSettings = replicatorSettings; this.stateManager = stateManager; this.tracer = tracer; this.roleContextDrainState = roleContextDrainState; this.recordsProcessor = recordsProcessor; this.fabricReplicator = fabricReplicator; this.backupManager = backupManager; this.transactionManager = transactionManager; this.checkpointManager = checkpointManager; this.replicatedLogManager = replicatedLogManager; }
public void Open(ReplicatedLogManager logManager, ITracer tracer, ulong checkpointSizeMB, ulong minLogSizeInMB, uint truncationThresholdFactor, uint throttlingThresholdFactor) { this.tracer = tracer; this.logManager = logManager; this.checkpointIntervalBytes = checkpointSizeMB * MBtoBytesMultiplier; this.minLogSizeInBytes = minLogSizeInMB * MBtoBytesMultiplier; this.truncationThresholdInBytes = truncationThresholdFactor * this.minLogSizeInBytes; this.throttleAtLogUsageBytes = this.GetThrottleThresholdInBytes(throttlingThresholdFactor, this.checkpointIntervalBytes, this.minLogSizeInBytes); this.minTruncationAmountInBytes = this.GetMinTruncationAmountInBytes(this.checkpointIntervalBytes); this.indexIntervalBytes = this.checkpointIntervalBytes / NumberOfIndexRecordsPerCheckpoint; this.txnAbortThresholdInBytes = this.checkpointIntervalBytes / AbortOldTxFactor; Utility.Assert(this.minTruncationAmountInBytes > 0, "Min truncation amount in bytes cannot be less than 1"); Utility.Assert(this.indexIntervalBytes != 0, "Index interval in bytes cannot be 0"); Utility.Assert(this.checkpointIntervalBytes != 0, "Checkpoint Interval cannot be 0"); Utility.Assert(this.minLogSizeInBytes != 0, "Min Log Size in bytes cannot be 0"); Utility.Assert(this.truncationThresholdInBytes >= this.minLogSizeInBytes, "truncationThresholdInBytes {0} must be larger than minLogSizeInBytes {1}", this.truncationThresholdInBytes, this.minLogSizeInBytes); Utility.Assert(this.throttleAtLogUsageBytes > this.truncationThresholdInBytes, "throttleAtLogUsageBytes {0} must be larger than truncationThresholdInBytes {1}", this.throttleAtLogUsageBytes, this.truncationThresholdInBytes); Utility.Assert(this.throttleAtLogUsageBytes > this.checkpointIntervalBytes, "throttleAtLogUsageBytes {0} must be larger than checkpointIntervalBytes {1}", this.throttleAtLogUsageBytes, this.checkpointIntervalBytes); var trace = string.Format( CultureInfo.InvariantCulture, "IndexIntervalBytes = {0}, CheckpointIntervalBytes = {1}, MinLogSizeInMB = {2}, TruncateIntervalBytes = {3}, ThrottleAtLogUsageBytes = {4}, MinTruncationThresholdInBytes = {5}", this.indexIntervalBytes, this.checkpointIntervalBytes, this.minLogSizeInBytes, this.truncationThresholdInBytes, this.throttleAtLogUsageBytes, this.minTruncationAmountInBytes); LoggingReplicator.ReplicatorTraceOnApi(tracer, trace); }
public TransactionManager( RecoveredOrCopiedCheckpointLsn recoveredOrCopiedCheckpointLsn, TransactionMap transactionMap, FabricPerformanceCounterSetInstance instance, CheckpointManager checkpointManager, ReplicatedLogManager replicatedLogManager, OperationProcessor unlockCallbackManager, ITracer tracer, long flushAtBufferedBytes) { this.recoveredOrCopiedCheckpointLsn = recoveredOrCopiedCheckpointLsn; this.transactionMap = transactionMap; this.checkpointManager = checkpointManager; this.replicatedLogManager = replicatedLogManager; this.unlockCallbackManager = unlockCallbackManager; this.tracer = tracer; this.flushAtBufferedBytes = flushAtBufferedBytes; this.beginTransactionOperationRatePerformanceCounterWriter = new BeginTransactionOperationRatePerformanceCounterWriter(instance); this.addOperationRatePerformanceCounterWriter = new AddOperationRatePerformanceCounterWriter(instance); this.transactionCommitRatePerformanceCounterWriter = new TransactionCommitRatePerformanceCounterWriter(instance); this.transactionAbortRatePerformanceCounterWriter = new TransactionAbortRatePerformanceCounterWriter(instance); this.addAtomicOperationRatePerformanceCounterWriter = new AddAtomicOperationRatePerformanceCounterWriter(instance); }
public TruncateTailManager( ReplicatedLogManager replicatedLogManager, TransactionMap transactionsMap, IStateManager stateManager, IBackupManager backupManager, LogicalSequenceNumber tailLsn, ApplyContext falseProgressApplyContext, PhysicalLogReader recoveryLogsReader, ITracer tracer) { Utility.Assert(tracer != null, "{0} TruncateTailManager: Input tracer cannot be null"); Utility.Assert(backupManager != null, "{0} TruncateTailManager: Input backupManager cannot be null", tracer.Type); this.replicatedLogManager = replicatedLogManager; this.recoveryLogsReader = recoveryLogsReader; this.transactionsMap = transactionsMap; this.stateManager = stateManager; this.backupManager = backupManager; this.tracer = tracer; this.tailLsn = tailLsn; this.falseProgressApplyContext = falseProgressApplyContext; }
public async Task PerformRecoveryAsync( RecoveredOrCopiedCheckpointLsn recoveredOrCopiedCheckpointLsn, OperationProcessor recordsProcessor, CheckpointManager checkpointManager, TransactionManager transactionManager, LogRecordsDispatcher logRecordsDispatcher, ReplicatedLogManager replicatedLogManager) { var lastPhysicalRecord = PhysicalLogRecord.InvalidPhysicalLogRecord; LogicalSequenceNumber lsn; var recoveredRecords = new List <LogRecord>(); var recoveredLastCompletedBeginCheckpointRecord = await this.RecoveryLogsReader.GetLastCompletedBeginCheckpointRecord(this.RecoveredLastEndCheckpointRecord).ConfigureAwait(false); var recoveredLastCompletedBeginCheckpointRecordPosition = recoveredLastCompletedBeginCheckpointRecord.RecordPosition; var recoveryStartingPosition = recoveredLastCompletedBeginCheckpointRecordPosition - recoveredLastCompletedBeginCheckpointRecord.EarliestPendingTransactionOffset; // Set the recovered lsn before performing recovery as it impacts unlock callback logic during recovery recoveredOrCopiedCheckpointLsn.Update(recoveredLastCompletedBeginCheckpointRecord.Lsn); var trace = string.Format( CultureInfo.InvariantCulture, "PerformRecoveryAsync: " + Environment.NewLine + " Recovered last completed begin checkpoint record." + Environment.NewLine + " Type: {0} LSN: {1} PSN:{2} Position: {3}" + Environment.NewLine + " Recovery Starting Position: {4} Recovery Starting Epoch: {5},{6}" + Environment.NewLine + " LogCompleteCheckpointAfterRecovery: {7}" + " Recovered ProgressVector: {8}" + Environment.NewLine, recoveredLastCompletedBeginCheckpointRecord.RecordType, recoveredLastCompletedBeginCheckpointRecord.Lsn.LSN, recoveredLastCompletedBeginCheckpointRecord.Psn.PSN, recoveredLastCompletedBeginCheckpointRecord.RecordPosition, recoveryStartingPosition, recoveredLastCompletedBeginCheckpointRecord.Epoch.DataLossNumber, recoveredLastCompletedBeginCheckpointRecord.Epoch.ConfigurationNumber, this.logCompleteCheckpointAfterRecovery, recoveredLastCompletedBeginCheckpointRecord.ProgressVector.ToString(Constants.ProgressVectorMaxStringSizeInKb)); FabricEvents.Events.Api(tracer.Type, trace); LogRecord lastRecoverableRecord = null; replicatedLogManager.LogManager.SetSequentialAccessReadSize( this.RecoveryLogsReader.ReadStream, LogManager.ReadAheadBytesForSequentialStream); // Updated to the recovered value in LogRecordsMap during successful recovery long lastPeriodicTruncationTimeTicks = 0; using (var records = new LogRecords(this.RecoveryLogsReader.ReadStream, recoveryStartingPosition, this.tailRecordAtStart.RecordPosition)) { var hasMoved = await records.MoveNextAsync(CancellationToken.None).ConfigureAwait(false); Utility.Assert(hasMoved == true, "hasMoved == true"); lsn = records.Current.Lsn; if (recoveredLastCompletedBeginCheckpointRecord.EarliestPendingTransactionOffset != 0) { lsn -= 1; } var logRecordsMap = new LogRecordsMap( lsn, transactionManager.TransactionsMap, recoveredLastCompletedBeginCheckpointRecord.Epoch, checkpointManager.LastStableLsn, recoveredLastCompletedBeginCheckpointRecord.ProgressVector, recoveredLastCompletedBeginCheckpointRecord, this.tracer, this.RecoveredLastEndCheckpointRecord); do { var isRecoverableRecord = true; var record = records.Current; record.CompletedFlush(null); Utility.Assert( record.PreviousPhysicalRecord == logRecordsMap.LastPhysicalRecord, "record.PreviousPhysicalRecord == lastPhysicalRecord"); logRecordsMap.ProcessLogRecord(record, out isRecoverableRecord); if (isRecoverableRecord == true) { recoveredRecords.Add(record); lastRecoverableRecord = record; if (LoggingReplicator.IsBarrierRecord(record) && recoveredRecords.Count >= ReplicatorDynamicConstants.ParallelRecoveryBatchSize) { logRecordsDispatcher.DispatchLoggedRecords(new LoggedRecords(recoveredRecords, null)); recoveredRecords = new List <LogRecord>(); this.recoveryException = recordsProcessor.ServiceException; if (this.recoveryException == null) { this.recoveryException = recordsProcessor.LogException; } if (this.recoveryException != null) { // If there was an apply or unlock failure, report fault does not help during recovery because the replica is not opened yet. // The only solution here is to throw during OpenAsync FabricEvents.Events.Api( tracer.Type, "PerformRecoveryAsync: RecoveryFailed"); await lastRecoverableRecord.AwaitProcessing().ConfigureAwait(false); await recordsProcessor.WaitForAllRecordsProcessingAsync().ConfigureAwait(false); throw this.recoveryException; } } } else { Utility.Assert(LoggingReplicator.IsBarrierRecord(record) == false, "IsBarrierRecord(record) == false"); record.CompletedApply(null); record.CompletedProcessing(null); } hasMoved = await records.MoveNextAsync(CancellationToken.None).ConfigureAwait(false); } while (hasMoved == true); this.LastRecoveredAtomicRedoOperationLsn = logRecordsMap.LastRecoveredAtomicRedoOperationLsn; checkpointManager.ResetStableLsn(logRecordsMap.LastStableLsn); lastPhysicalRecord = logRecordsMap.LastPhysicalRecord; lsn = logRecordsMap.LastLogicalSequenceNumber; if (recoveredRecords.Count > 0) { logRecordsDispatcher.DispatchLoggedRecords(new LoggedRecords(recoveredRecords, null)); } var tailRecord = records.Current; FabricEvents.Events.Api( tracer.Type, "PerformRecoveryAsync: Current tail record Type: " + tailRecord.RecordType + " LSN: " + tailRecord.Lsn.LSN + " PSN: " + tailRecord.Psn.PSN + " Position: " + tailRecord.RecordPosition); Utility.Assert( lastPhysicalRecord == records.LastPhysicalRecord, "lastPhysicalRecord == records.LastPhysicalRecord"); Utility.Assert( (tailRecord == lastPhysicalRecord) || (tailRecord.PreviousPhysicalRecord == lastPhysicalRecord), "(tailRecord == lastPhysicalRecord) || " + "(tailRecord.PreviousPhysicalRecord == lastPhysicalRecord), " + "LastPhysicalRecord PSN: {0}", lastPhysicalRecord.Psn.PSN); Utility.Assert( logRecordsMap.LastCompletedEndCheckpointRecord != null, "this.lastCompletedEndCheckpointRecord != null"); Utility.Assert( logRecordsMap.LastInProgressCheckpointRecord == null, "this.lastInProgressCheckpointRecord == null"); Utility.Assert(logRecordsMap.LastLinkedPhysicalRecord != null, "this.lastLinkedPhysicalRecord != nul"); Utility.Assert(lsn == tailRecord.Lsn, "lsn == tailRecord.LastLogicalSequenceNumber"); // Disable read ahead as indexing physical records will read the log backwards replicatedLogManager.LogManager.SetSequentialAccessReadSize(this.RecoveryLogsReader.ReadStream, 0); await this.RecoveryLogsReader.IndexPhysicalRecords(lastPhysicalRecord).ConfigureAwait(false); var callbackManager = new PhysicalLogWriterCallbackManager(this.flushedRecordsCallback); callbackManager.FlushedPsn = tailRecord.Psn + 1; replicatedLogManager.LogManager.PrepareToLog(tailRecord, callbackManager); replicatedLogManager.Reuse( recoveredLastCompletedBeginCheckpointRecord.ProgressVector, logRecordsMap.LastCompletedEndCheckpointRecord, logRecordsMap.LastInProgressCheckpointRecord, logRecordsMap.LastLinkedPhysicalRecord, replicatedLogManager.LastInformationRecord, (IndexingLogRecord)this.RecoveryLogsReader.StartingRecord, logRecordsMap.CurrentLogTailEpoch, lsn); this.RecoveredLsn = lsn; // GopalK: The order of the following statements is significant if (this.logCompleteCheckpointAfterRecovery) { replicatedLogManager.CompleteCheckpoint(); } replicatedLogManager.Information(InformationEvent.Recovered); await replicatedLogManager.LogManager.FlushAsync("PerformRecovery").ConfigureAwait(false); await lastRecoverableRecord.AwaitProcessing().ConfigureAwait(false); await recordsProcessor.WaitForAllRecordsProcessingAsync().ConfigureAwait(false); lastPeriodicTruncationTimeTicks = logRecordsMap.LastPeriodicTruncationTimeTicks; } this.recoveryException = recordsProcessor.ServiceException; if (this.recoveryException == null) { this.recoveryException = recordsProcessor.LogException; } if (this.recoveryException != null) { FabricEvents.Events.Api( tracer.Type, "PerformRecoveryAsync: RecoveryFailed"); // If there was an apply or unlock failure, report fault does not help during recovery because the replica is not opened yet. // The only solution here is to throw during OpenAsync throw this.recoveryException; } checkpointManager.Recover( recoveredLastCompletedBeginCheckpointRecord, lastPeriodicTruncationTimeTicks); }
private async Task FlushTask(object initiatingTcs) { var flushingTasks = new List <TaskCompletionSource <object> >(); flushingTasks.Add((TaskCompletionSource <object>)initiatingTcs); var isFlushTask = true; var flushWatch = Stopwatch.StartNew(); var serializationWatch = Stopwatch.StartNew(); do { TaskCompletionSource <object> notificationTcs; try { Utility.Assert(this.loggingException == null, "this.loggingException == null"); var numberOfLatencySensitiveRecords = 0; ulong numberOfBytes = 0; var startingPsn = this.flushingRecords[0].Psn; FabricEvents.Events.PhysicalLogWriterFlushStart( this.tracer.Type, this.flushingRecords.Count, startingPsn.PSN); // Enable group commit as we are about to issue IO // Operations above this line must not throw. notificationTcs = Interlocked.Exchange <TaskCompletionSource <object> >( ref this.flushNotificationTcs, FlushPendingTcs); flushWatch.Reset(); serializationWatch.Reset(); foreach (var record in this.flushingRecords) { serializationWatch.Start(); var operationData = this.WriteRecord(record, numberOfBytes); #if DEBUG ReplicatedLogManager.ValidateOperationData(operationData, "Log Write for " + record.RecordType); #endif var logicalRecord = record as LogicalLogRecord; if (logicalRecord != null && logicalRecord.IsLatencySensitiveRecord == true) { ++numberOfLatencySensitiveRecords; } serializationWatch.Stop(); this.avgSerializationLatencyCounterWriter.IncrementBy(serializationWatch); flushWatch.Start(); foreach (var arraySegment in operationData) { numberOfBytes += (ulong)arraySegment.Count; await this.logicalLogStream.AppendAsync( arraySegment.Array, arraySegment.Offset, arraySegment.Count, CancellationToken.None).ConfigureAwait(false); } flushWatch.Stop(); } Utility.Assert(notificationTcs == FlushPermittedTcs, "NotificationTcs == FlushPermittedTcs"); flushWatch.Start(); await this.logicalLogStream.FlushWithMarkerAsync(CancellationToken.None).ConfigureAwait(false); flushWatch.Stop(); this.UpdateWriteStats(flushWatch, numberOfBytes); var lastWrittenTailRecord = this.flushingRecords[this.flushingRecords.Count - 1]; // Save the new log tail position and no need to interlock as single // instruction 64-bit writes are atomic on 64-bit machines and there // can only be one thread here this.currentLogTailPosition += numberOfBytes; this.currentLogTailRecord = lastWrittenTailRecord; this.bytesPerFlushCounterWriter.IncrementBy((long)numberOfBytes); if (flushWatch.ElapsedMilliseconds > 3000) { FabricEvents.Events.PhysicalLogWriterFlushEndWarning( this.tracer.Type, numberOfBytes, this.flushingRecords.Count, numberOfLatencySensitiveRecords, flushWatch.ElapsedMilliseconds, serializationWatch.ElapsedMilliseconds, (double)this.writeSpeedBytesPerSecondSum / MovingAverageHistory, (double)this.runningLatencySumMs / MovingAverageHistory, this.logicalLogStream.WritePosition - (long)numberOfBytes); } else { FabricEvents.Events.PhysicalLogWriterFlushEnd( this.tracer.Type, numberOfBytes, this.flushingRecords.Count, numberOfLatencySensitiveRecords, flushWatch.ElapsedMilliseconds, serializationWatch.ElapsedMilliseconds, (double)this.writeSpeedBytesPerSecondSum / MovingAverageHistory, (double)this.runningLatencySumMs / MovingAverageHistory, this.logicalLogStream.WritePosition - (long)numberOfBytes); } } catch (Exception e) { this.loggingException = e; } finally { try { // Disable group commit as there is no pending IO notificationTcs = this.FlushCompleted(); // GopalK: The order of the following instructions is very important. // It is important to process flushed records first before // waking up flush waiters var flushedTasks = flushingTasks; var flushedRecords = new LoggedRecords(this.flushingRecords, this.loggingException); this.ProcessFlushedRecords(flushedRecords); isFlushTask = this.ProcessFlushCompletion(flushedRecords, ref flushedTasks, out flushingTasks); this.WakeupFlushWaiters(flushedTasks); if ((isFlushTask == true) && (this.loggingException != null)) { this.FailedFlushTask(flushingTasks); isFlushTask = false; } } catch (Exception e) { int innerHResult = 0; var exception = Utility.FlattenException(e, out innerHResult); var exceptionMessage = string.Format( CultureInfo.InvariantCulture, "PhysicalLogWriter::FlushTask() - Hit an exception, Type: {0}, Message: {1}, HResult: 0x{2:X8}, Stack Trace: {3}", exception.GetType().ToString(), exception.Message, exception.HResult != 0 ? exception.HResult : innerHResult, exception.StackTrace); FabricEvents.Events.Warning(this.tracer.Type, exceptionMessage); Utility.Assert(false, exceptionMessage); throw; } } } while (isFlushTask == true); return; }
private async Task DrainReplicationStreamAsync(IOperationStream replicationStream) { FabricEvents.Events.DrainStart(this.tracer.Type, "Replication stream"); TaskCompletionSource <object> allOperationsAckedTcs = new TaskCompletionSource <object>(); var lastReplicatedRecord = LogicalLogRecord.InvalidLogicalLogRecord; long replicatedRecordNumber = 0, acksOutstanding = 1, bytesOutstanding = 0; this.roleContextDrainState.OnDrainReplication(); do { var drainTask = replicationStream.GetOperationAsync(CancellationToken.None); if (drainTask.IsCompleted == false) { this.replicatedLogManager.LogManager.FlushAsync("DrainReplicationStream.IsEmpty").IgnoreExceptionVoid(); await drainTask.ConfigureAwait(false); } var operation = drainTask.GetAwaiter().GetResult(); if (operation != null) { var data = operation.Data; #if DEBUG ReplicatedLogManager.ValidateOperationData(data, "DrainReplicationStream LSN: " + operation.SequenceNumber); #endif lastReplicatedRecord = (LogicalLogRecord)LogRecord.FromOperationData(data); lastReplicatedRecord.Lsn = new LogicalSequenceNumber(operation.SequenceNumber); await this.LogLogicalRecordOnSecondaryAsync(lastReplicatedRecord).ConfigureAwait(false); var acksRemaining = Interlocked.Increment(ref acksOutstanding); FabricEvents.Events.DrainReplicationReceive( this.tracer.Type, replicatedRecordNumber, (uint)lastReplicatedRecord.RecordType, lastReplicatedRecord.Lsn.LSN, acksRemaining); ++replicatedRecordNumber; long operationSize = Utility.GetOperationSize(data); var bytesRemaining = Interlocked.Add(ref bytesOutstanding, operationSize); if (((this.replicatorSettings.PublicSettings.MaxSecondaryReplicationQueueSize / 2 <= acksRemaining) || ((this.replicatorSettings.PublicSettings.MaxSecondaryReplicationQueueMemorySize > 0) && (this.replicatorSettings.PublicSettings.MaxSecondaryReplicationQueueMemorySize / 2 <= bytesRemaining))) || ((this.replicatorSettings.PublicSettings.MaxPrimaryReplicationQueueSize / 2 <= acksRemaining) || ((this.replicatorSettings.PublicSettings.MaxPrimaryReplicationQueueMemorySize > 0) && (this.replicatorSettings.PublicSettings.MaxPrimaryReplicationQueueMemorySize / 2 <= bytesRemaining)))) { FabricEvents.Events.DrainReplicationFlush( this.tracer.Type, replicatedRecordNumber, lastReplicatedRecord.Lsn.LSN, acksRemaining, bytesRemaining); this.replicatedLogManager.LogManager.FlushAsync("DrainReplicationStream.IsFull").IgnoreExceptionVoid(); } var capturedOperation = operation; var capturedRecord = lastReplicatedRecord; lastReplicatedRecord.AwaitFlush().IgnoreException().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; } var bytesPending = Interlocked.Add(ref bytesOutstanding, -operationSize); Utility.Assert( (acksPending >= 0) && (bytesPending >= 0), "(acksPending >= 0) && (bytesPending >= 0)"); if (acksPending == 0) { allOperationsAckedTcs.TrySetResult(null); } capturedOperation.Acknowledge(); FabricEvents.Events.DrainReplicationNoise( this.tracer.Type, capturedRecord.Lsn.LSN, acksPending, bytesPending); await capturedRecord.AwaitApply().ConfigureAwait(false); }).IgnoreExceptionVoid(); } else { await this.replicatedLogManager.FlushInformationRecordAsync( InformationEvent.ReplicationFinished, closeLog : false, flushInitiator : "DrainReplicationstream.IsFinished").ConfigureAwait(false); await this.replicatedLogManager.LastInformationRecord.AwaitProcessing().ConfigureAwait(false); await this.recordsProcessor.WaitForLogicalRecordsProcessingAsync().ConfigureAwait(false); var acksPending = Interlocked.Decrement(ref acksOutstanding); Utility.Assert(acksPending >= 0, "acksPending >= 0"); if (acksPending != 0) { await allOperationsAckedTcs.Task.ConfigureAwait(false); } Utility.Assert(acksOutstanding == 0, "acksOutstanding == 0"); break; } } while (true); #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, "Replication", "Completed", replicatedRecordNumber, (uint)lastReplicatedRecord.RecordType, lastReplicatedRecord.Lsn.LSN, lastReplicatedRecord.Psn.PSN, lastReplicatedRecord.RecordPosition); #endif }
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 }