public void DisposeStopsTimingTest()
{
Assert.Equal(0, _timingBlock.Count);
Task.Delay(1);
_timerContext.Dispose();
Assert.Equal(1, _timingBlock.Count);
}
async Task ICommandUnitOfWork.End(Exception ex)
{
if (ex == null)
{
await Commit();
}
else
{
_errorsMeter.Mark();
}
_commandsConcurrent.Decrement();
_timerContext.Dispose();
}
public void Acknowledge(ResolvedEvent @event)
{
if (!Live)
{
throw new InvalidOperationException("Cannot ACK an event, subscription is dead");
}
Processed.Increment(Id);
_idleContext.Dispose();
_toAck.Add(@event);
}
protected virtual void Dispose(bool disposing)
{
if (_disposed)
{
return;
}
if (disposing && _ctx != null)
{
_ctx.Dispose();
}
_disposed = true;
}
public void Acknowledge(ResolvedEvent[] events)
{
Processed.Increment(Id);
_idleContext.Dispose();
_toAck.AddRange(events);
}
public Task DeactivatedFinallyAsync()
{
_deactivatingActivity?.Dispose();
_deactivationTimer.Dispose();
return(Task.CompletedTask);
}
public Task HandledEventFinallyAsync(IEvent @event)
{
_handlingActivity?.Dispose();
_eventHandlingTimer.Dispose();
return(Task.CompletedTask);
}
public void Dispose()
{
_counter.Decrement();
_context.Dispose();
}
public override void OnSuccess(MethodExecutionArgs args)
{
_counter.Decrement();
_context.Dispose();
base.OnSuccess(args);
}
private static void Threaded(object state)
{
var param = (ThreadParam)state;
param.Clients.SelectAsync(x => x.Connect()).Wait();
var threadIdle = Metric.Timer("Delayed Events Idle", Unit.None, tags: "debug");
var tasks = new Task[param.Clients.Count()];
TimerContext?idleContext = threadIdle.NewContext();
while (true)
{
param.Token.ThrowIfCancellationRequested();
var noEvents = true;
for (var i = 0; i < param.Clients.Count(); i++)
{
// Check if current task is complete
if (tasks[i] != null && !tasks[i].IsCompleted)
{
continue;
}
var client = param.Clients.ElementAt(i);
var events = client.Flush();
DelayedHandled.Update(events.Count());
if (!events.Any())
{
continue;
}
noEvents = false;
idleContext?.Dispose();
idleContext = null;
tasks[i] = Task.Run(async() =>
{
using (var ctx = DelayedExecution.NewContext())
{
// Group delayed events from by stream id and process in chunks
// Same stream ids should modify the same models, processing this way reduces write collisions on commit
await events.GroupBy(x => x.Event.EventStreamId)
.SelectAsync(x => ProcessEvents(param, client, x.ToArray())).ConfigureAwait(false);
if (ctx.Elapsed > TimeSpan.FromSeconds(5))
{
SlowLogger.Warn($"Processing {events.Count()} bulked events took {ctx.Elapsed.TotalSeconds} seconds!");
}
Logger.Write(LogLevel.Info,
() => $"Processing {events.Count()} bulked events took {ctx.Elapsed.TotalMilliseconds} ms");
}
}, param.Token);
}
if (idleContext == null)
{
idleContext = threadIdle.NewContext();
}
// Cheap hack to not burn cpu incase there are no events
if (noEvents)
{
Thread.Sleep(50);
}
}
}
private static void Threaded(object state)
{
var param = (ThreadParam)state;
param.Clients.SelectAsync(x => x.Connect()).Wait();
var threadIdle = Metric.Timer("Process Events Idle", Unit.None, tags: "debug");
var tasks = new Task[param.Clients.Count()];
TimerContext?idleContext = threadIdle.NewContext();
while (true)
{
param.Token.ThrowIfCancellationRequested();
var noEvents = true;
for (var i = 0; i < param.Clients.Count(); i++)
{
// Check if current task is complete
if (tasks[i] != null && !tasks[i].IsCompleted)
{
continue;
}
// Ready for a new event
var client = param.Clients.ElementAt(i);
ResolvedEvent e;
if (!client.TryDequeue(out e))
{
continue;
}
var @event = e.Event;
Logger.Write(LogLevel.Debug,
() => $"Processing event {@event.EventId} type {@event.EventType} stream [{@event.EventStreamId}] number {@event.EventNumber}");
noEvents = false;
idleContext?.Dispose();
idleContext = null;
Events.Mark(e.OriginalStreamId);
tasks[i] = Task.Run(async() =>
{
await ProcessEvent(param.MessageMeta, param.JsonSettings, @event, param.Token).ConfigureAwait(false);
Logger.Write(LogLevel.Debug,
() => $"Scheduling acknowledge event {@event.EventId} type {@event.EventType} stream [{@event.EventStreamId}] number {@event.EventNumber}");
client.Acknowledge(e);
}, param.Token);
}
if (idleContext == null)
{
idleContext = threadIdle.NewContext();
}
// Cheap hack to not burn cpu incase there are no events
if (noEvents)
{
Thread.Sleep(50);
}
}
}
public override void OnSuccess(MethodExecutionArgs args)
{
context.Dispose();
}
public Task DeactivatedAsync()
{
_deactivationTimer.Dispose();
return(Task.CompletedTask);
}
public Task HandledEventAsync(IEvent @event)
{
_eventHandlingTimer.Dispose();
return(Task.CompletedTask);
}
private static TracerDecoratorBuilder WithAppMetrics(this TracerDecoratorBuilder builder, IMetrics metrics, OpenTracingAppMetricsDecoratorOptions options, Action <OpenTracingAppMetricsDecoratorOptions> setupOptions)
{
options = options ?? throw new ArgumentNullException(nameof(options));
setupOptions?.Invoke(options);
if (options.SpansCountersEnabled)
{
var spansCounter = new CounterOptions
{
Name = options.SpansCounterName
};
builder.OnSpanStarted((span, operationName) =>
{
metrics.Measure.Counter.Increment(spansCounter, operationName);
if (options.DistinctOperationsCountersEnabled)
{
var distinctCounter = new CounterOptions {
Name = options.DistinctOperationCountersName + operationName
};
metrics.Measure.Counter.Increment(distinctCounter);
}
});
builder.OnSpanFinished((span, operationName) =>
{
metrics.Measure.Counter.Decrement(spansCounter, operationName);
if (options.DistinctOperationsCountersEnabled)
{
var distinctCounter = new CounterOptions {
Name = options.DistinctOperationCountersName + operationName
};
metrics.Measure.Counter.Decrement(distinctCounter);
}
});
}
if (options.SpansMetersEnabled)
{
var spansMeter = new MeterOptions
{
Name = options.SpansMeterName
};
builder.OnSpanStarted((span, operationName) =>
{
metrics.Measure.Meter.Mark(spansMeter, operationName);
if (options.DistinctOperationsMetersEnabled)
{
var distinctMeter = new MeterOptions {
Name = options.DistinctOperationMetersName + operationName
};
metrics.Measure.Meter.Mark(distinctMeter);
}
});
}
if (options.SpansTimersEnabled)
{
var spansTimer = new TimerOptions
{
Name = options.SpansTimerName,
DurationUnit = TimeUnit.Milliseconds,
RateUnit = TimeUnit.Milliseconds
};
builder.OnSpanStartedWithCallback((span, operationName) =>
{
var timerContext = metrics.Measure.Timer.Time(spansTimer, operationName);
TimerContext distinctTimerContext = default(TimerContext);
if (options.DistinctOperationsTimersEnabled)
{
var distinctTimer = new TimerOptions
{
Name = options.DistinctOperationTimersName + operationName,
DurationUnit = TimeUnit.Milliseconds,
RateUnit = TimeUnit.Milliseconds
};
distinctTimerContext = metrics.Measure.Timer.Time(distinctTimer);
}
return((sp, op) =>
{
timerContext.Dispose();
distinctTimerContext.Dispose();
});
});
}
return(builder);
}
private static void Threaded(object state)
{
var param = (ThreadParam)state;
// A fake message that will travel through the pipeline in order to bulk process messages from the context bag
var bulkMarker = new BulkMessage().Serialize(param.JsonSettings).AsByteArray();
param.Clients.SelectAsync(x => x.Connect()).Wait();
var threadIdle = Metric.Timer("Delayed Events Idle", Unit.None, tags: "debug");
TimerContext?idleContext = threadIdle.NewContext();
while (true)
{
param.Token.ThrowIfCancellationRequested();
var noEvents = true;
for (var i = 0; i < param.Clients.Count(); i++)
{
var client = param.Clients.ElementAt(i);
var events = client.Flush();
if (!events.Any())
{
continue;
}
noEvents = false;
idleContext?.Dispose();
idleContext = null;
var delayed = events.Select(x => x.Event.Data.Deserialize <DelayedMessage>(param.JsonSettings)).ToArray();
Logger.Write(LogLevel.Info, () => $"Processing {delayed.Count()} bulk events");
var transportTransaction = new TransportTransaction();
var contextBag = new ContextBag();
// Hack to get all the delayed messages to bulk invoker without NSB deserializing and processing each one
contextBag.Set(Defaults.BulkHeader, delayed);
// Need to supply EnclosedMessageTypes to trick NSB pipeline into processing our fake message
var messageId = Guid.NewGuid().ToString();
var headers = new Dictionary <string, string>()
{
[Headers.EnclosedMessageTypes] = typeof(BulkMessage).AssemblyQualifiedName,
[Headers.MessageIntent] = MessageIntentEnum.Send.ToString(),
[Headers.MessageId] = messageId,
[Defaults.BulkHeader] = delayed.Count().ToString(),
};
// Run bulk process on this thread
using (var tokenSource = new CancellationTokenSource())
{
var success = false;
var retry = 0;
do
{
using (var ctx = DelayedExecution.NewContext())
{
try
{
// If canceled, this will throw the number of time immediate retry requires to send the message to the error queue
param.Token.ThrowIfCancellationRequested();
// Don't re-use the event id for the message id
var messageContext = new NServiceBus.Transport.MessageContext(messageId,
headers,
bulkMarker, transportTransaction, tokenSource,
contextBag);
Bus.OnMessage(messageContext).Wait(param.Token);
Logger.Write(LogLevel.Debug,
() => $"Scheduling acknowledge of {delayed.Count()} bulk events");
DelayedHandled.Update(delayed.Count());
client.Acknowledge(events);
success = true;
}
catch (ObjectDisposedException)
{
// NSB transport has been disconnected
break;
}
catch (Exception ex)
{
}
if (ctx.Elapsed > TimeSpan.FromSeconds(5))
{
SlowLogger.Warn(
$"Processing {delayed.Count()} bulked events took {ctx.Elapsed.TotalSeconds} seconds!");
}
Logger.Write(LogLevel.Info,
() =>
$"Processing {delayed.Count()} bulked events took {ctx.Elapsed.TotalMilliseconds} ms");
}
// Todo: use max retry setting
} while (!success && retry < 10);
if (!success)
{
// Dont run through NSB's error handler, it expects a single serialized message which
// is not compatible here. Just tell EventStore to retry it
// Todo: ES will park messages that fail - develop something to monitor parked messages
client.Nack(events);
}
}
}
if (idleContext == null)
{
idleContext = threadIdle.NewContext();
}
// Cheap hack to not burn cpu incase there are no events
if (noEvents)
{
Thread.Sleep(50);
}
}
}
