Umbraco ScheduledTasks Causing Delay with Custom PetaPoco Data Access
Hi there,
I'm not 100% sure my title is exactly what is happening but I'm pretty sure I've been able to narrow down my performance issue to something to do with the ScheduledTask running.
Quick overview of my setup. I have an Umbraco 7.4.3 site running where I use the CMS for site structure and about 50% of the content. Then I have some Partial Views on page that use Ajax to call SurfaceControllers which then call my DataRepository classes which use PetaPoco and the ApplicationContext.Current.DatabaseContext.Database.
Users are answering a series of questions (~250) using a simple YES/NO/NA dropdownlist and when that onchange fires I use ajax to call surface controller to save the response and check if there are any subsequent changes to questions. Running the SQL directly in MSSQLMS it's fast, and it's even fast running in Umbraco (40 - 80ms). This is great.
The catch is that as you go through and answer questions one after another, every minute my call takes 8-15 seconds! It's almost as if the AppPool were restarting behind the scenes. However when I enable detailed logging and look at my log file I see the following right when my call starts and then my call doesn't finish until the ScheduledTasks complete.
Scheduled tasks executing
....
...
hits /ping.aspx
...
Keep alive complete
Scheduled publishing executing...
Hits scheduledpublish/index
....
Then my task completes.
So I have a couple questions. I know I haven't posted any code and I can if required, but am I possibly doing something fundamentally wrong? Is there a way I can use PetaPoco and Umbraco DB Context on a different thread or something so the scheduled tasks don't hold things up? If that's not an option can I at least change the schedule for these tasks so that they run every 60 minutes and not 60 seconds. I can't seem to find this setting, as my UmbracoConfig file has nothing defined for scheduled tasks so I don't know what I would add to change this or if that's only for custom tasks and not these system tasks.
Just doing some more digging on this. Is it really possible that the background tasks KeepAlive, ScheduledPublishing, ScheduledTasks and LogScrubber are all hard coded to run every 60 seconds? As previously posted, the running of these tasks is making my apple unresponsive for 10-15 seconds, so I'm a little dumbfounded that I can't change the frequency without modifying source code for Umbraco. Please tell me I'm wrong:
Umbraco-CMS/src/Umbraco.Web/Scheduling/Scheduler.cs
RegisterBackgroundTasks
I can't see anywhere else that these tasks are initialized and the timing is hard coded here.
Still struggling with this so hoping someone might have someone from HQ with more intimate knowledge might be able to chime in. I've actually downloaded 7.4.3 source and changed the scheduled tasks in scheduler.cs to run every hour instead of every 60 seconds and I still have the issue. There is still something that runs even more frequently which could possibly be the issue. There's also the possibility that there are other things that aren't being logged with "debug" logging enabled.
With scheduled tasks out of the picture, I still frequently get 10-15 second delays and they coincide with the following in the log:
DEBUG Umbraco.Core.Sync.DatabaseServerMessenger - Syncing from database...
With just a little digging I think this is for syncing in a multi-server environment? My site is running on single server (currently all local on single dev machine). Any ideas on how I could disable this to try and rule it out? Or where I can change the interval it runs at as it doesn't appear to be controlled by the Scheduler.
Hoping someone can help out otherwise I'm going to have to scrap Umbraco completely, something I'm really hoping to avoid.
Seems you're the only one here that ever responds to my posts, big thanks!!
I will go through the above and check each to see if I can narrow it down. Right off the bat I don't actually have a "DistCache" folder under AppData. My project is built with NuGet and all is running locally. What or how would that folder and the lastsynced.txt file get created? I'm not at all familiar with this area but my wild guess is that it's something created for distributed servers/dbs and I'm running it all on the same box (local IIS though, not IIS Express, only use that when debugging). Network Service can create anything else under AppData so not sure why it wouldn't be able to create DistCache if needed.
I also just have one row in umbracoCacheInstruction table, very little admin work on this site.
A bit more info about the setup and what I've done so far.
Am using a SurfaceController that inherits SurfaceRenderMvcController and function returns JsonResult. I don't think that it's an issue with DataAccess as monitoring using SQL profiler things run remarkably fast. I've tried moving things from SurfaceController to UmbracoApiController and same problem. The View is displaying the data using jQuery DataTables so I removed that from equation. After doing that, I don't think it's the "Syncing from database..." as I see that after almost every ajax call (not sure if that's normal or not). What I do see appear when it stalls for 10-15 seconds is the following:
Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Task added Umbraco.Web.Strategies.ServerRegistrationEventHandler+TouchServerTask
I no longer see any of the other scheduled tasks as I've hard coded them to only run every 60 minutes (but doesn't look like they were the problem).
So I'm going to try and dig into source code to see what the ServerRegistrationEventHandler + TouchServerTask is/does and why it might be causing this issue. If you have any thoughts would love to hear them.
Oops, I think that file is actually located at ~/App_Data/TEMP/DistCache/SomeMachineName/SOMEID-lastsynced.txt.
I believe that file indicates the ID of the row that was last synchronized to the current machine (e.g., for load balancing). I think this would exist on all machines, as flexible load balancing is now the default.
So I'm going to try and dig into source code to see what the ServerRegistrationEventHandler + TouchServerTask is/does and why it might be causing this issue.
Umbraco ScheduledTasks Causing Delay with Custom PetaPoco Data Access
Hi there,
I'm not 100% sure my title is exactly what is happening but I'm pretty sure I've been able to narrow down my performance issue to something to do with the ScheduledTask running.
Quick overview of my setup. I have an Umbraco 7.4.3 site running where I use the CMS for site structure and about 50% of the content. Then I have some Partial Views on page that use Ajax to call SurfaceControllers which then call my DataRepository classes which use PetaPoco and the ApplicationContext.Current.DatabaseContext.Database.
Users are answering a series of questions (~250) using a simple YES/NO/NA dropdownlist and when that onchange fires I use ajax to call surface controller to save the response and check if there are any subsequent changes to questions. Running the SQL directly in MSSQLMS it's fast, and it's even fast running in Umbraco (40 - 80ms). This is great.
The catch is that as you go through and answer questions one after another, every minute my call takes 8-15 seconds! It's almost as if the AppPool were restarting behind the scenes. However when I enable detailed logging and look at my log file I see the following right when my call starts and then my call doesn't finish until the ScheduledTasks complete. Scheduled tasks executing .... ... hits /ping.aspx ... Keep alive complete Scheduled publishing executing... Hits scheduledpublish/index .... Then my task completes.
So I have a couple questions. I know I haven't posted any code and I can if required, but am I possibly doing something fundamentally wrong? Is there a way I can use PetaPoco and Umbraco DB Context on a different thread or something so the scheduled tasks don't hold things up? If that's not an option can I at least change the schedule for these tasks so that they run every 60 minutes and not 60 seconds. I can't seem to find this setting, as my UmbracoConfig file has nothing defined for scheduled tasks so I don't know what I would add to change this or if that's only for custom tasks and not these system tasks.
Any insight would be greatly appreciated.
Cheers, Phill
Just doing some more digging on this. Is it really possible that the background tasks KeepAlive, ScheduledPublishing, ScheduledTasks and LogScrubber are all hard coded to run every 60 seconds? As previously posted, the running of these tasks is making my apple unresponsive for 10-15 seconds, so I'm a little dumbfounded that I can't change the frequency without modifying source code for Umbraco. Please tell me I'm wrong:
Umbraco-CMS/src/Umbraco.Web/Scheduling/Scheduler.cs RegisterBackgroundTasks I can't see anywhere else that these tasks are initialized and the timing is hard coded here.
Again, any help is greatly appreciated. Phill
Still struggling with this so hoping someone might have someone from HQ with more intimate knowledge might be able to chime in. I've actually downloaded 7.4.3 source and changed the scheduled tasks in scheduler.cs to run every hour instead of every 60 seconds and I still have the issue. There is still something that runs even more frequently which could possibly be the issue. There's also the possibility that there are other things that aren't being logged with "debug" logging enabled.
With scheduled tasks out of the picture, I still frequently get 10-15 second delays and they coincide with the following in the log: DEBUG Umbraco.Core.Sync.DatabaseServerMessenger - Syncing from database...
With just a little digging I think this is for syncing in a multi-server environment? My site is running on single server (currently all local on single dev machine). Any ideas on how I could disable this to try and rule it out? Or where I can change the interval it runs at as it doesn't appear to be controlled by the Scheduler.
Hoping someone can help out otherwise I'm going to have to scrap Umbraco completely, something I'm really hoping to avoid.
Cheers, Phill
I haven't seen that, but here are some links that might be of use:
Based on what I read above, some things you might try:
~/App_Data/DistCache/LastSynced.txt.umbracoCacheInstructiontable.You might also use SQL Profiler to see what types of database operations are occurring every minute.
Hi Nicholas,
Seems you're the only one here that ever responds to my posts, big thanks!!
I will go through the above and check each to see if I can narrow it down. Right off the bat I don't actually have a "DistCache" folder under AppData. My project is built with NuGet and all is running locally. What or how would that folder and the lastsynced.txt file get created? I'm not at all familiar with this area but my wild guess is that it's something created for distributed servers/dbs and I'm running it all on the same box (local IIS though, not IIS Express, only use that when debugging). Network Service can create anything else under AppData so not sure why it wouldn't be able to create DistCache if needed.
I also just have one row in umbracoCacheInstruction table, very little admin work on this site.
A bit more info about the setup and what I've done so far. Am using a SurfaceController that inherits SurfaceRenderMvcController and function returns JsonResult. I don't think that it's an issue with DataAccess as monitoring using SQL profiler things run remarkably fast. I've tried moving things from SurfaceController to UmbracoApiController and same problem. The View is displaying the data using jQuery DataTables so I removed that from equation. After doing that, I don't think it's the "Syncing from database..." as I see that after almost every ajax call (not sure if that's normal or not). What I do see appear when it stalls for 10-15 seconds is the following: Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Task added Umbraco.Web.Strategies.ServerRegistrationEventHandler+TouchServerTask
I no longer see any of the other scheduled tasks as I've hard coded them to only run every 60 minutes (but doesn't look like they were the problem).
So I'm going to try and dig into source code to see what the ServerRegistrationEventHandler + TouchServerTask is/does and why it might be causing this issue. If you have any thoughts would love to hear them.
Thanks again! Phill
Oops, I think that file is actually located at
~/App_Data/TEMP/DistCache/SomeMachineName/SOMEID-lastsynced.txt.I believe that file indicates the ID of the row that was last synchronized to the current machine (e.g., for load balancing). I think this would exist on all machines, as flexible load balancing is now the default.
Good luck! Maybe try disabling it temporarily to see if that helps anything. Perhaps by commenting out this class: https://github.com/umbraco/Umbraco-CMS/blob/75c2b07ad3a093b5b65b6ebd45697687c062f62a/src/Umbraco.Web/Strategies/ServerRegistrationEventHandler.cs
is working on a reply...