/// <inheritdoc/>
public override Task <RpcResponse> Notify(WorkerNotificationArgs message, ServerCallContext context)
{
var bondMessage = message.ToOpenBond();
m_masterService.ReceivedWorkerNotificationAsync(bondMessage);
return(Task.FromResult(new RpcResponse()));
}
public static WorkerNotificationArgs ToGrpc(this OpenBond.WorkerNotificationArgs message)
{
var workerNotificationArgs = new WorkerNotificationArgs()
{
WorkerId = message.WorkerId,
ExecutionLogBlobSequenceNumber = message.ExecutionLogBlobSequenceNumber,
ExecutionLogData = message.ExecutionLogData.ToByteString(),
};
foreach (var i in message.CompletedPips)
{
workerNotificationArgs.CompletedPips.Add(new PipCompletionData()
{
ExecuteStepTicks = i.ExecuteStepTicks,
PipIdValue = i.PipIdValue,
QueueTicks = i.QueueTicks,
ResultBlob = i.ResultBlob.ToByteString(),
Step = i.Step,
ThreadId = i.ThreadId,
StartTimeTicks = i.StartTimeTicks
});
}
foreach (var i in message.ForwardedEvents)
{
var eventMessage = new EventMessage()
{
EventId = i.EventId,
EventKeywords = i.EventKeywords,
EventName = i.EventName,
Id = i.Id,
Level = i.Level,
Text = i.Text,
};
if (i.PipProcessErrorEvent != null)
{
eventMessage.PipProcessErrorEvent = new global::BuildXL.Distribution.Grpc.PipProcessErrorEvent()
{
PipSemiStableHash = i.PipProcessErrorEvent.PipSemiStableHash,
PipDescription = i.PipProcessErrorEvent.PipDescription,
PipSpecPath = i.PipProcessErrorEvent.PipSpecPath,
PipWorkingDirectory = i.PipProcessErrorEvent.PipWorkingDirectory,
PipExe = i.PipProcessErrorEvent.PipExe,
OutputToLog = i.PipProcessErrorEvent.OutputToLog,
MessageAboutPathsToLog = i.PipProcessErrorEvent.MessageAboutPathsToLog,
PathsToLog = i.PipProcessErrorEvent.PathsToLog,
ExitCode = i.PipProcessErrorEvent.ExitCode,
OptionalMessage = i.PipProcessErrorEvent.OptionalMessage,
ShortPipDescription = i.PipProcessErrorEvent.ShortPipDescription
};
}
workerNotificationArgs.ForwardedEvents.Add(eventMessage);
}
return(workerNotificationArgs);
}
public static OpenBond.WorkerNotificationArgs ToOpenBond(this WorkerNotificationArgs message)
{
var completedPips = new List <OpenBond.PipCompletionData>();
foreach (var i in message.CompletedPips)
{
completedPips.Add(new OpenBond.PipCompletionData()
{
ExecuteStepTicks = i.ExecuteStepTicks,
PipIdValue = i.PipIdValue,
QueueTicks = i.QueueTicks,
ResultBlob = i.ResultBlob.ToArraySegmentByte(),
Step = i.Step,
ThreadId = i.ThreadId,
StartTimeTicks = i.StartTimeTicks
});
}
var eventMessages = new List <OpenBond.EventMessage>();
foreach (var i in message.ForwardedEvents)
{
eventMessages.Add(new OpenBond.EventMessage()
{
EventId = i.EventId,
EventKeywords = i.EventKeywords,
EventName = i.EventName,
Id = i.Id,
Level = i.Level,
Text = i.Text,
PipProcessErrorEvent = i.ErrorEventCase == EventMessage.ErrorEventOneofCase.PipProcessErrorEvent ? new OpenBond.PipProcessErrorEvent()
{
PipSemiStableHash = i.PipProcessErrorEvent.PipSemiStableHash,
PipDescription = i.PipProcessErrorEvent.PipDescription,
PipSpecPath = i.PipProcessErrorEvent.PipSpecPath,
PipWorkingDirectory = i.PipProcessErrorEvent.PipWorkingDirectory,
PipExe = i.PipProcessErrorEvent.PipExe,
OutputToLog = i.PipProcessErrorEvent.OutputToLog,
MessageAboutPathsToLog = i.PipProcessErrorEvent.MessageAboutPathsToLog,
PathsToLog = i.PipProcessErrorEvent.PathsToLog,
ExitCode = i.PipProcessErrorEvent.ExitCode,
OptionalMessage = i.PipProcessErrorEvent.OptionalMessage,
ShortPipDescription = i.PipProcessErrorEvent.ShortPipDescription
} : null,
});
}
return(new OpenBond.WorkerNotificationArgs()
{
WorkerId = message.WorkerId,
CompletedPips = completedPips,
ExecutionLogBlobSequenceNumber = message.ExecutionLogBlobSequenceNumber,
ExecutionLogData = message.ExecutionLogData.ToArraySegmentByte(),
ForwardedEvents = eventMessages
});
}
public async void ReceivedWorkerNotificationAsync(WorkerNotificationArgs notification)
{
var worker = GetWorkerById(notification.WorkerId);
if (notification.ExecutionLogData != null && notification.ExecutionLogData.Count != 0)
{
// The channel is unblocked and ACK is sent after we put the execution blob to the queue in 'LogExecutionBlobAsync' method.
await worker.LogExecutionBlobAsync(notification);
}
// Return immediately to unblock the channel so that worker can receive the ACK for the sent message
await Task.Yield();
foreach (var forwardedEvent in notification.ForwardedEvents)
{
EventLevel eventLevel = (EventLevel)forwardedEvent.Level;
switch (eventLevel)
{
case EventLevel.Error:
Logger.Log.DistributionWorkerForwardedError(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
m_loggingContext.SpecifyErrorWasLogged((ushort)forwardedEvent.EventId);
break;
case EventLevel.Warning:
Logger.Log.DistributionWorkerForwardedWarning(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
break;
default:
break;
}
}
foreach (PipCompletionData completedPip in notification.CompletedPips)
{
worker.NotifyPipCompletion(completedPip);
}
}
public async void ReceivedWorkerNotificationAsync(WorkerNotificationArgs notification)
{
var worker = GetWorkerById(notification.WorkerId);
if (notification.ExecutionLogData != null && notification.ExecutionLogData.Count != 0)
{
// NOTE: We need to log the execution blob synchronously as the order of the execution log events
// must be retained for proper deserialization
worker.LogExecutionBlob(notification.ExecutionLogData, notification.ExecutionLogBlobSequenceNumber);
}
// Return immediately to unblock worker
await Task.Yield();
foreach (var forwardedEvent in notification.ForwardedEvents)
{
EventLevel eventLevel = (EventLevel)forwardedEvent.Level;
switch (eventLevel)
{
case EventLevel.Error:
Logger.Log.DistributionWorkerForwardedError(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
break;
case EventLevel.Warning:
Logger.Log.DistributionWorkerForwardedWarning(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
break;
default:
break;
}
}
foreach (PipCompletionData completedPip in notification.CompletedPips)
{
worker.NotifyPipCompletion(completedPip);
}
}
/// <inheritdoc/>
public override async Task <RpcResponse> Notify(WorkerNotificationArgs message, ServerCallContext context)
{
var bondMessage = message.ToOpenBond();
var notifyTask = m_masterService.ReceivedWorkerNotificationAsync(bondMessage);
if (EngineEnvironmentSettings.InlineWorkerXLGHandling)
{
await notifyTask;
}
else
{
notifyTask.Forget();
}
return(new RpcResponse());
}
public static OpenBond.WorkerNotificationArgs ToOpenBond(this WorkerNotificationArgs message)
{
var completedPips = new List <OpenBond.PipCompletionData>();
foreach (var i in message.CompletedPips)
{
completedPips.Add(new OpenBond.PipCompletionData()
{
ExecuteStepTicks = i.ExecuteStepTicks,
PipIdValue = i.PipIdValue,
QueueTicks = i.QueueTicks,
ResultBlob = i.ResultBlob.ToArraySegmentByte(),
Step = i.Step
});
}
var eventMessages = new List <OpenBond.EventMessage>();
foreach (var i in message.ForwardedEvents)
{
eventMessages.Add(new OpenBond.EventMessage()
{
EventId = i.EventId,
EventKeywords = i.EventKeywords,
EventName = i.EventName,
Id = i.Id,
Level = i.Level,
Text = i.Text
});
}
return(new OpenBond.WorkerNotificationArgs()
{
BuildId = message.Sender.BuildId,
SenderId = message.Sender.SenderId,
SenderName = message.Sender.SenderName,
WorkerId = message.WorkerId,
CompletedPips = completedPips,
ExecutionLogBlobSequenceNumber = message.ExecutionLogBlobSequenceNumber,
ExecutionLogData = message.ExecutionLogData.ToArraySegmentByte(),
ForwardedEvents = eventMessages
});
}
public static WorkerNotificationArgs ToGrpc(this OpenBond.WorkerNotificationArgs message, SenderInfo senderInfo)
{
var workerNotificationArgs = new WorkerNotificationArgs()
{
Sender = senderInfo,
WorkerId = message.WorkerId,
ExecutionLogBlobSequenceNumber = message.ExecutionLogBlobSequenceNumber,
ExecutionLogData = message.ExecutionLogData.ToByteString(),
};
foreach (var i in message.CompletedPips)
{
workerNotificationArgs.CompletedPips.Add(new PipCompletionData()
{
ExecuteStepTicks = i.ExecuteStepTicks ?? 0,
PipIdValue = i.PipIdValue,
QueueTicks = i.QueueTicks ?? 0,
ResultBlob = i.ResultBlob.ToByteString(),
Step = i.Step
});
}
foreach (var i in message.ForwardedEvents)
{
workerNotificationArgs.ForwardedEvents.Add(new EventMessage()
{
EventId = i.EventId,
EventKeywords = i.EventKeywords,
EventName = i.EventName,
Id = i.Id,
Level = i.Level,
Text = i.Text
});
}
return(workerNotificationArgs);
}
public async Task LogExecutionBlobAsync(WorkerNotificationArgs notification)
{
Contract.Requires(notification.ExecutionLogData != null || notification.ExecutionLogData.Count != 0);
m_executionBlobQueue.Add(notification);
// After we put the executionBlob in a queue, we can unblock the caller and give an ACK to the worker.
await Task.Yield();
// Execution log events cannot be logged by multiple threads concurrently since they must be ordered
using (await m_logBlobMutex.AcquireAsync())
{
// We need to dequeue and process the blobs in order.
// Here, we do not necessarily process the blob that is just added to the queue above.
// There might be another thread that adds the next blob to the queue after the current thread,
// and that thread might acquire the lock earlier.
WorkerNotificationArgs executionBlobNotification = null;
Contract.Assert(m_executionBlobQueue.TryTake(out executionBlobNotification), "The executionBlob queue cannot be empty");
int blobSequenceNumber = executionBlobNotification.ExecutionLogBlobSequenceNumber;
ArraySegment <byte> executionLogBlob = executionBlobNotification.ExecutionLogData;
if (m_workerExecutionLogTarget == null)
{
return;
}
try
{
// Workers send execution log blobs one-at-a-time, waiting for a response from the master between each message.
// A sequence number higher than the last logged blob sequence number indicates a worker sent a subsequent blob without waiting for a response.
Contract.Assert(blobSequenceNumber <= m_lastBlobSeqNumber + 1, "Workers should not send a new execution log blob until receiving a response from the master for all previous blobs.");
// Due to network latency and retries, it's possible to receive a message multiple times.
// Ignore any low numbered blobs since they should have already been logged and ack'd at some point before
// the worker could send a higher numbered blob.
if (blobSequenceNumber != m_lastBlobSeqNumber + 1)
{
return;
}
if (m_executionLogBufferStream == null)
{
// Create the stream on demand, because we need to pass the BinaryLogReader stream with the header bytes in order
// to correctly deserialize events
m_executionLogBufferStream = new MemoryStream();
}
// Write the new execution log event content into buffer starting at beginning of buffer stream
m_executionLogBufferStream.SetLength(0);
m_executionLogBufferStream.Write(executionLogBlob.Array, executionLogBlob.Offset, executionLogBlob.Count);
// Reset the buffer stream to beginning and reset reader to ensure it reads events starting from beginning
m_executionLogBufferStream.Position = 0;
if (m_executionLogBinaryReader == null)
{
m_executionLogBinaryReader = new BinaryLogReader(m_executionLogBufferStream, m_masterService.Environment.Context);
m_executionLogReader = new ExecutionLogFileReader(m_executionLogBinaryReader, m_workerExecutionLogTarget);
}
m_executionLogBinaryReader.Reset();
// Read all events into worker execution log target
if (!m_executionLogReader.ReadAllEvents())
{
Logger.Log.DistributionCallMasterCodeException(m_appLoggingContext, nameof(LogExecutionBlobAsync), "Failed to read all worker events");
// Disable further processing of execution log since an error was encountered during processing
m_workerExecutionLogTarget = null;
}
else
{
m_lastBlobSeqNumber = blobSequenceNumber;
}
}
catch (Exception ex)
{
Logger.Log.DistributionCallMasterCodeException(m_appLoggingContext, nameof(LogExecutionBlobAsync), ex.ToStringDemystified() + Environment.NewLine
+ "Message sequence number: " + blobSequenceNumber
+ " Last sequence number logged: " + m_lastBlobSeqNumber);
// Disable further processing of execution log since an exception was encountered during processing
m_workerExecutionLogTarget = null;
}
}
if (m_executionBlobQueue.IsCompleted)
{
m_executionBlobCompletion.TrySetResult(true);
}
}
public async Task ReceivedWorkerNotificationAsync(WorkerNotificationArgs notification)
{
var worker = GetWorkerById(notification.WorkerId);
if (notification.ExecutionLogData.Count != 0)
{
// The channel is unblocked and ACK is sent after we put the execution blob to the queue in 'LogExecutionBlobAsync' method.
await worker.LogExecutionBlobAsync(notification);
}
// Return immediately to unblock the channel so that worker can receive the ACK for the sent message
await Task.Yield();
foreach (var forwardedEvent in notification.ForwardedEvents)
{
EventLevel eventLevel = (EventLevel)forwardedEvent.Level;
// For some errors, we need to exit the worker.
// Those errors should not make the master fail,
// so we override the level with Warning.
if (await worker.NotifyInfrastructureErrorAsync(forwardedEvent))
{
eventLevel = EventLevel.Warning;
}
switch (eventLevel)
{
case EventLevel.Error:
var status = worker.Status;
// If we receive new failures from an already stopped worker (we're not talking to it anymore), we log them as verbose events instead.
// This prevents logging errors for failed work that we retried elsewhere after abandoning that worker: in those cases,
// the build will succeed but we will complain about the logged errors and crash.
var shouldLogForwardedErrorAsVerbose = status == WorkerNodeStatus.Stopped;
Action <LoggingContext, WorkerForwardedEvent> logForwardedError =
shouldLogForwardedErrorAsVerbose ? Logger.Log.StoppedDistributionWorkerForwardedError : Logger.Log.DistributionWorkerForwardedError;
if (forwardedEvent.EventId == (int)BuildXL.Processes.Tracing.LogEventId.PipProcessError)
{
var pipProcessErrorEvent = new PipProcessErrorEventFields(
forwardedEvent.PipProcessErrorEvent.PipSemiStableHash,
forwardedEvent.PipProcessErrorEvent.PipDescription,
forwardedEvent.PipProcessErrorEvent.PipSpecPath,
forwardedEvent.PipProcessErrorEvent.PipWorkingDirectory,
forwardedEvent.PipProcessErrorEvent.PipExe,
forwardedEvent.PipProcessErrorEvent.OutputToLog,
forwardedEvent.PipProcessErrorEvent.MessageAboutPathsToLog,
forwardedEvent.PipProcessErrorEvent.PathsToLog,
forwardedEvent.PipProcessErrorEvent.ExitCode,
forwardedEvent.PipProcessErrorEvent.OptionalMessage,
forwardedEvent.PipProcessErrorEvent.ShortPipDescription);
logForwardedError(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
PipProcessErrorEvent = pipProcessErrorEvent,
});
}
else
{
logForwardedError(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
}
if (!shouldLogForwardedErrorAsVerbose)
{
m_loggingContext.SpecifyErrorWasLogged((ushort)forwardedEvent.EventId);
}
break;
case EventLevel.Warning:
Logger.Log.DistributionWorkerForwardedWarning(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
break;
default:
break;
}
}
foreach (PipCompletionData completedPip in notification.CompletedPips)
{
worker.NotifyPipCompletion(completedPip);
}
}
public async Task ReceivedWorkerNotificationAsync(WorkerNotificationArgs notification)
{
var worker = GetWorkerById(notification.WorkerId);
if (notification.ExecutionLogData.Count != 0)
{
// The channel is unblocked and ACK is sent after we put the execution blob to the queue in 'LogExecutionBlobAsync' method.
await worker.LogExecutionBlobAsync(notification);
}
// Return immediately to unblock the channel so that worker can receive the ACK for the sent message
await Task.Yield();
foreach (var forwardedEvent in notification.ForwardedEvents)
{
EventLevel eventLevel = (EventLevel)forwardedEvent.Level;
// For some errors, we need to exit the worker.
// Those errors should not make the master fail,
// so we override the level with Warning.
if (await worker.NotifyInfrastructureErrorAsync(forwardedEvent))
{
eventLevel = EventLevel.Warning;
}
switch (eventLevel)
{
case EventLevel.Error:
if (forwardedEvent.EventId == (int)BuildXL.Processes.Tracing.LogEventId.PipProcessError)
{
var pipProcessErrorEvent = new PipProcessErrorEventFields(
forwardedEvent.PipProcessErrorEvent.PipSemiStableHash,
forwardedEvent.PipProcessErrorEvent.PipDescription,
forwardedEvent.PipProcessErrorEvent.PipSpecPath,
forwardedEvent.PipProcessErrorEvent.PipWorkingDirectory,
forwardedEvent.PipProcessErrorEvent.PipExe,
forwardedEvent.PipProcessErrorEvent.OutputToLog,
forwardedEvent.PipProcessErrorEvent.MessageAboutPathsToLog,
forwardedEvent.PipProcessErrorEvent.PathsToLog,
forwardedEvent.PipProcessErrorEvent.ExitCode,
forwardedEvent.PipProcessErrorEvent.OptionalMessage,
forwardedEvent.PipProcessErrorEvent.ShortPipDescription);
Logger.Log.DistributionWorkerForwardedError(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
PipProcessErrorEvent = pipProcessErrorEvent,
});
}
else
{
Logger.Log.DistributionWorkerForwardedError(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
}
m_loggingContext.SpecifyErrorWasLogged((ushort)forwardedEvent.EventId);
break;
case EventLevel.Warning:
Logger.Log.DistributionWorkerForwardedWarning(
m_loggingContext,
new WorkerForwardedEvent()
{
Text = forwardedEvent.Text,
WorkerName = worker.Name,
EventId = forwardedEvent.EventId,
EventName = forwardedEvent.EventName,
EventKeywords = forwardedEvent.EventKeywords,
});
break;
default:
break;
}
}
foreach (PipCompletionData completedPip in notification.CompletedPips)
{
worker.NotifyPipCompletion(completedPip);
}
}
