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

[Christophe Dubray]

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)]

This is probably an esent issue, is there anything else in the event log?

Oren Eini

CEO

Hibernating Rhinos

Cellular: +972-52-548-6969

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]

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? 

[Oren Eini (Ayende Rahien)]

Afraid not.

Anything in the debug log?

Oren Eini

CEO

Hibernating Rhinos

Cellular: +972-52-548-6969

Office:    +972-4-674-7811

Fax:       +972-153-4622-7811

--

[Christophe Dubray]

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

[Oren Eini (Ayende Rahien)]

Okay, that might be related to this, yes.

Any way for us to reproduce this?

Oren Eini

CEO

Hibernating Rhinos

Cellular: +972-52-548-6969

Office:    +972-4-674-7811

Fax:       +972-153-4622-7811

[Christophe Dubray]

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.

http://www.filedropper.com/ravenrequests-onlysaz The fiddler log

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

[Fitzchak Yitzchaki]

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

Tel: +972-4-6227811

Fax: +972-153-4-6227811

Email: fitz...@hibernatingrhinos.com

[Jared Kells]

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)]

This is already handled as a support call

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

 

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

[Jahmai Lay]

To anyone else who has this issue, it was reproducible in Windows Server 2012 Datacenter, but not in 2012 R2.