umbracomodule very slow

Go to solution

Press Ctrl / CMD + C to copy this to your clipboard.

Copied to clipboard

Flag this post as spam?

This post will be reported to the moderators as potential spam to be looked at

Josh Reid 182 posts 258 karma points

Sep 13, 2013 @ 23:59

IIS6 + .NET4
Umbraco 4.11.10

UmbracoModule is SUPER SLOW

I don't what this is doing, but UmbracoModule hangs the loading of every page (this said it isn't every load), just MOST - sometimes upwards to 8-10 seconds!

Trace Information
Category        Message                 From First(s)       From Last(s)
content         Initializing content on thread '' (Threadpool? True)        
content         Content initialized (loaded)        0.0653830667857143  0.065383
UmbracoModule       Umbraco request begins          1.42367841642857    1.358295
UmbracoModule       Umbraco request confirmed       5.92453762357143    4.500859
            test                    6.02375110464286    0.099213
aspx.page       Begin PreInit               6.34465496642857    0.320904
...

EG: most of the time if refreshed within seconds, it isn't running, and back to performance I'd expect:

Trace Information
Category        Message                 From First(s)   From Last(s)
aspx.page       Begin PreInit       
aspx.page       End PreInit             0.00361216107142857 0.003612
aspx.page       Begin Init              0.00366217285714286 0.000050
renderMacro     Rendering started (macro: HTML Title, type: 1, cacheRate: 3600)
                               0.00382766678571429 0.000165
renderMacro     Macro Content loaded from cache 'HTMLtitle-1243-++-'.   
                              0.00637256714285714 0.002545
renderMacro     Rendering started (macro: Meta Data, type: 1, cacheRate: 3600)
                                0.00647622714285714 0.000104
...

As soon as UmbracoModule runs the load grrrrrinds to a halt, wtf?!

Anything I can do? Any thoughts much appreciated!

Thanks
Josh

Copy Link

Stephen 767 posts 2273 karma points c-trib

Sep 14, 2013 @ 08:36

0

Can you enable debug in log4net.config (priority=debug) and post the relevant log from app_data/logs ?

Copy Link
Josh Reid 182 posts 258 karma points

Sep 14, 2013 @ 12:18

0

Awesome thanks Stephen, I didn't know about these logs!

Looks like it's just shutting down continuously- HostingEnvironment appears to be an issue..

hmmmm any thoughts? Or time to get a better server?

Logs below from last 10minutes:

---

2013-09-14 21:55:40,317 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 5] Application shutdown. Reason: HostingEnvironment
2013-09-14 21:55:41,473 [9] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 21:55:41,536 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 21:55:41,551 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 11ms)
2013-09-14 21:55:41,817 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 250ms)
2013-09-14 21:55:42,051 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 229ms)
2013-09-14 21:55:42,098 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 35ms)
2013-09-14 21:55:42,129 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 32ms)
2013-09-14 21:55:42,301 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 164ms)
2013-09-14 21:55:42,364 [9] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 889ms)
2013-09-14 21:55:44,082 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 72ms)
2013-09-14 21:55:44,426 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 307ms)
2013-09-14 21:56:39,145 [9] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of umbraco.interfaces.IDataType, found 104 (took 637ms)
2013-09-14 21:56:39,552 [9] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 356ms)
2013-09-14 21:56:40,614 [9] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of umbraco.BusinessLogic.Actions.IActionHandler, found 2 (took 28ms)
2013-09-14 21:56:40,864 [9] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 21:56:40,911 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 21:56:40,927 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 14ms)
2013-09-14 21:56:41,192 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 246ms)
2013-09-14 21:56:41,364 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 163ms)
2013-09-14 21:56:41,395 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 20ms)
2013-09-14 21:56:41,411 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 20ms)
2013-09-14 21:56:41,567 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 145ms)
2013-09-14 21:56:41,645 [9] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 774ms)
2013-09-14 21:56:42,270 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 71ms)
2013-09-14 21:56:42,614 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 310ms)
2013-09-14 21:56:43,552 [9] INFO Umbraco.Web.UmbracoApplication - [Thread 5] Application shutdown. Reason: HostingEnvironment
2013-09-14 21:56:51,567 [9] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 316ms)
2013-09-14 21:56:51,692 [9] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of umbraco.BusinessLogic.Actions.IActionHandler, found 2 (took 34ms)
2013-09-14 21:57:40,552 [9] INFO Umbraco.Core.PluginManager - [Thread 18] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 56ms)
2013-09-14 21:57:41,583 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 21:57:41,661 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 21:57:41,677 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 10ms)
2013-09-14 21:57:41,943 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 243ms)
2013-09-14 21:57:42,161 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 227ms)
2013-09-14 21:57:42,208 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 33ms)
2013-09-14 21:57:42,239 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 31ms)
2013-09-14 21:57:42,411 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 163ms)
2013-09-14 21:57:42,489 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 888ms)
2013-09-14 21:57:43,036 [9] INFO Umbraco.Core.PluginManager - [Thread 18] Completed resolution of types of umbraco.MacroEngines.IRazorDataTypeModel, found 15 (took 184ms)
2013-09-14 21:57:43,286 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 72ms)
2013-09-14 21:57:43,583 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 273ms)
2013-09-14 21:57:46,489 [9] INFO Umbraco.Web.UmbracoApplication - [Thread 22] Application shutdown. Reason: HostingEnvironment
2013-09-14 21:57:49,411 [6] INFO Umbraco.Core.PluginManager - [Thread 17] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 34ms)
2013-09-14 21:57:57,802 [6] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 41ms)
2013-09-14 21:58:10,411 [6] INFO Umbraco.Core.PluginManager - [Thread 17] Completed resolution of types of umbraco.BusinessLogic.Actions.IActionHandler, found 2 (took 31ms)
2013-09-14 21:58:11,427 [6] INFO Umbraco.Core.PluginManager - [Thread 17] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 588ms)
2013-09-14 21:58:42,505 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 1] Application shutdown. Reason: HostingEnvironment
2013-09-14 21:58:42,740 [7] INFO Umbraco.Core.CoreBootManager - [Thread 6] Umbraco application starting
2013-09-14 21:58:42,802 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Determining hash of code files on disk
2013-09-14 21:58:42,818 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Hash determined (took 15ms)
2013-09-14 21:58:43,130 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 292ms)
2013-09-14 21:58:43,365 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 233ms)
2013-09-14 21:58:43,412 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 34ms)
2013-09-14 21:58:43,443 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 33ms)
2013-09-14 21:58:43,615 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 158ms)
2013-09-14 21:58:43,693 [7] INFO Umbraco.Core.CoreBootManager - [Thread 6] Umbraco application startup complete (took 934ms)
2013-09-14 21:58:44,396 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 66ms)
2013-09-14 21:58:44,740 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 313ms)
2013-09-14 21:58:55,037 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IDataType, found 104 (took 449ms)
2013-09-14 21:58:55,302 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 247ms)
2013-09-14 21:58:55,990 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.BusinessLogic.Actions.IActionHandler, found 2 (took 30ms)
2013-09-14 21:59:05,631 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 27ms)
2013-09-14 21:59:06,756 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 26ms)
2013-09-14 21:59:07,224 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.MacroEngines.IRazorDataTypeModel, found 15 (took 106ms)
2013-09-14 21:59:11,693 [7] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 29ms)
2013-09-14 21:59:42,490 [8] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 21:59:42,553 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 21:59:42,568 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 16ms)
2013-09-14 21:59:42,865 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 279ms)
2013-09-14 21:59:43,100 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 234ms)
2013-09-14 21:59:43,146 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 35ms)
2013-09-14 21:59:43,178 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 31ms)
2013-09-14 21:59:43,350 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 160ms)
2013-09-14 21:59:43,428 [8] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 925ms)
2013-09-14 21:59:43,725 [7] INFO Umbraco.Web.UmbracoApplication - [Thread 8] Application shutdown. Reason: HostingEnvironment
2013-09-14 21:59:44,178 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 74ms)
2013-09-14 21:59:44,537 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 324ms)
2013-09-14 21:59:49,912 [8] INFO Umbraco.Core.PluginManager - [Thread 10] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 43ms)
2013-09-14 22:00:42,444 [7] INFO Umbraco.Core.CoreBootManager - [Thread 5] Umbraco application starting
2013-09-14 22:00:42,506 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Determining hash of code files on disk
2013-09-14 22:00:42,522 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Hash determined (took 16ms)
2013-09-14 22:00:42,537 [8] INFO Umbraco.Web.UmbracoApplication - [Thread 7] Application shutdown. Reason: HostingEnvironment
2013-09-14 22:00:42,819 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 279ms)
2013-09-14 22:00:43,037 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 217ms)
2013-09-14 22:00:43,069 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 31ms)
2013-09-14 22:00:43,100 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 30ms)
2013-09-14 22:00:43,256 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 146ms)
2013-09-14 22:00:43,334 [7] INFO Umbraco.Core.CoreBootManager - [Thread 5] Umbraco application startup complete (took 877ms)
2013-09-14 22:00:44,475 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 75ms)
2013-09-14 22:00:44,803 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 300ms)
2013-09-14 22:01:15,147 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 46ms)
2013-09-14 22:01:42,491 [7] INFO Umbraco.Core.CoreBootManager - [Thread 5] Umbraco application starting
2013-09-14 22:01:42,553 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Determining hash of code files on disk
2013-09-14 22:01:42,569 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Hash determined (took 15ms)
2013-09-14 22:01:42,835 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 244ms)
2013-09-14 22:01:43,007 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 175ms)
2013-09-14 22:01:43,038 [7] INFO Umbraco.Web.UmbracoApplication - [Thread 8] Application shutdown. Reason: HostingEnvironment
2013-09-14 22:01:43,053 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 31ms)
2013-09-14 22:01:43,085 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 28ms)
2013-09-14 22:01:43,241 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 154ms)
2013-09-14 22:01:43,319 [7] INFO Umbraco.Core.CoreBootManager - [Thread 5] Umbraco application startup complete (took 809ms)
2013-09-14 22:01:44,085 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 73ms)
2013-09-14 22:01:44,413 [7] INFO Umbraco.Core.PluginManager - [Thread 5] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 313ms)
2013-09-14 22:02:06,101 [7] INFO Umbraco.Core.PluginManager - [Thread 9] Completed resolution of types of umbraco.interfaces.IDataType, found 104 (took 529ms)
2013-09-14 22:02:06,429 [7] INFO Umbraco.Core.PluginManager - [Thread 9] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 317ms)
2013-09-14 22:02:07,397 [7] INFO Umbraco.Core.PluginManager - [Thread 9] Completed resolution of types of umbraco.BusinessLogic.Actions.IActionHandler, found 2 (took 29ms)
2013-09-14 22:02:21,085 [7] INFO Umbraco.Core.PluginManager - [Thread 12] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 34ms)
2013-09-14 22:02:22,038 [7] INFO Umbraco.Core.PluginManager - [Thread 12] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 40ms)
2013-09-14 22:02:23,101 [7] INFO Umbraco.Core.PluginManager - [Thread 12] Completed resolution of types of umbraco.MacroEngines.IRazorDataTypeModel, found 15 (took 185ms)
2013-09-14 22:02:25,648 [7] INFO Umbraco.Core.PluginManager - [Thread 9] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 30ms)
2013-09-14 22:02:43,101 [7] INFO Umbraco.Web.UmbracoApplication - [Thread 12] Application shutdown. Reason: HostingEnvironment
2013-09-14 22:02:44,085 [8] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 22:02:44,148 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 22:02:44,163 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 16ms)
2013-09-14 22:02:44,444 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 274ms)
2013-09-14 22:02:44,679 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 232ms)
2013-09-14 22:02:44,726 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 23ms)
2013-09-14 22:02:44,757 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 31ms)
2013-09-14 22:02:44,913 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 156ms)
2013-09-14 22:02:44,960 [8] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 867ms)
2013-09-14 22:02:45,741 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 74ms)
2013-09-14 22:02:46,054 [8] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 296ms)
2013-09-14 22:02:51,163 [8] INFO Umbraco.Core.PluginManager - [Thread 17] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 36ms)
2013-09-14 22:02:51,382 [8] INFO Umbraco.Core.PluginManager - [Thread 11] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 35ms)
2013-09-14 22:02:59,507 [8] INFO Umbraco.Core.PluginManager - [Thread 11] Completed resolution of types of umbraco.interfaces.IDataType, found 104 (took 487ms)
2013-09-14 22:02:59,820 [8] INFO Umbraco.Core.PluginManager - [Thread 11] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 305ms)
2013-09-14 22:03:02,257 [8] INFO Umbraco.Core.PluginManager - [Thread 9] Completed resolution of types of umbraco.MacroEngines.IRazorDataTypeModel, found 15 (took 119ms)
2013-09-14 22:03:08,085 [8] INFO Umbraco.Core.PluginManager - [Thread 22] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 30ms)
2013-09-14 22:03:42,992 [7] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 22:03:43,039 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 22:03:43,054 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 15ms)
2013-09-14 22:03:43,320 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 252ms)
2013-09-14 22:03:43,507 [8] INFO Umbraco.Web.UmbracoApplication - [Thread 17] Application shutdown. Reason: HostingEnvironment
2013-09-14 22:03:43,554 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 217ms)
2013-09-14 22:03:43,601 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 34ms)
2013-09-14 22:03:43,632 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 30ms)
2013-09-14 22:03:43,789 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 160ms)
2013-09-14 22:03:43,836 [7] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 843ms)
2013-09-14 22:03:44,539 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 70ms)
2013-09-14 22:03:44,914 [7] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 303ms)
2013-09-14 22:03:50,695 [7] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 42ms)
2013-09-14 22:04:27,695 [7] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 34ms)
2013-09-14 22:04:36,633 [7] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 30ms)
2013-09-14 22:04:43,008 [7] INFO Umbraco.Web.UmbracoApplication - [Thread 5] Application shutdown. Reason: HostingEnvironment
2013-09-14 22:04:44,664 [9] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 22:04:44,727 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 22:04:44,742 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 15ms)
2013-09-14 22:04:45,039 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 280ms)
2013-09-14 22:04:45,289 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 243ms)
2013-09-14 22:04:45,336 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 34ms)
2013-09-14 22:04:45,367 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 31ms)
2013-09-14 22:04:45,539 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 164ms)
2013-09-14 22:04:45,617 [9] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 944ms)
2013-09-14 22:04:46,367 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 71ms)
2013-09-14 22:04:46,695 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 299ms)
2013-09-14 22:04:53,273 [9] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 34ms)
2013-09-14 22:04:53,289 [9] INFO Umbraco.Core.PluginManager - [Thread 7] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 0ms)
2013-09-14 22:04:53,289 [9] INFO Umbraco.Core.PluginManager - [Thread 8] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 0ms)
2013-09-14 22:04:53,289 [9] INFO Umbraco.Core.PluginManager - [Thread 10] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 0ms)
2013-09-14 22:04:53,289 [9] INFO Umbraco.Core.PluginManager - [Thread 6] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 0ms)
2013-09-14 22:04:53,289 [9] INFO Umbraco.Core.PluginManager - [Thread 11] Completed resolution of types of Umbraco.Web.BaseRest.RestExtensionAttribute, found 3 (took 0ms)
2013-09-14 22:04:56,523 [9] INFO Umbraco.Core.PluginManager - [Thread 23] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 36ms)
2013-09-14 22:04:57,430 [9] INFO Umbraco.Core.PluginManager - [Thread 23] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 31ms)
2013-09-14 22:04:57,445 [9] INFO Umbraco.Core.PluginManager - [Thread 21] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 0ms)
2013-09-14 22:04:58,180 [9] INFO Umbraco.Core.PluginManager - [Thread 23] Completed resolution of types of umbraco.MacroEngines.IRazorDataTypeModel, found 15 (took 350ms)
2013-09-14 22:05:43,883 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-14 22:05:43,946 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-14 22:05:43,961 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 15ms)
2013-09-14 22:05:44,211 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 239ms)
2013-09-14 22:05:44,211 [9] INFO Umbraco.Web.UmbracoApplication - [Thread 13] Application shutdown. Reason: HostingEnvironment
2013-09-14 22:05:44,383 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 163ms)
2013-09-14 22:05:44,414 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 25ms)
2013-09-14 22:05:44,446 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 23ms)
2013-09-14 22:05:44,602 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 149ms)
2013-09-14 22:05:44,664 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 765ms)
2013-09-14 22:05:45,352 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 73ms)
2013-09-14 22:05:45,696 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 321ms)
2013-09-14 22:05:51,649 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 24ms)

Copy Link
Josh Reid 182 posts 258 karma points

Sep 15, 2013 @ 01:41

0

Oh I see the priority = debug now, and have included a few minutes of browsing below:

Do you have any further thoughts on this? Thanks heaps!

2013-09-15 11:18:08,171 [6] DEBUG Umbraco.Web.UmbracoModule - [Thread 7] Total milliseconds for umbraco request to process: 359.3773
2013-09-15 11:18:12,749 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 8] Application shutdown. Reason: HostingEnvironment
2013-09-15 11:18:13,561 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-15 11:18:13,593 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-15 11:18:13,608 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 9ms)
2013-09-15 11:18:13,608 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2013-09-15 11:18:13,796 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 175ms)
2013-09-15 11:18:13,796 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2013-09-15 11:18:13,952 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 166ms)
2013-09-15 11:18:13,968 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2013-09-15 11:18:13,999 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 25ms)
2013-09-15 11:18:13,999 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2013-09-15 11:18:14,015 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 24ms)
2013-09-15 11:18:14,030 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2013-09-15 11:18:14,171 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 145ms)
2013-09-15 11:18:14,233 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 669ms)
2013-09-15 11:18:14,655 [6] DEBUG umbraco.content - [Thread 1] Initializing content on thread '' (Threadpool? True)
2013-09-15 11:18:14,718 [6] DEBUG umbraco.content - [Thread 1] Content initialized (loaded)
2013-09-15 11:18:14,890 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplication
2013-09-15 11:18:14,968 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 73ms)
2013-09-15 11:18:14,983 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.ITree
2013-09-15 11:18:15,374 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 385ms)
2013-09-15 11:18:19,155 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupDomain: Uri="http://xpozenz.com/more/dashboard/band-manager"
2013-09-15 11:18:19,171 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupDomain: Matches domain="xpozenz.com", rootId=1065, culture="en-NZ"
2013-09-15 11:18:19,171 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupDomain: Culture="en-NZ"
2013-09-15 11:18:19,171 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupDocument: Path="/more/dashboard/band-manager"
2013-09-15 11:18:19,187 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] LookupDocument: Begin resolvers
2013-09-15 11:18:19,187 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 1] Test route "1065/more/dashboard/band-manager"
2013-09-15 11:18:19,187 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 1] Cache miss, query
2013-09-15 11:18:19,218 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 1] Query matches, id=1324
2013-09-15 11:18:19,233 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] LookupDocument: End resolvers, a document was found (took 56ms)
2013-09-15 11:18:19,249 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupDocument2: Begin
2013-09-15 11:18:19,265 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] EnsurePageAccess: Page is protected, check for access
2013-09-15 11:18:19,327 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] EnsurePageAccess: Current member has access
2013-09-15 11:18:19,343 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupTemplate: Look for template id=1330
2013-09-15 11:18:19,421 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupTemplate: Got template id=1330 alias="M-Bands"
2013-09-15 11:18:19,421 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupTemplate: Running with template id=1330 alias="M-Bands"
2013-09-15 11:18:19,421 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] LookupDocument2: End
2013-09-15 11:18:19,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] HandleWildcardDomains: Path="-1,1065,1306,1308,1324"
2013-09-15 11:18:19,515 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 1] HandleWildcardDomains: No match.
2013-09-15 11:18:22,827 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.XsltExtensionAttribute
2013-09-15 11:18:22,874 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 34ms)
2013-09-15 11:18:23,796 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.cms.businesslogic.macro.IMacroEngine
2013-09-15 11:18:23,843 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 43ms)
2013-09-15 11:18:26,671 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IDataType
2013-09-15 11:18:27,280 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IDataType, found 104 (took 612ms)
2013-09-15 11:18:27,296 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.ITree
2013-09-15 11:18:27,608 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 311ms)
2013-09-15 11:18:31,062 [6] DEBUG Umbraco.Web.UmbracoModule - [Thread 1] Total milliseconds for umbraco request to process: 15140.7219
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupDomain: Uri="http://xpozenz.com/more/dashboard/band-manager?p=3"
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupDomain: Matches domain="xpozenz.com", rootId=1065, culture="en-NZ"
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupDomain: Culture="en-NZ"
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupDocument: Path="/more/dashboard/band-manager"
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Core.PluginManager - [Thread 7] LookupDocument: Begin resolvers
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 7] Test route "1065/more/dashboard/band-manager"
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 7] Cache hit, id=1324
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Core.PluginManager - [Thread 7] LookupDocument: End resolvers, a document was found (took 2ms)
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupDocument2: Begin
2013-09-15 11:18:36,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] EnsurePageAccess: Page is protected, check for access
2013-09-15 11:18:36,030 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] EnsurePageAccess: Current member has access
2013-09-15 11:18:36,030 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupTemplate: Look for template id=1330
2013-09-15 11:18:36,030 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupTemplate: Got template id=1330 alias="M-Bands"
2013-09-15 11:18:36,030 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupTemplate: Running with template id=1330 alias="M-Bands"
2013-09-15 11:18:36,030 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] LookupDocument2: End
2013-09-15 11:18:36,030 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] HandleWildcardDomains: Path="-1,1065,1306,1308,1324"
2013-09-15 11:18:36,030 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 7] HandleWildcardDomains: No match.
2013-09-15 11:18:37,108 [6] DEBUG Umbraco.Web.UmbracoModule - [Thread 7] Total milliseconds for umbraco request to process: 1093.757
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupDomain: Uri="http://xpozenz.com/bands/hip-hop/savage"
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupDomain: Matches domain="xpozenz.com", rootId=1065, culture="en-NZ"
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupDomain: Culture="en-NZ"
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupDocument: Path="/bands/hip-hop/savage"
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Core.PluginManager - [Thread 11] LookupDocument: Begin resolvers
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 11] Test route "1065/bands/hip-hop/savage"
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 11] Cache hit, id=1516
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Core.PluginManager - [Thread 11] LookupDocument: End resolvers, a document was found (took 3ms)
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupDocument2: Begin
2013-09-15 11:18:47,468 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] EnsurePageAccess: Page is protected, check for access
2013-09-15 11:18:47,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] EnsurePageAccess: Current member has access
2013-09-15 11:18:47,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupTemplate: Look for template id=1337
2013-09-15 11:18:47,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupTemplate: Got template id=1337 alias="List Content"
2013-09-15 11:18:47,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupTemplate: Running with template id=1337 alias="List Content"
2013-09-15 11:18:47,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] LookupDocument2: End
2013-09-15 11:18:47,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] HandleWildcardDomains: Path="-1,1065,1303,1374,1516"
2013-09-15 11:18:47,499 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 11] HandleWildcardDomains: No match.
2013-09-15 11:18:50,234 [6] DEBUG Umbraco.Web.UmbracoModule - [Thread 11] Total milliseconds for umbraco request to process: 2765.6427
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupDomain: Uri="http://xpozenz.com/search?search=antix&filter=1065-1307-1303-1417-1418"
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupDomain: Matches domain="xpozenz.com", rootId=1065, culture="en-NZ"
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupDomain: Culture="en-NZ"
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupDocument: Path="/search"
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Core.PluginManager - [Thread 5] LookupDocument: Begin resolvers
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 5] Test route "1065/search"
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 5] Cache miss, query
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 5] Query matches, id=1335
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Core.PluginManager - [Thread 5] LookupDocument: End resolvers, a document was found (took 6ms)
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupDocument2: Begin
2013-09-15 11:19:09,577 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] EnsurePageAccess: Page is protected, check for access
2013-09-15 11:19:09,593 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] EnsurePageAccess: Current member has access
2013-09-15 11:19:09,593 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupTemplate: Look for template id=1055
2013-09-15 11:19:09,593 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupTemplate: Got template id=1055 alias="XSLTsearch"
2013-09-15 11:19:09,593 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupTemplate: Running with template id=1055 alias="XSLTsearch"
2013-09-15 11:19:09,593 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] LookupDocument2: End
2013-09-15 11:19:09,593 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] HandleWildcardDomains: Path="-1,1065,1335"
2013-09-15 11:19:09,593 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 5] HandleWildcardDomains: No match.
2013-09-15 11:19:14,968 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-15 11:19:14,999 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-15 11:19:15,015 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 10ms)
2013-09-15 11:19:15,015 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2013-09-15 11:19:15,187 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 171ms)
2013-09-15 11:19:15,187 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2013-09-15 11:19:15,327 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 137ms)
2013-09-15 11:19:15,343 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2013-09-15 11:19:15,359 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 20ms)
2013-09-15 11:19:15,359 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2013-09-15 11:19:15,374 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 18ms)
2013-09-15 11:19:15,390 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2013-09-15 11:19:15,484 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 101ms)
2013-09-15 11:19:15,531 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 557ms)
2013-09-15 11:19:15,812 [6] DEBUG umbraco.content - [Thread 1] Initializing content on thread '' (Threadpool? True)
2013-09-15 11:19:15,859 [6] DEBUG umbraco.content - [Thread 1] Content initialized (loaded)
2013-09-15 11:19:15,984 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplication
2013-09-15 11:19:16,031 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 53ms)
2013-09-15 11:19:16,062 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.ITree
2013-09-15 11:19:16,265 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 203ms)
2013-09-15 11:19:17,374 [6] DEBUG Umbraco.Web.UmbracoModule - [Thread 5] Total milliseconds for umbraco request to process: 7796.9249
2013-09-15 11:19:19,109 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 7] Application shutdown. Reason: HostingEnvironment
2013-09-15 11:19:22,093 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupDomain: Uri="http://xpozenz.com/bands/dance-electronic/antix-fiord"
2013-09-15 11:19:22,109 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupDomain: Matches domain="xpozenz.com", rootId=1065, culture="en-NZ"
2013-09-15 11:19:22,109 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupDomain: Culture="en-NZ"
2013-09-15 11:19:22,109 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupDocument: Path="/bands/dance-electronic/antix-fiord"
2013-09-15 11:19:22,124 [6] DEBUG Umbraco.Core.PluginManager - [Thread 12] LookupDocument: Begin resolvers
2013-09-15 11:19:22,124 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 12] Test route "1065/bands/dance-electronic/antix-fiord"
2013-09-15 11:19:22,124 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 12] Cache miss, query
2013-09-15 11:19:22,171 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 12] Query matches, id=2489
2013-09-15 11:19:22,203 [6] DEBUG Umbraco.Core.PluginManager - [Thread 12] LookupDocument: End resolvers, a document was found (took 76ms)
2013-09-15 11:19:22,203 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupDocument2: Begin
2013-09-15 11:19:22,218 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] EnsurePageAccess: Page is protected, check for access
2013-09-15 11:19:22,249 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] EnsurePageAccess: Current member has access
2013-09-15 11:19:22,249 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupTemplate: Look for template id=1337
2013-09-15 11:19:22,312 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupTemplate: Got template id=1337 alias="List Content"
2013-09-15 11:19:22,312 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupTemplate: Running with template id=1337 alias="List Content"
2013-09-15 11:19:22,312 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] LookupDocument2: End
2013-09-15 11:19:22,312 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] HandleWildcardDomains: Path="-1,1065,1303,1322,2489"
2013-09-15 11:19:22,312 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 12] HandleWildcardDomains: No match.
2013-09-15 11:19:22,687 [6] DEBUG Umbraco.Core.PluginManager - [Thread 12] Starting resolution types of umbraco.XsltExtensionAttribute
2013-09-15 11:19:22,718 [6] INFO Umbraco.Core.PluginManager - [Thread 12] Completed resolution of types of umbraco.XsltExtensionAttribute, found 7 (took 36ms)
2013-09-15 11:19:23,656 [6] DEBUG Umbraco.Core.PluginManager - [Thread 12] Starting resolution types of umbraco.cms.businesslogic.macro.IMacroEngine
2013-09-15 11:19:23,703 [6] INFO Umbraco.Core.PluginManager - [Thread 12] Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 4 (took 43ms)
2013-09-15 11:19:26,640 [6] DEBUG Umbraco.Core.PluginManager - [Thread 12] Starting resolution types of umbraco.interfaces.IDataType
2013-09-15 11:19:27,359 [6] INFO Umbraco.Core.PluginManager - [Thread 12] Completed resolution of types of umbraco.interfaces.IDataType, found 104 (took 719ms)
2013-09-15 11:19:27,374 [6] DEBUG Umbraco.Core.PluginManager - [Thread 12] Starting resolution types of umbraco.interfaces.ITree
2013-09-15 11:19:27,687 [6] INFO Umbraco.Core.PluginManager - [Thread 12] Completed resolution of types of umbraco.interfaces.ITree, found 45 (took 308ms)
2013-09-15 11:19:28,265 [6] DEBUG Umbraco.Web.UmbracoModule - [Thread 12] Total milliseconds for umbraco request to process: 6187.5396
2013-09-15 11:19:48,937 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] LookupDomain: Uri="http://xpozenz.com/home"
2013-09-15 11:19:48,937 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] LookupDomain: Matches domain="xpozenz.com", rootId=1065, culture="en-NZ"
2013-09-15 11:19:48,937 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] LookupDomain: Culture="en-NZ"
2013-09-15 11:19:48,937 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] LookupDocument: Path="/home"
2013-09-15 11:19:48,937 [6] DEBUG Umbraco.Core.PluginManager - [Thread 14] LookupDocument: Begin resolvers
2013-09-15 11:19:48,937 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 14] Test route "1065/home"
2013-09-15 11:19:48,937 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 14] Cache miss, query
2013-09-15 11:19:48,953 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 14] Query does not match
2013-09-15 11:19:48,953 [6] DEBUG Umbraco.Web.Routing.LookupByIdPath - [Thread 14] Not a node id
2013-09-15 11:19:48,968 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Registering custom handlers.
2013-09-15 11:19:48,968 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Registering 'umbraco.SearchForAlias,umbraco'.
2013-09-15 11:19:48,968 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Registering 'umbraco.SearchForTemplate,umbraco'.
2013-09-15 11:19:48,968 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Registering 'umbraco.SearchForProfile,umbraco'.
2013-09-15 11:19:48,968 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Registering 'umbraco.handle404,umbraco'.
2013-09-15 11:19:48,984 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Running for legacy url='home'.
2013-09-15 11:19:48,984 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Handler 'umbraco.SearchForAlias'.
2013-09-15 11:19:48,984 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Replace handler 'umbraco.SearchForAlias' by new lookup 'Umbraco.Web.Routing.LookupByAlias'.
2013-09-15 11:19:49,000 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Handler 'umbraco.SearchForTemplate'.
2013-09-15 11:19:49,000 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Replace handler 'umbraco.SearchForTemplate' by new lookup 'Umbraco.Web.Routing.LookupByNiceUrlAndTemplate'.
2013-09-15 11:19:49,015 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrlAndTemplate - [Thread 14] Valid template: "home"
2013-09-15 11:19:49,015 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 14] Test route "1065/"
2013-09-15 11:19:49,015 [6] DEBUG Umbraco.Web.Routing.LookupByNiceUrl - [Thread 14] Cache hit, id=1065
2013-09-15 11:19:49,015 [6] DEBUG Umbraco.Web.Routing.LookupByNotFoundHandlers - [Thread 14] Lookup 'Umbraco.Web.Routing.LookupByNiceUrlAndTemplate' found node with id=1065.
2013-09-15 11:19:49,015 [6] DEBUG Umbraco.Core.PluginManager - [Thread 14] LookupDocument: End resolvers, a document was found (took 80ms)
2013-09-15 11:19:49,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] LookupDocument2: Begin
2013-09-15 11:19:49,015 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] EnsurePageAccess: Page is protected, check for access
2013-09-15 11:19:49,062 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] EnsurePageAccess: Current member has access
2013-09-15 11:19:49,062 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] LookupTemplate: Has a template already, and no alternate template.
2013-09-15 11:19:49,062 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] LookupDocument2: End
2013-09-15 11:19:49,109 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] HandleWildcardDomains: Path="-1,1065"
2013-09-15 11:19:49,109 [6] DEBUG Umbraco.Web.Routing.PublishedContentRequest - [Thread 14] HandleWildcardDomains: No match.
2013-09-15 11:19:49,812 [6] DEBUG Umbraco.Web.UmbracoModule - [Thread 14] Total milliseconds for umbraco request to process: 875.0056
2013-09-15 11:20:15,109 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 14] Application shutdown. Reason: HostingEnvironment
2013-09-15 11:20:19,328 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-15 11:20:19,375 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-15 11:20:19,375 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 9ms)
2013-09-15 11:20:19,390 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2013-09-15 11:20:19,547 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 163ms)
2013-09-15 11:20:19,562 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2013-09-15 11:20:19,719 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 165ms)
2013-09-15 11:20:19,734 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2013-09-15 11:20:19,750 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 25ms)
2013-09-15 11:20:19,750 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2013-09-15 11:20:19,781 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 23ms)
2013-09-15 11:20:19,781 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2013-09-15 11:20:19,922 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 127ms)
2013-09-15 11:20:19,969 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 634ms)
2013-09-15 11:20:20,422 [6] DEBUG umbraco.content - [Thread 1] Initializing content on thread '' (Threadpool? True)
2013-09-15 11:20:20,484 [6] DEBUG umbraco.content - [Thread 1] Content initialized (loaded)
2013-09-15 11:20:20,640 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplication
2013-09-15 11:20:20,719 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 75ms)
2013-09-15 11:20:20,750 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.ITree
2013-09-15 11:20:21,078 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 335ms)
2013-09-15 11:21:13,563 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 9] Application shutdown. Reason: HostingEnvironment
2013-09-15 11:21:19,047 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-15 11:21:19,078 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-15 11:21:19,094 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 9ms)
2013-09-15 11:21:19,094 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2013-09-15 11:21:19,266 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 163ms)
2013-09-15 11:21:19,266 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2013-09-15 11:21:19,391 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 133ms)
2013-09-15 11:21:19,406 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2013-09-15 11:21:19,422 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 20ms)
2013-09-15 11:21:19,422 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2013-09-15 11:21:19,453 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 19ms)
2013-09-15 11:21:19,453 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2013-09-15 11:21:19,547 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 93ms)
2013-09-15 11:21:19,594 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 540ms)
2013-09-15 11:21:19,891 [6] DEBUG umbraco.content - [Thread 1] Initializing content on thread '' (Threadpool? True)
2013-09-15 11:21:19,953 [6] DEBUG umbraco.content - [Thread 1] Content initialized (loaded)
2013-09-15 11:21:20,063 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplication
2013-09-15 11:21:20,110 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 44ms)
2013-09-15 11:21:20,125 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.ITree
2013-09-15 11:21:20,313 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 198ms)
2013-09-15 11:22:13,922 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 8] Application shutdown. Reason: HostingEnvironment
2013-09-15 11:22:19,204 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application starting
2013-09-15 11:22:19,235 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Determining hash of code files on disk
2013-09-15 11:22:19,251 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Hash determined (took 9ms)
2013-09-15 11:22:19,251 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2013-09-15 11:22:19,438 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 186ms)
2013-09-15 11:22:19,438 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2013-09-15 11:22:19,579 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 139ms)
2013-09-15 11:22:19,594 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2013-09-15 11:22:19,610 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 3 (took 19ms)
2013-09-15 11:22:19,610 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2013-09-15 11:22:19,626 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 1 (took 19ms)
2013-09-15 11:22:19,641 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2013-09-15 11:22:19,735 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 21 (took 95ms)
2013-09-15 11:22:19,766 [6] INFO Umbraco.Core.CoreBootManager - [Thread 1] Umbraco application startup complete (took 566ms)
2013-09-15 11:22:20,047 [6] DEBUG umbraco.content - [Thread 1] Initializing content on thread '' (Threadpool? True)
2013-09-15 11:22:20,079 [6] DEBUG umbraco.content - [Thread 1] Content initialized (loaded)
2013-09-15 11:22:20,204 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.IApplication
2013-09-15 11:22:20,251 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.IApplication, found 7 (took 48ms)
2013-09-15 11:22:20,266 [6] DEBUG Umbraco.Core.PluginManager - [Thread 1] Starting resolution types of umbraco.interfaces.ITree
2013-09-15 11:22:20,485 [6] INFO Umbraco.Core.PluginManager - [Thread 1] Completed resolution of types of umbraco.interfaces.ITree, found 27 (took 222ms)
2013-09-15 11:23:14,157 [6] INFO Umbraco.Web.UmbracoApplication - [Thread 7] Application shutdown. Reason: HostingEnvironment

Copy Link
Stephen 767 posts 2273 karma points c-trib

Sep 15, 2013 @ 15:53

0

The first trace you posted does indeed show the hosting environment restarting all the time. Not sure I understand why. The second trace shows that Umbraco is serving pages, but the actual execution of the page seems to take quite some time, and again the hosting environment seems to restart quite frequently. Unfortunately, I don't see what's going wrong as no exception seem to be reported...

Can you have a look at the umbraco log database table, and at the Windows event log, to figure out if you seen anything unusual?

Stephan

Copy Link
Josh Reid 182 posts 258 karma points

Sep 15, 2013 @ 23:16

0

I have searched to no avail where "URL could not be resolved" is coming from (all files are there where they should be- web addresses shouldnt show up here should they?) - have you seen this before, or know how I could fix?

I'm on shared hosting so have requested windows logs but not sure I'll get anything... Here are some logs from same time as yesterday's post activity:

Josh Reid     0         15/09/2013 11:19:08     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:18:58     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:18:50     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:50     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:48     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:18:47     Debug     URL could not be resolved for: /bands/hip-hop/savage
Josh Reid     0         15/09/2013 11:18:38     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:18:37     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:37     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:35     Debug     URL could not be resolved for: /more/dashboard/band-manager
Josh Reid     0         15/09/2013 11:18:31     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:31     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:28     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:18:18     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:18:15     Debug     URL could not be resolved for: /more/dashboard/band-manager
Josh Reid     0         15/09/2013 11:18:15     Debug     Reloading all entities of type uwbsCategory for store XpozeNZ
Josh Reid     0         15/09/2013 11:18:15     Debug     uWebshop initialized
Josh Reid     -1         15/09/2013 11:18:15     Custom     [UmbracoExamine] Adding examine event handlers for index providers: 3
Josh Reid     0         15/09/2013 11:18:14     Debug     uWebshop initialized
Josh Reid     -1         15/09/2013 11:18:14     System     Loading content from disk cache...
Josh Reid     -1         15/09/2013 11:18:12     System     Log scrubbed. Removed all items older than 2013-07-17 11:18:12
Josh Reid     0         15/09/2013 11:18:08     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:08     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:08     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:08     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:18:08     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:18:07     Debug     URL could not be resolved for: /more/bands
Josh Reid     0         15/09/2013 11:19:50     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:19:50     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:19:48     Debug     URL could not be resolved for: /home
Josh Reid     0         15/09/2013 11:19:48     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:19:38     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:19:28     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:19:28     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:19:28     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:19:21     Debug     URL could not be resolved for: /bands/dance-electronic/antix-fiord
Josh Reid     0         15/09/2013 11:19:21     Debug     Reloading all entities of type uwbsCategory for store XpozeNZ
Josh Reid     -1         15/09/2013 11:19:18     System     Log scrubbed. Removed all items older than 2013-07-17 11:19:19
Josh Reid     0         15/09/2013 11:19:18     Debug     URL could not be resolved for: /umbraco/webservices/legacyajaxcalls.asmx/getsecondsbeforeuserlogout
Josh Reid     0         15/09/2013 11:19:17     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:19:17     Debug     URL could not be resolved for: /umbraco/imagegen.ashx
Josh Reid     0         15/09/2013 11:19:16     Debug     URL could not be resolved for: /umbraco/ping.aspx
Josh Reid     0         15/09/2013 11:19:16     Debug     uWebshop initialized
Josh Reid     -1         15/09/2013 11:19:16     Custom     [UmbracoExamine] Adding examine event handlers for index providers: 3
Josh Reid     0         15/09/2013 11:19:15     Debug     uWebshop initialized
Josh Reid     -1         15/09/2013 11:19:15     System     Loading content from disk cache...
Josh Reid     0         15/09/2013 11:19:09     Debug     URL could not be resolved for: /search

Copy Link
Josh Reid 182 posts 258 karma points

Sep 16, 2013 @ 01:25

0

Some Windows event logs as supplied by the hosting provider:

Event code: 4005
Event message: Forms authentication failed for the request. Reason: The ticket supplied has expired.
Event time: 15/09/2013 11:43:19 a.m.
Event time (UTC): 14/09/2013 11:43:19 p.m.
Event ID: ab669a2f0ce24253b42dff5c96622e57
Event sequence: 4
Event occurrence: 1
Event detail code: 50202

Application information:
    Application domain: /LM/W3SVC/304342352/ROOT-1-130236755368199290
    Trust level: Full
    Application Virtual Path: /
    Application Path: D:\Inetpub\ftproot\LocalUser\xpoze\xpozenz.com\
    Machine name: AK0WD-WWS-001

Process information:
    Process ID: 28328
    Process name: w3wp.exe
    Account name: MW\IWPG_WINBOX

Request information:
    Request URL: http://xpozenz.com/
    Request path: /
    User host address: 125.236.241.32
    User:
    Is authenticated: False
    Authentication Type:
    Thread account name: MW\IWPG_WINBOX

Name to authenticate:

Custom event details:

For more information, see Help and Support Center at
http://go.microsoft.com/fwlink/events.asp

Event code: 3005
Event message: An unhandled exception has occurred.
Event time: 15/09/2013 12:27:26 p.m.
Event time (UTC): 15/09/2013 12:27:26 a.m.
Event ID: 53191e8c88e64e3e8cd937a75032a1c5
Event sequence: 4
Event occurrence: 1
Event detail code: 0

Application information:
    Application domain: /LM/W3SVC/304342352/ROOT-1-130236784391978791
    Trust level: Full
    Application Virtual Path: /
    Application Path: D:\Inetpub\ftproot\LocalUser\xpoze\xpozenz.com\
    Machine name: AK0WD-WWS-001

Process information:
    Process ID: 25608
    Process name: w3wp.exe
    Account name: MW\IWPG_WINBOX

Exception information:
    Exception type: NullReferenceException
    Exception message: Object reference not set to an instance of an object.
   at umbraco.cms.presentation.Trees.JsTreeNodeConverter.Serialize(Object obj, JavaScriptSerializer serializer)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeValue(Object o, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeEnumerable(IEnumerable enumerable, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeValueInternal(Object o, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeValue(Object o, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.Serialize(Object obj, StringBuilder output, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.Serialize(Object obj, SerializationFormat serializationFormat)
   at umbraco.businesslogic.Utils.JSONSerializer.Serialize(Object obj)
   at umbraco.cms.presentation.Trees.XmlTree.ToString(SerializedTreeType type)
   at umbraco.cms.presentation.Trees.XmlTree.ToString()
   at umbraco.presentation.webservices.TreeDataService.ProcessRequest(HttpContext context)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Request information:
    Request URL: http://xpozenz.com/umbraco/webservices/TreeDataService.ashx?rnd=5cba3d1b6ee7406690b6bdea7adfd96c&id=1065&treeType=FilteredContentTree&contextMenu=false&isDialog=true&dialogMode=id&nodeKey=1045&rnd2=8
    Request path: /umbraco/webservices/TreeDataService.ashx
    User host address: 122.62.238.186
    User: [email protected]
    Is authenticated: True
    Authentication Type: Forms
    Thread account name: MW\IWPG_WINBOX

Thread information:
    Thread ID: 1
    Thread account name: MW\IWPG_WINBOX
    Is impersonating: False
    Stack trace:    at umbraco.cms.presentation.Trees.JsTreeNodeConverter.Serialize(Object obj, JavaScriptSerializer serializer)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeValue(Object o, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeEnumerable(IEnumerable enumerable, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeValueInternal(Object o, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.SerializeValue(Object o, StringBuilder sb, Int32 depth, Hashtable objectsInUse, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.Serialize(Object obj, StringBuilder output, SerializationFormat serializationFormat)
   at System.Web.Script.Serialization.JavaScriptSerializer.Serialize(Object obj, SerializationFormat serializationFormat)
   at umbraco.businesslogic.Utils.JSONSerializer.Serialize(Object obj)
   at umbraco.cms.presentation.Trees.XmlTree.ToString(SerializedTreeType type)
   at umbraco.cms.presentation.Trees.XmlTree.ToString()
   at umbraco.presentation.webservices.TreeDataService.ProcessRequest(HttpContext context)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

Custom event details:

For more information, see Help and Support Center at
http://go.microsoft.com/fwlink/events.asp

Event code: 4005
Event message: Forms authentication failed for the request. Reason: The ticket supplied has expired.
Event time: 14/09/2013 10:02:50 p.m.
Event time (UTC): 14/09/2013 10:02:50 a.m.
Event ID: b5435f6ecc3a4ea1b2aeb550a3ce79ee
Event sequence: 5
Event occurrence: 1
Event detail code: 50202

Application information:
    Application domain: /LM/W3SVC/304342352/ROOT-1-130236265631793629
    Trust level: Full
    Application Virtual Path: /
    Application Path: D:\Inetpub\ftproot\LocalUser\xpoze\xpozenz.com\
    Machine name: AK0WD-WWS-001

Process information:
    Process ID: 34868
    Process name: w3wp.exe
    Account name: MW\IWPG_WINBOX

Request information:
    Request URL: http://xpozenz.com/umbraco/webservices/legacyAjaxCalls.asmx/GetSecondsBeforeUserLogout
    Request path: /umbraco/webservices/legacyAjaxCalls.asmx/GetSecondsBeforeUserLogout
    User host address: 125.236.241.32
    User:
    Is authenticated: False
    Authentication Type:
    Thread account name: MW\IWPG_WINBOX

Name to authenticate:

Custom event details:

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Event code: 4005
Event message: Forms authentication failed for the request. Reason: The ticket supplied has expired.
Event time: 14/09/2013 9:55:49 p.m.
Event time (UTC): 14/09/2013 9:55:49 a.m.
Event ID: 2960ca69d11d4d14bf77bc3b5bf1d38f
Event sequence: 3
Event occurrence: 1
Event detail code: 50202

Application information:
    Application domain: /LM/W3SVC/304342352/ROOT-1-130236261398329035
    Trust level: Full
    Application Virtual Path: /
    Application Path: D:\Inetpub\ftproot\LocalUser\xpoze\xpozenz.com\
    Machine name: AK0WD-WWS-001

Process information:
    Process ID: 30892
    Process name: w3wp.exe
    Account name: MW\IWPG_WINBOX

Request information:
    Request URL: http://xpozenz.com/umbraco/webservices/legacyAjaxCalls.asmx/GetSecondsBeforeUserLogout
    Request path: /umbraco/webservices/legacyAjaxCalls.asmx/GetSecondsBeforeUserLogout
    User host address: 125.236.241.32
    User:
    Is authenticated: False
    Authentication Type:
    Thread account name: MW\IWPG_WINBOX

Name to authenticate:

Custom event details:

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Event Type:   Information
Event Source:   W3SVC
Event Category:   None
Event ID:   1117
Date:       15/09/2013
Time:       11:19:11 a.m.
User:       N/A
Computer:   AK0WD-WWS-001
Description:
A worker process with process id of '7916' serving application pool 'xpozenz.com' has requested a recycle because it reached its private bytes memory limit.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Event Type:   Information
Event Source:   W3SVC
Event Category:   None
Event ID:   1117
Date:       15/09/2013
Time:       11:18:11 a.m.
User:       N/A
Computer:   AK0WD-WWS-001
Description:
A worker process with process id of '18144' serving application pool 'xpozenz.com' has requested a recycle because it reached its private bytes memory limit.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Event Type:   Information
Event Source:   W3SVC
Event Category:   None
Event ID:   1117
Date:       14/09/2013
Time:       9:55:38 p.m.
User:       N/A
Computer:   AK0WD-WWS-001
Description:
A worker process with process id of '2364' serving application pool 'xpozenz.com' has requested a recycle because it reached its private bytes memory limit.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Event Type:   Information
Event Source:   W3SVC
Event Category:   None
Event ID:   1117
Date:       14/09/2013
Time:       9:56:39 p.m.
User:       N/A
Computer:   AK0WD-WWS-001
Description:
A worker process with process id of '30892' serving application pool 'xpozenz.com' has requested a recycle because it reached its private bytes memory limit.

For more information, see Help and Support Center at http://go.microsoft.com/fwlink/events.asp.

Copy Link
Stephen 767 posts 2273 karma points c-trib

Sep 16, 2013 @ 08:19

0

The few last Event Log entries are interesting. Seems that the IIS process is being recycled because it's using too much memory (that is, more that what it's allowed to). Do you know if your hosting provider has a strict, low limit set on memory? Also, anything you're doing that might cause memory leaks, high memory usage...?

Stephan

Copy Link
Josh Reid 182 posts 258 karma points

Sep 22, 2013 @ 21:02

100

Thanks for you help Stephan.

My hosting provider hasn't helped a whole lot, but from what little I can tell things aren't way out of the ordinary there- but the site runs perfectly well locally, so I raised a new server and installed there without issue, in fact it is blazingly fast! (thank god!)

Overall very weird- issues appear not to be Umbraco, or my code, but as the logs say, simply: HostingEnvironment

Copy Link
is working on a reply...

Please Sign in or register to post replies