Sign in Register
Go to solution
Copied to clipboard

Flag this post as spam?

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


  • Tommy Enger 72 posts 277 karma points c-trib
    Jan 08, 2016 @ 12:28
    Tommy Enger
    0

    Slow startup

    Using Umbraco 7
    Umbraco 7

    I'm currently on 7.3.2 and every application restarts takes about 3 minutes.

    From the log:

    2016-01-08 13:13:54,376 [37] INFO  Umbraco.Core.CoreBootManager - Umbraco 7.3.2 application starting on DEV-EPI02
2016-01-08 13:13:54,481 [37] INFO  Umbraco.Core.PluginManager - Determining hash of code files on disk
2016-01-08 13:13:54,506 [37] INFO  Umbraco.Core.PluginManager - Hash determined (took 21ms)
2016-01-08 13:13:54,947 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2016-01-08 13:13:55,573 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 626ms)
2016-01-08 13:13:55,639 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2016-01-08 13:13:55,663 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 24ms)
2016-01-08 13:13:55,664 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
2016-01-08 13:13:55,694 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 29ms)
2016-01-08 13:13:55,732 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2016-01-08 13:13:55,754 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 21ms)
2016-01-08 13:13:55,756 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
2016-01-08 13:13:55,854 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 98ms)
2016-01-08 13:13:56,693 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2016-01-08 13:13:56,745 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 52ms)
2016-01-08 13:13:56,750 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2016-01-08 13:13:56,781 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 30ms)
2016-01-08 13:13:58,914 [37] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
2016-01-08 13:13:59,591 [37] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
2016-01-08 13:13:59,720 [37] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
2016-01-08 13:13:59,751 [37] WARN  Umbraco.Core.Sync.DatabaseServerMessenger - No last synced Id found, this generally means this is a new server/install. The server will rebuild its caches and indexes and then adjust it's last synced id to the latest found in the database and will start maintaining cache updates based on that id
2016-01-08 13:13:59,802 [37] INFO  umbraco.content - Load Xml from file...
2016-01-08 13:14:00,248 [37] INFO  umbraco.content - Loaded Xml from file.
2016-01-08 13:14:00,461 [37] INFO  umbraco.content - Loading content from database...
2016-01-08 13:14:07,644 [37] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2016-01-08 13:14:07,766 [37] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 122ms)
2016-01-08 13:14:09,908 [37] INFO  umbraco.content - Save Xml to file...
2016-01-08 13:14:11,417 [37] INFO  umbraco.content - Saved Xml to file.
2016-01-08 13:16:48,206 [37] INFO  Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
2016-01-08 13:16:48,241 [37] INFO  Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
2016-01-08 13:16:48,242 [37] INFO  Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 4
2016-01-08 13:16:48,284 [37] INFO  Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 174220ms)

    As you see from the timestamps, the majority of the time is spent between:

    2016-01-08 13:14:11,417 [37] INFO  umbraco.content - Saved Xml to file.
2016-01-08 13:16:48,206 [37] INFO  Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing

    Anybody knows what Umbraco performs between these two events? Can anybody check their log-file to see if the majority of start-up time is spent at the same place?

    Copy Link
  • Tommy Enger 72 posts 277 karma points c-trib
    Jan 08, 2016 @ 12:32
    Tommy Enger
    0

    Ok, I just realized this line from the log as I posted.

    2016-01-08 13:13:59,751 [37] WARN  Umbraco.Core.Sync.DatabaseServerMessenger - No last synced Id found, this generally means this is a new server/install. The server will rebuild its caches and indexes and then adjust it's last synced id to the latest found in the database and will start maintaining cache updates based on that id

    So I guess this is my problem.... Anybody had this problem? This is certainly not a new server/install...

    Copy Link
  • Tommy Enger 72 posts 277 karma points c-trib
    Jan 08, 2016 @ 13:31
    Tommy Enger
    0

    Think I figured it out now. First I saw that Umbraco tried to read the last synced ID in:

    IOHelper.MapPath("~/App_Data/TEMP/DistCache/" + NetworkHelper.FileSafeMachineName)

    That file existed and had a valid int value, so that was not the problem.

    Then It gets the cache instructions, and overrides lastid to -1 if empty

    var dtos = _appContext.DatabaseContext.Database.Fetch<CacheInstructionDto>(sql);
if (dtos.Count == 0)
     _lastId = -1;

    I checked the DB table, and it was indeed empty. I logged into Umbraco, published a page, restarted the site and start-up time back to normal.

    i have no idea why this table ended up empty. Is there a ttl on the items in umbracoCacheInstruction?

    Copy Link
  • Tommy Enger 72 posts 277 karma points c-trib
    Jan 12, 2016 @ 14:19
    Tommy Enger
    100

    In case anybody stumbles upon this post. This will be fixed in version 7.3.5

    http://issues.umbraco.org/issue/U4-7643

    Copy Link
Please Sign in or register to post replies

Write your reply to:

Draft