2012-09-28 47 views
11

我在webapp中遇到了nhibernate競態條件問題。加載實體時nhibernate競爭條件

我知道這發生在使用舊版本的log4net時(應該在1.2.10中修復),儘管我也遇到過這種情況。正因爲如此,我們現在已經禁用了log4net,因爲競爭條件導致IIS崩潰,並且在生產中發生這種情況是不可接受的。加載實體時發生這種情況(請參閱下面的堆棧跟蹤)。除此之外,RavenDB中似乎也出現了類似的問題,請參閱此link,以及此處沒有NHibernate的示例link

堆棧跟蹤:

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 

用戶的映射:

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

一些細節:我使用的查詢和命令(和兩個會話工廠)兩會,因爲我用的有點CQRS樣模式。一個用於讀取對象的會話,一個用於進行更改(這有助於保持我的域模型簡單並查看可能與命令模型不同的模型和映射)。

在我的開發環境(單用戶)中加載User viewmodel時發生競態條件,但我們確保這不會發生在生產中,因爲它會使IIS 7崩潰。另外,在生產中會有多個用戶,所以也許錯誤可能會更頻繁地發生。

此外,我們有很多遺留代碼,它使用System.Data和MySql.Data.MySqlClient.MySqlDataAdapter讀取/寫入數據庫。這可能會有影響嗎?我使用NHibernate的3.1.0(將升級到3.3.1GA,但這是很難重現),和我的映射fluentNhibernate。

的sessionfactories是在Global.asax創建:

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

我的網頁從我DynamicPage其中查詢會話打開繼承和關閉:

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

在SessionInit(讀取用戶ID來自httpcontext.session,並創建一個'webuser',一個用戶擁有一些簡單的信息,比如userId)。後來,我把鎖放在了一個事務中完成了用戶請求,並不確定它是否有用。

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

命令會話在需要時在使用塊中打開和關閉。

根據堆棧跟蹤,問題發生在StreamWriter - > System.Buffer中,它又被System.IO.SyncTextWriter調用,它應該是System.IO.TextWriter的線程安全包裝。

因爲這發生在TextWriter中,有沒有辦法解決這個問題,使用線程安全的TextWriter?

在DynamicPage中以何種方式打開和關閉會話是否安全?

由於這顯然很難重現,所以如何做到這一點的任何想法都是受歡迎的。

[UPDATE] NHibernate Profiler告訴我們,在母版頁中也打開和關閉了一個會話(在一個使用塊中),因爲需要檢查當前用戶的一些權限,所以每個會話都打開請求。我重構了它,所以現在它不是在頁面超類中打開一個會話,而是在Application_BeginRequest的global.asax中打開會話,並在Application_EndRequest上關閉該會話,會話放在HttpContext.Current.Items中。

但沒有確定的測試方式,如果這可以修復它。

+0

我對這篇SO文章感興趣。在堆棧跟蹤中,你有這樣的: - 'SessionInit.GetCurrentUser(ISession session)in j:\ dev \ app \ app_wwwroot \ App_Code \ SessionInit.cs:107' SessionInit.cs代碼中有什麼? –

+0

尼克,我添加了SessionInit.GetCurrentUser()的代碼。查看更新。 – Stamppot

+0

我在NHibernate的同一個地方,現在每時每刻都會遇到這個問題 - 您是否設法確定如何解決? –

回答

12

Stamppot,感謝您發佈此問題到StackOverflow;如你所知,在網上找不到關於這個錯誤信息的其他信息。幾個月前,我的團隊在使用NHibernate和log4net的webapp中遇到了類似的問題。 (StringTemplate的可能已經介入了。)我們的「固定」通過重定向Console.Out /錯誤爲空在Application_Start()事件處理流(有效地禁用它們)在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)); 
} 

詳情:在我們的例子中,「可能的競爭條件...」錯誤與負載有關。在生產服務器上,這種異常會偶爾出現,每次都會導致工作進程崩潰。最終,我們通過運行一個腳本,在短時間內滿足許多請求的情況下,找到了如何重現它的方法。異常堆棧跟蹤與NHibernate/StringTemplate/log4net源代碼相關時,指出使用Console.Out/Error方法記錄各種情況。看起來像一個奇怪的地方出現這樣的錯誤---是不是這些方法considered to be thread-safe?然而,在我們應用上述解決方法後,問題立即消失,並且從那以後沒有返回。不幸的是,其他優先事項使我們無法深入挖掘 - 但無論問題的根源如何,它都沒有以任何其他方式表現出來。

+0

Awk,感謝您的「修復」。如果它保持錯誤,我很高興。 – Stamppot

+0

順便說一句,你可以在每次運行腳本時重現它嗎?關於它的任何細節,比如多長時間的請求等等?如果可能的話,腳本本身也會很好。 – Stamppot

+3

@APW:當我們最近將log4net升級到1.2.12時,出現了這個確切的問題。不知道爲什麼寫入Console Out會這樣做。您的修補程序將全局禁用控制檯日誌記錄,這將最終解決問題。你可以做的另一個(不太全局的)事情是確保在NHibernate的情況下,「show_sql」配置選項設置爲false。 show_sql直接*寫入控制檯輸出,完全獨立於log4net。我認爲這是導致OP出現問題的具體情況。 –

0

@APW提供的解決方案的問題是默認情況下StreamWriter是 不是線程安全的。在此處檢查:https://msdn.microsoft.com/en-us/library/system.io.streamwriter(v=vs.110).aspx

通過將「新StreamWriter」傳遞給Console.Set *,您正在傳遞非線程安全實例。所以我認爲再次看到類似的錯誤是時間問題。

正確的方法是使用TextWriter.Synchronized方法來包裝不安全的Stream.Null。

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

UPD:請忽略此操作。我發現Console.SetOut將任何流封裝到TextWriter.Synchronized(...)中。 Proof.