serilog-archive/serilog-sinks-azuredocumentdb

Upgrading from 3.8.0 to 3.8.1 destroys production server CPU (~400% increase)

kspearrin opened this issue · 10 comments

Hey guys,
We did a production release of our codebase yesterday and immediately following had a massive change in CPU usage on the server. After debugging the problem today I have narrowed it down to upgrading our Serilog.Sinks.AzureDocumentDB nuget package from 3.8.0 to 3.8.1.

The following graph shows our Azure web app before and after deployment when the only change was upgrading Serilog.Sinks.AzureDocumentDB from 3.8.0 to 3.8.1.

image

The overloaded CPU never stops unless we revert the change from 3.8.1 back down to 3.8.0.

Our implementation of Serilog is pretty simple, wired up to an ASP.NET Core MVC API project. See here:

https://github.com/bitwarden/core/blob/adc97f82f55a98eb3ef0604992123d8a063525f4/src/Core/Utilities/LoggerFactoryExtensions.cs#L12-L65

The code path for this deployment scenario utilizes the DocumentDB configuration.

Upgrading from 3.8.0 to 3.8.1 also seems to bring in a few other dependency updates, so I am uncertain if it could be one of the others, such as the main Serilog package.

image

@kspearrin, sorry to hear that you had issue with latest release. I'll investigate issue. However, I need help to replicate issue.

Please let me know what is your log load? how many messages are being logged per unit of time?
Also, it will be great help if I can get piece of code to reproduce this issue.

thank you.

@saleem-mirza This is a fairly active application, however, the load load is pretty light (after filtering). I linked the code we are using for Serilog above.

Since this original report I have updated my project to .NET Core 2.1. I decided to give this package upgrade to 3.8.1 a try again this evening, yet the same problem still seems to be occurring.

Here's the CPU graph from this evening's deployment attempt with 3.8.1 (shown in red section):

image

Reverting back to 3.8.0 resolved the problem.

@kspearrin, I will investigate keep you posted regarding this issue.

surprisingly, I couldn't find any reason for CPU spike except third party drivers. However, I have updated drivers and hoping this issue will go away.
Please try latest dev version (https://www.nuget.org/packages/Serilog.Sinks.AzureDocumentDb/3.9.0-dev-00171) and let me know if it solved issue?

@kspearrin we made few changes to put less stress on host under few circumstances. please try https://www.nuget.org/packages/Serilog.Sinks.AzureDocumentDb/4.0.0 and let us know if it improves.

@saleem-mirza I tried again this evening with version 4.0.0. The same problem still occurs.

Can you please capture a process dump to figure out what's going on?

I'll have to try and get that when we do another deployment. Unfortunately it has been reverted for now and the deployment is over.