Stan wyścigu nhibernate podczas ładowania podmiotu

Question

Mam problem z kondycją wyścigu nhibernate w moim webapp.

Jestem tego świadomy, gdy używam starszych wersji log4net (powinno to być naprawione w wersji 1.2.10), chociaż doświadczyłem tego. Z tego powodu wyłączyliśmy na razie log4net, ponieważ warunki wyścigu powodują awarię usług IIS i nie można tego zaakceptować w produkcji. Stało się to podczas ładowania encji (zobacz opis stosu poniżej). Poza tym podobny problem zdaje się występować w RavenDB, zobacz ten link, a przykład bez NHibernate tutaj 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 

Mapowanie dla użytkowników:

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(); 
} 

kilka szczegółów: Używam dwie sesje dla zapytań i poleceń (oraz dwóch fabryk sesję), ponieważ używam nieco CQRS-like wzór. Jedna sesja do czytania obiektów, druga do wprowadzania zmian (pomaga to w utrzymaniu prostego modelu domeny i przeglądaniu modeli i mapowania, prawdopodobnie różniących się od modelu poleceń).

Warunki wyścigu wystąpiły podczas ładowania wersji Viewmodel użytkownika w moim środowisku programistycznym (pojedynczy użytkownik), ale upewniamy się, że tak się nigdy nie stanie w produkcji, ponieważ spowodowało to awarię usług IIS 7. Ponadto w produkcji będzie wielu użytkowników, więc może błąd wystąpi częściej.

Ponadto mamy wiele starszych kodów, które używają System.Data i MySql.Data.MySqlClient.MySqlDataAdapter do odczytu/zapisu w bazie danych. Czy to może mieć wpływ?

Używam NHibernate 3.1.0 (uaktualni się do wersji 3.3.1GA, ale jest to trudne do odtworzenia) i fluentNhibernate dla moich mapowań.

W sessionfactories są tworzone w global.asax:

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

Moje strony dziedziczą z moim DynamicPage gdzie sesja zapytanie jest otwarte i zamknięte:

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(); 
    } 
} 

W SessionInit (odczytuje identyfikator użytkownika z httpcontext.session i tworzy "webuser", użytkownika z kilkoma prostymi informacjami, takimi jak userId). Później zablokowałem i wykonałem żądanie użytkownika w transakcji, nie wiem, czy byłoby to przydatne.

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; 
} 

Sesje poleceń są w razie potrzeby otwierane i zamykane w bloku używanym.

Zgodnie ze stosu, problem występuje w StreamWriter -> System.Buffer, który jest ponownie wywoływany przez System.IO.SyncTextWriter, który ma być wątkowo bezpieczne opakowanie wokół System.IO.TextWriter.

Skoro stało się to w TextWriter, czy istnieje sposób na obejście tego, aby użyć wątku Safe TextWriter?

Czy otwieranie i zamykanie sesji jest bezpieczne, tak jak to robię w DynamicPage?

Ponieważ jest to oczywiście trudne do odtworzenia, wszelkie pomysły dotyczące tego sposobu są również mile widziane.

[AKTUALIZACJA] Profil NHibernate powiedział, że również otworzyliśmy i zamknęliśmy sesję (w bloku używanym) na stronie wzorcowej, ponieważ była ona potrzebna do sprawdzenia niektórych uprawnień dla bieżącego użytkownika, więc otwarto dwie sesje na żądanie. Przebudowałem go, więc teraz zamiast otwierać sesję w nadklasie strony, otwiera sesję w pliku global.asax na Application_BeginRequest i zamyka ją ponownie w Application_EndRequest, gdzie sesja jest umieszczona w HttpContext.Current.Items.

Ale nie ma pewności, jak sprawdzić, czy to naprawi.

Answer 1

Stamppot, dziękuję za wysłanie tego problemu do StackOverflow; jak wiesz, nie ma zbyt wielu innych informacji na temat tego komunikatu o błędzie, który można znaleźć w Internecie. Mój zespół wpadł na podobny problem kilka miesięcy temu w aplikacji internetowej, która używa NHibernate i log4net. (StringTemplate mogły być zaangażowane zbyt.) My "stałe" THE problen poprzez przekierowanie Console.Out/Error null strumienie (skutecznie je wyłączyć) w Application_Start() obsługi zdarzeń w Global.ascx.cs:

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)); 
} 

Szczegóły: W naszym przypadku błąd "prawdopodobny wyścig ..." był związany z obciążeniem. Na serwerze produkcyjnym ten wyjątek pojawiłby się sporadycznie, powodując awarię procesu roboczego przy każdej okazji. Ostatecznie dowiedzieliśmy się, jak ją odtworzyć, uruchamiając skrypt, który w krótkim czasie zalał aplikację webową wieloma żądaniami. Ścieżki stosu wyjątków, w powiązaniu z kodem źródłowym NHibernate/StringTemplate/log4net, wskazywały na użycie metod Console.Out/Error do logowania w różnych sytuacjach. Wydaje się, że to dziwne miejsce na taki błąd - nie są to metody considered to be thread-safe? Jednak po zastosowaniu powyższego obejścia problem natychmiast zniknął i nie powrócił od tego czasu. Niestety, inne priorytety powstrzymywały nas od głębszego wykopywania - ale bez względu na przyczynę problemu, nie objawiło się ono w żaden inny sposób.

Answer 2

Problem z rozwiązaniem dostarczonym przez @APW polega na tym, że domyślnie StreamWriter ma wartość , a nie wątek bezpieczny. Sprawdź to tutaj: https://msdn.microsoft.com/en-us/library/system.io.streamwriter(v=vs.110).aspx

Przekazując "nowy StreamWriter" do Console.Set * przechodzisz przez instancję nie-wątkową. Myślę, że to kwestia czasu, aby ponownie zobaczyć podobny błąd.

Prawidłowy sposób polega na użyciu metody TextWriter.Synchronized do zawijania niebezpiecznego strumienia.Null.

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

UPD: Zignoruj ​​to. Odkryłem, że Console.SetOut zawijanie dowolnego strumienia do TextWriter.Synchronized (...). Proof.