U4-10698 - [DatabaseServerMessenger] Syncing from database on most requests. Is this right?

Created by Dan Booth 16 Nov 2017, 16:08:50 Updated by Dan Booth 16 Nov 2017, 16:21:00

'''What did you do?'''

Upgraded a site to Umbraco 7.7.6. Out of interest I thought I'd do some profiling with the mini-profiler, so put the site in debug mode and added ?umbDebug=true to URLs to get profiler output.

The site was running on a localhost (in IIS Express) connecting to an SQL Server 2008r2 database (on an external server). No load-balancing was configured.

The page itself consisted of a master template, child template and a number of partials (some cached). Though I also tried many different templates, with the same result.

'''What did you expect to happen?'''

I expected the profiler to show little to no database queries being executed after application had "warmed up".

'''What actually happened?'''

On about 1 in 5 requests (just by reloading page) I could see SQL queries being run, similar to this:

38.60 ms [DatabaseServerMessenger] Syncing from database... — 35.10 ms

[DatabaseServerMessenger] Syncing from database... T+38.6 ms Reader 12.8 ms b__0 ExecuteAction ExecuteReaderWithRetry ExecuteReaderWithRetry ExecuteReaderWithRetry MoveNext Fetch Fetch ProcessDatabaseInstructions Sync UmbracoModule_RouteAttempt OnRouteAttempt ProcessRequest b__12_3 DECLARE @0 int = 2460;

SELECT TOP 100 * FROM [umbracoCacheInstruction] WHERE (([umbracoCacheInstruction].[id] > @0)) ORDER BY ([umbracoCacheInstruction].[id])

I compared this to an older Umbraco 7.x site and could see no Database Server Messenger SQL requests being made, no matter how many times I reloaded the page.

I'm not exactly sure what DatabaseServerMessenger is supposed to do, but I wouldn't expect it to be running SQL queries all the time as this is an obvious performance overhead.

Further Info. I turned on debug logging and then just tried reloading the page (F5) over and over again. Here are the logs for Umbraco.Core.Sync.DatabaseServerMessenger

16:15:45.395 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:15:40.306 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:15:32.221 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:15:15.944 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:15:10.918 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:14:56.317 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:14:51.254 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:14:43.508 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:14:36.096 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:14:27.642 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:13:40.577 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:13:27.585 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database... 16:13:21.126 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database...

You can see its being run regularly. In fact, it appears to be running in the background as the log fills up with entries even if I do nothing...

Comments