public SiloStatisticsManager(SiloInitializationParameters initializationParams, SerializationManager serializationManager, ITelemetryProducer telemetryProducer, ILoggerFactory loggerFactory)
{
MessagingStatisticsGroup.Init(true);
MessagingProcessingStatisticsGroup.Init();
NetworkingStatisticsGroup.Init(true);
ApplicationRequestsStatisticsGroup.Init(initializationParams.GlobalConfig.ResponseTimeout);
SchedulerStatisticsGroup.Init(loggerFactory);
StorageStatisticsGroup.Init();
TransactionsStatisticsGroup.Init();
this.logger = new LoggerWrapper <SiloStatisticsManager>(loggerFactory);
runtimeStats = new RuntimeStatisticsGroup(loggerFactory);
this.logStatistics = new LogStatistics(initializationParams.NodeConfig.StatisticsLogWriteInterval, true, serializationManager, loggerFactory);
this.MetricsTable = new SiloPerformanceMetrics(this.runtimeStats, loggerFactory, initializationParams.NodeConfig);
this.countersPublisher = new CountersStatistics(initializationParams.NodeConfig.StatisticsPerfCountersWriteInterval, telemetryProducer, loggerFactory);
initializationParams.ClusterConfig.OnConfigChange(
"Defaults/LoadShedding",
() => this.MetricsTable.NodeConfig = initializationParams.NodeConfig,
false);
}
protected override void FailMessage(Message msg, string reason)
{
msg.ReleaseBodyAndHeaderBuffers();
MessagingStatisticsGroup.OnFailedSentMessage(msg);
if (MsgCenter.Running && msg.Direction == Message.Directions.Request)
{
if (Log.IsVerbose)
{
Log.Verbose(ErrorCode.ProxyClient_RejectingMsg, "Rejecting message: {0}. Reason = {1}", msg, reason);
}
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message error = msg.CreateRejectionResponse(Message.RejectionTypes.Unrecoverable, reason);
MsgCenter.QueueIncomingMessage(error);
}
else
{
Log.Warn(ErrorCode.ProxyClient_DroppingMsg, "Dropping message: {0}. Reason = {1}", msg, reason);
MessagingStatisticsGroup.OnDroppedSentMessage(msg);
}
}
private Task ProbeInternal(SiloAddress remoteSilo, int probeNumber)
{
Task task;
try
{
RequestContext.Set(RequestContext.PING_APPLICATION_HEADER, true);
var remoteOracle = this.grainFactory.GetSystemTarget <IMembershipService>(Constants.MembershipOracleType, remoteSilo);
task = remoteOracle.Ping(probeNumber);
// Update stats counter. Only count Pings that were successfuly sent, but not necessarily replied to.
MessagingStatisticsGroup.OnPingSend(remoteSilo);
}
finally
{
RequestContext.Remove(RequestContext.PING_APPLICATION_HEADER);
}
return(task);
}
protected override void OnReceiveMessageFailure(Message message, Exception exception)
{
// If deserialization completely failed or the message was one-way, rethrow the exception
// so that it can be handled at another level.
if (message?.Headers == null || message.Direction != Message.Directions.Request)
{
ExceptionDispatchInfo.Capture(exception).Throw();
}
// The message body was not successfully decoded, but the headers were.
// Send a fast fail to the caller.
MessagingStatisticsGroup.OnRejectedMessage(message);
var response = this.messageFactory.CreateResponseMessage(message);
response.Result = Message.ResponseTypes.Error;
response.BodyObject = Response.ExceptionResponse(exception);
// Send the error response and continue processing the next message.
this.messageCenter.SendMessage(response);
}
protected override void OnMessageSerializationFailure(Message msg, Exception exc)
{
// we only get here if we failed to serialize the msg (or any other catastrophic failure).
// Request msg fails to serialize on the sending silo, so we just enqueue a rejection msg.
// Response msg fails to serialize on the responding silo, so we try to send an error response back.
this.Log.LogWarning(
(int)ErrorCode.MessagingUnexpectedSendError,
"Unexpected error serializing message {Message}: {Exception}",
msg,
exc);
msg.ReleaseBodyAndHeaderBuffers();
MessagingStatisticsGroup.OnFailedSentMessage(msg);
var retryCount = msg.RetryCount ?? 0;
if (msg.Direction == Message.Directions.Request)
{
messageCenter.SendRejection(msg, Message.RejectionTypes.Unrecoverable, exc.ToString());
}
else if (msg.Direction == Message.Directions.Response && retryCount < 1)
{
// if we failed sending an original response, turn the response body into an error and reply with it.
// unless we have already tried sending the response multiple times.
msg.Result = Message.ResponseTypes.Error;
msg.BodyObject = Response.ExceptionResponse(exc);
msg.RetryCount = retryCount + 1;
this.messageCenter.SendMessage(msg);
}
else
{
this.Log.LogWarning(
(int)ErrorCode.Messaging_OutgoingMS_DroppingMessage,
"Silo {SiloAddress} is dropping message which failed during serialization: {Message}. Exception = {Exception}",
this.messageCenter.MyAddress,
msg,
exc);
MessagingStatisticsGroup.OnDroppedSentMessage(msg);
}
}
public SiloStatisticsManager(
IOptions <SiloStatisticsOptions> statisticsOptions,
IOptions <MonitoringStorageOptions> azureStorageOptions,
ILocalSiloDetails siloDetails,
SerializationManager serializationManager,
ITelemetryProducer telemetryProducer,
ILoggerFactory loggerFactory)
{
this.siloDetails = siloDetails;
this.storageOptions = azureStorageOptions.Value;
MessagingStatisticsGroup.Init(true);
MessagingProcessingStatisticsGroup.Init();
NetworkingStatisticsGroup.Init(true);
ApplicationRequestsStatisticsGroup.Init();
SchedulerStatisticsGroup.Init(loggerFactory);
StorageStatisticsGroup.Init();
TransactionsStatisticsGroup.Init();
this.logger = loggerFactory.CreateLogger <SiloStatisticsManager>();
this.logStatistics = new LogStatistics(statisticsOptions.Value.LogWriteInterval, true, serializationManager, loggerFactory);
this.countersPublisher = new CountersStatistics(statisticsOptions.Value.PerfCountersWriteInterval, telemetryProducer, loggerFactory);
}
public ClientOutboundConnection(
SiloAddress remoteSiloAddress,
ConnectionContext connection,
ConnectionDelegate middleware,
ClientMessageCenter messageCenter,
ConnectionManager connectionManager,
ConnectionOptions connectionOptions,
ConnectionCommon connectionShared,
ConnectionPreambleHelper connectionPreambleHelper,
ClusterOptions clusterOptions)
: base(connection, middleware, connectionShared)
{
this.messageCenter = messageCenter;
this.connectionManager = connectionManager;
this.connectionOptions = connectionOptions;
this.connectionPreambleHelper = connectionPreambleHelper;
this.clusterOptions = clusterOptions;
this.RemoteSiloAddress = remoteSiloAddress ?? throw new ArgumentNullException(nameof(remoteSiloAddress));
this.MessageReceivedCounter = MessagingStatisticsGroup.GetMessageReceivedCounter(this.RemoteSiloAddress);
this.MessageSentCounter = MessagingStatisticsGroup.GetMessageSendCounter(this.RemoteSiloAddress);
}
protected override void OnMessageSerializationFailure(Message msg, Exception exc)
{
// we only get here if we failed to serialize the msg (or any other catastrophic failure).
// Request msg fails to serialize on the sender, so we just enqueue a rejection msg.
// Response msg fails to serialize on the responding silo, so we try to send an error response back.
this.Log.LogWarning(
(int)ErrorCode.ProxyClient_SerializationError,
"Unexpected error serializing message {Message}: {Exception}",
msg,
exc);
msg.ReleaseBodyAndHeaderBuffers();
MessagingStatisticsGroup.OnFailedSentMessage(msg);
var retryCount = msg.RetryCount ?? 0;
if (msg.Direction == Message.Directions.Request)
{
this.MsgCenter.RejectMessage(msg, $"Unable to serialize message. Encountered exception: {exc?.GetType()}: {exc?.Message}", exc);
}
else if (msg.Direction == Message.Directions.Response && retryCount < 1)
{
// if we failed sending an original response, turn the response body into an error and reply with it.
// unless we have already tried sending the response multiple times.
msg.Result = Message.ResponseTypes.Error;
msg.BodyObject = Response.ExceptionResponse(exc);
msg.RetryCount = retryCount + 1;
this.MsgCenter.SendMessage(msg);
}
else
{
this.Log.LogWarning(
(int)ErrorCode.ProxyClient_DroppingMsg,
"Gateway client is dropping message which failed during serialization: {Message}. Exception = {Exception}",
msg,
exc);
MessagingStatisticsGroup.OnDroppedSentMessage(msg);
}
}
/// <summary>
/// Handles a message receive failure.
/// </summary>
/// <returns><see langword="true"/> if the exception should not be caught and <see langword="false"/> if it should be caught.</returns>
private bool HandleReceiveMessageFailure(Message message, Exception exception)
{
this.Log.LogWarning(
exception,
"Exception reading message {Message} from remote endpoint {Remote} to local endpoint {Local}",
message,
this.RemoteEndPoint,
this.LocalEndPoint);
// If deserialization completely failed, rethrow the exception so that it can be handled at another level.
if (message is null)
{
// Returning false here informs the caller that the exception should not be caught.
return(false);
}
// The message body was not successfully decoded, but the headers were.
MessagingStatisticsGroup.OnRejectedMessage(message);
if (message.Direction == Message.Directions.Request)
{
// Send a fast fail to the caller.
var response = this.MessageFactory.CreateResponseMessage(message);
response.Result = Message.ResponseTypes.Error;
response.BodyObject = Response.FromException(exception);
// Send the error response and continue processing the next message.
this.Send(response);
}
else if (message.Direction == Message.Directions.Response)
{
// If the message was a response, propagate the exception to the intended recipient.
message.Result = Message.ResponseTypes.Error;
message.BodyObject = Response.FromException(exception);
this.MessageCenter.DispatchLocalMessage(message);
}
// The exception has been handled by propagating it onwards.
return(true);
}
private bool RecordSuccess(long id, int diagnosticProbeNumber)
{
if (this.log.IsEnabled(LogLevel.Trace))
{
this.log.LogTrace("Got successful ping response for ping #{ProbeNumber}/{Id} from {Silo}", diagnosticProbeNumber, id, this.SiloAddress);
}
MessagingStatisticsGroup.OnPingReplyReceived(this.SiloAddress);
lock (this.lockObj)
{
if (id <= this.highestCompletedProbeId)
{
this.log.Info(
"Ignoring success result for ping #{ProbeNumber}/{Id} from {Silo} since a later probe has already completed. Highest ({HighestCompletedProbeId}) > Current ({CurrentProbeId})",
diagnosticProbeNumber,
id,
this.SiloAddress,
this.highestCompletedProbeId,
id);
return(false);
}
else if (this.stoppingCancellation.IsCancellationRequested)
{
this.log.Info(
"Ignoring success result for ping #{ProbeNumber}/{Id} from {Silo} since this monitor has been stopped",
diagnosticProbeNumber,
id,
this.SiloAddress);
return(false);
}
else
{
this.highestCompletedProbeId = id;
Interlocked.Exchange(ref this.missedProbes, 0);
return(true);
}
}
}
public void FailMessage(Message msg, string reason)
{
if (msg?.Headers != null && msg.IsPing())
{
this.Log.LogWarning("Failed ping message {Message}", msg);
}
MessagingStatisticsGroup.OnFailedSentMessage(msg);
if (msg.Direction == Message.Directions.Request)
{
if (this.Log.IsEnabled(LogLevel.Debug))
{
this.Log.LogDebug((int)ErrorCode.MessagingSendingRejection, "Silo {SiloAddress} is rejecting message: {Message}. Reason = {Reason}", this.LocalSiloAddress, msg, reason);
}
// Done retrying, send back an error instead
this.messageCenter.SendRejection(msg, Message.RejectionTypes.Transient, $"Silo {this.LocalSiloAddress} is rejecting message: {msg}. Reason = {reason}");
}
else
{
this.MessagingTrace.OnSiloDropSendingMessage(this.LocalSiloAddress, msg, reason);
}
}
private void RecordFailure(long id, int diagnosticProbeNumber, Exception failureReason)
{
if (this.log.IsEnabled(LogLevel.Trace))
{
this.log.LogTrace("Got failed ping response for ping #{ProbeNumber} from {Silo}: {Exception}", diagnosticProbeNumber, this.SiloAddress, failureReason);
}
MessagingStatisticsGroup.OnPingReplyMissed(this.SiloAddress);
lock (this.lockObj)
{
if (id <= this.highestCompletedProbeId)
{
this.log.Info("Ignoring failure result for ping #{ProbeNumber} from {Silo} since a later probe has already completed", diagnosticProbeNumber, this.SiloAddress);
}
else if (this.stoppingCancellation.IsCancellationRequested)
{
this.log.Info("Ignoring failure result for ping #{ProbeNumber} from {Silo} since this monitor has been stopped", diagnosticProbeNumber, this.SiloAddress);
}
else
{
this.highestCompletedProbeId = id;
var missed = Interlocked.Increment(ref this.missedProbes);
this.log.LogWarning(
(int)ErrorCode.MembershipMissedPing,
"Did not get ping response for ping #{ProbeNumber} from {Silo}: {Exception}",
diagnosticProbeNumber,
this.SiloAddress,
failureReason);
if (this.log.IsEnabled(LogLevel.Trace))
{
this.log.LogTrace("Current number of failed probes for {Silo}: {MissedProbes}", this.SiloAddress, missed);
}
}
}
}
public SiloStatisticsManager(
NodeConfiguration nodeConfiguration,
ILocalSiloDetails siloDetails,
SerializationManager serializationManager,
ITelemetryProducer telemetryProducer,
IHostEnvironmentStatistics hostEnvironmentStatistics,
IAppEnvironmentStatistics appEnvironmentStatistics,
ILoggerFactory loggerFactory,
IOptions <MessagingOptions> messagingOptions)
{
this.siloDetails = siloDetails;
MessagingStatisticsGroup.Init(true);
MessagingProcessingStatisticsGroup.Init();
NetworkingStatisticsGroup.Init(true);
ApplicationRequestsStatisticsGroup.Init(messagingOptions.Value.ResponseTimeout);
SchedulerStatisticsGroup.Init(loggerFactory);
StorageStatisticsGroup.Init();
TransactionsStatisticsGroup.Init();
this.logger = loggerFactory.CreateLogger <SiloStatisticsManager>();
this.hostEnvironmentStatistics = hostEnvironmentStatistics;
this.logStatistics = new LogStatistics(nodeConfiguration.StatisticsLogWriteInterval, true, serializationManager, loggerFactory);
this.MetricsTable = new SiloPerformanceMetrics(this.hostEnvironmentStatistics, appEnvironmentStatistics, loggerFactory, nodeConfiguration);
this.countersPublisher = new CountersStatistics(nodeConfiguration.StatisticsPerfCountersWriteInterval, telemetryProducer, loggerFactory);
}
protected override void OnReceivedMessage(Message msg)
{
// See it's a Ping message, and if so, short-circuit it
var requestContext = msg.RequestContextData;
if (requestContext != null &&
requestContext.TryGetValue(RequestContext.PING_APPLICATION_HEADER, out var pingObj) &&
pingObj is bool &&
(bool)pingObj)
{
MessagingStatisticsGroup.OnPingReceive(msg.SendingSilo);
if (this.Log.IsEnabled(LogLevel.Trace))
{
this.Log.Trace("Responding to Ping from {0}", msg.SendingSilo);
}
if (!msg.TargetSilo.Equals(messageCenter.MyAddress)) // got ping that is not destined to me. For example, got a ping to my older incarnation.
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message rejection = this.messageFactory.CreateRejectionResponse(msg, Message.RejectionTypes.Unrecoverable,
$"The target silo is no longer active: target was {msg.TargetSilo.ToLongString()}, but this silo is {messageCenter.MyAddress.ToLongString()}. " +
$"The rejected ping message is {msg}.");
messageCenter.OutboundQueue.SendMessage(rejection);
}
else
{
var response = this.messageFactory.CreateResponseMessage(msg);
response.BodyObject = Response.Done;
this.messageCenter.SendMessage(response);
}
return;
}
// sniff message headers for directory cache management
this.messageCenter.SniffIncomingMessage?.Invoke(msg);
// Don't process messages that have already timed out
if (msg.IsExpired)
{
msg.DropExpiredMessage(MessagingStatisticsGroup.Phase.Receive);
return;
}
// If we've stopped application message processing, then filter those out now
// Note that if we identify or add other grains that are required for proper stopping, we will need to treat them as we do the membership table grain here.
if (messageCenter.IsBlockingApplicationMessages && (msg.Category == Message.Categories.Application) && !Constants.SystemMembershipTableId.Equals(msg.SendingGrain))
{
// We reject new requests, and drop all other messages
if (msg.Direction != Message.Directions.Request)
{
return;
}
MessagingStatisticsGroup.OnRejectedMessage(msg);
var reject = this.messageFactory.CreateRejectionResponse(msg, Message.RejectionTypes.Unrecoverable, "Silo stopping");
this.messageCenter.SendMessage(reject);
return;
}
// Make sure the message is for us. Note that some control messages may have no target
// information, so a null target silo is OK.
if ((msg.TargetSilo == null) || msg.TargetSilo.Matches(messageCenter.MyAddress))
{
// See if it's a message for a client we're proxying.
if (messageCenter.IsProxying && messageCenter.TryDeliverToProxy(msg))
{
return;
}
// Nope, it's for us
messageCenter.OnReceivedMessage(msg);
return;
}
if (!msg.TargetSilo.Endpoint.Equals(messageCenter.MyAddress.Endpoint))
{
// If the message is for some other silo altogether, then we need to forward it.
if (this.Log.IsEnabled(LogLevel.Trace))
{
this.Log.Trace("Forwarding message {0} from {1} to silo {2}", msg.Id, msg.SendingSilo, msg.TargetSilo);
}
messageCenter.OutboundQueue.SendMessage(msg);
return;
}
// If the message was for this endpoint but an older epoch, then reject the message
// (if it was a request), or drop it on the floor if it was a response or one-way.
if (msg.Direction == Message.Directions.Request)
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message rejection = this.messageFactory.CreateRejectionResponse(msg, Message.RejectionTypes.Transient,
string.Format("The target silo is no longer active: target was {0}, but this silo is {1}. The rejected message is {2}.",
msg.TargetSilo.ToLongString(), messageCenter.MyAddress.ToLongString(), msg));
// Invalidate the remote caller's activation cache entry.
if (msg.TargetAddress != null)
{
rejection.AddToCacheInvalidationHeader(msg.TargetAddress);
}
messageCenter.OutboundQueue.SendMessage(rejection);
if (this.Log.IsEnabled(LogLevel.Debug))
{
this.Log.Debug("Rejecting an obsolete request; target was {0}, but this silo is {1}. The rejected message is {2}.",
msg.TargetSilo.ToLongString(), messageCenter.MyAddress.ToLongString(), msg);
}
}
}
/// <summary>
/// Probes the remote node via an intermediary silo.
/// </summary>
/// <param name="intermediary">The node to probe the target with.</param>
/// <param name="directProbeTimeout">The amount of time which the intermediary should allow for the target to respond.</param>
/// <param name="cancellation">A token to cancel and fail the probe attempt.</param>
/// <returns>The number of failed probes since the last successful probe.</returns>
private async Task <ProbeResult> ProbeIndirectly(SiloAddress intermediary, TimeSpan directProbeTimeout, CancellationToken cancellation)
{
var id = ++_nextProbeId;
if (_log.IsEnabled(LogLevel.Trace))
{
_log.LogTrace("Going to send indirect ping #{Id} to probe silo {Silo} via {Intermediary}", id, SiloAddress, intermediary);
}
var roundTripTimer = ValueStopwatch.StartNew();
ProbeResult probeResult;
try
{
using var cancellationSource = CancellationTokenSource.CreateLinkedTokenSource(cancellation, _stoppingCancellation.Token);
var cancellationTask = cancellationSource.Token.WhenCancelled();
var probeTask = _prober.ProbeIndirectly(intermediary, SiloAddress, directProbeTimeout, id);
var task = await Task.WhenAny(cancellationTask, probeTask);
if (ReferenceEquals(task, cancellationTask) && probeTask.Status != TaskStatus.RanToCompletion)
{
probeTask.Ignore();
probeResult = ProbeResult.CreateIndirect(_failedProbes, ProbeResultStatus.Unknown, default);
}
else
{
var indirectResult = await probeTask;
roundTripTimer.Stop();
var roundTripTime = roundTripTimer.Elapsed - indirectResult.ProbeResponseTime;
// Record timing regardless of the result.
_elapsedSinceLastSuccessfulResponse.Restart();
LastRoundTripTime = roundTripTimer.Elapsed - indirectResult.ProbeResponseTime;
if (indirectResult.Succeeded)
{
_log.LogInformation(
"Indirect probe request #{Id} to silo {SiloAddress} via silo {IntermediarySiloAddress} succeeded after {RoundTripTime} with a direct probe response time of {ProbeResponseTime}.",
id,
SiloAddress,
intermediary,
roundTripTimer.Elapsed,
indirectResult.ProbeResponseTime);
MessagingStatisticsGroup.OnPingReplyReceived(SiloAddress);
_failedProbes = 0;
probeResult = ProbeResult.CreateIndirect(0, ProbeResultStatus.Succeeded, indirectResult);
}
else
{
MessagingStatisticsGroup.OnPingReplyMissed(SiloAddress);
if (indirectResult.IntermediaryHealthScore > 0)
{
_log.LogInformation(
"Ignoring failure result for ping #{Id} from {Silo} since the intermediary used to probe the silo is not healthy. Intermediary health degradation score: {IntermediaryHealthScore}",
id,
SiloAddress,
indirectResult.IntermediaryHealthScore);
probeResult = ProbeResult.CreateIndirect(_failedProbes, ProbeResultStatus.Unknown, indirectResult);
}
else
{
_log.LogWarning(
"Indirect probe request #{Id} to silo {SiloAddress} via silo {IntermediarySiloAddress} failed after {RoundTripTime} with a direct probe response time of {ProbeResponseTime}. Failure message: {FailureMessage}. Intermediary health score: {IntermediaryHealthScore}",
id,
SiloAddress,
intermediary,
roundTripTimer.Elapsed,
indirectResult.ProbeResponseTime,
indirectResult.FailureMessage,
indirectResult.IntermediaryHealthScore);
var missed = ++_failedProbes;
probeResult = ProbeResult.CreateIndirect(missed, ProbeResultStatus.Failed, indirectResult);
}
}
}
}
catch (Exception exception)
{
_log.LogWarning(exception, "Indirect probe request failed");
probeResult = ProbeResult.CreateIndirect(_failedProbes, ProbeResultStatus.Unknown, default);
}
return(probeResult);
}
/// <summary>
/// Probes the remote silo.
/// </summary>
/// <param name="cancellation">A token to cancel and fail the probe attempt.</param>
/// <returns>The number of failed probes since the last successful probe.</returns>
private async Task <ProbeResult> ProbeDirectly(CancellationToken cancellation)
{
var id = ++_nextProbeId;
if (_log.IsEnabled(LogLevel.Trace))
{
_log.LogTrace("Going to send Ping #{Id} to probe silo {Silo}", id, SiloAddress);
}
var roundTripTimer = ValueStopwatch.StartNew();
ProbeResult probeResult;
Exception failureException;
try
{
var probeCancellation = cancellation.WhenCancelled();
var probeTask = _prober.Probe(SiloAddress, id);
var task = await Task.WhenAny(probeCancellation, probeTask);
if (ReferenceEquals(task, probeCancellation) && probeTask.Status != TaskStatus.RanToCompletion)
{
probeTask.Ignore();
failureException = new OperationCanceledException($"The ping attempt was cancelled after {roundTripTimer.Elapsed}. Ping #{id}");
}
else
{
await probeTask;
failureException = null;
}
}
catch (Exception exception)
{
failureException = exception;
}
finally
{
roundTripTimer.Stop();
}
if (failureException is null)
{
MessagingStatisticsGroup.OnPingReplyReceived(SiloAddress);
if (_log.IsEnabled(LogLevel.Trace))
{
_log.LogTrace(
"Got successful ping response for ping #{Id} from {Silo} with round trip time of {RoundTripTime}",
id,
SiloAddress,
roundTripTimer.Elapsed);
}
_failedProbes = 0;
_elapsedSinceLastSuccessfulResponse.Restart();
LastRoundTripTime = roundTripTimer.Elapsed;
probeResult = ProbeResult.CreateDirect(0, ProbeResultStatus.Succeeded);
}
else
{
MessagingStatisticsGroup.OnPingReplyMissed(SiloAddress);
var failedProbes = ++_failedProbes;
_log.LogWarning(
(int)ErrorCode.MembershipMissedPing,
failureException,
"Did not get response for probe #{Id} to silo {Silo} after {Elapsed}. Current number of consecutive failed probes is {FailedProbeCount}",
id,
SiloAddress,
roundTripTimer.Elapsed,
failedProbes);
probeResult = ProbeResult.CreateDirect(failedProbes, ProbeResultStatus.Failed);
}
return(probeResult);
}
private void ReceiveMessage(Message msg)
{
MessagingProcessingStatisticsGroup.OnImaMessageReceived(msg);
ISchedulingContext context;
// Find the activation it targets; first check for a system activation, then an app activation
if (msg.TargetGrain.IsSystemTarget)
{
SystemTarget target = directory.FindSystemTarget(msg.TargetActivation);
if (target == null)
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message response = this.messageFactory.CreateRejectionResponse(msg, Message.RejectionTypes.Unrecoverable,
String.Format("SystemTarget {0} not active on this silo. Msg={1}", msg.TargetGrain, msg));
messageCenter.SendMessage(response);
Log.Warn(ErrorCode.MessagingMessageFromUnknownActivation, "Received a message {0} for an unknown SystemTarget: {1}", msg, msg.TargetAddress);
return;
}
context = target.SchedulingContext;
switch (msg.Direction)
{
case Message.Directions.Request:
MessagingProcessingStatisticsGroup.OnImaMessageEnqueued(context);
scheduler.QueueWorkItem(new RequestWorkItem(target, msg), context);
break;
case Message.Directions.Response:
MessagingProcessingStatisticsGroup.OnImaMessageEnqueued(context);
scheduler.QueueWorkItem(new ResponseWorkItem(target, msg), context);
break;
default:
Log.Error(ErrorCode.Runtime_Error_100097, "Invalid message: " + msg);
break;
}
}
else
{
// Run this code on the target activation's context, if it already exists
ActivationData targetActivation = directory.FindTarget(msg.TargetActivation);
if (targetActivation != null)
{
lock (targetActivation)
{
var target = targetActivation; // to avoid a warning about nulling targetActivation under a lock on it
if (target.State == ActivationState.Valid)
{
var overloadException = target.CheckOverloaded(Log);
if (overloadException != null)
{
// Send rejection as soon as we can, to avoid creating additional work for runtime
dispatcher.RejectMessage(msg, Message.RejectionTypes.Overloaded, overloadException, "Target activation is overloaded " + target);
return;
}
// Run ReceiveMessage in context of target activation
context = new SchedulingContext(target);
}
else
{
// Can't use this activation - will queue for another activation
target = null;
context = null;
}
EnqueueReceiveMessage(msg, target, context);
}
}
else
{
// No usable target activation currently, so run ReceiveMessage in system context
EnqueueReceiveMessage(msg, null, null);
}
}
}
public void SendMessage(Message msg)
{
if (msg == null)
{
throw new ArgumentNullException("msg", "Can't send a null message.");
}
if (stopped)
{
logger.Info(ErrorCode.Runtime_Error_100112, "Message was queued for sending after outbound queue was stopped: {0}", msg);
return;
}
// Don't process messages that have already timed out
if (msg.IsExpired)
{
msg.DropExpiredMessage(MessagingStatisticsGroup.Phase.Send);
return;
}
if (!msg.QueuedTime.HasValue)
{
msg.QueuedTime = DateTime.UtcNow;
}
// First check to see if it's really destined for a proxied client, instead of a local grain.
if (messageCenter.IsProxying && messageCenter.TryDeliverToProxy(msg))
{
return;
}
if (msg.TargetSilo == null)
{
logger.Error(ErrorCode.Runtime_Error_100113, "Message does not have a target silo: " + msg + " -- Call stack is: " + Utils.GetStackTrace());
messageCenter.SendRejection(msg, Message.RejectionTypes.Unrecoverable, "Message to be sent does not have a target silo");
return;
}
if (!messageCenter.TrySendLocal(msg))
{
if (stopped)
{
logger.Info(ErrorCode.Runtime_Error_100115, "Message was queued for sending after outbound queue was stopped: {0}", msg);
return;
}
// check for simulation of lost messages
if (messageCenter.ShouldDrop?.Invoke(msg) == true)
{
logger.Info(ErrorCode.Messaging_SimulatedMessageLoss, "Message blocked by test");
messageCenter.SendRejection(msg, Message.RejectionTypes.Unrecoverable, "Message blocked by test");
return;
}
if (this.siloStatusOracle.IsDeadSilo(msg.TargetSilo))
{
MessagingStatisticsGroup.OnFailedSentMessage(msg);
var reason = $"Target {msg.TargetSilo.ToLongString()} silo is known to be dead";
if (logger.IsEnabled(LogLevel.Debug))
{
logger.LogDebug(
(int)ErrorCode.MessagingSendingRejection,
"Silo {siloAddress} is rejecting message: {message}. Reason = {reason}",
messageCenter.MyAddress,
msg,
reason);
}
this.messageCenter.SendRejection(msg, Message.RejectionTypes.Transient, reason);
return;
}
var senderTask = this.connectionManager.GetConnection(msg.TargetSilo);
if (senderTask.IsCompletedSuccessfully)
{
var sender = senderTask.Result;
sender.Send(msg);
}
else
{
_ = SendAsync(senderTask, msg);
async Task SendAsync(ValueTask <Connection> c, Message m)
{
try
{
var sender = await c;
sender.Send(m);
}
catch (Exception exception)
{
this.messageCenter.SendRejection(m, Message.RejectionTypes.Transient, $"Exception while sending message: {exception}");
}
}
}
}
}
protected override void Process(OutgoingClientMessage request)
{
if (Cts.IsCancellationRequested)
{
return;
}
var client = request.Item1;
var msg = request.Item2;
// Find the client state
ClientState clientState;
bool found;
// TODO: Why do we need this lock here if clients is a ConcurrentDictionary?
//lock (gateway.lockable)
{
found = gateway.clients.TryGetValue(client, out clientState);
}
// This should never happen -- but make sure to handle it reasonably, just in case
if (!found || (clientState == null))
{
if (msg == null)
{
return;
}
Log.Info(ErrorCode.GatewayTryingToSendToUnrecognizedClient, "Trying to send a message {0} to an unrecognized client {1}", msg.ToString(), client);
MessagingStatisticsGroup.OnFailedSentMessage(msg);
// Message for unrecognized client -- reject it
if (msg.Direction == Message.Directions.Request)
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message error = this.messageFactory.CreateRejectionResponse(
msg,
Message.RejectionTypes.Unrecoverable,
"Unknown client " + client);
gateway.SendMessage(error);
}
else
{
MessagingStatisticsGroup.OnDroppedSentMessage(msg);
}
return;
}
// if disconnected - queue for later.
if (!clientState.IsConnected)
{
if (msg == null)
{
return;
}
if (Log.IsEnabled(LogLevel.Trace))
{
Log.Trace("Queued message {0} for client {1}", msg, client);
}
clientState.PendingToSend.Enqueue(msg);
return;
}
// if the queue is non empty - drain it first.
if (clientState.PendingToSend.Count > 0)
{
if (msg != null)
{
clientState.PendingToSend.Enqueue(msg);
}
// For now, drain in-line, although in the future this should happen in yet another asynch agent
Drain(clientState);
return;
}
// the queue was empty AND we are connected.
// If the request includes a message to send, send it (or enqueue it for later)
if (msg == null)
{
return;
}
if (!Send(msg, clientState.Socket))
{
if (Log.IsEnabled(LogLevel.Trace))
{
Log.Trace("Queued message {0} for client {1}", msg, client);
}
clientState.PendingToSend.Enqueue(msg);
}
else
{
if (Log.IsEnabled(LogLevel.Trace))
{
Log.Trace("Sent message {0} to client {1}", msg, client);
}
}
}
private bool SendBatch(List <Message> msgs, Socket sock)
{
if (Cts.IsCancellationRequested)
{
return(false);
}
if (sock == null)
{
return(false);
}
if (msgs == null || msgs.Count == 0)
{
return(true);
}
// Send the message
List <ArraySegment <byte> > data;
int headerLengths;
bool continueSend = OutgoingMessageSender.SerializeMessages(msgs, out data, out headerLengths, OnMessageSerializationFailure);
if (!continueSend)
{
return(false);
}
int length = data.Sum(x => x.Count);
int bytesSent = 0;
bool exceptionSending = false;
bool countMismatchSending = false;
string sendErrorStr;
try
{
bytesSent = sock.Send(data);
if (bytesSent != length)
{
// The complete message wasn't sent, even though no error was reported; treat this as an error
countMismatchSending = true;
sendErrorStr = String.Format("Byte count mismatch on send: sent {0}, expected {1}", bytesSent, length);
Log.Warn(ErrorCode.GatewayByteCountMismatch, sendErrorStr);
}
}
catch (Exception exc)
{
exceptionSending = true;
string remoteEndpoint = "";
if (!(exc is ObjectDisposedException))
{
remoteEndpoint = sock.RemoteEndPoint.ToString();
}
sendErrorStr = String.Format("Exception sending to client at {0}: {1}", remoteEndpoint, exc);
Log.Warn(ErrorCode.GatewayExceptionSendingToClient, sendErrorStr, exc);
}
MessagingStatisticsGroup.OnMessageBatchSend(msgs[0].TargetSilo, msgs[0].Direction, bytesSent, headerLengths, SocketDirection.GatewayToClient, msgs.Count);
bool sendError = exceptionSending || countMismatchSending;
if (sendError)
{
gateway.RecordClosedSocket(sock);
SocketManager.CloseSocket(sock);
}
gatewaySends.Increment();
foreach (Message msg in msgs)
{
msg.ReleaseBodyAndHeaderBuffers();
}
return(!sendError);
}
public void ProcessReceivedBuffer(int bytes)
{
offset += bytes;
if (offset < CurrentLength)
{
return; // Nothing to do except start the next receive
}
#if TRACK_DETAILED_STATS
ThreadTrackingStatistic tracker = null;
if (StatisticsCollector.CollectThreadTimeTrackingStats)
{
int id = System.Threading.Thread.CurrentThread.ManagedThreadId;
if (!trackers.TryGetValue(id, out tracker))
{
tracker = new ThreadTrackingStatistic("ThreadPoolThread." + System.Threading.Thread.CurrentThread.ManagedThreadId);
bool added = trackers.TryAdd(id, tracker);
if (added)
{
tracker.OnStartExecution();
}
}
tracker.OnStartProcessing();
}
#endif
try
{
if (batchingMode)
{
switch (phase)
{
case ReceivePhase.MetaHeader:
numberOfMessages = BitConverter.ToInt32(metaHeaderBuffer, 0);
lengthBuffer = new byte[numberOfMessages * Message.LENGTH_HEADER_SIZE];
lengths = new List <ArraySegment <byte> >()
{
new ArraySegment <byte>(lengthBuffer)
};
phase = ReceivePhase.Lengths;
offset = 0;
break;
case ReceivePhase.Lengths:
headerBodies = new List <ArraySegment <byte> >();
headerLengths = new int[numberOfMessages];
bodyLengths = new int[numberOfMessages];
for (int i = 0; i < numberOfMessages; i++)
{
headerLengths[i] = BitConverter.ToInt32(lengthBuffer, i * 8);
bodyLengths[i] = BitConverter.ToInt32(lengthBuffer, i * 8 + 4);
headerBodiesLength += (headerLengths[i] + bodyLengths[i]);
// We need to set the boundary of ArraySegment<byte>s to the same as the header/body boundary
headerBodies.AddRange(BufferPool.GlobalPool.GetMultiBuffer(headerLengths[i]));
headerBodies.AddRange(BufferPool.GlobalPool.GetMultiBuffer(bodyLengths[i]));
}
phase = ReceivePhase.HeaderBodies;
offset = 0;
break;
case ReceivePhase.HeaderBodies:
int lengtshSoFar = 0;
for (int i = 0; i < numberOfMessages; i++)
{
header = ByteArrayBuilder.BuildSegmentListWithLengthLimit(headerBodies, lengtshSoFar, headerLengths[i]);
body = ByteArrayBuilder.BuildSegmentListWithLengthLimit(headerBodies, lengtshSoFar + headerLengths[i], bodyLengths[i]);
lengtshSoFar += (headerLengths[i] + bodyLengths[i]);
var msg = new Message(header, body);
MessagingStatisticsGroup.OnMessageReceive(msg, headerLengths[i], bodyLengths[i]);
if (IMA.Log.IsVerbose3)
{
IMA.Log.Verbose3("Received a complete message of {0} bytes from {1}", headerLengths[i] + bodyLengths[i], msg.SendingAddress);
}
if (headerLengths[i] + bodyLengths[i] > Message.LargeMessageSizeThreshold)
{
IMA.Log.Info(ErrorCode.Messaging_LargeMsg_Incoming, "Receiving large message Size={0} HeaderLength={1} BodyLength={2}. Msg={3}",
headerLengths[i] + bodyLengths[i], headerLengths[i], bodyLengths[i], msg.ToString());
if (IMA.Log.IsVerbose3)
{
IMA.Log.Verbose3("Received large message {0}", msg.ToLongString());
}
}
IMA.HandleMessage(msg, Sock);
}
MessagingStatisticsGroup.OnMessageBatchReceive(IMA.SocketDirection, numberOfMessages, lengtshSoFar);
Reset();
break;
}
}
else
{
// We've completed a buffer. What we do depends on which phase we were in
switch (phase)
{
case ReceivePhase.Lengths:
// Pull out the header and body lengths
headerLength = BitConverter.ToInt32(lengthBuffer, 0);
bodyLength = BitConverter.ToInt32(lengthBuffer, 4);
header = BufferPool.GlobalPool.GetMultiBuffer(headerLength);
body = BufferPool.GlobalPool.GetMultiBuffer(bodyLength);
phase = ReceivePhase.Header;
offset = 0;
break;
case ReceivePhase.Header:
phase = ReceivePhase.Body;
offset = 0;
break;
case ReceivePhase.Body:
var msg = new Message(header, body);
MessagingStatisticsGroup.OnMessageReceive(msg, headerLength, bodyLength);
if (IMA.Log.IsVerbose3)
{
IMA.Log.Verbose3("Received a complete message of {0} bytes from {1}", headerLength + bodyLength, msg.SendingAddress);
}
if (headerLength + bodyLength > Message.LargeMessageSizeThreshold)
{
IMA.Log.Info(ErrorCode.Messaging_LargeMsg_Incoming, "Receiving large message Size={0} HeaderLength={1} BodyLength={2}. Msg={3}",
headerLength + bodyLength, headerLength, bodyLength, msg.ToString());
if (IMA.Log.IsVerbose3)
{
IMA.Log.Verbose3("Received large message {0}", msg.ToLongString());
}
}
IMA.HandleMessage(msg, Sock);
Reset();
break;
}
}
}
catch (Exception exc)
{
try
{
// Log details of receive state machine
IMA.Log.Error(ErrorCode.MessagingProcessReceiveBufferException,
string.Format(
"Exception trying to process {0} bytes from endpoint {1} at offset {2} in phase {3}"
+ " CurrentLength={4} HeaderLength={5} BodyLength={6}",
bytes, RemoteEndPoint, offset, phase,
CurrentLength, headerLength, bodyLength
),
exc);
}
catch (Exception) { }
Reset(); // Reset back to a hopefully good base state
throw;
}
finally
{
#if TRACK_DETAILED_STATS
if (StatisticsCollector.CollectThreadTimeTrackingStats)
{
tracker.IncrementNumberOfProcessed();
tracker.OnStopProcessing();
}
#endif
}
}
protected virtual void HandleMessage(Message msg, Socket receivedOnSocket)
{
if (Message.WriteMessagingTraces)
{
msg.AddTimestamp(Message.LifecycleTag.ReceiveIncoming);
}
// See it's a Ping message, and if so, short-circuit it
if (msg.GetScalarHeader <bool>(PingHeader))
{
MessagingStatisticsGroup.OnPingReceive(msg.SendingSilo);
if (Log.IsVerbose2)
{
Log.Verbose2("Responding to Ping from {0}", msg.SendingSilo);
}
if (!msg.TargetSilo.Equals(MessageCenter.MyAddress)) // got ping that is not destined to me. For example, got a ping to my older incarnation.
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message rejection = msg.CreateRejectionResponse(Message.RejectionTypes.Unrecoverable,
string.Format("The target silo is no longer active: target was {0}, but this silo is {1}. The rejected ping message is {2}.",
msg.TargetSilo.ToLongString(), MessageCenter.MyAddress.ToLongString(), msg.ToString()));
MessageCenter.OutboundQueue.SendMessage(rejection);
}
else
{
var response = msg.CreateResponseMessage();
response.BodyObject = Response.Done;
MessageCenter.SendMessage(response);
}
return;
}
// sniff message headers for directory cache management
if (sniffIncomingMessageHandler != null)
{
sniffIncomingMessageHandler(msg);
}
// Don't process messages that have already timed out
if (msg.IsExpired)
{
msg.DropExpiredMessage(MessagingStatisticsGroup.Phase.Receive);
return;
}
// If we've stopped application message processing, then filter those out now
// Note that if we identify or add other grains that are required for proper stopping, we will need to treat them as we do the membership table grain here.
if (MessageCenter.IsBlockingApplicationMessages && (msg.Category == Message.Categories.Application) && (msg.SendingGrain != Constants.SystemMembershipTableId))
{
// We reject new requests, and drop all other messages
if (msg.Direction != Message.Directions.Request)
{
return;
}
MessagingStatisticsGroup.OnRejectedMessage(msg);
var reject = msg.CreateRejectionResponse(Message.RejectionTypes.Unrecoverable, "Silo stopping");
MessageCenter.SendMessage(reject);
return;
}
// Make sure the message is for us. Note that some control messages may have no target
// information, so a null target silo is OK.
if ((msg.TargetSilo == null) || msg.TargetSilo.Matches(MessageCenter.MyAddress))
{
// See if it's a message for a client we're proxying.
if (MessageCenter.IsProxying && MessageCenter.TryDeliverToProxy(msg))
{
return;
}
// Nope, it's for us
MessageCenter.InboundQueue.PostMessage(msg);
return;
}
if (!msg.TargetSilo.Endpoint.Equals(MessageCenter.MyAddress.Endpoint))
{
// If the message is for some other silo altogether, then we need to forward it.
if (Log.IsVerbose2)
{
Log.Verbose2("Forwarding message {0} from {1} to silo {2}", msg.Id, msg.SendingSilo, msg.TargetSilo);
}
if (Message.WriteMessagingTraces)
{
msg.AddTimestamp(Message.LifecycleTag.EnqueueForForwarding);
}
MessageCenter.OutboundQueue.SendMessage(msg);
return;
}
// If the message was for this endpoint but an older epoch, then reject the message
// (if it was a request), or drop it on the floor if it was a response or one-way.
if (msg.Direction == Message.Directions.Request)
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message rejection = msg.CreateRejectionResponse(Message.RejectionTypes.Transient,
string.Format("The target silo is no longer active: target was {0}, but this silo is {1}. The rejected message is {2}.",
msg.TargetSilo.ToLongString(), MessageCenter.MyAddress.ToLongString(), msg.ToString()));
MessageCenter.OutboundQueue.SendMessage(rejection);
if (Log.IsVerbose)
{
Log.Verbose("Rejecting an obsolete request; target was {0}, but this silo is {1}. The rejected message is {2}.",
msg.TargetSilo.ToLongString(), MessageCenter.MyAddress.ToLongString(), msg.ToString());
}
}
}
protected override async Task RunInternal()
{
Exception error = default;
try
{
if (this.connectionOptions.ProtocolVersion == NetworkProtocolVersion.Version1)
{
// This version of the protocol does not support symmetric preamble, so either send or receive preamble depending on
// Whether or not this is an inbound or outbound connection.
if (this.RemoteSiloAddress is null)
{
// Inbound connection
var protocolVersion = await ReadPreamble();
// To support graceful transition to higher protocol versions, send a preamble if the remote endpoint supports it.
if (protocolVersion >= NetworkProtocolVersion.Version2)
{
await WritePreamble();
}
}
else
{
// Outbound connection
await WritePreamble();
}
}
else
{
// Later versions of the protocol send and receive preamble at both ends of the connection.
if (this.RemoteSiloAddress is null)
{
// Inbound connection
var protocolVersion = await ReadPreamble();
// To support graceful transition from lower protocol versions, only send a preamble if the remote endpoint supports it.
if (protocolVersion >= NetworkProtocolVersion.Version2)
{
await WritePreamble();
}
}
else
{
// Outbound connection
await Task.WhenAll(ReadPreamble().AsTask(), WritePreamble());
}
}
this.MessageReceivedCounter = MessagingStatisticsGroup.GetMessageReceivedCounter(this.RemoteSiloAddress);
this.MessageSentCounter = MessagingStatisticsGroup.GetMessageSendCounter(this.RemoteSiloAddress);
await base.RunInternal();
}
catch (Exception exception) when((error = exception) is null)
{
Debug.Fail("Execution should not be able to reach this point.");
}
finally
{
if (!(this.RemoteSiloAddress is null))
{
this.connectionManager.OnConnectionTerminated(this.RemoteSiloAddress, this, error);
}
}
async Task WritePreamble()
{
await ConnectionPreamble.Write(
this.Context,
Constants.SiloDirectConnectionId,
this.connectionOptions.ProtocolVersion,
this.LocalSiloAddress);
}
async ValueTask <NetworkProtocolVersion> ReadPreamble()
{
var(grainId, protocolVersion, siloAddress) = await ConnectionPreamble.Read(this.Context);
if (!grainId.Equals(Constants.SiloDirectConnectionId))
{
throw new InvalidOperationException("Unexpected non-proxied connection on silo endpoint.");
}
if (siloAddress is object)
{
this.RemoteSiloAddress = siloAddress;
this.connectionManager.OnConnected(siloAddress, this);
}
this.RemoteProtocolVersion = protocolVersion;
return(protocolVersion);
}
}
private bool Send(Message msg, Socket sock)
{
if (Cts.IsCancellationRequested)
{
return(false);
}
if (sock == null)
{
return(false);
}
// Send the message
List <ArraySegment <byte> > data;
int headerLength;
try
{
int bodyLength;
data = msg.Serialize(this.serializationManager, out headerLength, out bodyLength);
if (headerLength + bodyLength > this.serializationManager.LargeObjectSizeThreshold)
{
Log.Info(ErrorCode.Messaging_LargeMsg_Outgoing, "Preparing to send large message Size={0} HeaderLength={1} BodyLength={2} #ArraySegments={3}. Msg={4}",
headerLength + bodyLength + Message.LENGTH_HEADER_SIZE, headerLength, bodyLength, data.Count, this.ToString());
if (Log.IsEnabled(LogLevel.Trace))
{
Log.Trace("Sending large message {0}", msg.ToLongString());
}
}
}
catch (Exception exc)
{
this.OnMessageSerializationFailure(msg, exc);
return(true);
}
int length = data.Sum(x => x.Count);
int bytesSent = 0;
bool exceptionSending = false;
bool countMismatchSending = false;
string sendErrorStr;
try
{
bytesSent = sock.Send(data);
if (bytesSent != length)
{
// The complete message wasn't sent, even though no error was reported; treat this as an error
countMismatchSending = true;
sendErrorStr = String.Format("Byte count mismatch on send: sent {0}, expected {1}", bytesSent, length);
Log.Warn(ErrorCode.GatewayByteCountMismatch, sendErrorStr);
}
}
catch (Exception exc)
{
exceptionSending = true;
string remoteEndpoint = "";
if (!(exc is ObjectDisposedException))
{
try
{
remoteEndpoint = sock.RemoteEndPoint.ToString();
}
catch (Exception) {}
}
sendErrorStr = String.Format("Exception sending to client at {0}: {1}", remoteEndpoint, exc);
Log.Warn(ErrorCode.GatewayExceptionSendingToClient, sendErrorStr, exc);
}
MessagingStatisticsGroup.OnMessageSend(msg.TargetSilo, msg.Direction, bytesSent, headerLength, SocketDirection.GatewayToClient);
bool sendError = exceptionSending || countMismatchSending;
if (sendError)
{
gateway.RecordClosedSocket(sock);
SocketManager.CloseSocket(sock);
}
gatewaySends.Increment();
msg.ReleaseBodyAndHeaderBuffers();
return(!sendError);
}
public void Send(ClientState clientState, Message msg)
{
// This should never happen -- but make sure to handle it reasonably, just in case
if (clientState == null)
{
if (msg == null)
{
return;
}
this.log.Info(ErrorCode.GatewayTryingToSendToUnrecognizedClient, "Trying to send a message {0} to an unrecognized client {1}", msg.ToString(), msg.TargetGrain);
MessagingStatisticsGroup.OnFailedSentMessage(msg);
// Message for unrecognized client -- reject it
if (msg.Direction == Message.Directions.Request)
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message error = this.messageFactory.CreateRejectionResponse(
msg,
Message.RejectionTypes.Unrecoverable,
"Unknown client " + msg.TargetGrain);
messageCenter.SendMessage(error);
}
else
{
MessagingStatisticsGroup.OnDroppedSentMessage(msg);
}
return;
}
lock (clientState.PendingToSend)
{
// if disconnected - queue for later.
if (!clientState.IsConnected)
{
if (msg == null)
{
return;
}
if (this.log.IsEnabled(LogLevel.Trace))
{
this.log.Trace("Queued message {0} for client {1}", msg, msg.TargetGrain);
}
clientState.PendingToSend.Enqueue(msg);
return;
}
// if the queue is non empty - drain it first.
if (clientState.PendingToSend.Count > 0)
{
if (msg != null)
{
clientState.PendingToSend.Enqueue(msg);
}
// For now, drain in-line, although in the future this should happen in yet another asynch agent
Drain(clientState);
return;
}
// the queue was empty AND we are connected.
// If the request includes a message to send, send it (or enqueue it for later)
if (msg == null)
{
return;
}
if (!Send(msg, clientState))
{
if (this.log.IsEnabled(LogLevel.Trace))
{
this.log.Trace("Queued message {0} for client {1}", msg, msg.TargetGrain);
}
clientState.PendingToSend.Enqueue(msg);
}
else
{
if (this.log.IsEnabled(LogLevel.Trace))
{
this.log.Trace("Sent message {0} to client {1}", msg, msg.TargetGrain);
}
}
}
}
/// <summary>
/// Handles an incoming (proxied) message by rerouting it immediately and unconditionally,
/// after some header massaging.
/// </summary>
/// <param name="msg"></param>
/// <param name="receivedOnSocket"></param>
protected override void HandleMessage(Message msg, Socket receivedOnSocket)
{
// Don't process messages that have already timed out
if (msg.IsExpired)
{
msg.DropExpiredMessage(MessagingStatisticsGroup.Phase.Receive);
return;
}
if (Message.WriteMessagingTraces)
{
msg.AddTimestamp(Message.LifecycleTag.ReceiveIncoming);
}
gatewayTrafficCounter.Increment();
// Are we overloaded?
if ((MessageCenter.Metrics != null) && MessageCenter.Metrics.IsOverloaded)
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message rejection = msg.CreateRejectionResponse(Message.RejectionTypes.GatewayTooBusy, "Shedding load");
MessageCenter.TryDeliverToProxy(rejection);
if (Log.IsVerbose)
{
Log.Verbose("Rejecting a request due to overloading: {0}", msg.ToString());
}
loadSheddingCounter.Increment();
return;
}
gateway.RecordSendingProxiedGrain(msg.SendingGrain, receivedOnSocket);
SiloAddress targetAddress = gateway.TryToReroute(msg);
msg.SendingSilo = MessageCenter.MyAddress;
if (targetAddress == null)
{
// reroute via Dispatcher
msg.RemoveHeader(Message.Header.TARGET_SILO);
msg.RemoveHeader(Message.Header.TARGET_ACTIVATION);
if (msg.TargetGrain.IsSystemTarget)
{
msg.TargetSilo = MessageCenter.MyAddress;
msg.TargetActivation = ActivationId.GetSystemActivation(msg.TargetGrain, MessageCenter.MyAddress);
}
if (Message.WriteMessagingTraces)
{
msg.AddTimestamp(Message.LifecycleTag.RerouteIncoming);
}
MessagingStatisticsGroup.OnMessageReRoute(msg);
MessageCenter.RerouteMessage(msg);
}
else
{
// send directly
msg.TargetSilo = targetAddress;
MessageCenter.SendMessage(msg);
}
}
protected override void ProcessBatch(List <OutgoingClientMessage> requests)
{
if (Cts.IsCancellationRequested)
{
return;
}
if (requests == null || requests.Count == 0)
{
return;
}
// Every Tuple in requests are guaranteed to have the same client
var client = requests[0].Item1;
var msgs = requests.Where(r => r != null).Select(r => r.Item2).ToList();
// Find the client state
ClientState clientState;
bool found;
// TODO: Why do we need this lock here if clients is a ConcurrentDictionary?
//lock (gateway.lockable)
{
found = gateway.clients.TryGetValue(client, out clientState);
}
// This should never happen -- but make sure to handle it reasonably, just in case
if (!found || (clientState == null))
{
if (msgs.Count == 0)
{
return;
}
Log.Info(ErrorCode.GatewayTryingToSendToUnrecognizedClient, "Trying to send {0} messages to an unrecognized client {1}. First msg {0}",
msgs.Count, client, msgs[0].ToString());
foreach (var msg in msgs)
{
MessagingStatisticsGroup.OnFailedSentMessage(msg);
// Message for unrecognized client -- reject it
if (msg.Direction == Message.Directions.Request)
{
MessagingStatisticsGroup.OnRejectedMessage(msg);
Message error = msg.CreateRejectionResponse(Message.RejectionTypes.Unrecoverable, "Unknown client " + client);
gateway.SendMessage(error);
}
else
{
MessagingStatisticsGroup.OnDroppedSentMessage(msg);
}
}
return;
}
// if disconnected - queue for later.
if (!clientState.IsConnected)
{
if (msgs.Count == 0)
{
return;
}
if (Log.IsVerbose3)
{
Log.Verbose3("Queued {0} messages for client {1}", msgs.Count, client);
}
clientState.PendingBatchesToSend.Enqueue(msgs);
return;
}
// if the queue is non empty - drain it first.
if (clientState.PendingBatchesToSend.Count > 0)
{
if (msgs.Count != 0)
{
clientState.PendingBatchesToSend.Enqueue(msgs);
}
// For now, drain in-line, although in the future this should happen in yet another asynch agent
DrainBatch(clientState);
return;
}
// the queue was empty AND we are connected.
// If the request includes a message to send, send it (or enqueue it for later)
if (msgs.Count == 0)
{
return;
}
if (!SendBatch(msgs, clientState.Socket))
{
if (Log.IsVerbose3)
{
Log.Verbose3("Queued {0} messages for client {1}", msgs.Count, client);
}
clientState.PendingBatchesToSend.Enqueue(msgs);
}
else
{
if (Log.IsVerbose3)
{
Log.Verbose3("Sent {0} message to client {1}", msgs.Count, client);
}
}
}
private async Task ProcessOutgoing()
{
await Task.Yield();
Exception error = default;
var serializer = this.shared.ServiceProvider.GetRequiredService <IMessageSerializer>();
try
{
var output = this._transport.Output;
var reader = this.outgoingMessages.Reader;
while (true)
{
var more = await reader.WaitToReadAsync();
if (!more)
{
break;
}
Message message = default;
try
{
while (inflight.Count < inflight.Capacity && reader.TryRead(out message) && this.PrepareMessageForSend(message))
{
inflight.Add(message);
var(headerLength, bodyLength) = serializer.Write(ref output, message);
MessagingStatisticsGroup.OnMessageSend(this.MessageSentCounter, message, headerLength + bodyLength, headerLength, this.ConnectionDirection);
}
}
catch (Exception exception) when(message != default)
{
this.OnMessageSerializationFailure(message, exception);
}
var flushResult = await output.FlushAsync();
if (flushResult.IsCompleted || flushResult.IsCanceled)
{
break;
}
inflight.Clear();
}
}
catch (Exception exception)
{
if (IsValid)
{
this.Log.LogWarning(
exception,
"Exception while processing messages to remote endpoint {EndPoint}",
this.RemoteEndPoint);
}
error = exception;
}
finally
{
_transport.Output.Complete();
(serializer as IDisposable)?.Dispose();
this.StartClosing(error);
}
}
protected override void Process(Message msg)
{
if (Log.IsVerbose2)
{
Log.Verbose2("Got a {0} message to send: {1}", msg.Direction, msg);
}
bool continueSend = PrepareMessageForSend(msg);
if (!continueSend)
{
return;
}
Socket sock;
string error;
SiloAddress targetSilo;
continueSend = GetSendingSocket(msg, out sock, out targetSilo, out error);
if (!continueSend)
{
OnGetSendingSocketFailure(msg, error);
return;
}
List <ArraySegment <byte> > data;
int headerLength = 0;
try
{
data = msg.Serialize(this.serializationManager, out headerLength);
}
catch (Exception exc)
{
OnMessageSerializationFailure(msg, exc);
return;
}
int length = data.Sum(x => x.Count);
int bytesSent = 0;
bool exceptionSending = false;
bool countMismatchSending = false;
string sendErrorStr = null;
try
{
bytesSent = sock.Send(data);
if (bytesSent != length)
{
// The complete message wasn't sent, even though no error was reported; treat this as an error
countMismatchSending = true;
sendErrorStr = String.Format("Byte count mismatch on sending to {0}: sent {1}, expected {2}", targetSilo, bytesSent, length);
Log.Warn(ErrorCode.Messaging_CountMismatchSending, sendErrorStr);
}
}
catch (Exception exc)
{
exceptionSending = true;
if (!(exc is ObjectDisposedException))
{
sendErrorStr = String.Format("Exception sending message to {0}. Message: {1}. {2}", targetSilo, msg, exc);
Log.Warn(ErrorCode.Messaging_ExceptionSending, sendErrorStr, exc);
}
}
MessagingStatisticsGroup.OnMessageSend(targetSilo, msg.Direction, bytesSent, headerLength, GetSocketDirection());
bool sendError = exceptionSending || countMismatchSending;
if (sendError)
{
OnSendFailure(sock, targetSilo);
}
ProcessMessageAfterSend(msg, sendError, sendErrorStr);
}
public void ProcessReceived(SocketAsyncEventArgs e)
{
#if TRACK_DETAILED_STATS
ThreadTrackingStatistic tracker = null;
if (StatisticsCollector.CollectThreadTimeTrackingStats)
{
int id = System.Threading.Thread.CurrentThread.ManagedThreadId;
if (!trackers.TryGetValue(id, out tracker))
{
tracker = new ThreadTrackingStatistic("ThreadPoolThread." + System.Threading.Thread.CurrentThread.ManagedThreadId);
bool added = trackers.TryAdd(id, tracker);
if (added)
{
tracker.OnStartExecution();
}
}
tracker.OnStartProcessing();
}
#endif
try
{
_buffer.UpdateReceivedData(e.Buffer, e.BytesTransferred);
while (true)
{
Message msg = null;
try
{
if (!this._buffer.TryDecodeMessage(out msg))
{
break;
}
this.IMA.HandleMessage(msg, this.Socket);
}
catch (Exception exception)
{
// If deserialization completely failed or the message was one-way, rethrow the exception
// so that it can be handled at another level.
if (msg?.Headers == null || msg.Direction != Message.Directions.Request)
{
throw;
}
// The message body was not successfully decoded, but the headers were.
// Send a fast fail to the caller.
MessagingStatisticsGroup.OnRejectedMessage(msg);
var response = this.messageFactory.CreateResponseMessage(msg);
response.Result = Message.ResponseTypes.Error;
response.BodyObject = Response.ExceptionResponse(exception);
// Send the error response and continue processing the next message.
this.IMA.MessageCenter.SendMessage(response);
}
}
}
catch (Exception exc)
{
try
{
// Log details of receive state machine
IMA.Log.Error(ErrorCode.MessagingProcessReceiveBufferException,
$"Exception trying to process {e.BytesTransferred} bytes from endpoint {RemoteEndPoint}",
exc);
}
catch (Exception) { }
_buffer.Reset(); // Reset back to a hopefully good base state
throw;
}
#if TRACK_DETAILED_STATS
finally
{
if (StatisticsCollector.CollectThreadTimeTrackingStats)
{
tracker.IncrementNumberOfProcessed();
tracker.OnStopProcessing();
}
}
#endif
}
