public async Task Save(String storageConnectionString, IProcess process, LeaseManager leaseManager)
{
process.SaveState(out var serialized, out var label);
var cloudBlobContainer = await AzureBlobStorageStateManager.GetCloudBlobContainer(storageConnectionString, HostLogger, initialize : false);
await AzureBlobStorageStateManager
.Save(cloudBlobContainer, deploymentId, HostLogger, processId,
new ProcessState(deploymentTimestamp, lastCheckpointedSequenceNumber, serialized, seenClock, ourClock), leaseManager.LeaseId);
}
public static async Task Doorbell(Microsoft.Azure.WebJobs.ExecutionContext executionContext, ILogger logger, EventData[] messages)
{
var stopwatch = new System.Diagnostics.Stopwatch();
stopwatch.Start();
var msg = DoorbellMessage.Deserialize(messages[0].Body.Array);
var processId = msg.ProcessId;
var applicationInfo = new TStaticApplicationInfo();
var configuration = applicationInfo.GetHostConfiguration();
var hostlogger = new LoggerWrapper(logger, $"[p{processId:d3} doorbell] ");
var lastRing = messages[messages.Length - 1].SystemProperties.SequenceNumber;
try
{
var cloudBlobContainer = await AzureBlobStorageStateManager.GetCloudBlobContainer(configuration.StorageConnectionString, hostlogger);
var stateBlob = cloudBlobContainer.GetBlockBlobReference(AzureBlobStorageStateManager.BlobName(processId));
var leaseManager = new LeaseManager(stateBlob);
if (await leaseManager.TryGetLease(hostlogger))
{
hostlogger.LogInformation($"{DateTime.UtcNow:o} Rings x{messages.Length} on {Environment.MachineName}, through #{lastRing}, lease acquired");
await RunHost(applicationInfo, configuration, processId, hostlogger, logger, leaseManager, stopwatch, executionContext.InvocationId);
}
else
{
hostlogger.LogInformation($"{DateTime.UtcNow:o} Rings x{messages.Length} on {Environment.MachineName}, through #{lastRing}, ignored");
}
}
catch (Exception e)
{
hostlogger.LogError($"Doorbell failed: {e}");
}
}
private static async Task RunHost(IStaticApplicationInfo applicationInfo, FunctionsHostConfiguration configuration, uint processId,
ILogger hostlogger, ILogger logger, LeaseManager leaseManager, System.Diagnostics.Stopwatch stopwatch, Guid invocationId)
{
try
{
var host = new Host <TStaticApplicationInfo>(applicationInfo, configuration, logger, processId, stopwatch, invocationId);
var done = await host.ResumeFromCheckpoint(leaseManager);
// if we get here, there is no more work for this process
await leaseManager.Release();
hostlogger.LogInformation($"Lease released");
if (!done)
{
await host.RingMyself();
}
else
{
await host.FinalRecheck();
}
await host.Cleanup(false);
}
catch (Exception e)
{
hostlogger.LogError($"RunHost Failed: {e}");
// throw exception, so event hub delivers doorbell message again
// TODO think about poison messages
throw;
}
finally
{
hostlogger.LogDebug($"Control returned");
}
}
public async Task <bool> ResumeFromCheckpoint(LeaseManager leaseManager)
{
var start = stopwatch.Elapsed;
try
{
// kick off the load
var storageConnectionString = configuration.StorageConnectionString;
var loadtask = AzureBlobStorageStateManager.Load(storageConnectionString, HostLogger, processId);
// register host services
application.HostServices.RegisterSend(Send);
application.HostServices.RegisterApplicationLogger(ApplicationLogger);
application.HostServices.RegisterRuntimeLogger(RuntimeLogger);
// if (_configuration.AppInsightsInstrumentationKey != null)
// _application.HostServices.RegisterTelemetryListener(new ApplicationInsightsTelemetryListener(_configuration.AppInsightsInstrumentationKey, "eventhubs"));
if (blobTelemetryListener != null)
{
application.HostServices.RegisterTelemetryListener(blobTelemetryListener);
}
// read the checkpoint
var checkpointedState = await loadtask;
SetDeploymentTimestamp(checkpointedState.DeploymentTimestamp);
seenClock = checkpointedState.SeenClock;
ourClock = checkpointedState.OurClock;
var state = checkpointedState.State;
lastCheckpointedSequenceNumber = checkpointedState.Version;
HostLogger.LogDebug($"Resuming at position {lastCheckpointedSequenceNumber}");
Connections.ResumeFrom(lastCheckpointedSequenceNumber);
// build the process
IProcess process = application.MakeProcess(processId);
if (state == null)
{
process.FirstStart();
}
else
{
process.Restore(state, out var label);
}
process.BecomePrimary();
// start the message receiving loop
long lastProcessedPosition = 0;
int iterationCount = 0;
int dedupCount = 0;
int receiveCount = 0;
int loopbackCount = 0;
int clientCount = 0;
TimeSpan lastReport = stopwatch.Elapsed;
long lastReportedPosition = 0;
while (true)
{
iterationCount++;
if (lastProcessedPosition > lastReportedPosition && stopwatch.Elapsed - lastReport > TimeSpan.FromSeconds(15))
{
HostLogger.LogInformation($"progress to v{lastProcessedPosition} after {stopwatch.Elapsed.TotalSeconds:f2}s, {receiveCount + dedupCount + loopbackCount + clientCount} messages ({receiveCount} new, {loopbackCount} loopback, {clientCount} client, {dedupCount} deduped) in {iterationCount} batches");
lastReportedPosition = lastProcessedPosition;
lastReport = stopwatch.Elapsed;
CombinedLogger.Flush();
}
try
{
bool outOfTime = stopwatch.Elapsed > configuration.TimeLimit;
IEnumerable <EventData> eventData = outOfTime ? null :
await Connections.ProcessReceiver.ReceiveAsync(configuration.MaxReceiveBatchSize, iterationCount == 1?TimeSpan.FromSeconds(10) : configuration.ReceiveWaitTime);
if (eventData == null)
{
HostLogger.LogTrace($"{ DateTime.UtcNow:o} Received nothing. {Connections.ProcessReceiver.RuntimeInfo.LastSequenceNumber}");
if (process.RequestsOutstanding() && !outOfTime)
{
HostLogger.LogDebug($"continue for outstanding requests.");
CombinedLogger.Flush();
continue;
}
else if (lastProcessedPosition > lastCheckpointedSequenceNumber)
{
await Task.WhenAll(Senders.Select(s => s.WaitForCurrentWorkToBeServiced()).ToList());
lastCheckpointedSequenceNumber = lastProcessedPosition;
await Save(storageConnectionString, process, leaseManager);
HostLogger.LogDebug($"continue for saving snapshot.");
continue;
}
else
{
// no more work to do here
HostLogger.LogInformation($"{(outOfTime ? "out of time" : "done")} after {stopwatch.Elapsed.TotalSeconds}s, {receiveCount + dedupCount + loopbackCount + clientCount} messages ({receiveCount} new, {loopbackCount} loopback, {clientCount} client, {dedupCount} deduped) in {iterationCount} batches");
CombinedLogger.Flush();
return(!outOfTime);
}
}
foreach (var ed in eventData)
{
var body = ed.Body;
var message = ProcessMessage.Deserialize(body.Array);
HostLogger.LogTrace($"{DateTime.UtcNow:o} Received {message}");
if (!message.IsExternalRequest && message.DeploymentTimestamp < deploymentTimestamp)
{
HostLogger.LogDebug($"Ignoring message from earlier deployment {message.DeploymentTimestamp}");
}
else if (!message.IsExternalRequest && message.DeploymentTimestamp > deploymentTimestamp)
{
HostLogger.LogError($"****** MISSING STATE ERROR process state is from older deployment, should have been initialized for new one! {message.DeploymentTimestamp} != {deploymentTimestamp}");
}
else if (message.IsSequenced &&
seenClock.HasSeen(message.Source, message.LastClock.Value))
{
dedupCount++;
HostLogger.LogTrace($"Deduping: {message}");
}
else if (message.IsExternalRequest)
{
clientCount++;
HostLogger.LogTrace($"Processing: {message}");
// deserialize content
List <IMessage> payload;
MemoryStream stream = new MemoryStream(message.Payload);
using (var binaryDictionaryReader = XmlDictionaryReader.CreateBinaryReader(stream, XmlDictionaryReaderQuotas.Max))
{
payload = (List <IMessage>)payloadSerializerLoopback.ReadObject(binaryDictionaryReader);
}
// Iterate
foreach (var m in payload)
{
process.ProcessMessage(m);
}
}
else if (message.IsLoopback)
{
loopbackCount++;
HostLogger.LogTrace($"Processing: {message}");
// deserialize content
List <IMessage> payload;
MemoryStream stream = new MemoryStream(message.Payload);
using (var binaryDictionaryReader = XmlDictionaryReader.CreateBinaryReader(stream, XmlDictionaryReaderQuotas.Max))
{
payload = (List <IMessage>)payloadSerializerLoopback.ReadObject(binaryDictionaryReader);
}
// Iterate
foreach (var m in payload)
{
process.ProcessMessage(m);
}
}
else
{
receiveCount++;
HostLogger.LogTrace($"Processing: {message}");
// deserialize content
List <KeyValuePair <long, IMessage> > payload;
MemoryStream stream = new MemoryStream(message.Payload);
using (var binaryDictionaryReader = XmlDictionaryReader.CreateBinaryReader(stream, XmlDictionaryReaderQuotas.Max))
{
payload = (List <KeyValuePair <long, IMessage> >)payloadSerializer.ReadObject(binaryDictionaryReader);
}
// Iterate
foreach (var kvp in payload)
{
if (!seenClock.HasSeen(message.Source, kvp.Key))
{
process.ProcessMessage(kvp.Value);
}
}
// Update seen clock.
seenClock.Set(message.Source, message.LastClock.Value);
}
lastProcessedPosition = ed.SystemProperties.SequenceNumber;
// Checkpoint and commit every X.
if (lastProcessedPosition > lastCheckpointedSequenceNumber &&
lastProcessedPosition % configuration.CheckpointInterval == configuration.CheckpointInterval - 1)
{
await Task.WhenAll(Senders.Select(s => s.WaitForCurrentWorkToBeServiced()).ToList());
// Checkpoint state.
lastCheckpointedSequenceNumber = lastProcessedPosition;
await Save(storageConnectionString, process, leaseManager);
}
}
}
catch (System.OperationCanceledException)
{
HostLogger.LogDebug($"receive returned OperationCanceledException, scheduling retry!");
continue;
}
}
}
finally
{
if (this.collectHostEvents)
{
this.blobTelemetryListener.OnApplicationEvent(processId, invocationId.ToString(), $"Process {processId}", "", OperationSide.Caller, OperationType.Host, (stopwatch.Elapsed - start).TotalMilliseconds);
}
}
}
