2012-09-28 14 views
11

Webアプリケーションでnhibernate競合状態に問題があります。エンティティをロードするときのnhibernate競合状態

log4netの古いバージョン(1.2.10で修正されているはずです)を使用しているときにこれが起こっていることに気付いていますが、これもまた経験しました。このため、競合状態がIISをクラッシュさせるため、現時点ではlog4netを無効にしています。これが本番環境では発生することは容認できません。これはエンティティのロード時に発生しました(下記のstacktraceを参照)。これに加えて、同様の問題が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-などを使用するので、私は、クエリやコマンド用の2つのセッション(と2セッションの工場)を使用パターン。 1つはセッションを変更するためのセッション、もう1つはドメインモデルをシンプルにし、モデルを表示したり、コマンドモデルとは異なるマッピングをするのに役立ちます。

私の開発環境(シングルユーザー)に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継承:(SESSIONINITで

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

は、ユーザーIDを読み込み、 httpcontext.sessionから取得し、userIdのような単純な情報を持つ 'webuser'を作成します。後で、ロックをかけて、ユーザーがトランザクションでリクエストを受け取るようにしましたが、それが有用かどうかはわかりません。

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

コマンドセッションは、必要に応じて使用ブロックで開閉されます。

stacktraceによると、この問題はStreamWriter - > System.Bufferで発生し、System.IO.SyncTextWriterによって再度呼び出されます。これはSystem.IO.TextWriterの周りのスレッドセーフラッパーであるはずです。

これはTextWriterで発生したので、スレッドセーフなTextWriterを使用するには、これを回避する方法がありますか?

DynamicPageでセッションを開いたり閉じたりするのは安全ですか?

これは明らかに再現するのが難しいため、そのやり方に関するアイディアも歓迎します。

[UPDATE] ザ・NHibernateのプロファイラは、それが現在のユーザーのためのいくつかの権限を確認するために必要とされたことから、マスターページに、我々はまた、オープンした(使用してブロック内の)セッションを閉じたことを告げたので、2つのセッションがあたりに開かれました要求。私はそれをリファクタリングしました。したがって、ページスーパークラスでセッションを開く代わりに、Application_BeginRequestのglobal.asaxでセッションを開き、SessionがHttpContext.Current.Itemsに置かれているApplication_EndRequestで再び閉じます。

これで解決するかどうかはわかりませんが、テストする方法はありません。

+0

私はこのSOの記事に興味があります。スタックトレースでは、次のようになります。 - jInternet.GetCurrentUser(セッションセッション)がj:\ dev \ app \ app_wwwroot \ App_Code \ SessionInit.csにある:107' SessionInit.csコードには何がありますか? –

+0

Nick、SessionInit.GetCurrentUser()のコードを追加しました。アップデートを参照してください。 – Stamppot

+0

NHibernateでこの問題が毎日、そしてまったく同じ場所に届いています。修正する方法を確認できましたか? –

答えて

12

スタムポット、StackOverflowにこの問題を投稿していただきありがとうございます。ご存じのように、このエラーメッセージに関するその他の情報はWeb上にはありません。私のチームは、NHibernateとlog4netを使用するWebアプリケーションで数ヶ月前に同様の問題に遭遇しました。 (StringTemplateも関与している可能性があります。)私たちは、Global.ascx.cs中のApplication_Start()イベントハンドラに(効果的にそれらを無効にする)のストリームをnullにConsole.Out /エラーをリダイレクトすることによってproblen「固定」:

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

詳細:私たちの場合、「予想される競合状態...」エラーは負荷に関連していました。プロダクションサーバでは、この例外は散発的に発生し、各機会にワーカープロセスをクラッシュさせます。最終的には、短時間で多くのリクエストをWebアプリケーションに流し込んだスクリプトを実行することで、それを再現する方法を見つけました。例外スタックトレースは、NHibernate/StringTemplate/log4netのソースコードと関連づけられている場合、Console.Out/Errorメソッドを使用して様々な状況でロギングすることを指し示していました。このようなエラーが発生する奇妙な場所のようです---これらのメソッドではありませんconsidered to be thread-safe?しかし、上記の回避策を適用した後、問題はすぐに消えてから復帰しませんでした。残念なことに、他の優先事項によって私たちは深く掘り下げることができませんでしたが、問題の根本的な原因が何であれ、それは他の方法では明らかになりませんでした。

+0

awk、この "修正"のおかげで。エラーを遠ざけると、私は満足しています。 – Stamppot

+0

ところで、スクリプトを実行するたびにそれを再現できますか?どのくらいの長さのリクエストなど、何か詳細は?可能であれば、スクリプト自体も素晴らしいでしょう。 – Stamppot

+3

@APW:最近、log4netを1.2.12にアップグレードしたときに、この問題が発生しました。コンソールアウトに書き込むのがなぜそうするのか分かりません。あなたの修正は、グローバルにコンソールログを無効にし、問題を確実に解決します。あなたが行うことができる別の(よりグローバルではない)ことは、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

Console.Set *に "new StreamWriter"を渡すことで、スレッドセーフでないインスタンスを渡しています。だから私は同じようなエラーを再び見るのは時間の問題だと思う。

正しい方法は、安全でないStream.NullをラップするためにTextWriter.Synchronizedメソッドを使用することです。

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

UPD:これは無視してください。 Console.SetOutがTextWriter.Synchronized(...)にストリームをラップしていることがわかりました。 Proof.

関連する問題