Copied to clipboard

Flag this post as spam?

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


  • Bo Jacobsen 174 posts 923 karma points
    Jan 17, 2018 @ 13:37
    Bo Jacobsen
    0

    Write lock error on all examine indexes

    Hi all.

    One day we suddenly got write lock error on one of our sites. That shutdown the website for atleast 3 hours. Then i rebuild all the examine indexes and fixed the Xml Cache Data integrity. But we still get write lock errors from time to time.

    Do anyone have a clue what can cause it and how we may prevent it in the fureture?

     2018-01-15 01:36:28,929 [P156252/D4115/T43] INFO  Umbraco.Core.CoreBootManager - Umbraco 7.3.3 application starting on WEB31
     2018-01-15 01:36:28,991 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Determining hash of code files on disk
     2018-01-15 01:36:29,007 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Hash determined (took 10ms)
     2018-01-15 01:36:29,163 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
     2018-01-15 01:36:29,194 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 25ms)
     2018-01-15 01:36:29,226 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
     2018-01-15 01:36:29,226 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 1ms)
     2018-01-15 01:36:29,226 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
     2018-01-15 01:36:29,226 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 3ms)
     2018-01-15 01:36:29,241 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
     2018-01-15 01:36:29,241 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 2ms)
     2018-01-15 01:36:29,241 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
     2018-01-15 01:36:29,273 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 34ms)
     2018-01-15 01:36:29,335 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
     2018-01-15 01:36:29,335 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 0ms)
     2018-01-15 01:36:29,335 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
     2018-01-15 01:36:29,335 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 0ms)
     2018-01-15 01:36:29,804 [P156252/D4115/T43] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
     2018-01-15 01:36:30,289 [P156252/D4115/T60] INFO  umbraco.BusinessLogic.Log - Redirected log call (please use Umbraco.Core.Logging.LogHelper instead of umbraco.BusinessLogic.Log) | Type: Error | User: 0 | NodeId: 0 | Comment: The file 'D:\WEB\homepage.dk\www\macroscripts\NewsletterSubscribe.cshtml' already exists.   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
       at System.IO.File.InternalCopy(String sourceFileName, String destFileName, Boolean overwrite, Boolean checkHost)
       at System.IO.FileInfo.CopyTo(String destFileName, Boolean overwrite)
       at NewsletterStudio.Bootstrapping.FolderSynchronizer.DirectoryCopy(String sourceDirName, String destDirName, Boolean copySubDirs, Boolean overwriteFiles)
       at NewsletterStudio.Bootstrapping.FolderSynchronizer.Synchronize(String sourceFolder, String destinationFolder, Boolean copySubDirs, Boolean overwrite)
     2018-01-15 01:36:31,086 [P156252/D4115/T43] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
     2018-01-15 01:36:31,086 [P156252/D4115/T43] INFO  Umbraco.Forms.Core.Cache.CacheEventHandler - Initializing Umbraco Forms Events to trigger Cache Refreshers
     2018-01-15 01:36:31,149 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
     2018-01-15 01:36:31,149 [P156252/D4115/T43] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 1ms)
     2018-01-15 01:36:31,258 [P156252/D4115/T43] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
     2018-01-15 01:36:31,274 [P156252/D4115/T43] 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
     2018-01-15 01:36:31,290 [P156252/D4115/T43] INFO  umbraco.content - Load Xml from file...
     2018-01-15 01:36:31,368 [P156252/D4115/T43] INFO  umbraco.content - Loaded Xml from file.
     2018-01-15 01:36:31,384 [P156252/D4115/T43] INFO  umbraco.content - Loading content from database...
     2018-01-15 01:36:33,182 [P156252/D4115/T43] ERROR Umbraco.Core.CoreBootManager - An error occurred running OnApplicationStarted for handler Umbraco.Web.BatchedDatabaseServerMessengerStartup
    Lucene.Net.Store.LockObtainFailedException: Lock obtain timed out: NativeFSLock@D:\WEB\homepage.dk\www\App_Data\TEMP\ExamineIndexes\WEB31\InternalMember\Index\write.lock: System.IO.IOException: The process cannot access the file 'D:\WEB\homepage.dk\www\App_Data\TEMP\ExamineIndexes\WEB31\InternalMember\Index\write.lock' because it is being used by another process.
       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)
       at Lucene.Net.Store.NativeFSLock.Obtain() ---> System.IO.IOException: The process cannot access the file 'D:\WEB\homepage.dk\www\App_Data\TEMP\ExamineIndexes\WEB31\InternalMember\Index\write.lock' because it is being used by another process.
       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)
       at Lucene.Net.Store.NativeFSLock.Obtain()
       --- End of inner exception stack trace ---
       at Lucene.Net.Store.Lock.Obtain(Int64 lockWaitTimeout)
       at Lucene.Net.Index.IndexWriter.Init(Directory d, Analyzer a, Boolean create, Boolean closeDir, IndexDeletionPolicy deletionPolicy, Boolean autoCommit, Int32 maxFieldLength, IndexingChain indexingChain, IndexCommit commit)
       at Lucene.Net.Index.IndexWriter..ctor(Directory d, Analyzer a, Boolean create, MaxFieldLength mfl)
       at Examine.LuceneEngine.Providers.LuceneIndexer.CreateIndexWriter()
       at UmbracoExamine.BaseUmbracoIndexer.CreateIndexWriter()
       at Examine.LuceneEngine.Providers.LuceneIndexer.EnsureIndex(Boolean forceOverwrite)
       at Examine.LuceneEngine.Providers.LuceneIndexer.RebuildIndex()
       at UmbracoExamine.UmbracoContentIndexer.RebuildIndex()
       at Examine.ExamineManager._RebuildIndex()
       at Umbraco.Web.WebBootManager.<InitializeResolvers>b__c()
       at Umbraco.Core.Sync.DatabaseServerMessenger.Initialize()
       at Umbraco.Core.Sync.DatabaseServerMessenger.Boot()
       at Umbraco.Web.BatchedDatabaseServerMessenger.Startup()
       at Umbraco.Web.BatchedDatabaseServerMessengerStartup.ApplicationStarted(UmbracoApplicationBase umbracoApplication, ApplicationContext applicationContext)
       at Umbraco.Core.ApplicationEventHandler.OnApplicationStarted(UmbracoApplicationBase umbracoApplication, ApplicationContext applicationContext)
       at Umbraco.Core.CoreBootManager.<Complete>b__8(IApplicationEventHandler x)
     2018-01-15 01:36:33,369 [P156252/D4115/T43] ERROR Umbraco.Core.UmbracoApplicationBase - An unhandled exception occurred
    Lucene.Net.Store.LockObtainFailedException: Lock obtain timed out: NativeFSLock@D:\WEB\homepage.dk\www\App_Data\TEMP\ExamineIndexes\WEB31\InternalMember\Index\write.lock: System.IO.IOException: The process cannot access the file 'D:\WEB\homepage.dk\www\App_Data\TEMP\ExamineIndexes\WEB31\InternalMember\Index\write.lock' because it is being used by another process.
       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)
       at Lucene.Net.Store.NativeFSLock.Obtain() ---> System.IO.IOException: The process cannot access the file 'D:\WEB\homepage.dk\www\App_Data\TEMP\ExamineIndexes\WEB31\InternalMember\Index\write.lock' because it is being used by another process.
       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)
       at Lucene.Net.Store.NativeFSLock.Obtain()
       --- End of inner exception stack trace ---
       at Lucene.Net.Store.Lock.Obtain(Int64 lockWaitTimeout)
       at Lucene.Net.Index.IndexWriter.Init(Directory d, Analyzer a, Boolean create, Boolean closeDir, IndexDeletionPolicy deletionPolicy, Boolean autoCommit, Int32 maxFieldLength, IndexingChain indexingChain, IndexCommit commit)
       at Lucene.Net.Index.IndexWriter..ctor(Directory d, Analyzer a, Boolean create, MaxFieldLength mfl)
       at Examine.LuceneEngine.Providers.LuceneIndexer.CreateIndexWriter()
       at UmbracoExamine.BaseUmbracoIndexer.CreateIndexWriter()
       at Examine.LuceneEngine.Providers.LuceneIndexer.EnsureIndex(Boolean forceOverwrite)
       at Examine.LuceneEngine.Providers.LuceneIndexer.RebuildIndex()
       at UmbracoExamine.UmbracoContentIndexer.RebuildIndex()
       at Examine.ExamineManager._RebuildIndex()
       at Umbraco.Web.WebBootManager.<InitializeResolvers>b__c()
       at Umbraco.Core.Sync.DatabaseServerMessenger.Initialize()
       at Umbraco.Core.Sync.DatabaseServerMessenger.Boot()
       at Umbraco.Web.BatchedDatabaseServerMessenger.Startup()
       at Umbraco.Web.BatchedDatabaseServerMessengerStartup.ApplicationStarted(UmbracoApplicationBase umbracoApplication, ApplicationContext applicationContext)
       at Umbraco.Core.ApplicationEventHandler.OnApplicationStarted(UmbracoApplicationBase umbracoApplication, ApplicationContext applicationContext)
       at Umbraco.Core.CoreBootManager.<Complete>b__8(IApplicationEventHandler x)
       at Umbraco.Core.EnumerableExtensions.ForEach[TItem](IEnumerable`1 items, Action`1 action)
       at Umbraco.Core.CoreBootManager.Complete(Action`1 afterComplete)
       at Umbraco.Web.WebBootManager.Complete(Action`1 afterComplete)
       at Umbraco.Core.UmbracoApplicationBase.StartApplication(Object sender, EventArgs e)
       at Umbraco.Core.UmbracoApplicationBase.Application_Start(Object sender, EventArgs e)
     2018-01-15 01:36:36,028 [P156252/D4115/T42] INFO  umbraco.content - Save Xml to file...
     2018-01-15 01:36:36,528 [P156252/D4115/T53] INFO  umbraco.content - Saved Xml to file.
     2018-01-15 01:36:43,393 [P156252/D4115/T57] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalMemberIndexer, NodeId=-1
    System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: InternalMemberIndexSet
     2018-01-15 01:36:43,393 [P156252/D4115/T57] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalIndexer, NodeId=-1
    System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: InternalIndexSet
     2018-01-15 01:36:43,393 [P156252/D4115/T57] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=ExternalIndexer, NodeId=-1
    System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: ExternalIndexSet
     2018-01-15 01:36:43,393 [P156252/D4115/T57] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=PageSearchIndexer, NodeId=-1
    System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: PageSearchIndexSet
    

    Notice:

    At 2018-01-15 01:36:30,289 - Newsletter is using BusinessLogic.Log instead of Logging.LogHelper. But i dont think thats the issue...

    At 2018-01-15 01:36:31,274 - No last synced Id found, this generally means this is a new server/install. Maybe theres something wrong here? Because it is not a new server or Install.

    At 2018-01-15 01:36:33,182 - First write lock error.

    At 2018-01-15 01:36:43,393 - PageSearchIndexer is a custom index, created in /Config/ExamineSettings.config and ExamineIndex.config for search results.

  • Sebastiaan Janssen 4668 posts 13055 karma points MVP admin hq
    Jan 18, 2018 @ 14:40
    Sebastiaan Janssen
    0

    We've been working on Examine and locking for a while now, more specifically the symptoms here should be fixed now in 7.7.8 - make sure to upgrade.

    For more info: http://issues.umbraco.org/issue/U4-10735

  • Bo Jacobsen 174 posts 923 karma points
    Jan 19, 2018 @ 17:31
    Bo Jacobsen
    0

    Thanks for your answer Sebastiaan.

    From 7.3.3 to 7.7.8 - Nothing can go wrong :-)

    Do you think is could be caused by app shutdowns?

  • John Moss 12 posts 92 karma points
    Jul 11, 2018 @ 21:04
    John Moss
    0

    @Sebastiaan Janssen -- we are still having these issues after upgrading to 7.9 See my post below.

  • John Moss 12 posts 92 karma points
    Jul 11, 2018 @ 20:58
    John Moss
    0

    We were having these same index lock errors on 7.5.8. We upgraded to 7.9, and the errors are persisting.

    2018-07-05 00:00:37,751 [P800/D4/T39] ERROR GeoSuite.GeoSearch.Examine.GeoLocationExamineSearch - Error in GetNearestLocationsByLatLongAndRadius Lucene.Net.Store.AlreadyClosedException: this IndexReader is closed at Lucene.Net.Index.IndexReader.EnsureOpen() at Lucene.Net.Index.DirectoryReader.GetFieldNames(FieldOption fieldNames) at Examine.LuceneEngine.Providers.LuceneSearcher.GetSearchFields() in C:\projects\examine-qvx04\src\Examine\LuceneEngine\Providers\LuceneSearcher.cs:line 248 at UmbracoExamine.UmbracoExamineSearcher.GetSearchFields() at Examine.LuceneEngine.Providers.BaseLuceneSearcher.CreateSearchCriteria(String type, BooleanOperation defaultOperation) in C:\projects\examine-qvx04\src\Examine\LuceneEngine\Providers\BaseLuceneSearcher.cs:line 117 at UmbracoExamine.UmbracoExamineSearcher.CreateSearchCriteria(String type, BooleanOperation defaultOperation) at GeoSuite.GeoSearch.Examine.GeoLocationExamineSearch.GetNearestLocationsByLatLongAndRadius(String originLatitude, String originLongitude, Double searchRadius, String locationDocTypes, Boolean firsttime)

    We recycle the app pool and rebuild all the indexes, and then the error is fine again for a while. Occasionally, system reboots and regularly scheduled IIS recycles cause the indexes to lock up again.

Please Sign in or register to post replies

Write your reply to:

Draft