99
1010
1111using System . Collections ;
12-
12+ using System . Collections . Concurrent ;
13+ using System . Linq ;
14+ using System . Threading ;
15+ using System . Threading . Tasks ;
16+ using NHibernate . Cfg ;
1317using NHibernate . Impl ;
14-
18+ using NHibernate . SqlCommand ;
19+ using NHibernate . Type ;
1520using NUnit . Framework ;
21+ using NHibernate . Linq ;
1622
1723namespace NHibernate . Test . NHSpecificTest . Logs
1824{
@@ -24,7 +30,6 @@ namespace NHibernate.Test.NHSpecificTest.Logs
2430 using log4net . Core ;
2531 using log4net . Layout ;
2632 using log4net . Repository . Hierarchy ;
27- using System . Threading . Tasks ;
2833
2934 [ TestFixture ]
3035 public class LogsFixtureAsync : TestCase
@@ -39,6 +44,33 @@ protected override string MappingsAssembly
3944 get { return "NHibernate.Test" ; }
4045 }
4146
47+ protected override void Configure ( Configuration configuration )
48+ {
49+ base . Configure ( configuration ) ;
50+ configuration . SetProperty ( Cfg . Environment . UseSecondLevelCache , "false" ) ;
51+ }
52+
53+ protected override void OnSetUp ( )
54+ {
55+ using ( var s = Sfi . OpenSession ( ) )
56+ using ( var t = s . BeginTransaction ( ) )
57+ {
58+ s . Save ( new Person ( ) ) ;
59+ s . Save ( new Person ( ) ) ;
60+ t . Commit ( ) ;
61+ }
62+ }
63+
64+ protected override void OnTearDown ( )
65+ {
66+ using ( var s = Sfi . OpenSession ( ) )
67+ using ( var t = s . BeginTransaction ( ) )
68+ {
69+ s . CreateQuery ( "delete from Person" ) . ExecuteUpdate ( ) ;
70+ t . Commit ( ) ;
71+ }
72+ }
73+
4274 [ Test ]
4375 public async Task WillGetSessionIdFromSessionLogsAsync ( )
4476 {
@@ -47,15 +79,128 @@ public async Task WillGetSessionIdFromSessionLogsAsync()
4779 using ( var spy = new TextLogSpy ( "NHibernate.SQL" , "%message | SessionId: %property{sessionId}" ) )
4880 using ( var s = Sfi . OpenSession ( ) )
4981 {
50- var sessionId = ( ( SessionImpl ) s ) . SessionId ;
82+ var sessionId = ( ( SessionImpl ) s ) . SessionId ;
5183
52- await ( s . GetAsync < Person > ( 1 ) ) ; //will execute some sql
84+ await ( s . GetAsync < Person > ( 1 ) ) ; //will execute some sql
5385
5486 var loggingEvent = spy . GetWholeLog ( ) ;
5587 Assert . That ( loggingEvent . Contains ( sessionId . ToString ( ) ) , Is . True ) ;
5688 }
5789 }
5890
91+ [ Test ]
92+ public async Task WillGetSessionIdFromConsecutiveSessionsLogsAsync ( )
93+ {
94+ GlobalContext . Properties [ "sessionId" ] = new SessionIdCapturer ( ) ;
95+
96+ using ( var spy = new TextLogSpy ( "NHibernate.SQL" , "%message | SessionId: %property{sessionId}" ) )
97+ {
98+ var sessions = Enumerable . Range ( 1 , 10 ) . Select ( i => Sfi . OpenSession ( ) ) . ToArray ( ) ;
99+ try
100+ {
101+ for ( var i = 0 ; i < 10 ; i ++ )
102+ for ( var j = 0 ; j < 10 ; j ++ )
103+ {
104+ var s = sessions [ j ] ;
105+ await ( s . GetAsync < Person > ( i * 10 + j ) ) ; //will execute some sql
106+ }
107+ }
108+ finally
109+ {
110+ foreach ( var s in sessions )
111+ {
112+ s . Dispose ( ) ;
113+ }
114+ }
115+
116+ var loggingEvent = spy . GetWholeLog ( ) ;
117+ for ( var i = 0 ; i < 10 ; i ++ )
118+ for ( var j = 0 ; j < 10 ; j ++ )
119+ {
120+ var sessionId = sessions [ j ] . GetSessionImplementation ( ) . SessionId ;
121+ Assert . That ( loggingEvent , Does . Contain ( $ "p0 = { i * 10 + j } [Type: Int32 (0:0:0)] | SessionId: { sessionId } ") ) ;
122+ }
123+ }
124+ }
125+
126+ [ Test ]
127+ public async Task WillGetSessionIdFromInterlacedSessionsLogsAsync ( )
128+ {
129+ GlobalContext . Properties [ "sessionId" ] = new SessionIdCapturer ( ) ;
130+ var interceptor = new InterlacedSessionInterceptor ( Sfi ) ;
131+ using ( var spy = new TextLogSpy ( "NHibernate.SQL" , "%message | SessionId: %property{sessionId}" ) )
132+ using ( var s = Sfi . WithOptions ( ) . Interceptor ( interceptor ) . OpenSession ( ) )
133+ {
134+ // Trigger an operation which will fire many interceptor events, before and after s own logging.
135+ var persons = await ( s . Query < Person > ( ) . ToListAsync ( ) ) ;
136+
137+ var loggingEvent = spy . GetWholeLog ( ) ;
138+ for ( var i = 0 ; i < interceptor . SessionIds . Count ; i ++ )
139+ {
140+ var sessionId = interceptor . SessionIds [ i ] ;
141+ Assert . That ( loggingEvent , Does . Contain ( $ "p0 = { i + 1 } [Type: Int32 (0:0:0)] | SessionId: { sessionId } ") ) ;
142+ }
143+ Assert . That ( loggingEvent , Does . Contain ( $ "Person person0_ | SessionId: { s . GetSessionImplementation ( ) . SessionId } ") ) ;
144+ }
145+ }
146+
147+ [ Test ]
148+ public async Task WillGetSessionIdFromSessionLogsConcurrentAsync ( )
149+ {
150+ GlobalContext . Properties [ "sessionId" ] = new SessionIdCapturer ( ) ;
151+
152+ // Do not use a ManualResetEventSlim, it does not support async and exhausts the task thread pool in the
153+ // async counterparts of this test. SemaphoreSlim has the async support and release the thread when waiting.
154+ var semaphore = new SemaphoreSlim ( 0 ) ;
155+ var failures = new ConcurrentBag < Exception > ( ) ;
156+ var sessionIds = new ConcurrentDictionary < int , Guid > ( ) ;
157+ using ( var spy = new TextLogSpy ( "NHibernate.SQL" , "%message | SessionId: %property{sessionId}" ) )
158+ {
159+ await ( Task . WhenAll ( Enumerable . Range ( 1 , 12 ) . Select ( async i =>
160+ {
161+ if ( i > 10 )
162+ {
163+ // Give some time to threads for reaching the wait, having all of them ready to do most of their job concurrently.
164+ await ( Task . Delay ( 100 ) ) ;
165+ semaphore . Release ( 10 ) ;
166+ return ;
167+ }
168+ try
169+ {
170+ using ( var s = Sfi . OpenSession ( ) )
171+ {
172+ sessionIds . AddOrUpdate (
173+ i ,
174+ s . GetSessionImplementation ( ) . SessionId ,
175+ ( ti , old ) => throw new InvalidOperationException (
176+ $ "Thread number { ti } has already session id { old } , while attempting to set it to"+
177+ $ " { s . GetSessionImplementation ( ) . SessionId } ") ) ;
178+ await ( semaphore . WaitAsync ( ) ) ;
179+
180+ for ( int j = 0 ; j < 10 ; j ++ )
181+ {
182+ await ( s . GetAsync < Person > ( i * 10 + j ) ) ; //will execute some sql
183+ }
184+ }
185+ }
186+ catch ( Exception e )
187+ {
188+ failures . Add ( e ) ;
189+ }
190+ } ) ) ) ;
191+
192+ Assert . That ( failures , Is . Empty , $ "{ failures . Count } task(s) failed.") ;
193+
194+ var loggingEvent = spy . GetWholeLog ( ) ;
195+ for ( var i = 1 ; i < 11 ; i ++ )
196+ for ( var j = 0 ; j < 10 ; j ++ )
197+ {
198+ var sessionId = sessionIds [ i ] ;
199+ Assert . That ( loggingEvent , Does . Contain ( $ "p0 = { i * 10 + j } [Type: Int32 (0:0:0)] | SessionId: { sessionId } ") ) ;
200+ }
201+ }
202+ }
203+
59204 // IFixingRequired interface ensures the value is evaluated at log time rather than at log buffer flush time.
60205 public class SessionIdCapturer : IFixingRequired
61206 {
@@ -83,7 +228,7 @@ public TextLogSpy(string loggerName, string pattern)
83228 Threshold = Level . All ,
84229 Writer = new StringWriter ( stringBuilder )
85230 } ;
86- loggerImpl = ( Logger ) LogManager . GetLogger ( typeof ( LogsFixtureAsync ) . Assembly , loggerName ) . Logger ;
231+ loggerImpl = ( Logger ) LogManager . GetLogger ( typeof ( LogsFixtureAsync ) . Assembly , loggerName ) . Logger ;
87232 loggerImpl . AddAppender ( appender ) ;
88233 previousLevel = loggerImpl . Level ;
89234 loggerImpl . Level = Level . All ;
@@ -100,7 +245,37 @@ public void Dispose()
100245 loggerImpl . Level = previousLevel ;
101246 }
102247 }
103- }
104248
249+ public class InterlacedSessionInterceptor : EmptyInterceptor
250+ {
251+ private readonly ISessionFactory _sfi ;
252+
253+ public System . Collections . Generic . List < Guid > SessionIds { get ; } = new System . Collections . Generic . List < Guid > ( ) ;
105254
255+ public InterlacedSessionInterceptor ( ISessionFactory sfi )
256+ {
257+ _sfi = sfi ;
258+ }
259+
260+ public override SqlString OnPrepareStatement ( SqlString sql )
261+ {
262+ using ( var s = _sfi . OpenSession ( ) )
263+ {
264+ SessionIds . Add ( s . GetSessionImplementation ( ) . SessionId ) ;
265+ s . Get < Person > ( SessionIds . Count ) ; //will execute some sql
266+ }
267+ return base . OnPrepareStatement ( sql ) ;
268+ }
269+
270+ public override bool OnLoad ( object entity , object id , object [ ] state , string [ ] propertyNames , IType [ ] types )
271+ {
272+ using ( var s = _sfi . OpenSession ( ) )
273+ {
274+ SessionIds . Add ( s . GetSessionImplementation ( ) . SessionId ) ;
275+ s . Get < Person > ( SessionIds . Count ) ; //will execute some sql
276+ }
277+ return base . OnLoad ( entity , id , state , propertyNames , types ) ;
278+ }
279+ }
280+ }
106281}
0 commit comments