Developer forum

Forget the email bug. I noticed we allready got anwser on that in https://doc.dynamicweb.com/forum?ThreadID=57944&PID=1605

Hello again,

In our custom index builder we are getting an Lock obtain timeout on our first method call `writer.Open(false)`. It leaves the following stacktrace:
Lucene.Net.Store.LockObtainFailedException: Lock obtain timed out: NativeFSLock@D:\home\site\wwwroot\Files\System\Indexes\Content repository\News index\News B\write.lock
   at Lucene.Net.Store.Lock.Obtain(Int64 lockWaitTimeout) in d:\Lucene.Net\FullRepo\trunk\src\core\Store\Lock.cs:line 97
   at Lucene.Net.Index.IndexWriter.Init(Directory d, Analyzer a, Boolean create, IndexDeletionPolicy deletionPolicy, Int32 maxFieldLength, IndexingChain indexingChain, IndexCommit commit) in d:\Lucene.Net\FullRepo\trunk\src\core\Index\IndexWriter.cs:line 1228
   at Lucene.Net.Index.IndexWriter..ctor(Directory d, Analyzer a, Boolean create, MaxFieldLength mfl) in d:\Lucene.Net\FullRepo\trunk\src\core\Index\IndexWriter.cs:line 1019
   at Dynamicweb.Indexing.Lucene.LuceneIndexWriter.Open(Boolean openForAppend)
   at Warmgarant.Shop.Application.CustomCode.Search.NewsIndexBuilder.Build(IIndexWriter writer, Tracker tracker)

I think we also got this issue in our 9.4.4 release. As i can see it happens every automated attempt.

After upgrading a second site to 9.4.12 the same errors occured on product index builds.

Ive tried upgrading to 9.4.13 and the frontpage to 9.4.34, errors didnt disapear.

I've attached some new errors.

Hi Antek

Please provide a link to the solution so we can have a look.

BR Nicolai

Hi Nicolai! 

I've send the links to your email address.

Best regards,

Antek Drzewiecki

Upgrading to 9.4.16 gives me mostly these errors during the chron tasks. This one came from the content builder.

Nicolai,

Is there anything to say in this matter, it still occurs on our production website warmgarant on 9.4.18.

The exception message is 'Object reference not set to an instance of an object.'

Can this be caused by configuration, or is this a code issue?

When I manually run the index build in the CMS it always succeeds by the way.

Ive added a notification to this build which results in many failures, but not every time
It runs every 5 minutes and once an hour by avarage we receive an error mail.
The log attached to the mail is like below.

It mentiones a lock on instance A.
We had instance A and B.
We threw away instance A and created an instance C.
Still the error occurres with instance A in the file path ... I have no idea why tis is ...

2018-11-01 07:15:49.774: Running.
2018-11-01 07:15:50.290: Fetching build definition.
2018-11-01 07:15:50.352: Fetched build definition. 'Dynamicweb.Ecommerce.Indexing.ProductIndexBuilder'.
2018-11-01 07:15:50.387: Creating index writer.
2018-11-01 07:15:50.416: Created index writer: 'Dynamicweb.Indexing.Lucene.LuceneIndexWriter'.
2018-11-01 07:15:50.524: Starting build process.
2018-11-01 07:15:50.603: Dynamicweb.Ecommerce.Indexing.ProductIndexBuilder building using Dynamicweb.Indexing.Lucene.LuceneIndexWriter... Action: 'Full', Resume: 'False'
2018-11-01 07:15:50.711: Opening index writer.
2018-11-01 07:15:51.915: Product index builder experienced a fatal error.. Lucene.Net.Store.LockObtainFailedException: Lock obtain timed out: NativeFSLock@D:\home\site\wwwroot\Files\System\Indexes\Ketel repository\Ketel index\KetelInstanceA\write.lock    at Lucene.Net.Store.Lock.Obtain(Int64 lockWaitTimeout) in d:\Lucene.Net\FullRepo\trunk\src\core\Store\Lock.cs:line 97    at Lucene.Net.Index.IndexWriter.Init(Directory d, Analyzer a, Boolean create, IndexDeletionPolicy deletionPolicy, Int32 maxFieldLength, IndexingChain indexingChain, IndexCommit commit) in d:\Lucene.Net\FullRepo\trunk\src\core\Index\IndexWriter.cs:line 1228    at Lucene.Net.Index.IndexWriter..ctor(Directory d, Analyzer a, Boolean create, MaxFieldLength mfl) in d:\Lucene.Net\FullRepo\trunk\src\core\Index\IndexWriter.cs:line 1019    at Dynamicweb.Indexing.Lucene.LuceneIndexWriter.Open(Boolean openForAppend)    at Dynamicweb.Ecommerce.Indexing.ProductIndexBuilder.Build(IIndexWriter writer, Tracker tracker)
2018-11-01 07:15:51.915: Product index builder experienced a fatal error.
2018-11-01 07:15:52.508: Failed.
2018-11-01 07:15:52.730: Closing index writer.
2018-11-01 07:15:52.900: BuildIndex failed.. System.NullReferenceException: Object reference not set to an instance of an object.    at Dynamicweb.Indexing.Lucene.LuceneIndexWriter.Close()    at Dynamicweb.Indexing.Index.Build(String instance, String name, Tracker tracker)    at Dynamicweb.Indexing.IndexService.<>c__DisplayClass14_0.<BuildIndex>b__0(Tracker tracker)
2018-11-01 07:15:52.900: BuildIndex failed.

Any updates about this problem yet?

Grtz Harald

Hi Nicolai,

Thanks for the update!

I will give the new Indexing package a try tomorrow, and post the results of that.

Greetings Harald

Hi Morten,

I installed the new package on our Azure staging environment. Its running for a day now, and no build errors sofar.

Thanx for the update!
Greetins Harald

Hello,

Unfortunately the problems with the indexes are back. After running for a while without problems, the build errors started returning. We get dozens of build errors per day. And the errors we get are:

Index build Installers build was executed with error

Start time: 2019-01-03 09:07:41
End time: 2019-01-03 09:07:42
Run time: 00:00:01.59
Number of last processed record: 0
Total number of records: 0
Latest log information: Closing index writer.
Fail reason: BuildIndex failed.
Exception message: Object reference not set to an instance of an object.
Exception stack trace: at Dynamicweb.Indexing.Lucene.LuceneIndexWriter.Close() at Dynamicweb.Indexing.Index.Build(String instance, String name, Tracker tracker) at Dynamicweb.Indexing.IndexService.<>c__DisplayClass14_0.b__0(Tracker tracker)

I attached the log file for more information.

Do you have any idea what might be causing this, and how to solve it?

Greetings Harald

Hi Harald

This is the userindex builder - last time it was the productindexbuilder... So this is another issue?

BR Nicolai

Hi Nicolai,

Thank jou for your reply, we have this problem with all 5 index builders in the site. The errors the indexbuilders generate are the same.
Previously the problem was also with all index builders (but we posted one as example).

Grt Harald

Hi Harald

I cannot see those errors on the solution - I only see SQL timeout from the userindexbuilder.... It seems to come from this SQL:

SELECT OrderCustomerAccessUserId, OrderLineProductId FROM EcomOrders INNER JOIN EcomOrderLines On OrderId = OrderLineOrderId WHERE OrderCustomerAccessUserId > 0 AND OrderLineProductId IS NOT NULL AND OrderLineProductId <> '' AND OrderComplete = 1 AND OrderDeleted = 0 GROUP BY OrderCustomerAccessUserId, OrderLineProductId

Anyways - I can see from the logfiles that your index lock files keeps locking themselves indicating you have more instances running at the same time or an instance is not releasing its locks. It could also be caused by slow disks as the locktimeout we improved the last time helped - but this new exception seems to be coming from the next step in the build process, but basically from the same issue...

I've added some improved logging and error handling to Dynamicweb.Indexing, TFS#59008, and you will get a release that might give us better insight.

BR Nicolai

Hi Nicolai,

Thanks for te support. I will await the new Dynamicweb.Indexing package, and update the solution when it is available.

Greetings Harald

Hi,

We have updated the site with the new Dynamicweb.Indexing package (3.0.6), this is the error log of one of the indexes we are getting now:

Index build Content build was executed with error

Start time: 2019-01-10 08:05:13
End time: 2019-01-10 08:05:15
Run time: 00:00:02.64
Number of last processed record: 0
Total number of records: 0
Latest log information: Failed.
Fail reason: BuildIndex failed.
Exception message: Lock file is NOT present: D:\home\site\wwwroot\Files\System\Indexes\Content repository\Content index\B\write.lock. Time in ms taken in Open: 2018, writer timeout ms: (2000)
Exception stack trace: at Dynamicweb.Indexing.Lucene.LuceneIndexWriter.Open(Boolean openForAppend) at Dynamicweb.Content.ContentIndexBuilder.Build(IIndexWriter writer, Tracker tracker) at Dynamicweb.Indexing.Index.Build(String instance, String name, Tracker tracker) at Dynamicweb.Indexing.IndexService.<>c__DisplayClass14_0.b__0(Tracker tracker)

I attached the corresponding log file. Hopefully it gives you some insights, why the indexex are failing.

Greetings Harald

Hi Harald

As you might be able to see from the log, the system gets a LockObtainFailedException after the 2000 ms timeout. 2 secs is a long time to write an empty file... We can of course change the timeout to a even higher number, but this server must have a (serious) problem with disk performance that I suggest you look into.

I can give you an option to overwrite the timeout and set it to 10000 or so - but that is not a real solution to the underlying problem...

BR Nicolai

Hi Nicolai,

The solution is running on a Azure WebApp with a premium plan, which is backed by SSD disks. But because of the environment we dont heave any further control of the disk performance.

If you could supply me with the option to overwrite the timeout and set it to 10000, that would be nice. So we can check if this will prevent the index build errors.

Greetings Harald

Hi Nicolai,

Thanks for te fix !

Greetings Harald