Issue with resetting indexes on 3.5.0-rc-35169?

[Bruno Lopes]

We're testing upgrading to ravendb 3.5 from 3.0, and we've ocasionally seen issues during our initial setup of the database, where we run a bunch of migrations to bring it up to date.

I've got logs I can share, but they contain a lot of info, and if needed I'd prefer to share over to hibernating rhinos via a private channel.

It's not something I can easily reproduce, but I've seen it twice today (testing the upgrade, so I end up creating databases from scratch a lot).

I've seen two "types" of errors.

The first error shows as
"""
System.AggregateException: One or more errors occurred. ---> System.AggregateException: One or more errors occurred. ---> System.IO.IOException: The following processing are locking D:\InnovationCast\local\RavenDBv3.5\RavenDb.Server\tools\Databases\branch_test_new_4\Indexes\8\_a.cfs
        Raven.Server 473004

   at Raven.Database.Extensions.IOExtensions.TryHandlingError(String directory, Int32 i, Exception e) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Extensions\IOExtensions.cs:line 115
   at Raven.Database.Extensions.IOExtensions.DeleteDirectory(String directory) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Extensions\IOExtensions.cs:line 97
   at Raven.Database.Indexing.IndexStorage.RegenerateMapReduceIndex(Directory directory, IndexDefinition indexDefinition) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 567
   at Raven.Database.Indexing.IndexStorage.TryRecoveringIndex(IndexDefinition indexDefinition, Directory luceneDirectory) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 401
   at Raven.Database.Indexing.IndexStorage.OpenIndex(String indexName, Boolean onStartup, Boolean forceFullIndexCheck) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 263
   at Raven.Database.Indexing.IndexStorage.<>c__DisplayClass13_0.<.ctor>b__0(String name) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 156
   at System.Threading.Tasks.Task.Execute()
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task.WaitAll(Task[] tasks, Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at Raven.Database.Indexing.DefaultBackgroundTaskExecuter.ExecuteAllInterleaved[T](WorkContext context, IList`1 result, Action`1 action) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Impl\BackgroundTaskExecuter\DefaultBackgroundTaskExecuter.cs:line 165
   at Raven.Database.Indexing.IndexStorage..ctor(IndexDefinitionStorage indexDefinitionStorage, InMemoryRavenConfiguration configuration, DocumentDatabase documentDatabase) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 177
   at Raven.Database.DocumentDatabase.DocumentDatabaseInitializer.InitializeIndexStorage() in C:\Builds\RavenDB-3.5-RC\Raven.Database\DocumentDatabase.cs:line 1467
   at Raven.Database.DocumentDatabase..ctor(InMemoryRavenConfiguration configuration, DocumentDatabase systemDatabase, TransportState recievedTransportState) in C:\Builds\RavenDB-3.5-RC\Raven.Database\DocumentDatabase.cs:line 258
   at Raven.Database.Server.Tenancy.DatabasesLandlord.<>c__DisplayClass27_0.<TryGetOrCreateResourceStore>b__1() in C:\Builds\RavenDB-3.5-RC\Raven.Database\Server\Tenancy\DatabaseLandlord.cs:line 200
   at System.Threading.Tasks.Task`1.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Raven.Database.Server.Tenancy.DatabasesLandlord.<GetResourceInternal>d__26.MoveNext() in C:\Builds\RavenDB-3.5-RC\Raven.Database\Server\Tenancy\DatabaseLandlord.cs:line 148
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task`1.GetResultCore(Boolean waitCompletionNotification)
   at Raven.Database.Common.ResourceApiController`2.get_Resource() in C:\Builds\RavenDB-3.5-RC\Raven.Database\Common\ResourceApiController.cs:line 156
   at Raven.Database.Common.ResourceApiController`2.get_MaxSecondsForTaskToWaitForResourceToLoad() in C:\Builds\RavenDB-3.5-RC\Raven.Database\Common\ResourceApiController.cs:line 43
   at Raven.Database.Common.ResourceApiController`2.<TrySetupRequestToProperResource>d__33.MoveNext() in C:\Builds\RavenDB-3.5-RC\Raven.Database\Common\ResourceApiController.cs:line 258
---> (Inner Exception #0) System.AggregateException: One or more errors occurred. ---> System.IO.IOException: The following processing are locking D:\InnovationCast\local\RavenDBv3.5\RavenDb.Server\tools\Databases\branch_test_new_4\Indexes\8\_a.cfs
        Raven.Server 473004

   at Raven.Database.Extensions.IOExtensions.TryHandlingError(String directory, Int32 i, Exception e) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Extensions\IOExtensions.cs:line 115
   at Raven.Database.Extensions.IOExtensions.DeleteDirectory(String directory) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Extensions\IOExtensions.cs:line 97
   at Raven.Database.Indexing.IndexStorage.RegenerateMapReduceIndex(Directory directory, IndexDefinition indexDefinition) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 567
   at Raven.Database.Indexing.IndexStorage.TryRecoveringIndex(IndexDefinition indexDefinition, Directory luceneDirectory) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 401
   at Raven.Database.Indexing.IndexStorage.OpenIndex(String indexName, Boolean onStartup, Boolean forceFullIndexCheck) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 263
   at Raven.Database.Indexing.IndexStorage.<>c__DisplayClass13_0.<.ctor>b__0(String name) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Indexing\IndexStorage.cs:line 156
   at System.Threading.Tasks.Task.Execute()
   --- End of inner exception stack trace ---
"""

(the actual "stack trace" it's way way longer, but seems to all be the same.)

The second I've seen shows on the server:
"""
TransactionalStorage.Batch was called after it was disposed, call was ignored.
Microsoft.Isam.Esent.Interop.EsentInvalidInstanceException: Invalid instance handle
   at Microsoft.Isam.Esent.Interop.Api.Check(Int32 err)
   at Microsoft.Isam.Esent.Interop.Api.JetBeginSession(JET_INSTANCE instance, JET_SESID& sesid, String username, String password)
   at Raven.Database.Storage.Esent.StorageActions.DocumentStorageActions..ctor(JET_INSTANCE instance, String database, TableColumnsCache tableColumnsCache, OrderedPartCollection`1 documentCodecs, IUuidGenerator uuidGenerator, IDocumentCacher cacher, EsentTransactionContext transactionContext, TransactionalStorage transactionalStorage) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Storage\Esent\StorageActions\General.cs:line 118
   at Raven.Storage.Esent.TransactionalStorage.ExecuteBatch(Action`1 action, EsentTransactionContext transactionContext) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Storage\Esent\TransactionalStorage.cs:line 908
   at Raven.Storage.Esent.TransactionalStorage.Batch(Action`1 action) in C:\Builds\RavenDB-3.5-RC\Raven.Database\Storage\Esent\TransactionalStorage.cs:line 814
Receive Request #4,629: EVAL    - branch_test_new_9 - http://ravendb.vcap.me:8080/databases/branch_test_new_9/bulk_docs/Raven/DocumentsByEntityName?&query=Tag:BlogPostTranslations&pageSize=128&allowStale=False&maxOpsPerSec=&details=False&staleTimeout=00:05:00
Could not open index UserAuth/By/UserNameOrEmail. Recovery operation failed, forcibly resetting index Cannot delete D:\InnovationCast\local\RavenDBv3.5\RavenDb.Server\tools\Databases\branch_test_new_9\Indexes\3\write.lock

Request #4,629: EVAL    - 1,537 ms - branch_test_new_9 - 503 - http://ravendb.vcap.me:8080/databases/branch_test_new_9/bulk_docs/Raven/DocumentsByEntityName?&query=Tag:BlogPostTranslations&pageSize=128&allowStale=False&maxOpsPerSec=&details=False&staleTimeout=00:05:00
Receive Request #4,630: GET     -  - http://ravendb.vcap.me:8080/docs?id=Raven%2FDatabases%2Fbranch_test_new_9
Request #4,630: GET     -     0 ms -            - 200 - http://ravendb.vcap.me:8080/docs?id=Raven%2FDatabases%2Fbranch_test_new_9
Receive Request #4,631: POST    -  - http://ravendb.vcap.me:8080/bulk_docs
Request #4,631: POST    -     1 ms -            - 200 - http://ravendb.vcap.me:8080/bulk_docs
Receive Request #4,632: GET     -  - http://localhost:8080/docs/Raven/Databases/branch_test_new_9
Request #4,632: GET     -     0 ms -            - 200 - http://localhost:8080/docs/Raven/Databases/branch_test_new_9
Receive Request #4,633: POST    - branch_test_new_9 - http://ravendb.vcap.me:8080/databases/branch_test_new_9/bulk_docs
Could not open index UserAuth/By/UserNameOrEmail. Recovery operation failed, forcibly resetting index Index directory 'D:\InnovationCast\local\RavenDBv3.5\RavenDb.Server\tools\Databases\branch_test_new_9\Indexes\3' does not exists for 'UserAuth/By/UserNameOrEmail' index.
Request #4,633: POST    - 1,241 ms - branch_test_new_9 - 503 - http://ravendb.vcap.me:8080/databases/branch_test_new_9/bulk_docs
Receive Request #4,634: GET     -  - http://ravendb.vcap.me:8080/docs?id=Raven%2FDatabases%2Fbranch_test_new_9
Request #4,634: GET     -     5 ms -            - 200 - http://ravendb.vcap.me:8080/docs?id=Raven%2FDatabases%2Fbranch_test_new_9
Receive Request #4,635: GET     -  - http://ravendb.vcap.me:8080/databases?pageSize=128&start=0
Request #4,635: GET     -     9 ms -            - 200 - http://ravendb.vcap.me:8080/databases?pageSize=128&start=0
Receive Request #4,636: POST    - branch_test_new_9 - http://ravendb.vcap.me:8080/databases/branch_test_new_9/queries/
Could not open index UserAuth/By/UserNameOrEmail. Recovery operation failed, forcibly resetting index Index directory 'D:\InnovationCast\local\RavenDBv3.5\RavenDb.Server\tools\Databases\branch_test_new_9\Indexes\3' does not exists for 'UserAuth/By/UserNameOrEmail' index.
"""

[ar...@ayende.com]

Hi Bruno,

what 3.0 build were you using? Are you running RavenDB as a windows service or on IIS? Could you try to reproduce it once again and try to collect Debug Info Package then (Studio -> Manage Your Server -> Gather Debug Info)? You can send logs to our support mail  (support (at) ravendb.net)

Regards,
Arek

[Bruno Lopes]

Hi Arek,

Build 3.5.0-rc-35169 (I think that was the latest when I tested)
Since I'm testing the upgrade I run RavenDB in standalone mode (just run the .exe)

I'll send it later today when I get back to that branch.
Thanks,
Bruno

[Arkadiusz Palinski]

OK. Note that I asked about build number of 3.0 version which you are upgrading to 3.5.

--
You received this message because you are subscribed to a topic in the Google Groups "RavenDB - 2nd generation document database" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/ravendb/ok7c3SvI5t8/unsubscribe.
To unsubscribe from this group and all its topics, send an email to ravendb+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Bruno Lopes]

Sorry! My bad.

We ran 3.0.3800 for a long time (which doesn't show this issue), and recently upgraded to 3.0.30155 (which hasn't been as tested as much, but I don't think shows the problem)

To unsubscribe from this group and all its topics, send an email to ravendb+unsubscribe@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--

You received this message because you are subscribed to a topic in the Google Groups "RavenDB - 2nd generation document database" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/ravendb/ok7c3SvI5t8/unsubscribe.

To unsubscribe from this group and all its topics, send an email to ravendb+unsubscribe@googlegroups.com.

[Bruno Lopes]

Managed to grab debug info without stacktraces. With stacktraces it crashed with
"""
 Unable to fetch info package: Could not read stacktraces.
System.DllNotFoundException: Unable to load DLL 'dbgeng.dll': The operating system cannot run . (Exception from HRESULT: 0x800700B6) at Microsoft.Diagnostics.Runtime.Desktop.NativeMethods.DebugCreate(Guid& InterfaceId, Object& Interface) at Microsoft.Diagnostics.Runtime.DbgEngDataReader.CreateIDebugClient() at Microsoft.Diagnostics.Runtime.DbgEngDataReader..ctor(Int32 pid, AttachFlag flags, UInt32 msecTimeout) at Microsoft.Diagnostics.Runtime.DataTarget.AttachToProcess(Int32 pid, UInt32 msecTimeout, AttachFlag attachFlag) at Raven.Debug.Program.ShowStackTrace(Int32 processId, UInt32 attachTimeout, String outputPath) at Raven.Debug.Program.Main(String[] args)
"""

I've rebooted to see if I could create debug info with stacktraces, but still can't.
Running Windows 10 x64, Version 1607, build 14393.222 if that helps.

However, I now can't repro the index issues. I still have the previous debug info and logs if that's interesting.

On Monday, 3 October 2016 15:20:26 UTC+1, Bruno Lopes wrote:

Sorry! My bad.

We ran 3.0.3800 for a long time (which doesn't show this issue), and recently upgraded to 3.0.30155 (which hasn't been as tested as much, but I don't think shows the problem)

On Mon, Oct 3, 2016 at 3:12 PM, Arkadiusz Palinski <> wrote:

OK. Note that I asked about build number of 3.0 version which you are upgrading to 3.5.

[Oren Eini (Ayende Rahien)]

Yes, please send them

Hibernating Rhinos Ltd  

Oren Eini l CEO l Mobile: + 972-52-548-6969

Office: +972-4-622-7811 l Fax: +972-153-4-622-7811

 

--
You received this message because you are subscribed to the Google Groups "RavenDB - 2nd generation document database" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ravendb+unsubscribe@googlegroups.com.

[Bruno Lopes]

Gone