Nhibernate Race-Bedingung beim Laden der Entität

Question

Ich habe ein Problem mit einer Nibernate-Race-Bedingung in meiner Webapp.

Ich bin mir bewusst, dass dies passiert, wenn Sie ältere Versionen von log4net verwenden (sollte in 1.2.10 behoben sein), obwohl ich das auch erlebt habe. Aus diesem Grund haben wir log4net für jetzt deaktiviert, da die Race-Bedingung IIS stört und es inakzeptabel ist, dass dies in der Produktion passiert. Dies ist beim Laden einer Entity passiert (siehe Stacktrace unten). Außerdem scheint ein ähnliches Problem in RavenDB aufgetreten zu sein, siehe link, und ein Beispiel ohne NHibernate hier link.

Stacktrace:

Server Error in '/' Application. 
Probable I/O race condition detected while copying memory. The I/O package is not thread safe by default. In multithreaded applications, a stream must be accessed in a thread-safe way, such as a thread-safe wrapper returned by TextReader's or TextWriter's Synchronized methods. This also applies to classes like StreamWriter and StreamReader. 
Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code. 

Exception Details: System.IndexOutOfRangeException: Probable I/O race condition detected while copying memory. The I/O package is not thread safe by default. In multithreaded applications, a stream must be accessed in a thread-safe way, such as a thread-safe wrapper returned by TextReader's or TextWriter's Synchronized methods. This also applies to classes like StreamWriter and StreamReader. 

Source Error: 


Line 105: 
Line 106:    if(webUser.Id > 0) { // logged in 
Line 107:     _user = session.Get<User>(webUser.Id); 
Line 108:     if(_user == null) { // session exists, but no user in DB with this id 
Line 109:      new SessionInit().Remove(); 


Source File: \App_Code\SessionInit.cs Line: 107 

Stack Trace: 


[IndexOutOfRangeException: Probable I/O race condition detected while copying memory. The I/O package is not thread safe by default. In multithreaded applications, a stream must be accessed in a thread-safe way, such as a thread-safe wrapper returned by TextReader's or TextWriter's Synchronized methods. This also applies to classes like StreamWriter and StreamReader.] 
    System.Buffer.InternalBlockCopy(Array src, Int32 srcOffsetBytes, Array dst, Int32 dstOffsetBytes, Int32 byteCount) +0 
    System.IO.StreamWriter.Write(Char[] buffer, Int32 index, Int32 count) +117 
    System.IO.TextWriter.WriteLine(String value) +204 
    System.IO.SyncTextWriter.WriteLine(String value) +63 
    NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd) +71 
    NHibernate.Loader.Loader.GetResultSet(IDbCommand st, Boolean autoDiscoverTypes, Boolean callable, RowSelection selection, ISessionImplementor session) +580 
    NHibernate.Loader.Loader.DoQuery(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies) +275 
    NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(ISessionImplementor session, QueryParameters queryParameters, Boolean returnProxies) +205 
    NHibernate.Loader.Loader.LoadEntity(ISessionImplementor session, Object id, IType identifierType, Object optionalObject, String optionalEntityName, Object optionalIdentifier, IEntityPersister persister) +590 

[GenericADOException: could not load an entity: [app.Presentation.User#338][SQL: SELECT user0_.userID as userID24_0_, user0_.instituteID as institut2_24_0_, user0_.email as email24_0_, user0_.password as password24_0_, user0_.username as username24_0_, user0_.mod_remarks as mod6_24_0_, user0_.lastLogin as lastLogin24_0_, user0_.active as active24_0_, user0_.isAcademic as isAcademic24_0_, user0_.created as created24_0_, (select p.firstName from ej_profile p where p.userID = user0_.userID) as formula11_0_, (select p.lastName from ej_profile p where p.userID = user0_.userID) as formula12_0_, (select p.timeZone from ej_profile p where p.userID = user0_.userID) as formula13_0_ FROM ej_user user0_ WHERE user0_.userID=?]] 
    NHibernate.Loader.Loader.LoadEntity(ISessionImplementor session, Object id, IType identifierType, Object optionalObject, String optionalEntityName, Object optionalIdentifier, IEntityPersister persister) +960 
    NHibernate.Loader.Entity.AbstractEntityLoader.Load(ISessionImplementor session, Object id, Object optionalObject, Object optionalId) +76 
    NHibernate.Loader.Entity.AbstractEntityLoader.Load(Object id, Object optionalObject, ISessionImplementor session) +32 
    NHibernate.Event.Default.DefaultLoadEventListener.LoadFromDatasource(LoadEvent event, IEntityPersister persister, EntityKey keyToLoad, LoadType options) +173 
    NHibernate.Event.Default.DefaultLoadEventListener.Load(LoadEvent event, IEntityPersister persister, EntityKey keyToLoad, LoadType options) +181 
    NHibernate.Event.Default.DefaultLoadEventListener.OnLoad(LoadEvent event, LoadType loadType) +1019 
    NHibernate.Impl.SessionImpl.FireLoad(LoadEvent event, LoadType loadType) +403 
    NHibernate.Impl.SessionImpl.Get(String entityName, Object id) +469 
    NHibernate.Impl.SessionImpl.Get(Type entityClass, Object id) +374 
    NHibernate.Impl.SessionImpl.Get(Object id) +391 
    SessionInit.GetCurrentUser(ISession session) in j:\dev\app\app_wwwroot\App_Code\SessionInit.cs:107 
    DynamicPage.OnPreInit(EventArgs e) in j:\dev\app\app_wwwroot\App_Code\DynamicPage.cs:24 
    MemberPage.OnPreInit(EventArgs e) in j:\dev\app\app_wwwroot\App_Code\MemberPage.cs:20 
    members_stocks_Default.OnPreInit(EventArgs e) in j:\dev\app\app_wwwroot\members\Default.aspx.cs:28 
    System.Web.UI.Page.PerformPreInit() +49 
    System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint) +1716 

Die Zuordnung für Benutzer:

public class UserViewMapping : ClassMap<User> 
{ 
    public UserViewMapping() { 
     Table("ej_user"); 
     Id(s => s.Id, "userID").GeneratedBy.Native(); 
     Map(s => s.InstituteId, "instituteID"); 
     Map(s => s.Email, "email"); 
     Map(s => s.Password, "password"); 
     Map(s => s.Name, "username"); 
     Map(s => s.ModRemarks, "mod_remarks"); 
     Map(s => s.LastLogin, "lastLogin"); 
     Map(s => s.Active, "active"); 
     Map(s => s.IsAcademic, "isAcademic"); 
     Map(s => s.Created, "created"); 
     Map(s => s.FirstName).Formula("(select p.firstName from ej_profile p where p.userID = userID)"); 
     Map(s => s.LastName).Formula("(select p.lastName from ej_profile p where p.userID = userID)"); 
     Map(s => s.TimeZone).Formula("(select p.timeZone from ej_profile p where p.userID = userID)"); 
     HasMany<ProfileViewModel>(s => s.Profiles) 
      .Table("ej_profile") 
      .KeyColumn("userID") 
      .Cascade.All() 
      .Inverse(); 
} 

Einige Details: Ich verwende zwei Sitzungen für Abfragen und Befehle (und zwei Sitzungs Fabriken), seit ich ein etwas CQRS-like verwenden Muster. Eine Sitzung für das Lesen von Objekten, eine für das Vornehmen von Änderungen (dies hilft mir, mein Domänenmodell einfach zu halten und Modelle und Zuordnungen anzuzeigen, die möglicherweise vom Befehlsmodell abweichen).

Die Racebedingung trat beim Laden des User-Viewmodels in meiner Entwicklungsumgebung (Einzelbenutzer) auf, aber wir stellen sicher, dass dies in der Produktion nie passieren wird, da es IIS 7 abgestürzt ist. Auch in der Produktion gibt es mehrere Benutzer, Vielleicht wird der Fehler möglicherweise öfter auftreten.

Außerdem haben wir eine Menge Legacy-Code, der System.Data und MySql.Data.MySqlClient.MySqlDataAdapter zum Lesen/Schreiben in die Datenbank verwendet. Könnte das Einfluss haben?

Ich benutze NHibernate 3.1.0 (wird auf 3.3.1GA aktualisieren, aber das ist schwer zu reproduzieren), und fluentNhibernate für meine Mappings.

Die sessionfactories sind in der global.asax erstellt:

void Application_Start(object sender, EventArgs e) 
{ 
    QuerySessionFactory.Create(connectionString); 
    CommandSessionManager.Initialize(connString); 
} 

Meine Seiten von meinem DynamicPage erben, wo die Abfrage-Sitzung geöffnet und geschlossen:

public class DynamicPage : System.Web.UI.Page 
{ 
    protected override void OnPreInit(EventArgs e) 
    { 
     Session = QuerySessionFactory.Instance.OpenSession(); 
    } 

    protected override void OnUnload(EventArgs e) { 
     base.OnUnload(e); 
     Session.Close(); 
    } 
} 

Im SESSION (liest userID von httpcontext.session, und erstellt einen "Webuser", ein Benutzer mit einigen einfachen Informationen wie userId). Später habe ich die Sperre umgelegt und den Benutzer dazu gebracht, eine Anfrage in einer Transaktion zu erhalten, nicht sicher, ob es nützlich wäre.

public IUser GetCurrentUser(ISession session) { 
     if(_user == null) { 
      var webUser = new SessionInit().Get; 

      if(webUser.Id > 0) { // logged in 
       lock(_lock) { 
        using(var tx = session.BeginTransaction()) { 
         _user = session.Get<User>(webUser.Id); 
         tx.Commit(); 
        } 
       } 
       if(_user == null) { // session exists, but no user in DB with this id 
        new SessionInit().Remove(); 
       } 
       ((User)_user)._currentUser = webUser; 
      } else { 
       if(webUser is CurrentUser && webUser.Id == 0) { 
        if(HttpContext.Current.Session != null) { 
         HttpContext.Current.Response.Cookies.Remove("ASPSESSID"); 
         HttpContext.Current.Request.Cookies.Remove("ASPSESSID"); 
         HttpContext.Current.Session.RemoveAll(); 
         HttpContext.Current.Session.Abandon(); 
        } 

        if(HttpContext.Current.Request.Url.Host.Contains("members")) 
         HttpContext.Current.Response.Redirect("/login"); 
       } else 
        if(webUser.Id == 0) { 
         var userId = webUser.Id; 
         var userName = webUser.UserName; 
         var loginUrl = webUser.LoginUrl; 
         var clientIp = webUser.ClientIp; 
         var isAdmin = webUser.IsAdmin(); 
         return new eLab.Presentation.Visitor(userId, userName, loginUrl, clientIp, isAdmin, webUser.Theme); 
        } 
      } 
      if (_user == null) 
       return new eLab.Presentation.Visitor(webUser.Id, webUser.UserName, webUser.LoginUrl, webUser.ClientIp, false, webUser.Theme); 
     } 
     return _user; 
} 

Befehlssitzungen werden bei Bedarf in einem Verwendungsblock geöffnet und geschlossen.

Nach dem Stacktrace tritt das Problem in der StreamWriter -> System.Buffer, die wiederum von System.IO.SyncTextWriter aufgerufen wird, die thread-sichere Wrapper um System.IO.TextWriter sein soll.

Da dies im TextWriter passiert ist, gibt es eine Möglichkeit, dies zu umgehen, um einen threadsafe TextWriter zu verwenden?

Ist es sicher, die Sitzung so zu öffnen und zu schließen, wie ich es in DynamicPage mache?

Da dies offensichtlich schwierig zu reproduzieren ist, sind auch Ideen dazu willkommen.Der NHibernate Profiler sagte, dass wir auch eine Sitzung (in einem Benutzungsblock) auf einer Masterseite geöffnet und geschlossen haben, da sie benötigt wurde, um einige Berechtigungen für den aktuellen Benutzer zu überprüfen, sodass pro Sitzung zwei Sitzungen geöffnet wurden anfordern. Ich habe es refactored, so dass es jetzt, anstatt eine Sitzung in einer Seitenoberklasse zu öffnen, es die Sitzung in der global.asax auf Application_BeginRequest öffnet und es wieder auf Application_EndRequest schließt, wo die Sitzung in HttpContext.Current.Items abgelegt wird.

Aber keine sichere Art zu testen, wenn dies es behebt.

Answer 1

Stamppot, danke, dass Sie dieses Problem an StackOverflow gesendet haben; Wie Sie wissen, gibt es nicht viele andere Informationen zu dieser Fehlermeldung im Web. Mein Team stieß vor ein paar Monaten in einer Webanwendung, die NHibernate und log4net verwendet, auf ein ähnliches Problem. (String könnte auch beteiligt.) Wir "fixiert" die problen von Console.Out/Error Umleitung Ströme auf null in der Application_Start() Ereignishandler in Global.ascx.cs (effektiv sie zu deaktivieren):

protected void Application_Start(object sender, EventArgs e) 
{ 
    Console.SetOut(new System.IO.StreamWriter(System.IO.Stream.Null)); 
    Console.SetError(new System.IO.StreamWriter(System.IO.Stream.Null)); 
} 

Details: In unserem Fall war der Fehler "wahrscheinliche Racebedingung ..." mit der Last verbunden. Auf dem Produktionsserver würde diese Ausnahme sporadisch auftreten und den Worker-Prozess bei jeder Gelegenheit abstürzen. Schließlich haben wir herausgefunden, wie man es reproduzieren kann, indem man ein Skript ausführt, das die Webapp mit vielen Anfragen in kurzer Zeit überschwemmt. Die Exception-Stack-Traces wiesen bei der Korrelation mit dem NHibernate/StringTemplate/log4net-Quellcode auf die Verwendung der Console.Out/Error-Methoden zum Anmelden in verschiedenen Situationen hin. Scheint wie ein seltsamer Ort für einen solchen Fehler entstehen - sind nicht diese Methoden considered to be thread-safe? Allerdings, nachdem wir die obige Problemumgehung angewendet, verschwand das Problem sofort und ist seitdem nicht zurückgekehrt. Leider haben uns andere Prioritäten davon abgehalten, tiefer zu graben - aber was auch immer die Ursache des Problems ist, es hat sich auf keine andere Weise manifestiert.

Answer 2

Das Problem mit der von @APW bereitgestellten Lösung ist, dass StreamWriter standardmäßig nicht threadsicher ist. Überprüfen Sie es hier: https://msdn.microsoft.com/en-us/library/system.io.streamwriter(v=vs.110).aspx

Durch die Übergabe "neue StreamWriter" Console.Set * übergeben Sie nicht Thread-sichere Instanz. Also denke ich, es ist eine Frage der Zeit, um wieder ähnliche Fehler zu sehen.

Richtiger Weg wäre TextWriter.Synchronized Methode, unsafe Stream.Null zu wickeln.

using System.IO; 
... 
var nullStream = TextWriter.Synchronized(TextWriter.Null); 
Console.SetOut(nullStream); 
Console.SetError(nullStream); 

UPD: Bitte ignorieren Sie dies. Ich habe festgestellt, dass Console.SetOut jeden Stream in TextWriter.Synchronized (...) umschließt. Proof.