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.
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.
It took weeks of trial and error to eventually fix it.
We determined eventually that it was due to some corrupt XML cache. Once we resolved that, the indexes stopped locking up.
These were generally our steps. We determined the corrupted node was in the blog section, thus the specific steps below that deal with unpublishing and deleting the blog nodes.
To find that, we basically threw away whole branches of the content tree one at a time in a dev environment till we got the site to stop erroring.
1.Stop website
2.Stop app pool
3.Delete all folders in App_Data/TEMP
4.Restart Site then App Pool
5.Rebuild Umbraco indexes (ensure search results come up on homepage)
6.Try to rebuild XMLCache
7.Unpublish blog
8.Run the dialog script /dialogs/republish.aspx?xml=true
Under Umbraco > Developer > Health Check > XML Data Integrity...
Are your Content, Media and Members all green with checkmarks?
The blog is a custom package we developed, however, it was a node of content in the Umbraco tree that was corrupted.
Fortunately, it was old content, and the site didn't need it anymore -- so we deleted those old blog posts. Otherwise, we would have just recreated it with fresh nodes and node ID's.
Search google for Umbraco and "/dialogs/republish.aspx?xml=true" ... I think that was an older method for republishing with an XML refresh. Not sure if it is relevant with newer versions of Umbraco.
We found the corrupted node by deleting large chunks of the site (and running all or many of those steps above) until the XML cache rebuilt correctly and stayed green. Just a very slow process of elimination.
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?
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.
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
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?
@Sebastiaan Janssen -- we are still having these issues after upgrading to 7.9 See my post below.
Me too, we are having this problem despite we are running 7.15.1 (upgraded from 7.6).
The issue happens every day at least 1-2 times on all of most our indexes.
On one day I saw it was happening almost all morning around 20 times!
Sometimes I need to rebuild the indexes but sometimes they look fine in the backoffice and the issue is still persisting.
I suspect it crashes our site every some time which is very bad for our business :(
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.
Have you ever fixed this issue John?
Nick, yes we did. It was painful, though.
It took weeks of trial and error to eventually fix it.
We determined eventually that it was due to some corrupt XML cache. Once we resolved that, the indexes stopped locking up.
These were generally our steps. We determined the corrupted node was in the blog section, thus the specific steps below that deal with unpublishing and deleting the blog nodes.
To find that, we basically threw away whole branches of the content tree one at a time in a dev environment till we got the site to stop erroring.
1.Stop website
2.Stop app pool
3.Delete all folders in App_Data/TEMP
4.Restart Site then App Pool
5.Rebuild Umbraco indexes (ensure search results come up on homepage)
6.Try to rebuild XMLCache
7.Unpublish blog
8.Run the dialog script /dialogs/republish.aspx?xml=true
9.Publish home node (NOT unpublished children)
10.Try to rebuild XMLCache
11.Delete blog
12.Run the dialog script
13.Publish Home node (NOT unpublished children)
14.Go to XMLCache should be good
Thanks John, that's a lot indeed!
How did you find out which file was corrupted file?
Delete the blog? Is it just content or you're talking about a blog plugin? And how did you put it back?
What is /dialogs/republish.aspx?xml=true script ? Why to run it instead of just republishing from the CMS action?
I normally just delete the umbraco.config in app_data to rebuild the cache, I am not sure it is sufficient though.
Hey Nick,
Under Umbraco > Developer > Health Check > XML Data Integrity...
Are your Content, Media and Members all green with checkmarks?
The blog is a custom package we developed, however, it was a node of content in the Umbraco tree that was corrupted.
Fortunately, it was old content, and the site didn't need it anymore -- so we deleted those old blog posts. Otherwise, we would have just recreated it with fresh nodes and node ID's.
Search google for Umbraco and "/dialogs/republish.aspx?xml=true" ... I think that was an older method for republishing with an XML refresh. Not sure if it is relevant with newer versions of Umbraco.
We found the corrupted node by deleting large chunks of the site (and running all or many of those steps above) until the XML cache rebuilt correctly and stayed green. Just a very slow process of elimination.
Thanks John.
It is very useful indeed. I'll check if those work for our case.
is working on a reply...