microsoft / ApplicationInsights-dotnet-logging

.NET Logging adaptors
106 stars 49 forks source link

InMemoryChannel lock contention #267

Closed ionsphere closed 5 years ago

ionsphere commented 5 years ago

With high load applications the implementation of TelemetryBuffer becomes the bottleneck, that slows down all requests and causes high latency.

During a load test, that just calls TelemetryClient.Track 100,000 times in 400 parallel threads (only 250 calls from each thread) as fast as it can (consider it baseline with 100% of time spent) 65% is spent in Lock contention. Only 27% is due to GC Wait lock. All the rest 38% is actual locking.

Also notice, that only 7% of time is spent in OnBufferFull handler - the test is not blasting too heavy with events.

Such heavy locking gets strongest impacts on the ThreadPool as all our code is asynchronous with Tasks, but if a Task locks, then it cannot release a thread and causes either thread starvation or thread pool growth which is already a CPU starvation.

The reason behind having that many calls is because property dictionaries in those cases are different and cannot be just aggregated into a single Metric. All those properties are used as custom dimensions for search. There are 20 properties, each can have somewhere between 5 to 100 different values.

Possible options:

  1. Allow custom implementation of TelemetryBuffer. Testing shows that using TPL Dataflow to post events and then process them in a single Task (ActionBlock with parallelism 1) improves performance. Of course, standard implementation should not rely on yet another heavy library, but having the possibility to override just one class for our narrow use case can be beneficial. Current implementation does not allow such extensibility as InMemoryTransmitter requires exactly TelemetryBuffer class and not an interface and anyway all those classes are internal except InMemoryChannel's default constructor.

  2. Provide interface with batching support of an IEnumerable. There is a similar support with TrackEvent where for the same properties it is possible to send multiple metrics. Having similar interface but for different property sets could allow having a lock just once instead of N-times.

  3. Provide ETW-version of TelemetryClient to send events into asynchronous pipe. Sadly, right now TelemetryClient implements no interfaces and is sealed, meaning a lot of work to cut it out for another implementation.

ionsphere commented 5 years ago

Wrong repository