azure webapp web worker

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

Darren Clark 53 posts 250 karma points

Oct 10, 2017 @ 10:50

Hi ,

I am having issues hosting umbraco in azure when the web worker moves. The site does not respond during this time, i have seen the site take 8 minutes to return, it is a big site with a lot of content.

Umbraco version 7.5.3

I have the following line in my web.config:

<add key="umbracoContentXMLUseLocalTemp" value="true" />

My examine index file has the following:

<ExamineLuceneIndexSets>
  <!-- The internal index set used by Umbraco back-office - DO NOT REMOVE -->
  <IndexSet SetName="InternalIndexSet" IndexPath="~/App_Data/TEMP/ExamineIndexes/Internal/"/>

  <!-- The internal index set used by Umbraco back-office for indexing members - DO NOT REMOVE -->
  <IndexSet SetName="InternalMemberIndexSet" IndexPath="~/App_Data/TEMP/ExamineIndexes/InternalMember/">
    <IndexAttributeFields>
      <add Name="id" />
      <add Name="nodeName"/>
      <add Name="updateDate" />
      <add Name="writerName" />
      <add Name="loginName" />
      <add Name="email" />
      <add Name="nodeTypeAlias" />
    </IndexAttributeFields>
  </IndexSet>

  <!-- Default Indexset for external searches, this indexes all fields on all types of nodes-->
  <IndexSet SetName="ExternalIndexSet" IndexPath="~/App_Data/TEMP/ExamineIndexes/External/" />
</ExamineLuceneIndexSets>

My examine settings file has the following:

<Examine>
  <ExamineIndexProviders>
    <providers>
      <add name="InternalIndexer" type="UmbracoExamine.UmbracoContentIndexer, UmbracoExamine"
           supportUnpublished="true"
           supportProtected="true"
            useTempStorage="Sync"
           tempStorageDirectory="UmbracoExamine.LocalStorage.AzureLocalStorageDirectory, UmbracoExamine"
           analyzer="Lucene.Net.Analysis.WhitespaceAnalyzer, Lucene.Net"/>

      <add name="InternalMemberIndexer" type="UmbracoExamine.UmbracoMemberIndexer, UmbracoExamine"
           supportUnpublished="true"
           supportProtected="true"
          useTempStorage="Sync"
           tempStorageDirectory="UmbracoExamine.LocalStorage.AzureLocalStorageDirectory, UmbracoExamine"
           analyzer="Lucene.Net.Analysis.Standard.StandardAnalyzer, Lucene.Net"/>

        <!-- default external indexer, which excludes protected and unpublished pages-->
        <add name="ExternalIndexer" type="UmbracoExamine.UmbracoContentIndexer, UmbracoExamine"
         useTempStorage="Sync"
        tempStorageDirectory="UmbracoExamine.LocalStorage.AzureLocalStorageDirectory, UmbracoExamine"/>

    </providers>
  </ExamineIndexProviders>

  <ExamineSearchProviders defaultProvider="ExternalSearcher">
    <providers>
      <add name="InternalSearcher" type="UmbracoExamine.UmbracoExamineSearcher, UmbracoExamine"
      useTempStorage="Sync" tempStorageDirectory="UmbracoExamine.LocalStorage.AzureLocalStorageDirectory, UmbracoExamine" analyzer="Lucene.Net.Analysis.WhitespaceAnalyzer, Lucene.Net"/>

      <add name="ExternalSearcher" 
       useTempStorage="Sync" tempStorageDirectory="UmbracoExamine.LocalStorage.AzureLocalStorageDirectory, UmbracoExamine"
       type="UmbracoExamine.UmbracoExamineSearcher, UmbracoExamine" />

      <add name="InternalMemberSearcher" type="UmbracoExamine.UmbracoExamineSearcher, UmbracoExamine"
           useTempStorage="Sync"
           tempStorageDirectory="UmbracoExamine.LocalStorage.AzureLocalStorageDirectory, UmbracoExamine"
            analyzer="Lucene.Net.Analysis.Standard.StandardAnalyzer, Lucene.Net" enableLeadingWildcard="true"/>

    </providers>
  </ExamineSearchProviders>

</Examine>

I have followed the steps in documentation, but the site still goes down at least twice per month when the site moves.

Below is the log file from the site before it moved:

2017-10-05 23:32:07,677 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating
 2017-10-05 23:32:07,677 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Waiting for tasks to complete
 2017-10-05 23:32:07,677 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Terminating
 2017-10-05 23:32:07,677 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Waiting for tasks to complete
 2017-10-05 23:32:07,677 [P16220/D2/T47] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Tasks completed, terminated
 2017-10-05 23:32:07,944 [P16220/D2/T17] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Tasks completed, terminated
 2017-10-05 23:32:07,944 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Terminating
 2017-10-05 23:32:07,944 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Waiting for tasks to complete
 2017-10-05 23:32:07,976 [P16220/D2/T40] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalMemberIndexer, NodeId=-1
System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: InternalMemberIndexSet
 2017-10-05 23:32:07,976 [P16220/D2/T40] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalIndexer, NodeId=-1
System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: InternalIndexSet
 2017-10-05 23:32:08,007 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating
 2017-10-05 23:32:08,007 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Waiting for tasks to complete
 2017-10-05 23:32:08,007 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Terminating
 2017-10-05 23:32:08,007 [P16220/D2/T40] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Waiting for tasks to complete
 2017-10-05 23:32:08,007 [P16220/D2/T25] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Tasks completed, terminated
 2017-10-05 23:32:08,194 [P16220/D2/T55] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Tasks completed, terminated

And below is the log of the new worker:

2017-10-05 23:30:16,459 [P3064/D2/T1] INFO  Umbraco.Core.CoreBootManager - Umbraco 7.5.3 application starting on RD00155D3ACD5B
 2017-10-05 23:30:16,584 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Determining hash of code files on disk
 2017-10-05 23:30:16,743 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Hash determined (took 164ms)
 2017-10-05 23:30:16,962 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
 2017-10-05 23:30:18,259 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 1297ms)
 2017-10-05 23:30:18,306 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
 2017-10-05 23:30:18,321 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 24ms)
 2017-10-05 23:30:18,321 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
 2017-10-05 23:30:18,353 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 26ms)
 2017-10-05 23:30:18,384 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
 2017-10-05 23:30:18,431 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 41ms)
 2017-10-05 23:30:18,431 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
 2017-10-05 23:30:18,478 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 55ms)
 2017-10-05 23:30:18,998 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
 2017-10-05 23:30:19,013 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 21ms)
 2017-10-05 23:30:19,013 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
 2017-10-05 23:30:19,044 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 31ms)
 2017-10-05 23:30:22,202 [P3064/D2/T1] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
 2017-10-05 23:30:23,390 [P3064/D2/T1] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
 2017-10-05 23:30:23,390 [P3064/D2/T1] INFO  Umbraco.Forms.Core.Cache.CacheEventHandler - Initializing Umbraco Forms Events to trigger Cache Refreshers
 2017-10-05 23:30:23,483 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
 2017-10-05 23:30:23,530 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 36ms)
 2017-10-05 23:30:24,468 [P3064/D2/T1] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
 2017-10-05 23:30:24,499 [P3064/D2/T1] WARN  Umbraco.Core.Sync.DatabaseServerMessenger - No last synced Id found, this generally means this is a new server/install. The server will build its caches and indexes, and then adjust its last synced Id to the latest found in the database and maintain cache updates based on that Id.
 2017-10-05 23:30:24,561 [P3064/D2/T1] INFO  umbraco.content - Load Xml from file...
 2017-10-05 23:30:24,561 [P3064/D2/T1] ERROR umbraco.content - Failed to load Xml from file.
System.IO.DirectoryNotFoundException: Could not find a part of the path 'D:\local\Temporary ASP.NET Files\root\b73b12ce\240ef904\UmbracoData\umbraco.config'.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share)
   at umbraco.content.LoadXmlFromFile() in C:\Users\darrenc\AppData\Local\Temp\JustDecompile\Sources\umbraco.pdb\1753C2C8A6A54BBDBD413D7EB3514DEF1\umbraco\content.cs:line 600
 2017-10-05 23:30:25,028 [P3064/D2/T1] INFO  umbraco.content - Loading content from database...
 2017-10-05 23:31:13,638 [P3064/D2/T1] INFO  umbraco.content - Loading content from database...
 2017-10-05 23:31:20,493 [P3064/D2/T12] INFO  umbraco.content - Save Xml to file...
 2017-10-05 23:31:23,069 [P3064/D2/T12] INFO  umbraco.content - Saved Xml to file.
 2017-10-05 23:31:24,944 [P3064/D2/T1] INFO  UmbracoExamine.LocalStorage.LocalTempStorageIndexer - Successfully sync'd main index to local temp storage for index: ~/App_Data/TEMP/ExamineIndexes/Internal/
 2017-10-05 23:31:25,348 [P3064/D2/T1] INFO  UmbracoExamine.LocalStorage.LocalTempStorageIndexer - Successfully sync'd main index to local temp storage for index: ~/App_Data/TEMP/ExamineIndexes/InternalMember/
 2017-10-05 23:31:32,975 [P3064/D2/T1] INFO  UmbracoExamine.LocalStorage.LocalTempStorageIndexer - Successfully sync'd main index to local temp storage for index: ~/App_Data/TEMP/ExamineIndexes/External/
 2017-10-05 23:33:45,067 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
 2017-10-05 23:33:45,145 [P3064/D2/T1] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 78ms)
 2017-10-05 23:39:31,916 [P3064/D2/T1] INFO  Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
 2017-10-05 23:39:31,992 [P3064/D2/T1] INFO  Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
 2017-10-05 23:39:31,992 [P3064/D2/T1] INFO  Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 3
 2017-10-05 23:39:32,070 [P3064/D2/T1] INFO  Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 555908ms)

Can anyone assist or point me in the right direction!

Copy Link

Kelvin Schutz 1 post 71 karma points

Dec 19, 2017 @ 01:17
0
Darren,

I have noticed this exact same issue running a version just above yours (7.5.4) -- pretty much the same examine configuration as well (no machine name in IndexPath, useTempStorage="Sync", AzureLocalStorageDirectory usage, ...). I have umbracoContentXMLUseLocalTemp set to 'false' though to do away with any disk writing. As far as I have been able to research, you are using the recommended configuration for an Azure Web App, but some people still seem to have issues with it on a version this old and a large amount of content (there's about 240MB of indices between my Internal and External indices). 8 minutes is a long time for the site to be down and know mine gets to around 30 minutes -- I’ve even tested this on a test site with the same content and no requests.

What I find interesting is that the log files show that the previous site instance is still operating ~2 minutes AFTER the new instance starts, as it attempts to do some background cleanup tasks from the looks of it. I’m wondering if this coincides with the runtime having a default connection timeout of 2 minutes for requests (and if so, what is causing requests to take 2 minutes at this point and why does it still happen on a site with no traffic?). Also, if I see an error with an index in the log for one app instance I’ll see success in the other, leading me to believe that there is simply a file lock issue between the instances. Although, I feel this is an exceptional case and symptomatic of things not ending as they should during the web worker migration process on the old instance; things go quite smoothly for simple app restarts and redeployments.

Some other notable patterns:
- The app restarts seem to almost always occur at night usually between 9pm and 3pm
- Restarts seem to be happening roughly every two weeks.
- In one case that I have some data on, F5 recognized the sight was inaccessible for several large blocks of time during a 13 minute period up to the app restart; there were no log messages during this period.
- There is always a log message which seems merely symptomatic and not causal:
```
WARN  Umbraco.Core.Sync.DatabaseServerMessenger - No last synced Id found, this generally means this is a new server/install. The server will build its caches and indexes, and then adjust its last synced Id to the latest found in the database and maintain cache updates based on that Id.
```
One final thing to note, I don’t see any errors regarding indices in my test environment when this web worker migration happened (the one time it has so far)… yet, it still proceeded to rebuild each index. I haven’t noticed this in the production environment, where there are always file lock errors which I’m attributing to active usage of the site -- but that just seems to make the restart issues unrelated to file locking. I feel there’s something going on with having these two overlapping instances exist during startup that makes it unique from a typical restart. I’ve seen this casually mentioned in the comments of this link, but haven’t found anything that elaborates on it: https://github.com/Shazwazza/Examine/commit/695e9cc34b1670acc8b2f7a0f59400993d4b23a0#diff-6fe0d8def2b1b357226842ded9ae8244L457

I don’t know if I’m anywhere on the right track here, but feel like I’ve travelled down a lot of dead-ends at this point and needed to dump my brain somewhere.
Copy Link
Darren Clark 53 posts 250 karma points

Dec 19, 2017 @ 15:13

0

Hi Kelvin,

Thanks for the detailed response. I have also seen that link and comments but there is never a real solution to the issues. I am still seeing the issues in 7.5.8. For now i am going to upgrade to the latest version 7.7 and use the SyncTempEnvDirectoryFactory option instead to see if these issues go away.

This must be an issue in Umbraco Cloud surely.

Would be good to get some help.

Thanks Darren

Copy Link
is working on a reply...

Please Sign in or register to post replies