Text Indexer will not start up

Support
1

I have…

  • [ x] Checked the logs and have provided the logs if I found something suspicious there

“logLevel”: “Warning”,
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT “message”: "Unreleased index found.",
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT “schemaId”: “d3434550-a3c4-4d92-9ca7-ea09aa7c19ea”,
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT “app”: {
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT “name”: “Squidex”,
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT “version”: “4.1.0.0”,
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT “sessionId”: “756df6d4-a760-4d6d-8a6b-2c2eb2ef724f”
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT },
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT “timestamp”: “2020-02-25T12:13:31Z”
2020-02-25T12:13:31.07+0000 [APP/PROC/WEB/0] OUT }

System.NullReferenceException: Object reference not set to an instance of an object. at Squidex.Domain.Apps.Entities.Contents.Text.IndexManager.CommitInternalAsync(IIndex index, Boolean dispose) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/IndexManager.cs:line 118 at Squidex.Domain.Apps.Entities.Contents.Text.IndexManager.AcquireAsync(Guid schemaId) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/IndexManager.cs:line 73 at Squidex.Domain.Apps.Entities.Contents.Text.TextIndexerGrain.OnActivateAsync(Guid key) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/TextIndexerGrain.cs:line 57 at Squidex.Infrastructure.Orleans.GrainOfGuid.ActivateAsync(Guid key) in /src/src/Squidex.Infrastructure/Orleans/GrainOfGuid.cs:line 40 at Orleans.LifecycleSubject.g__CallOnStart|7_0(Int32 stage, OrderedObserver observer, CancellationToken cancellationToken) at Orleans.LifecycleSubject.OnStart(CancellationToken ct) at Orleans.Runtime.Catalog.CallGrainActivate(ActivationData activation, Dictionary2 requestContextData) at Orleans.Runtime.Scheduler.AsyncClosureWorkItem.Execute() at Orleans.Runtime.Catalog.InitActivation(ActivationData activation, String grainType, String genericArguments, Dictionary2 requestContextData) at Orleans.Runtime.Catalog.InitActivation(ActivationData activation, String grainType, String genericArguments, Dictionary2 requestContextData) at Orleans.Internal.OrleansTaskExtentions.<ToTypedTask>g__ConvertAsync|4_0[T](Task1 asyncTask) at Squidex.Domain.Apps.Entities.Contents.Text.GrainTextIndexer.On(Envelope1 event) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/GrainTextIndexer.cs:line 86 at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.DispatchConsumerAsync(Envelope1 event) in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 247 at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.<>c__DisplayClass12_0.<b__0>d.MoveNext() in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 91— End of stack trace from previous location where exception was thrown — at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.DoAndUpdateStateAsync(Func`1 action, String caller) in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 200

I’m submitting a…

  • [ ] Regression (a behavior that stopped working in a new release)
  • [ x] Bug report
  • [ ] Performance issue
  • [ ] Documentation issue or request

Current behavior

We are running v4.10 and have two environments (Dev and UAT). On Dev the TextIndexer2 consumer is not running. On UAT it works as expected. If I try to restart the consumer it fails after a few minutes with the above errors. The first indicates an index is locked which may be the cause for the object reference error that follows it.

Expected behavior

The TextIndexer2 consumer would run and searching within the interface would return results.

Minimal reproduction of the problem

This appears to be specific to one of our instances so maybe an index is corrupt?

Environment

  • [ ] Self hosted with docker
  • [ ] Self hosted with IIS
  • [ x] Self hosted with other version
  • [ ] Cloud version
    Hosted in GovPaaS (Cloud Foundry using a dotnetcore buildpack)

Version: 4.10

Browser:

  • [ x] Chrome (desktop)
  • [ ] Chrome (Android)
  • [ ] Chrome (iOS)
  • [ ] Firefox
  • [ ] Safari (desktop)
  • [ ] Safari (iOS)
  • [ ] IE
  • [ ] Edge

Others:
We are storing assets in MongoDB. I had seen an issue someone had regarding indexes and a suggestion was to delete the index_{id}.zip files. I cannot see these in the Mongo Assets collection so have not been able to try this as an option.

2

Hi, thank you very much. Do you have a formatted version of your logs? The stack trace is just a block of text.

If you can also format it correctly and perhaps provide me a backup of your database I can have a look. The Unreleased index found. warning is not the root cause, it just means that the indexing has crashed and has not released the index properly.

The zip files are from previous versions when the full text indices were stored in the asset storage, but I replaced it with a more robust solution. But this is not related in any way to your problem.

3

Hi Sebastian,

Thanks for your quick reply. I am unable to provide the database at this time for security reasons unfortunately. Getting the logs from the server is harder than you would expect based on the hosting. So I tried running locally but connecting to the same Mongo Atlas DB and am able to get logs. However the error was not the same on my local machine:

{
  "logLevel": "Fatal",

  "action": "OnEventAsync",

  "status": "Failed",

  "eventConsumer": "TextIndexer2",

  "exception": {

    "type": "System.IndexOutOfRangeException",

    "message": "Index was outside the bounds of the array.",

    "stackTrace": "   at Lucene.Net.Codecs.Lucene40.BitVector.Get(Int32 bit)\r\n   at Lucene.Net.Codecs.Lucene41.Lucene41PostingsReader.BlockDocsEnum.NextDoc()\r\n   at Lucene.Net.Search.Weight.DefaultBulkScorer.ScoreAll(ICollector collector, Scorer scorer)\r\n   at Lucene.Net.Search.Weight.DefaultBulkScorer.Score(ICollector collector, Int32 max)\r\n   at Lucene.Net.Search.BulkScorer.Score(ICollector collector)\r\n   at Lucene.Net.Search.IndexSearcher.Search(IList\u00601 leaves, Weight weight, ICollector collector)\r\n   at Lucene.Net.Search.IndexSearcher.Search(IList\u00601 leaves, Weight weight, ScoreDoc after, Int32 nDocs)\r\n   at Lucene.Net.Search.IndexSearcher.Search(Weight weight, ScoreDoc after, Int32 nDocs)\r\n   at Lucene.Net.Search.IndexSearcher.Search(Query query, Filter filter, Int32 n)\r\n   at Lucene.Net.Search.IndexSearcher.Search(Query query, Int32 n)\r\n   at Squidex.Domain.Apps.Entities.Contents.Text.IndexState.HasBeenAdded(Guid id, Scope scope, Term term, Int32\u0026 docId) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/IndexState.cs:line 73\r\n   at Squidex.Domain.Apps.Entities.Contents.Text.TextIndexContent.IsAdded(Scope scope, Int32\u0026 docId) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/TextIndexContent.cs:line 155\r\n   at Squidex.Domain.Apps.Entities.Contents.Text.TextIndexContent.Index(Dictionary\u00602 text, Boolean onlyDraft) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/TextIndexContent.cs:line 96\r\n   at Squidex.Domain.Apps.Entities.Contents.Text.TextIndexerGrain.IndexAsync(Update update) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/TextIndexerGrain.cs:line 61\r\n   at Squidex.Domain.Apps.Entities.Contents.Text.OrleansCodeGenTextIndexerGrainMethodInvoker.Invoke(IAddressable grain, InvokeMethodRequest request) in /src/src/Squidex.Domain.Apps.Entities/obj/Release/netcoreapp3.1/Squidex.Domain.Apps.Entities.orleans.g.cs:line 1418\r\n   at Orleans.Runtime.GrainMethodInvoker.Invoke()\r\n   at Squidex.Infrastructure.Orleans.StateFilter.Invoke(IIncomingGrainCallContext context) in /src/src/Squidex.Infrastructure/Orleans/StateFilter.cs:line 51\r\n   at Orleans.Runtime.GrainMethodInvoker.Invoke()\r\n   at Squidex.Infrastructure.Orleans.LoggingFilter.Invoke(IIncomingGrainCallContext context) in /src/src/Squidex.Infrastructure/Orleans/LoggingFilter.cs:line 46\r\n   at Orleans.Runtime.GrainMethodInvoker.Invoke()\r\n   at Squidex.Infrastructure.Orleans.LocalCacheFilter.Invoke(IIncomingGrainCallContext context) in /src/src/Squidex.Infrastructure/Orleans/LocalCacheFilter.cs:line 39\r\n   at Orleans.Runtime.GrainMethodInvoker.Invoke()\r\n   at Orleans.Runtime.GrainMethodInvoker.Invoke()\r\n   at OrleansDashboard.Metrics.GrainProfilerFilter.Invoke(IIncomingGrainCallContext context)\r\n   at Orleans.Runtime.GrainMethodInvoker.Invoke()\r\n   at Orleans.Runtime.InsideRuntimeClient.Invoke(IAddressable target, IInvokable invokable, Message message)\r\n   at Orleans.Internal.OrleansTaskExtentions.\u003CToTypedTask\u003Eg__ConvertAsync|4_0[T](Task\u00601 asyncTask)\r\n   at Squidex.Domain.Apps.Entities.Contents.Text.GrainTextIndexer.On(Envelope\u00601 event) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/GrainTextIndexer.cs:line 86\r\n   at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.DispatchConsumerAsync(Envelope\u00601 event) in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 247\r\n   at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.\u003C\u003Ec__DisplayClass12_0.\u003C\u003COnEventAsync\u003Eb__0\u003Ed.MoveNext() in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 91\r\n--- End of stack trace from previous location where exception was thrown ---\r\n   at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.DoAndUpdateStateAsync(Func\u00601 action, String caller) in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 200"

  },

  "app": {

    "name": "Squidex",

    "version": "4.1.0.0",

    "sessionId": "fe1623e5-1e31-4c7b-a3c9-d93d25e3ed1b"

  },

  "timestamp": "2020-02-25T13:36:16Z"

}

I wondered if it was due to two applications being connected to the same DB so tried disabling my local and seeing what the errors were on Dev. The error changed to (not formatted nicely I know - I am only able to take from a command line for that environment):

"message": "read past EOF: MMapIndexInput(path=\u0022/home/vcap/tmp/Indices/d3434550-a3c4-4d92-9ca7-ea09aa7c19ea/_0.si\u0022)",
   2020-02-25T14:00:41.31+0000 [APP/PROC/WEB/0] OUT     "stackTrace": "   at Lucene.Net.Index.SegmentInfos.FindSegmentsFile.Run(IndexCommit commit)\n   at Lucene.Net.Index.SegmentInfos.FindSegmentsFile.Run()\n   at Lucene.Net.Index.SegmentInfos.Read(Directory directory)\n   at Lucene.Net.Index.IndexWriter..ctor(Directory d, IndexWriterConfig conf)\n   at Squidex.Domain.Apps.Entities.Contents.Text.IndexManager.IndexHolder.RecreateIndexWriter() in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/IndexManager_Impl.cs:line 108\n   at Squidex.Domain.Apps.Entities.Contents.Text.IndexManager.IndexHolder.Open(Directory directory) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/IndexManager_Impl.cs:line 93\n   at Squidex.Domain.Apps.Entities.Contents.Text.IndexManager.AcquireAsync(Guid schemaId) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/IndexManager.cs:line 72\n   at Squidex.Domain.Apps.Entities.Contents.Text.TextIndexerGrain.OnActivateAsync(Guid key) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/TextIndexerGrain.cs:line 54\n   at Squidex.Infrastructure.Orleans.GrainOfGuid.ActivateAsync(Guid key) in /src/src/Squidex.Infrastructure/Orleans/GrainOfGuid.cs:line 39\n   at Orleans.LifecycleSubject.\u003COnStart\u003Eg__CallOnStart|7_0(Int32 stage, OrderedObserver observer, CancellationToken cancellationToken)\n   at Orleans.LifecycleSubject.OnStart(CancellationToken ct)\n   at Orleans.Runtime.Catalog.CallGrainActivate(ActivationData activation, Dictionary\u00602 requestContextData)\n   at Orleans.Runtime.Scheduler.AsyncClosureWorkItem.Execute()\n   at Orleans.Runtime.Catalog.InitActivation(ActivationData activation, String grainType, String genericArguments, Dictionary\u00602 requestContextData)\n   at Orleans.Runtime.Catalog.InitActivation(ActivationData activation, String grainType, String genericArguments, Dictionary\u00602 requestContextData)\n   at Orleans.Internal.OrleansTaskExtentions.\u003CToTypedTask\u003Eg__ConvertAsync|4_0[T](Task\u00601 asyncTask)\n   at Squidex.Domain.Apps.Entities.Contents.Text.GrainTextIndexer.On(Envelope\u00601 event) in /src/src/Squidex.Domain.Apps.Entities/Contents/Text/GrainTextIndexer.cs:line 86\n   at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.DispatchConsumerAsync(Envelope\u00601 event) in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 247\n   at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.\u003C\u003Ec__DisplayClass12_0.\u003C\u003COnEventAsync\u003Eb__0\u003Ed.MoveNext() in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 91\n--- End of stack trace from previous location where exception was thrown ---\n   at Squidex.Infrastructure.EventSourcing.Grains.EventConsumerGrain.DoAndUpdateStateAsync(Func\u00601 action, String caller) in /src/src/Squidex.Infrastructure/EventSourcing/Grains/EventConsumerGrain.cs:line 200"

Is there an easy way of simply purging the indexes? Are there references to them in Mongo or is it filesystem only? Are they the items in the /home/vcap/tmp/Indices/ folder I see mentioned?

I will keep looking at how I can get the logs off of the Dev environment so you can see them in full.

4

It is not a good idea to connect to the same DB, the indexes are not thread safe in any way.

The indices are stored in the tmp folder for performance reasons, but the real data is in GridFS in MongoDB. I would clear both.

5

I am supporting the application but have not been very involved in the past so am lacking some knowledge on this but if I look at the Assets database it has “fs.files” and “fs.chunks”. My understanding is tha this contains the media uploaded to Squidex as well as the indexes (and maybe other stuff). How do identify index items to remove? Based on an old post I tried looking for items with filename beginning “index” but found no results.

6

I have worked around the issue. Our dev environment is new and was a copy of UAT so I have just backed up UAT and restored it into dev and the indexing is working now. It was quicker this way.

1 Like
7

But if you can somehow manage it to send me a backup, it would be great. I will sign an NDA or whatever :wink:

8

Unfortunately it is a government client. I know it would have been helpful to understand though. It may have been to do with the way i carried out the upgrade from (1.10 to 4.10). I ran the application locally to get it to migrate then deployed to the relevant environment in the cloud. I couldn’t just upgrade in the cloud due to timeout issues when the migrate process runs. Maybe I accidentally left my local running and the cloud environment and something broke as you say the indexes aren’t threadsafe.

9

Wow, I have never seen somebody making an upgrade from 1.10 to 4.10 :smiley:

10

It went surprisingly smoothly. One issue we did have was that there seemed to be a changed to a Mongo Data Type on the user object. The LockoutExpiration (or named similarly) changed from a datetime to an offset or something. I was able to just remove this attribute from the users that had it as it seems it is only populated if they were locked out at some point. The impact was the contributors page was broken until I made the change in the DB.

1 Like