Terminating process due to non-recoverable failure: perfmon.cxx (555)

499 views
Skip to first unread message

Christophe Dubray

unread,
Dec 10, 2013, 9:03:09 AM12/10/13
to rav...@googlegroups.com
Hey,

I'm seeing the following error in Event Viewer and the RavenDB windows service gets shutdown.

12:35:57 0.908 ESENT Raven.Server (4404) Terminating process due to non-recoverable failure: perfmon.cxx (555)

Any clue what this means?

I have around 900 existing databases, thinking this could have something to do with the performance counters being created for each database?

Oren Eini (Ayende Rahien)

unread,
Dec 11, 2013, 7:24:36 AM12/11/13
to ravendb
This is probably an esent issue, is there anything else in the event log?

Oren Eini
CEO
Hibernating Rhinos
Office:    +972-4-674-7811
Fax:       +972-153-4622-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+u...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

Christophe Dubray

unread,
Dec 13, 2013, 4:22:48 AM12/13/13
to rav...@googlegroups.com
Here are the events just before the process being terminated:
 
Source: Esent, Raven.Server (13424) Terminating process due to non-recoverable failure: perfmon.cxx (555)

Source: Esent, Raven (13424) 308-1WU68p-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\Data: The database engine attached a database (613, C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\Data). (Time=0 seconds) 
 
Internal Timing Sequence: [1] 0.000, [2] 0.016, [3] 0.000, [4] 0.000, [5] 0.000, [6] 0.031, [7] 0.000, [8] 0.015, [9] 0.000, [10] 0.000, [11] 0.000, [12] 0.000. 
Saved Cache: 1

Source: Esent, Raven (13424) 308-1WU68p-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\Data: The database engine started a new instance (306). (Time=2 seconds) 
 
Internal Timing Sequence: [1] 0.016, [2] 0.000, [3] 0.000, [4] 0.624, [5] 1.185, [6] 0.468, [7] 0.437, [8] 0.000, [9] 0.000, [10] 0.000.

Source: Esent, Raven (13424) 308-1WU68p-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\Data: The database engine has successfully completed recovery steps.

Source: Esent, Raven (13424) 308-1WU68p-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\Data: The database engine has begun replaying logfile C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\logs\RVN.log.

Source: Esent, Raven (13424) 308-1WU68p-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\Data: The database engine is initiating recovery steps.

Source: Esent, Raven (13424) 308-1WU68p-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-fr\Data: The database engine (6.02.9200.0000) is starting a new instance (306).

Source: LoadPerf, Performance counters for the RavenDB 2.0 (RavenDB 2.0) service were loaded successfully. The Record Data in the data section contains the new index values assigned to this service.

Source: LoadPerf, Performance counters for the ravendb 2.0 (ravendb 2.0) service were removed successfully. The Record Data contains the new values of the system Last Counter and Last Help registry entries.

Source: Esent, Raven (13424) 307-1SWJfE-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\Data: The database engine attached a database (611, C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\Data). (Time=0 seconds) 
 
Internal Timing Sequence: [1] 0.000, [2] 0.016, [3] 0.015, [4] 0.000, [5] 0.000, [6] 0.032, [7] 0.000, [8] 0.000, [9] 0.000, [10] 0.000, [11] 0.000, [12] 0.000. 
Saved Cache: 1

Source: Esent, Raven (13424) 307-1SWJfE-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\Data: The database engine started a new instance (305). (Time=2 seconds) 
 
Internal Timing Sequence: [1] 0.000, [2] 0.000, [3] 0.000, [4] 0.624, [5] 0.889, [6] 0.390, [7] 0.327, [8] 0.000, [9] 0.000, [10] 0.000.

Source: Esent, Raven (13424) 307-1SWJfE-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\Data: The database engine has successfully completed recovery steps.

Source: Esent, Raven (13424) 307-1SWJfE-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\Data: The database engine has begun replaying logfile C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\logs\RVN.log.

Source: Esent, Raven (13424) 307-1SWJfE-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\Data: The database engine is initiating recovery steps.

Source: Esent, Raven (13424) 307-1SWJfE-C:\RavenData\Databases\o3.cbguide-5387.cbischannel-428.culture-en\Data: The database engine (6.02.9200.0000) is starting a new instance (305).

Source: LoadPerf, Performance counters for the RavenDB 2.0 (RavenDB 2.0) service were loaded successfully. The Record Data in the data section contains the new index values assigned to this service.

Source: LoadPerf, Performance counters for the ravendb 2.0 (ravendb 2.0) service were removed successfully. The Record Data contains the new values of the system Last Counter and Last Help registry entries.

I've attached the XML dump of the events from the EventViewer filtering on RavenDB, LoadPerf and ESENT. 

Any ideas? 
ravendb-esent.xml

Oren Eini (Ayende Rahien)

unread,
Dec 13, 2013, 10:42:25 AM12/13/13
to ravendb
Afraid not.
Anything in the debug log?

Oren Eini
CEO
Hibernating Rhinos
Office:    +972-4-674-7811
Fax:       +972-153-4622-7811





--

Christophe Dubray

unread,
Dec 16, 2013, 5:01:32 AM12/16/13
to rav...@googlegroups.com
I've attached a warning & error log from the RavenDB server from today morning. I can't see anything obvious in it?

The server is running RavenDB Server 2.5.2770 unstable.

From the Event Viewer:

Error 2013-12-16 09:57:27 ESENT 908 General
Raven.Server (3372) Terminating process due to non-recoverable failure: perfmon.cxx (555)

Saw a new error that I haven't seen previously:
Error 2013-12-16 09:21:59 ESENT 902 Transaction Manager
Raven (3372) 234-1ZAyfs-C:\RavenData\Databases\o3.cbguide-3510.cbischannel-125.culture-fr\Data: The database engine detected multiple threads illegally using the same database session to perform database operations. 
SessionId: 0x000000010142A3C0 
Session-context: 0x00000000000002E9 
Session-context ThreadId: 0x0000000000004328 
Current ThreadId: 0x0000000000004328 
Session-trace: 

OS Info:
OS Name:                   Microsoft Windows Server 2012 Datacenter
OS Version:                6.2.9200 N/A Build 9200
2013-12-16.zip

Oren Eini (Ayende Rahien)

unread,
Dec 17, 2013, 8:44:03 AM12/17/13
to ravendb
Okay, that might be related to this, yes.
Any way for us to reproduce this?

Oren Eini
CEO
Hibernating Rhinos
Office:    +972-4-674-7811
Fax:       +972-153-4622-7811





Christophe Dubray

unread,
Jan 3, 2014, 11:46:07 AM1/3/14
to rav...@googlegroups.com
I've been trying to reproduce "Terminating process due to non-recoverable failure: perfmon.cxx (555)" this against 2.5.2750 (I reverted the server to latest stable) without success.
I think I found the source of "The database engine detected multiple threads illegally using the same database session to perform database operations." which could be that we were calling CreateDatabase() when we wanted something similair to EnsureDatabase(..).

I have a fiddler log (available at http://www.filedropper.com/ravenrequests-onlysaz) of the requests we make against RavenDB until "Terminating process due to non-recoverable failure: perfmon.cxx (555)" occurs.
I tried replaying the log in order to reproduce the process termination but I only get a few "The database engine detected multiple threads illegally using the same database session to perform database operations." errors, which I did not see during the original requests, but the process doesn't actually die.

https://gist.github.com/anonymous/8240915 - Gist for creating the databases that are assumed to exist in this fiddler log.

Fitzchak Yitzchaki

unread,
Jan 7, 2014, 10:14:35 AM1/7/14
to <ravendb@googlegroups.com>
Hello,

Can you send us the stack trace of the errors or the log files with the exceptions?

You can send it to sup...@ravendb.net

FYI - I wasn't able to reproduce this error, but I see:
1. Concurrent exception - despiste that I'm reply the request sequently.
2. Error on request There is no transaction with id: 75302129-8d29-48f9-868e-03ad604caf48:4 ready to commit. Did you call PrepareTransaction?

Best Regards,

Fitzchak Yitzchaki

Hibernating Rhinos Core Team



Jared Kells

unread,
Jan 7, 2016, 10:43:02 PM1/7/16
to RavenDB - 2nd generation document database
Reviving this old thread as we're seeing this error message right now. Did you ever find a cause for this issue?


ESENT: ........ (11896) Terminating process due to non-recoverable failure: perfmon.cxx (555)


Application Log:

Faulting application name: ....., version: 3.18.3558.10, time stamp: 0x564536ba
Faulting module name: esent.dll, version: 6.2.9200.16384, time stamp: 0x5010aad8
Exception code: 0xc0000602
Fault offset: 0x00000000001ef44e
Faulting process id: 0x217c
Faulting application start time: 0x01d149b7dc27abab
Faulting application path: ......
Faulting module path: C:\Windows\SYSTEM32\esent.dll
Report Id: 3fad1ec4-b5ae-11e5-942b-00155d53d8bc
Faulting package full name: 
Faulting package-relative application ID:

Oren Eini (Ayende Rahien)

unread,
Jan 8, 2016, 5:40:57 AM1/8/16
to ravendb
This is already handled as a support call

Hibernating Rhinos Ltd  

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

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

 


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

Jahmai Lay

unread,
Jan 10, 2016, 9:41:27 AM1/10/16
to RavenDB - 2nd generation document database
To anyone else who has this issue, it was reproducible in Windows Server 2012 Datacenter, but not in 2012 R2.
Reply all
Reply to author
Forward
0 new messages