Server just dies when updated to 4.1.4

[Yogesh Jagota]

Hello,

The server starts and then immediately dies after updating to 4.1.4:

The log only shows this:

   Time, Thread, Level, Source, Logger, Message, Exception
2019-02-14T07:43:00.1683853Z, 1, Information, Server, Raven.Server.Program, Logging to D:\Projects\RavenDB.Server\Server\Logs set to Information level.
2019-02-14T07:43:00.2873662Z, 1, Operations, Server, Raven.Server.Program,  Build 41010, Version 4.1, SemVer 4.1.4, Commit dc2e9e3
 PID 12840, 64 bits, 4 Cores, Arch: X64
 7.879 GBytes Physical Memory, 1.924 GBytes Available Memory, 1.951 GBytes Calculated Available Memory
 Using GC in server concurrent mode retaining memory from the OS.
2019-02-14T07:43:00.3489671Z, 1, Information, Server, Raven.Server.RavenServer, Server store started took 3 ms
2019-02-14T07:43:00.6451819Z, 1, Information, Server, Raven.Server.RavenServer, Configuring HTTP server took 296 ms
2019-02-14T07:43:00.7320342Z, 1, Information, Server, Raven.Server.RavenServer, Initialized Server... http://yjdesktop:8081
2019-02-14T07:43:00.7572489Z, 1, Information, ServerStore, Raven.Server.ServerWide.ServerStore, Starting to open server store for D:\Raven
2019-02-14T07:43:00.7986533Z, 1, Information, Pager-D:\Raven\System\Raven.voron, Voron.StorageEnvironment, Physical drive 'D:' unique id = '1793' for file 'D:\Raven\System\Raven.voron'
2019-02-14T07:43:00.8186864Z, 1, Information, Pager-D:\Raven\System\Temp\scratch.0000000000.buffers, Voron.StorageEnvironment, Physical drive 'D:' unique id = '1793' for file 'D:\Raven\System\Temp\scratch.0000000000.buffers'
2019-02-14T07:43:00.8290332Z, 1, Information, Pager-D:\Raven\System\Temp\compression.0000000000.buffers, Voron.StorageEnvironment, Physical drive 'D:' unique id = '1793' for file 'D:\Raven\System\Temp\compression.0000000000.buffers'
2019-02-14T07:43:00.8396041Z, 1, Information, Pager-D:\Raven\System\Temp\0000000000000009892.recovery, Voron.StorageEnvironment, Physical drive 'D:' unique id = '1793' for file 'D:\Raven\System\Temp\0000000000000009892.recovery'
2019-02-14T07:43:00.8407918Z, 1, Information, Pager-D:\Raven\System\Journals\0000000000000009892.journal, Voron.StorageEnvironment, Physical drive 'D:' unique id = '1793' for file 'D:\Raven\System\Journals\0000000000000009892.journal'
2019-02-14T07:43:01.5242302Z, 1, Information, ServerStore, Raven.Server.NotificationCenter.NotificationsStorage, Deleting notification 'AlertRaised/Server_NewVersionAvailable'.

And naturally I cannot go back to 4.1.3/patches:

At D:\Raven\System ---> Voron.Exceptions.SchemaErrorException: The db file is for version 23, which is not compatible with the current version 22 on D:\Raven\System
   at Voron.Impl.FileHeaders.HeaderAccessor.Initialize() in C:\Builds\RavenDB-4.1-Patch\41008\src\Voron\Impl\FileHeaders\HeaderAccessor.cs:line 73
   at Voron.StorageEnvironment..ctor(StorageEnvironmentOptions options) in C:\Builds\RavenDB-4.1-Patch\41008\src\Voron\StorageEnvironment.cs:line 143
   at Raven.Server.Storage.Layout.LayoutUpdater.OpenEnvironmentInternal(DirectoryStorageEnvironmentOptions options) in C:\Builds\RavenDB-4.1-Patch\41008\src\Raven.Server\Storage\Layout\LayoutUpdater.cs:line 36
   at Raven.Server.Storage.Layout.LayoutUpdater.OpenEnvironment(StorageEnvironmentOptions options) in C:\Builds\RavenDB-4.1-Patch\41008\src\Raven.Server\Storage\Layout\LayoutUpdater.cs:line 16
   at Raven.Server.ServerWide.ServerStore.Initialize() in C:\Builds\RavenDB-4.1-Patch\41008\src\Raven.Server\ServerWide\ServerStore.cs:line 523
   --- End of inner exception stack trace ---
   at Raven.Server.ServerWide.ServerStore.Initialize() in C:\Builds\RavenDB-4.1-Patch\41008\src\Raven.Server\ServerWide\ServerStore.cs:line 527
   at Raven.Server.RavenServer.Initialize() in C:\Builds\RavenDB-4.1-Patch\41008\src\Raven.Server\RavenServer.cs:line 279

The problem affects both normal and embedded versions. Embedded version throws the following error:

Unable to start the RavenDB Server
Output:
       _____                       _____  ____
      |  __ \                     |  __ \|  _ \
      | |__) |__ ___   _____ _ __ | |  | | |_) |
      |  _  // _` \ \ / / _ \ '_ \| |  | |  _ <
      | | \ \ (_| |\ V /  __/ | | | |__| | |_) |
      |_|  \_\__,_| \_/ \___|_| |_|_____/|____/




      Safe by default, optimized for efficiency


 Build 41010, Version 4.1, SemVer 4.1.4, Commit dc2e9e3
 PID 13456, 64 bits, 4 Cores, Phys Mem 7.879 GBytes, Arch: X64
 Source Code (git repo): https://github.com/ravendb/ravendb
 Built with love by Hibernating Rhinos and awesome contributors!
+---------------------------------------------------------------+




Raven.Client.Exceptions.Server.ServerLoadFailureException: Failed to load system storage
At D:\RavenAdminData\System ---> Voron.Exceptions.InvalidJournalException: Failed to open a storage at D:\RavenAdminData\System due to invalid or missing journal files. In order to load the storage successfully we need all journals to be not corrupted. You can start the server in dangerous mode temporarily so it will ignore invalid journals on startup:Raven.Server.exe --Storage.Dangerous.IgnoreInvalidJournalErrors=true
This switch is meant to be use only for recovery purposes. Please make sure that you won't use it after you manage to recover your data. Eventually you should delete the system storage at 'D:\RavenAdminData\System', start the server and create your databases again with the usage of existing data.
Error details: No such journal 'D:\RavenAdminData\System\Journals\0000000000000000000.journal'. Journal details: CurrentJournal - 53, LastSyncedJournal - -1, LastSyncedTransactionId - -1, Flags - IgnoreMissingLastSyncJournal
   at Raven.Server.Storage.Layout.StorageLoader.OpenEnvironmentWithPossibleLayoutUpdate(DirectoryStorageEnvironmentOptions options, StorageEnvironmentType type) in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\Storage\Layout\StorageLoader.cs:line 102
   at Raven.Server.Storage.Layout.StorageLoader.OpenEnvironment(StorageEnvironmentOptions options, StorageEnvironmentType type) in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\Storage\Layout\StorageLoader.cs:line 20
   at Raven.Server.ServerWide.ServerStore.Initialize() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\ServerWide\ServerStore.cs:line 566
   --- End of inner exception stack trace ---
   at Raven.Server.ServerWide.ServerStore.Initialize() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\ServerWide\ServerStore.cs:line 570
   at Raven.Server.RavenServer.Initialize() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\RavenServer.cs:line 261
   at Raven.Server.Program.Main(String[] args) in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\Program.cs:line 149

Stack trace:

   at Raven.Embedded.EmbeddedServer.<>c__DisplayClass15_0.<<RunServer>b__1>d.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 243
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Raven.Embedded.EmbeddedServer.<ReadOutput>d__17.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 305
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Raven.Embedded.EmbeddedServer.<RunServer>d__15.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 225
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Raven.Embedded.EmbeddedServer.<GetServerUriAsync>d__13.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 145

And when run with --Storage.Dangerous.IgnoreInvalidJournalErrors=true flag throws this:

Unable to start the RavenDB Server
Output:
       _____                       _____  ____
      |  __ \                     |  __ \|  _ \
      | |__) |__ ___   _____ _ __ | |  | | |_) |
      |  _  // _` \ \ / / _ \ '_ \| |  | |  _ <
      | | \ \ (_| |\ V /  __/ | | | |__| | |_) |
      |_|  \_\__,_| \_/ \___|_| |_|_____/|____/




      Safe by default, optimized for efficiency


 Build 41010, Version 4.1, SemVer 4.1.4, Commit dc2e9e3
 PID 3360, 64 bits, 4 Cores, Phys Mem 7.879 GBytes, Arch: X64
 Source Code (git repo): https://github.com/ravendb/ravendb
 Built with love by Hibernating Rhinos and awesome contributors!
+---------------------------------------------------------------+

Stack trace:

   at Raven.Embedded.EmbeddedServer.<>c__DisplayClass15_0.<<RunServer>b__1>d.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 243
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Raven.Embedded.EmbeddedServer.<ReadOutput>d__17.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 305
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Raven.Embedded.EmbeddedServer.<RunServer>d__15.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 225
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Raven.Embedded.EmbeddedServer.<GetServerUriAsync>d__13.MoveNext() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Embedded\EmbeddedServer.cs:line 145

None of the databases (4 in total) previously had any errors apart from one instance with the bug which was fixed with the first patch version. I have not tried Voron.Recovery yet and will like to avoid it if possible.

Any help will be really appreciated. 

Regards,

Yogesh

[Arkadiusz Palinski]

Can you check Event Viewer after RavenDB server dies?

--
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+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Arkadiusz Paliński Team Leader   /   Hibernating Rhinos LTD Sales:  sa...@ravendb.net Support:  sup...@ravendb.net

[Arkadiusz Palinski]

Also, if possible can you send us the data?

[Yogesh Jagota]

Two error events are thrown when the server dies:

1.

-

- <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
- <System>
   <Provider Name=".NET Runtime" />
   <EventID Qualifiers="0">1023</EventID>
   <Level>2</Level>
   <Task>0</Task>
   <Keywords>0x80000000000000</Keywords>
   <TimeCreated SystemTime="2019-02-14T11:03:28.116612400Z" />
   <EventRecordID>65648</EventRecordID>
   <Channel>Application</Channel>
   <Computer>YJDESKTOP</Computer>
   <Security />
  </System>
- <EventData>
   <Data>Application: Raven.Server.exe CoreCLR Version: 4.6.27317.3 Description: The process was terminated due to an internal error in the .NET Runtime at IP 00007FFBC9853B8D (00007FFBC96B0000) with exit code c0000005.</Data>
  </EventData>
</Event>

Application: Raven.Server.exe

CoreCLR Version: 4.6.27317.3

Description: The process was terminated due to an internal error in the .NET Runtime at IP 00007FFBC9853B8D (00007FFBC96B0000) with exit code c0000005.

2.

- <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
- <System>
   <Provider Name="Application Error" />
   <EventID Qualifiers="0">1000</EventID>
   <Level>2</Level>
   <Task>100</Task>
   <Keywords>0x80000000000000</Keywords>
   <TimeCreated SystemTime="2019-02-14T11:03:28.299508300Z" />
   <EventRecordID>65649</EventRecordID>
   <Channel>Application</Channel>
   <Computer>YJDESKTOP</Computer>
   <Security />
  </System>
- <EventData>
   <Data>Raven.Server.exe</Data>
   <Data>0.0.0.0</Data>
   <Data>5c410542</Data>
   <Data>coreclr.dll</Data>
   <Data>4.6.27317.3</Data>
   <Data>5c40be0f</Data>
   <Data>c0000005</Data>
   <Data>00000000001a3b8d</Data>
   <Data>23f8</Data>
   <Data>01d4c454e802f8c7</Data>
   <Data>D:\Projects\RavenDB.Server\Server\Raven.Server.exe</Data>
   <Data>D:\Projects\RavenDB.Server\Server\coreclr.dll</Data>
   <Data>f001bd99-d2f1-4851-9ee7-584927f868d2</Data>
   <Data />
   <Data />
  </EventData>
</Event>

Faulting application name: Raven.Server.exe, version: 0.0.0.0, time stamp: 0x5c410542

Faulting module name: coreclr.dll, version: 4.6.27317.3, time stamp: 0x5c40be0f

Exception code: 0xc0000005

Fault offset: 0x00000000001a3b8d

Faulting process ID: 0x23f8

Faulting application start time: 0x01d4c454e802f8c7

Faulting application path: D:\Projects\RavenDB.Server\Server\Raven.Server.exe

Faulting module path: D:\Projects\RavenDB.Server\Server\coreclr.dll

Report ID: f001bd99-d2f1-4851-9ee7-584927f868d2

Faulting package full name: 

Faulting package-relative application ID: 

If this does not help, I can send the data.

[Yogesh Jagota]

The error does not seem data related as I just checked it with old 4.1.3 backup folder (whole folder was copied) and the same issues crop up. The patched versions never accessed this data, only raven 4.1.3. The same data works fine with 4.1.3. Only fails with the new version.

[Yogesh Jagota]

The same error is occuring in 4.1.3 too now. Used voron.recovery and version 4.1.4 is running fine now, so the error is infact data related.

[Arkadiusz Palinski]

Yes, please send us your data which reproduces the problem.

On Thu, Feb 14, 2019 at 1:05 PM Yogesh Jagota <justj...@jagotagroup.com> wrote:

The same error is occuring in 4.1.3 too now. Used voron.recovery and version 4.1.4 is running fine now, so the error is infact data related.

--

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+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Yogesh Jagota]

Can you tell me where to send it?

[Grzegorz Lachowski]

Please send it to sup...@ravendb.net .

Can you check if you have KB4487017 windows update installed?

[Yogesh Jagota]

Yes. I have the KB4487017 windows update installed. Was installed yesterday only via Window Update. Also, sent the data.

[Federico Lois]

We have reproduced that the issue is KB4487017. We are working on understanding the cause. Will keep you posted

On Thu, Feb 14, 2019 at 10:05 AM Yogesh Jagota <justj...@jagotagroup.com> wrote:

Yes. I have the KB4487017 windows update installed. Was installed yesterday only via Window Update. Also, sent the data.

--

[Yogesh Jagota]

Great. Thanks.

[Jan Marques]

I had the same issue and after a lot of looking, I got things working after Windows Update (fall update 1809).

[Arkadiusz Palinski]

To our support mail: sup...@ravendb.net

Can you check if you have KB4487017 windows update installed? (it was released February 12, 2019) 

[Arkadiusz Palinski]

To our support mail: sup...@ravendb.net

[Arkadiusz Palinski]

KB4487017 is only for users running Win10 version 1803

--

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+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Bob McAllan]

++ to the issue(s) listed. 

Appears 4.1.4 is unstable (just dies) Windows 10 with KB4487017, fatally crashed the machine. 

Running fine on Windows server 2016 Server (?), however did corrupt the database journals on install.

Bob

[Oren Eini (Ayende Rahien)]

We have confirmed that this is likely some JIT / OS bug here. We are working with the CoreCLR team to resolve this issue, see: https://github.com/dotnet/coreclr/issues/22597

For the 2016 machine, what do you mean, corrupted journals?

--

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+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Oren Eini CEO   /   Hibernating Rhinos LTD Mobile:  +972-52-548-6969 Sales:  sa...@ravendb.net Skype:  ayenderahien Support:  sup...@ravendb.net

[Bob McAllan]

Oren,

The first time I started Raven, crashed the app. The second time, Ravendb error was corrupted journals. I was able to start by ignoring the error, however I could not correct the issue. 

This occurred on both Windows Server 2016 and Windows 10 (w/ KB4487017), multiple machines and environments.

Bob

[Oren Eini (Ayende Rahien)]

I think that the KB is the root issue here, in the meantime, can you uninstall it and see how that works?

[Arkadiusz Palinski]

Bob,

Can you show us the error related to journals you got? I think you hit the additional journal validation we added in recent builds. The error message should guide you how to proceed then.

[Germán Fernández]

Hi, is this resolved?

I have experienced the same issue in my dev box upgrading from 4.1.3 to 4.1.4.

Environment:

- Windows 10 x64 1809 17763.316

- Couln't find KB4487017 in installed packages (C:>dism /online /get-packages | findstr KB4487017 yielded no results)

My update process consists of

- Remove all files and folders except C:\Raven\Server\RavenData

- Unzip 4.1.4 to C:\Raven

- Copy over settings.json so I don't need to setup raven again in unsecured mode etc.

- run.ps1

This has worked perfectly well in other updates but has failed upgrading from 4.1.3 to 4.1.4

If I unzip raven to a clean location, raven starts ok.

Regards!

Germán

Time,    Thread,    Level,    Source,    Logger,    Message,    Exception

2019-02-28T10:01:45.4955960Z, 1, Operations, Server, Raven.Server.Program,  Build 41010, Version 4.1, SemVer 4.1.4, Commit dc2e9e3
 PID 16604, 64 bits, 12 Cores, Arch: X64
 31.882 GBytes Physical Memory, 24.198 GBytes Available Memory, 24.224 GBytes Calculated Available Memory

 Using GC in server concurrent mode retaining memory from the OS.

2019-02-28T10:01:46.9197522Z, 1, Operations, ServerStore, Raven.Server.ServerWide.ServerStore, Could not open server store for C:\Raven\Server\RavenData, EXCEPTION: Raven.Client.Exceptions.Server.ServerLoadFailureException: Failed to load system storage
At C:\Raven\Server\RavenData\System ---> Voron.Exceptions.InvalidJournalException: Failed to open a storage at C:\Raven\Server\RavenData\System due to invalid or missing journal files. In order to load the storage successfully we need all journals to be not corrupted. You can start the server in dangerous mode temporarily so it will ignore invalid journals on startup:Raven.Server.exe --Storage.Dangerous.IgnoreInvalidJournalErrors=true
This switch is meant to be use only for recovery purposes. Please make sure that you won't use it after you manage to recover your data. Eventually you should delete the system storage at 'C:\Raven\Server\RavenData\System', start the server and create your databases again with the usage of existing data.
Error details: The last synced transaction id was 13699 (in journal: 32) but the first transaction being read in the recovery process is 13827 (transaction has valid hash). Some journals are missing. Current journal file C:\Raven\Server\RavenData\System\Journals\0000000000000000033.journal.. Journal details: CurrentJournal - 33, LastSyncedJournal - 32, LastSyncedTransactionId - 13699, Flags - IgnoreMissingLastSyncJournal

   at Raven.Server.Storage.Layout.StorageLoader.OpenEnvironmentWithPossibleLayoutUpdate(DirectoryStorageEnvironmentOptions options, StorageEnvironmentType type) in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\Storage\Layout\StorageLoader.cs:line 102
   at Raven.Server.Storage.Layout.StorageLoader.OpenEnvironment(StorageEnvironmentOptions options, StorageEnvironmentType type) in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\Storage\Layout\StorageLoader.cs:line 20
   at Raven.Server.ServerWide.ServerStore.Initialize() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\ServerWide\ServerStore.cs:line 566
   --- End of inner exception stack trace ---
   at Raven.Server.ServerWide.ServerStore.Initialize() in C:\Builds\RavenDB-Stable-4.1\41010\src\Raven.Server\ServerWide\ServerStore.cs:line 570

[Oren Eini (Ayende Rahien)]

You can start the server in dangerous mode temporarily so it will ignore invalid journals on startup:Raven.Server.exe --Storage.Dangerous.IgnoreInvalidJournalErrors=true  

--

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+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Germán Fernández]

Ok,

After starting the server in dangerous mode for one time now I can start raven again normally.

I have read the stack trace message (see below) and, just to be sure, should I backup the data,  recreate a new instance (with a new System database) and restore the data there? Or has Voron succesfully recovered the System database so no further action is needed?

Please make sure that you won't use it after you manage to recover your data. Eventually you should delete the system storage at 'C:\Raven\Server\RavenData\System', start the server and create your databases again with the usage of existing data.

Thx!

[Oren Eini (Ayende Rahien)]

For best case, re-create it, yes.

But it should be fine