From f245b8f509aff39c0521611069b94f89f1d6479a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Delaporte?= <12201973+fredericdelaporte@users.noreply.github.com> Date: Fri, 2 Feb 2024 21:59:39 +0100 Subject: [PATCH 01/22] Add a test case for system transactions timeout --- .../SystemTransactionFixture.cs | 20 +++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs index e5fb6fd46c0..73cfb38c883 100644 --- a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs @@ -643,6 +643,26 @@ public void CanUseSessionWithManyDependentTransaction(bool explicitFlush) } } + [Test] + public void SupportsTransactionTimeout() + { + // Test case adapted from https://github.com/kaksmet/NHibBugRepro + using (var s = OpenSession()) + using (var t = s.BeginTransaction()) + { + for (var i = 0; i < 5000; i++) + { + var person = new Person(); + s.Save(person); + } + + t.Commit(); + } + + var txOptions = new TransactionOptions { Timeout = TimeSpan.FromMilliseconds(1) }; + + } + [Theory, Explicit("Bench")] public void BenchTransactionAccess(bool inTransaction) { From 7df425a338d44f458d938e2ec2503b5183fecd6c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Delaporte?= <12201973+fredericdelaporte@users.noreply.github.com> Date: Sat, 3 Feb 2024 22:00:36 +0100 Subject: [PATCH 02/22] Fix concurrency issues on TransactionScope timeout fix #3355 --- .../SystemTransactionFixture.cs | 112 ++++++++++++++++++ .../SystemTransactionFixture.cs | 98 ++++++++++++++- .../AdoNetWithSystemTransactionFactory.cs | 1 + src/NHibernate/Impl/AbstractSessionImpl.cs | 2 +- .../AdoNetWithSystemTransactionFactory.cs | 55 ++++++--- 5 files changed, 246 insertions(+), 22 deletions(-) diff --git a/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs index 056ae272b0a..7a633fb069b 100644 --- a/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs @@ -19,6 +19,8 @@ using NHibernate.Engine; using NHibernate.Test.TransactionTest; using NUnit.Framework; + +using SysTran = System.Transactions; using NHibernate.Linq; namespace NHibernate.Test.SystemTransactions @@ -524,6 +526,116 @@ public async Task EnforceConnectionUsageRulesOnTransactionCompletionAsync() // Currently always forbidden, whatever UseConnectionOnSystemTransactionEvents. Assert.That(interceptor.AfterException, Is.TypeOf()); } + + // This test check a concurrency issue hard to reproduce. If it is flaky, it has to be considered failing. + // In such case, raise triesCount to investigate it locally with more chances of triggering the trouble. + [Test] + public async Task SupportsTransactionTimeoutAsync() + { + // Test case adapted from https://github.com/kaksmet/NHibBugRepro + + // Create some test data. + const int entitiesCount = 5000; + using (var s = OpenSession()) + using (var t = s.BeginTransaction()) + { + for (var i = 0; i < entitiesCount; i++) + { + var person = new Person + { + NotNullData = Guid.NewGuid().ToString() + }; + + await (s.SaveAsync(person)); + } + + await (t.CommitAsync()); + } + + // Setup unhandler exception catcher + _unhandledExceptionCount = 0; + AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; + try + { + // Generate transaction timeouts. + const int triesCount = 100; + var txOptions = new TransactionOptions { Timeout = TimeSpan.FromMilliseconds(1) }; + var timeoutsCount = 0; + for (var i = 0; i < triesCount; i++) + { + try + { + using var txScope = new TransactionScope(TransactionScopeOption.Required, txOptions, TransactionScopeAsyncFlowOption.Enabled); + using var session = OpenSession(); + var data = await (session.CreateCriteria().ListAsync()); + Assert.That(data, Has.Count.EqualTo(entitiesCount)); + await (Task.Delay(2)); + var count = await (session.Query().CountAsync()); + Assert.That(count, Is.EqualTo(entitiesCount)); + txScope.Complete(); + } + catch (Exception ex) + { + var currentEx = ex; + // Depending on where the transaction aborption has broken NHibernate processing, we may + // get various exceptions, like directly a TransactionAbortedException with an inner + // TimeoutException, or a HibernateException encapsulating a TransactionException with a + // timeout, ... + bool isTransactionException; + do + { + isTransactionException = currentEx is SysTran.TransactionException; + currentEx = currentEx.InnerException; + } + while (!isTransactionException && currentEx != null); + bool isTimeout; + do + { + isTimeout = currentEx is TimeoutException; + currentEx = currentEx?.InnerException; + } + while (!isTimeout && currentEx != null); + + if (!isTimeout) + { + // We may also get a GenericADOException with an InvalidOperationException stating the + // transaction associated to the connection is no more active but not yet suppressed, + // and that for executing some SQL, we need to suppress it. That is a weak way of + // identifying the case, especially with the possibility of localization of the message. + currentEx = ex; + do + { + isTimeout = currentEx is InvalidOperationException && currentEx.Message.Contains("SQL"); + currentEx = currentEx?.InnerException; + } + while (!isTimeout && currentEx != null); + } + + if (isTimeout) + timeoutsCount++; + else + throw; + } + } + + // Despite the Thread sleep and the count of entities to load, this test does get the timeout only for slightly + // more than 10% of the attempts. + Assert.That(timeoutsCount, Is.GreaterThan(5)); + Assert.That(_unhandledExceptionCount, Is.EqualTo(0)); + } + finally + { + AppDomain.CurrentDomain.UnhandledException -= CurrentDomain_UnhandledException; + } + } + + private int _unhandledExceptionCount; + + private void CurrentDomain_UnhandledException(object sender, UnhandledExceptionEventArgs e) + { + _unhandledExceptionCount++; + Assert.Warn("Unhandled exception: {0}", e.ExceptionObject); + } } [TestFixture] diff --git a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs index 73cfb38c883..2e2a4b9e31e 100644 --- a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs @@ -10,6 +10,8 @@ using NHibernate.Test.TransactionTest; using NUnit.Framework; +using SysTran = System.Transactions; + namespace NHibernate.Test.SystemTransactions { [TestFixture] @@ -643,24 +645,114 @@ public void CanUseSessionWithManyDependentTransaction(bool explicitFlush) } } + // This test check a concurrency issue hard to reproduce. If it is flaky, it has to be considered failing. + // In such case, raise triesCount to investigate it locally with more chances of triggering the trouble. [Test] public void SupportsTransactionTimeout() { // Test case adapted from https://github.com/kaksmet/NHibBugRepro + + // Create some test data. + const int entitiesCount = 5000; using (var s = OpenSession()) using (var t = s.BeginTransaction()) { - for (var i = 0; i < 5000; i++) + for (var i = 0; i < entitiesCount; i++) { - var person = new Person(); + var person = new Person + { + NotNullData = Guid.NewGuid().ToString() + }; + s.Save(person); } t.Commit(); } - var txOptions = new TransactionOptions { Timeout = TimeSpan.FromMilliseconds(1) }; + // Setup unhandler exception catcher + _unhandledExceptionCount = 0; + AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; + try + { + // Generate transaction timeouts. + const int triesCount = 100; + var txOptions = new TransactionOptions { Timeout = TimeSpan.FromMilliseconds(1) }; + var timeoutsCount = 0; + for (var i = 0; i < triesCount; i++) + { + try + { + using var txScope = new TransactionScope(TransactionScopeOption.Required, txOptions); + using var session = OpenSession(); + var data = session.CreateCriteria().List(); + Assert.That(data, Has.Count.EqualTo(entitiesCount)); + Thread.Sleep(2); + var count = session.Query().Count(); + Assert.That(count, Is.EqualTo(entitiesCount)); + txScope.Complete(); + } + catch (Exception ex) + { + var currentEx = ex; + // Depending on where the transaction aborption has broken NHibernate processing, we may + // get various exceptions, like directly a TransactionAbortedException with an inner + // TimeoutException, or a HibernateException encapsulating a TransactionException with a + // timeout, ... + bool isTransactionException; + do + { + isTransactionException = currentEx is SysTran.TransactionException; + currentEx = currentEx.InnerException; + } + while (!isTransactionException && currentEx != null); + bool isTimeout; + do + { + isTimeout = currentEx is TimeoutException; + currentEx = currentEx?.InnerException; + } + while (!isTimeout && currentEx != null); + + if (!isTimeout) + { + // We may also get a GenericADOException with an InvalidOperationException stating the + // transaction associated to the connection is no more active but not yet suppressed, + // and that for executing some SQL, we need to suppress it. That is a weak way of + // identifying the case, especially with the possibility of localization of the message. + currentEx = ex; + do + { + isTimeout = currentEx is InvalidOperationException && currentEx.Message.Contains("SQL"); + currentEx = currentEx?.InnerException; + } + while (!isTimeout && currentEx != null); + } + + if (isTimeout) + timeoutsCount++; + else + throw; + } + } + + // Despite the Thread sleep and the count of entities to load, this test does get the timeout only for slightly + // more than 10% of the attempts. + Assert.That(timeoutsCount, Is.GreaterThan(5)); + Assert.That(_unhandledExceptionCount, Is.EqualTo(0)); + } + finally + { + AppDomain.CurrentDomain.UnhandledException -= CurrentDomain_UnhandledException; + } + } + + private int _unhandledExceptionCount; + private void CurrentDomain_UnhandledException(object sender, UnhandledExceptionEventArgs e) + { + _unhandledExceptionCount++; + Assert.Warn("Unhandled exception: {0}", e.ExceptionObject); } [Theory, Explicit("Bench")] diff --git a/src/NHibernate/Async/Transaction/AdoNetWithSystemTransactionFactory.cs b/src/NHibernate/Async/Transaction/AdoNetWithSystemTransactionFactory.cs index 91558147f86..3e9de8e7836 100644 --- a/src/NHibernate/Async/Transaction/AdoNetWithSystemTransactionFactory.cs +++ b/src/NHibernate/Async/Transaction/AdoNetWithSystemTransactionFactory.cs @@ -10,6 +10,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Threading; using System.Transactions; diff --git a/src/NHibernate/Impl/AbstractSessionImpl.cs b/src/NHibernate/Impl/AbstractSessionImpl.cs index 4fe9c9ae598..063acbbad40 100644 --- a/src/NHibernate/Impl/AbstractSessionImpl.cs +++ b/src/NHibernate/Impl/AbstractSessionImpl.cs @@ -429,7 +429,7 @@ private sealed class ProcessHelper : IDisposable private IDisposable _context; [NonSerialized] - private bool _processing; + private volatile bool _processing; public ProcessHelper() { diff --git a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs index 7f74bc7218c..1a667b17ba9 100644 --- a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs +++ b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs @@ -1,5 +1,6 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Threading; using System.Transactions; @@ -418,23 +419,20 @@ void IEnlistmentNotification.InDoubt(Enlistment enlistment) /// callback, if this is an in-doubt callback. protected virtual void ProcessSecondPhase(Enlistment enlistment, bool? success) { - using (_session.BeginContext()) - { - _logger.Debug( - success.HasValue - ? success.Value - ? "Committing system transaction" - : "Rolled back system transaction" - : "System transaction is in doubt"); + _logger.Debug( + success.HasValue + ? success.Value + ? "Committing system transaction" + : "Rolled back system transaction" + : "System transaction is in doubt"); - try - { - CompleteTransaction(success ?? false); - } - finally - { - enlistment.Done(); - } + try + { + CompleteTransaction(success ?? false); + } + finally + { + enlistment.Done(); } } @@ -458,7 +456,28 @@ protected virtual void CompleteTransaction(bool isCommitted) { // Allow transaction completed actions to run while others stay blocked. _bypassLock.Value = true; - using (_session.BeginContext()) + // Ensure no other session processing is still ongoing. In case of a transaction timeout, the transaction is + // cancelled on a new thread even for non-distributed scopes. So, the session could be doing some processing, + // and will not be interrupted until attempting some usage of the connection. See #3355. + // Thread safety of a concurrent session BeginProcess is ensured by the Wait performed by BeginProcess. + var context = _session.BeginProcess(); + if (context == null) + { + var timeOutGuard = new Stopwatch(); + timeOutGuard.Start(); + while (context == null && timeOutGuard.ElapsedMilliseconds < _systemTransactionCompletionLockTimeout) + { + // Na�ve yield. + Thread.Sleep(10); + context = _session.BeginProcess(); + } + if (context == null) + throw new HibernateException( + $"Synchronization timeout for transaction completion. Either raise" + + $"{Cfg.Environment.SystemTransactionCompletionLockTimeout}, or check all scopes are properly" + + $"disposed and/or all direct System.Transaction.Current changes are properly managed."); + } + using (context) { // Flag active as false before running actions, otherwise the session may not cleanup as much // as possible. @@ -477,7 +496,7 @@ protected virtual void CompleteTransaction(bool isCommitted) // within scopes, although mixing is not advised. if (!ShouldCloseSessionOnSystemTransactionCompleted) _session.ConnectionManager.EnlistIfRequired(null); - + _session.AfterTransactionCompletion(isCommitted, null); foreach (var dependentSession in _session.ConnectionManager.DependentSessions) dependentSession.AfterTransactionCompletion(isCommitted, null); From c1ab2ebec2b5f69fe438b8280af89a4b9d718eb3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Delaporte?= <12201973+fredericdelaporte@users.noreply.github.com> Date: Tue, 6 Feb 2024 19:04:58 +0100 Subject: [PATCH 03/22] Fix the fix --- .../SystemTransactionFixture.cs | 83 +++++++------------ .../SystemTransactionFixture.cs | 83 +++++++------------ src/NHibernate.Test/TestDialect.cs | 5 ++ .../TestDialects/MySQL5TestDialect.cs | 5 ++ src/NHibernate/Engine/ISessionImplementor.cs | 9 ++ src/NHibernate/Impl/AbstractSessionImpl.cs | 5 ++ .../AdoNetWithSystemTransactionFactory.cs | 12 +-- 7 files changed, 94 insertions(+), 108 deletions(-) diff --git a/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs index 7a633fb069b..f16ab34974c 100644 --- a/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs @@ -9,6 +9,7 @@ using System; +using System.Collections.Concurrent; using System.Collections.Generic; using System.Diagnostics; using System.Linq; @@ -19,8 +20,6 @@ using NHibernate.Engine; using NHibernate.Test.TransactionTest; using NUnit.Framework; - -using SysTran = System.Transactions; using NHibernate.Linq; namespace NHibernate.Test.SystemTransactions @@ -532,6 +531,7 @@ public async Task EnforceConnectionUsageRulesOnTransactionCompletionAsync() [Test] public async Task SupportsTransactionTimeoutAsync() { + Assume.That(TestDialect.SupportsTransactionScopeTimeouts, Is.True); // Test case adapted from https://github.com/kaksmet/NHibBugRepro // Create some test data. @@ -553,7 +553,7 @@ public async Task SupportsTransactionTimeoutAsync() } // Setup unhandler exception catcher - _unhandledExceptionCount = 0; + _unhandledExceptions = new ConcurrentBag(); AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; try { @@ -568,60 +568,29 @@ public async Task SupportsTransactionTimeoutAsync() using var txScope = new TransactionScope(TransactionScopeOption.Required, txOptions, TransactionScopeAsyncFlowOption.Enabled); using var session = OpenSession(); var data = await (session.CreateCriteria().ListAsync()); - Assert.That(data, Has.Count.EqualTo(entitiesCount)); + Assert.That(data, Has.Count.EqualTo(entitiesCount), "Unexpected count of loaded entities."); await (Task.Delay(2)); var count = await (session.Query().CountAsync()); - Assert.That(count, Is.EqualTo(entitiesCount)); + Assert.That(count, Is.EqualTo(entitiesCount), "Unexpected entities count."); txScope.Complete(); } - catch (Exception ex) + catch { - var currentEx = ex; - // Depending on where the transaction aborption has broken NHibernate processing, we may - // get various exceptions, like directly a TransactionAbortedException with an inner - // TimeoutException, or a HibernateException encapsulating a TransactionException with a - // timeout, ... - bool isTransactionException; - do - { - isTransactionException = currentEx is SysTran.TransactionException; - currentEx = currentEx.InnerException; - } - while (!isTransactionException && currentEx != null); - bool isTimeout; - do - { - isTimeout = currentEx is TimeoutException; - currentEx = currentEx?.InnerException; - } - while (!isTimeout && currentEx != null); - - if (!isTimeout) - { - // We may also get a GenericADOException with an InvalidOperationException stating the - // transaction associated to the connection is no more active but not yet suppressed, - // and that for executing some SQL, we need to suppress it. That is a weak way of - // identifying the case, especially with the possibility of localization of the message. - currentEx = ex; - do - { - isTimeout = currentEx is InvalidOperationException && currentEx.Message.Contains("SQL"); - currentEx = currentEx?.InnerException; - } - while (!isTimeout && currentEx != null); - } - - if (isTimeout) - timeoutsCount++; - else - throw; + // Assume that is a transaction timeout. It may cause various failures, of which some are hard to identify. + timeoutsCount++; } } - // Despite the Thread sleep and the count of entities to load, this test does get the timeout only for slightly + // Despite the Thread sleep and the count of entities to load, this test may get the timeout only for slightly // more than 10% of the attempts. - Assert.That(timeoutsCount, Is.GreaterThan(5)); - Assert.That(_unhandledExceptionCount, Is.EqualTo(0)); + Assert.That(timeoutsCount, Is.GreaterThan(5), "The test should have generated more timeouts."); + Assert.That( + _unhandledExceptions.Count, + Is.EqualTo(0), + "Unhandled exceptions have occurred: {0}", + string.Join(@" + +", _unhandledExceptions)); } finally { @@ -629,12 +598,24 @@ public async Task SupportsTransactionTimeoutAsync() } } - private int _unhandledExceptionCount; + private ConcurrentBag _unhandledExceptions; private void CurrentDomain_UnhandledException(object sender, UnhandledExceptionEventArgs e) { - _unhandledExceptionCount++; - Assert.Warn("Unhandled exception: {0}", e.ExceptionObject); + if (e.ExceptionObject is Exception exception) + { + // Ascertain NHibernate is involved. Some unhandled exceptions occur due to the + // TransactionScope timeout operating on an unexpected thread for the data provider. + var isNHibernateInvolved = false; + while (exception != null && !isNHibernateInvolved) + { + isNHibernateInvolved = exception.StackTrace != null && exception.StackTrace.ToLowerInvariant().Contains("nhibernate"); + exception = exception.InnerException; + } + if (!isNHibernateInvolved) + return; + } + _unhandledExceptions.Add(e.ExceptionObject); } } diff --git a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs index 2e2a4b9e31e..fce324ba732 100644 --- a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs @@ -1,4 +1,5 @@ using System; +using System.Collections.Concurrent; using System.Collections.Generic; using System.Diagnostics; using System.Linq; @@ -10,8 +11,6 @@ using NHibernate.Test.TransactionTest; using NUnit.Framework; -using SysTran = System.Transactions; - namespace NHibernate.Test.SystemTransactions { [TestFixture] @@ -650,6 +649,7 @@ public void CanUseSessionWithManyDependentTransaction(bool explicitFlush) [Test] public void SupportsTransactionTimeout() { + Assume.That(TestDialect.SupportsTransactionScopeTimeouts, Is.True); // Test case adapted from https://github.com/kaksmet/NHibBugRepro // Create some test data. @@ -671,7 +671,7 @@ public void SupportsTransactionTimeout() } // Setup unhandler exception catcher - _unhandledExceptionCount = 0; + _unhandledExceptions = new ConcurrentBag(); AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; try { @@ -686,60 +686,29 @@ public void SupportsTransactionTimeout() using var txScope = new TransactionScope(TransactionScopeOption.Required, txOptions); using var session = OpenSession(); var data = session.CreateCriteria().List(); - Assert.That(data, Has.Count.EqualTo(entitiesCount)); + Assert.That(data, Has.Count.EqualTo(entitiesCount), "Unexpected count of loaded entities."); Thread.Sleep(2); var count = session.Query().Count(); - Assert.That(count, Is.EqualTo(entitiesCount)); + Assert.That(count, Is.EqualTo(entitiesCount), "Unexpected entities count."); txScope.Complete(); } - catch (Exception ex) + catch { - var currentEx = ex; - // Depending on where the transaction aborption has broken NHibernate processing, we may - // get various exceptions, like directly a TransactionAbortedException with an inner - // TimeoutException, or a HibernateException encapsulating a TransactionException with a - // timeout, ... - bool isTransactionException; - do - { - isTransactionException = currentEx is SysTran.TransactionException; - currentEx = currentEx.InnerException; - } - while (!isTransactionException && currentEx != null); - bool isTimeout; - do - { - isTimeout = currentEx is TimeoutException; - currentEx = currentEx?.InnerException; - } - while (!isTimeout && currentEx != null); - - if (!isTimeout) - { - // We may also get a GenericADOException with an InvalidOperationException stating the - // transaction associated to the connection is no more active but not yet suppressed, - // and that for executing some SQL, we need to suppress it. That is a weak way of - // identifying the case, especially with the possibility of localization of the message. - currentEx = ex; - do - { - isTimeout = currentEx is InvalidOperationException && currentEx.Message.Contains("SQL"); - currentEx = currentEx?.InnerException; - } - while (!isTimeout && currentEx != null); - } - - if (isTimeout) - timeoutsCount++; - else - throw; + // Assume that is a transaction timeout. It may cause various failures, of which some are hard to identify. + timeoutsCount++; } } - // Despite the Thread sleep and the count of entities to load, this test does get the timeout only for slightly + // Despite the Thread sleep and the count of entities to load, this test may get the timeout only for slightly // more than 10% of the attempts. - Assert.That(timeoutsCount, Is.GreaterThan(5)); - Assert.That(_unhandledExceptionCount, Is.EqualTo(0)); + Assert.That(timeoutsCount, Is.GreaterThan(5), "The test should have generated more timeouts."); + Assert.That( + _unhandledExceptions.Count, + Is.EqualTo(0), + "Unhandled exceptions have occurred: {0}", + string.Join(@" + +", _unhandledExceptions)); } finally { @@ -747,12 +716,24 @@ public void SupportsTransactionTimeout() } } - private int _unhandledExceptionCount; + private ConcurrentBag _unhandledExceptions; private void CurrentDomain_UnhandledException(object sender, UnhandledExceptionEventArgs e) { - _unhandledExceptionCount++; - Assert.Warn("Unhandled exception: {0}", e.ExceptionObject); + if (e.ExceptionObject is Exception exception) + { + // Ascertain NHibernate is involved. Some unhandled exceptions occur due to the + // TransactionScope timeout operating on an unexpected thread for the data provider. + var isNHibernateInvolved = false; + while (exception != null && !isNHibernateInvolved) + { + isNHibernateInvolved = exception.StackTrace != null && exception.StackTrace.ToLowerInvariant().Contains("nhibernate"); + exception = exception.InnerException; + } + if (!isNHibernateInvolved) + return; + } + _unhandledExceptions.Add(e.ExceptionObject); } [Theory, Explicit("Bench")] diff --git a/src/NHibernate.Test/TestDialect.cs b/src/NHibernate.Test/TestDialect.cs index e7bc20d304f..69ab31fcb37 100644 --- a/src/NHibernate.Test/TestDialect.cs +++ b/src/NHibernate.Test/TestDialect.cs @@ -177,6 +177,11 @@ public bool SupportsSqlType(SqlType sqlType) /// public virtual bool SupportsDependentTransaction => true; + /// + /// Transaction scope timeouts occur on a dedicated thread which wrecks some data providers. + /// + public virtual bool SupportsTransactionScopeTimeouts => true; + /// /// Some databases (provider?) fails to compute adequate column types for queries which columns /// computing include a parameter value. diff --git a/src/NHibernate.Test/TestDialects/MySQL5TestDialect.cs b/src/NHibernate.Test/TestDialects/MySQL5TestDialect.cs index ea68e6f19b7..d37bef44dd5 100644 --- a/src/NHibernate.Test/TestDialects/MySQL5TestDialect.cs +++ b/src/NHibernate.Test/TestDialects/MySQL5TestDialect.cs @@ -21,5 +21,10 @@ public MySQL5TestDialect(Dialect.Dialect dialect) /// See https://dev.mysql.com/doc/refman/8.0/en/correlated-subqueries.html /// public override bool SupportsCorrelatedColumnsInSubselectJoin => false; + + /// + /// MySQL data provider may be wrecked by transaction scope timeouts to the point of causing even the teardown to fail. + /// + public override bool SupportsTransactionScopeTimeouts => false; } } diff --git a/src/NHibernate/Engine/ISessionImplementor.cs b/src/NHibernate/Engine/ISessionImplementor.cs index 9a0cb58b77a..1d607af0c64 100644 --- a/src/NHibernate/Engine/ISessionImplementor.cs +++ b/src/NHibernate/Engine/ISessionImplementor.cs @@ -66,6 +66,15 @@ internal static IDisposable BeginProcess(this ISessionImplementor session) : SessionIdLoggingContext.CreateOrNull(session.SessionId); } + internal static bool IsProcessing(this ISessionImplementor session) + { + if (session == null) + return false; + return session is AbstractSessionImpl impl + ? impl.IsProcessing + : false; + } + //6.0 TODO: Expose as ISessionImplementor.FutureBatch and replace method usages with property internal static IQueryBatch GetFutureBatch(this ISessionImplementor session) { diff --git a/src/NHibernate/Impl/AbstractSessionImpl.cs b/src/NHibernate/Impl/AbstractSessionImpl.cs index 063acbbad40..0ea88ea048e 100644 --- a/src/NHibernate/Impl/AbstractSessionImpl.cs +++ b/src/NHibernate/Impl/AbstractSessionImpl.cs @@ -394,6 +394,11 @@ public bool IsClosed get { return closed; } } + /// + /// Indicates if the session is currently processing some operations. + /// + public bool IsProcessing => _processHelper.Processing; + /// /// If not nested in another call to BeginProcess on this session, check and update the /// session status and set its session id in context. diff --git a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs index 1a667b17ba9..bbc73c98379 100644 --- a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs +++ b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs @@ -460,24 +460,24 @@ protected virtual void CompleteTransaction(bool isCommitted) // cancelled on a new thread even for non-distributed scopes. So, the session could be doing some processing, // and will not be interrupted until attempting some usage of the connection. See #3355. // Thread safety of a concurrent session BeginProcess is ensured by the Wait performed by BeginProcess. - var context = _session.BeginProcess(); - if (context == null) + var isProcessing = _session.IsProcessing(); + if (isProcessing) { var timeOutGuard = new Stopwatch(); timeOutGuard.Start(); - while (context == null && timeOutGuard.ElapsedMilliseconds < _systemTransactionCompletionLockTimeout) + while (isProcessing && timeOutGuard.ElapsedMilliseconds < _systemTransactionCompletionLockTimeout) { // Na�ve yield. Thread.Sleep(10); - context = _session.BeginProcess(); + isProcessing = _session.IsProcessing(); } - if (context == null) + if (isProcessing) throw new HibernateException( $"Synchronization timeout for transaction completion. Either raise" + $"{Cfg.Environment.SystemTransactionCompletionLockTimeout}, or check all scopes are properly" + $"disposed and/or all direct System.Transaction.Current changes are properly managed."); } - using (context) + using (_session.BeginContext()) { // Flag active as false before running actions, otherwise the session may not cleanup as much // as possible. From df14163afd4a24b9b2a9fc1427ba6afb777fdb8a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Delaporte?= <12201973+fredericdelaporte@users.noreply.github.com> Date: Tue, 6 Feb 2024 19:18:09 +0100 Subject: [PATCH 04/22] Fix corrupted character --- .editorconfig | 1 + .../Transaction/AdoNetWithSystemTransactionFactory.cs | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/.editorconfig b/.editorconfig index 9315aa4e45e..da812d88d1b 100644 --- a/.editorconfig +++ b/.editorconfig @@ -2,6 +2,7 @@ root=true [*] insert_final_newline = true +charset = utf-8 [*.cs] indent_style = tab diff --git a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs index bbc73c98379..2a9a701bb7c 100644 --- a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs +++ b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs @@ -467,7 +467,7 @@ protected virtual void CompleteTransaction(bool isCommitted) timeOutGuard.Start(); while (isProcessing && timeOutGuard.ElapsedMilliseconds < _systemTransactionCompletionLockTimeout) { - // Na�ve yield. + // Naïve yield. Thread.Sleep(10); isProcessing = _session.IsProcessing(); } From 01e97aeeaa8e865af4f4e6c69d923ceb18a665e1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Delaporte?= <12201973+fredericdelaporte@users.noreply.github.com> Date: Wed, 7 Feb 2024 23:08:20 +0100 Subject: [PATCH 05/22] Still attempt to release the session even if in use --- .../SystemTransactionFixture.cs | 58 +++++++++++++++++-- .../SapSQLAnywhere17TestDialect.cs | 8 ++- .../AdoNetWithSystemTransactionFactory.cs | 39 +++++++++---- 3 files changed, 87 insertions(+), 18 deletions(-) diff --git a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs index fce324ba732..3644d2bbd64 100644 --- a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs @@ -649,7 +649,10 @@ public void CanUseSessionWithManyDependentTransaction(bool explicitFlush) [Test] public void SupportsTransactionTimeout() { - Assume.That(TestDialect.SupportsTransactionScopeTimeouts, Is.True); + Assume.That(TestDialect.SupportsTransactionScopeTimeouts, Is.True, "The tested dialect is not supported for transaction scope timeouts."); + // ODBC always freezes the session during transaction scopes timeouts. + Assume.That(Sfi.ConnectionProvider.Driver, Is.Not.InstanceOf(typeof(OdbcDriver)), "ODBC is not supported for transaction scope timeouts."); + // Test case adapted from https://github.com/kaksmet/NHibBugRepro // Create some test data. @@ -670,7 +673,7 @@ public void SupportsTransactionTimeout() t.Commit(); } - // Setup unhandler exception catcher + // Setup unhandled exception catcher. _unhandledExceptions = new ConcurrentBag(); AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; try @@ -697,11 +700,52 @@ public void SupportsTransactionTimeout() // Assume that is a transaction timeout. It may cause various failures, of which some are hard to identify. timeoutsCount++; } + // If in need of checking some specific failures, the following code may be used instead: + /* + catch (Exception ex) + { + var currentEx = ex; + // Depending on where the transaction aborption has broken NHibernate processing, we may + // get various exceptions, like directly a TransactionAbortedException with an inner + // TimeoutException, or a HibernateException encapsulating a TransactionException with a + // timeout, ... + bool isTransactionException, isTimeout; + do + { + isTransactionException = currentEx is System.Transactions.TransactionException; + isTimeout = isTransactionException && currentEx is TransactionAbortedException; + currentEx = currentEx.InnerException; + } + while (!isTransactionException && currentEx != null); + while (!isTimeout && currentEx != null) + { + isTimeout = currentEx is TimeoutException; + currentEx = currentEx?.InnerException; + } + + if (!isTimeout) + { + // We may also get a GenericADOException with an InvalidOperationException stating the + // transaction associated to the connection is no more active but not yet suppressed, + // and that for executing some SQL, we need to suppress it. That is a weak way of + // identifying the case, especially with the many localizations of the message. + currentEx = ex; + do + { + isTimeout = currentEx is InvalidOperationException && currentEx.Message.Contains("SQL"); + currentEx = currentEx?.InnerException; + } + while (!isTimeout && currentEx != null); + } + + if (isTimeout) + timeoutsCount++; + else + throw; + } + */ } - // Despite the Thread sleep and the count of entities to load, this test may get the timeout only for slightly - // more than 10% of the attempts. - Assert.That(timeoutsCount, Is.GreaterThan(5), "The test should have generated more timeouts."); Assert.That( _unhandledExceptions.Count, Is.EqualTo(0), @@ -709,6 +753,10 @@ public void SupportsTransactionTimeout() string.Join(@" ", _unhandledExceptions)); + + // Despite the Thread sleep and the count of entities to load, this test may get the timeout only for slightly + // more than 10% of the attempts. + Warn.Unless(timeoutsCount, Is.GreaterThan(5), "The test should have generated more timeouts."); } finally { diff --git a/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs b/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs index 35a35092ce3..c1d59cca066 100644 --- a/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs +++ b/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs @@ -1,4 +1,4 @@ -namespace NHibernate.Test.TestDialects +namespace NHibernate.Test.TestDialects { public class SapSQLAnywhere17TestDialect : TestDialect { @@ -43,5 +43,11 @@ public SapSQLAnywhere17TestDialect(Dialect.Dialect dialect) /// Does not support SELECT FOR UPDATE /// public override bool SupportsSelectForUpdate => false; + + /// + /// SQL Anywhere freezes on transaction scope timeout occuring on concurrent threads, always causing the + /// synchronization for end of session processing to timeout. + /// + public override bool SupportsTransactionScopeTimeouts => false; } } diff --git a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs index 2a9a701bb7c..e113eae9b56 100644 --- a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs +++ b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs @@ -243,9 +243,9 @@ public virtual void Wait() // Remove the block then throw. Unlock(); throw new HibernateException( - $"Synchronization timeout for transaction completion. Either raise" + - $"{Cfg.Environment.SystemTransactionCompletionLockTimeout}, or check all scopes are properly" + - $"disposed and/or all direct System.Transaction.Current changes are properly managed."); + "A synchronization timeout occurred at transaction completion. Either raise " + + $"{Cfg.Environment.SystemTransactionCompletionLockTimeout}, or check all scopes are properly " + + "disposed and/or all direct System.Transaction.Current changes are properly managed."); } catch (HibernateException) { @@ -452,6 +452,7 @@ protected virtual void CompleteTransaction(bool isCommitted) // do an early exit here in such case. if (!IsInActiveTransaction) return; + var isSessionProcessing = _session.IsProcessing(); try { // Allow transaction completed actions to run while others stay blocked. @@ -460,22 +461,27 @@ protected virtual void CompleteTransaction(bool isCommitted) // cancelled on a new thread even for non-distributed scopes. So, the session could be doing some processing, // and will not be interrupted until attempting some usage of the connection. See #3355. // Thread safety of a concurrent session BeginProcess is ensured by the Wait performed by BeginProcess. - var isProcessing = _session.IsProcessing(); - if (isProcessing) + if (isSessionProcessing) { var timeOutGuard = new Stopwatch(); timeOutGuard.Start(); - while (isProcessing && timeOutGuard.ElapsedMilliseconds < _systemTransactionCompletionLockTimeout) + while (isSessionProcessing && timeOutGuard.ElapsedMilliseconds < _systemTransactionCompletionLockTimeout) { // Naïve yield. Thread.Sleep(10); - isProcessing = _session.IsProcessing(); + isSessionProcessing = _session.IsProcessing(); + } + if (isSessionProcessing) + { + // Throwing would give up attempting to close the session if need be, which may still succeed. So, + // just log an error. + _logger.Error( + "A synchronization timeout occurred at transaction completion: the session is still processing. Attempting " + + "to finalize the transaction concurrently, which may cause thread safety failure. You may " + + "raise {0} if it is set too low. It may also be a limitation of the data provider, like not " + + "supporting transaction scope timeouts occurring on concurrent threads.", + Cfg.Environment.SystemTransactionCompletionLockTimeout); } - if (isProcessing) - throw new HibernateException( - $"Synchronization timeout for transaction completion. Either raise" + - $"{Cfg.Environment.SystemTransactionCompletionLockTimeout}, or check all scopes are properly" + - $"disposed and/or all direct System.Transaction.Current changes are properly managed."); } using (_session.BeginContext()) { @@ -516,6 +522,15 @@ protected virtual void CompleteTransaction(bool isCommitted) // Dispose releases blocked threads by the way. Dispose(); } + + if (isSessionProcessing) + { + throw new HibernateException( + "A synchronization timeout occurred at transaction completion: the session was still processing. You may " + + $"raise {Cfg.Environment.SystemTransactionCompletionLockTimeout} if it is set too low. It may also " + + "be a limitation of the data provider, like not supporting transaction scope timeouts occurring on " + + "concurrent threads."); + } } private static void Cleanup(ISessionImplementor session) From fa20807070034467cb7734b13ca8dfd2d625a129 Mon Sep 17 00:00:00 2001 From: "github-actions[bot]" Date: Wed, 7 Feb 2024 22:10:30 +0000 Subject: [PATCH 06/22] Generate async files --- .../SystemTransactionFixture.cs | 58 +++++++++++++++++-- 1 file changed, 53 insertions(+), 5 deletions(-) diff --git a/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs index f16ab34974c..67e43b4349e 100644 --- a/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/Async/SystemTransactions/SystemTransactionFixture.cs @@ -531,7 +531,10 @@ public async Task EnforceConnectionUsageRulesOnTransactionCompletionAsync() [Test] public async Task SupportsTransactionTimeoutAsync() { - Assume.That(TestDialect.SupportsTransactionScopeTimeouts, Is.True); + Assume.That(TestDialect.SupportsTransactionScopeTimeouts, Is.True, "The tested dialect is not supported for transaction scope timeouts."); + // ODBC always freezes the session during transaction scopes timeouts. + Assume.That(Sfi.ConnectionProvider.Driver, Is.Not.InstanceOf(typeof(OdbcDriver)), "ODBC is not supported for transaction scope timeouts."); + // Test case adapted from https://github.com/kaksmet/NHibBugRepro // Create some test data. @@ -552,7 +555,7 @@ public async Task SupportsTransactionTimeoutAsync() await (t.CommitAsync()); } - // Setup unhandler exception catcher + // Setup unhandled exception catcher. _unhandledExceptions = new ConcurrentBag(); AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; try @@ -579,11 +582,52 @@ public async Task SupportsTransactionTimeoutAsync() // Assume that is a transaction timeout. It may cause various failures, of which some are hard to identify. timeoutsCount++; } + // If in need of checking some specific failures, the following code may be used instead: + /* + catch (Exception ex) + { + var currentEx = ex; + // Depending on where the transaction aborption has broken NHibernate processing, we may + // get various exceptions, like directly a TransactionAbortedException with an inner + // TimeoutException, or a HibernateException encapsulating a TransactionException with a + // timeout, ... + bool isTransactionException, isTimeout; + do + { + isTransactionException = currentEx is System.Transactions.TransactionException; + isTimeout = isTransactionException && currentEx is TransactionAbortedException; + currentEx = currentEx.InnerException; + } + while (!isTransactionException && currentEx != null); + while (!isTimeout && currentEx != null) + { + isTimeout = currentEx is TimeoutException; + currentEx = currentEx?.InnerException; + } + + if (!isTimeout) + { + // We may also get a GenericADOException with an InvalidOperationException stating the + // transaction associated to the connection is no more active but not yet suppressed, + // and that for executing some SQL, we need to suppress it. That is a weak way of + // identifying the case, especially with the many localizations of the message. + currentEx = ex; + do + { + isTimeout = currentEx is InvalidOperationException && currentEx.Message.Contains("SQL"); + currentEx = currentEx?.InnerException; + } + while (!isTimeout && currentEx != null); + } + + if (isTimeout) + timeoutsCount++; + else + throw; + } + */ } - // Despite the Thread sleep and the count of entities to load, this test may get the timeout only for slightly - // more than 10% of the attempts. - Assert.That(timeoutsCount, Is.GreaterThan(5), "The test should have generated more timeouts."); Assert.That( _unhandledExceptions.Count, Is.EqualTo(0), @@ -591,6 +635,10 @@ public async Task SupportsTransactionTimeoutAsync() string.Join(@" ", _unhandledExceptions)); + + // Despite the Thread sleep and the count of entities to load, this test may get the timeout only for slightly + // more than 10% of the attempts. + Warn.Unless(timeoutsCount, Is.GreaterThan(5), "The test should have generated more timeouts."); } finally { From 1a71fc1812d284b5c99497959651ef60717ab722 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Delaporte?= <12201973+fredericdelaporte@users.noreply.github.com> Date: Thu, 8 Feb 2024 10:00:34 +0100 Subject: [PATCH 07/22] Apply review --- src/NHibernate/Engine/ISessionImplementor.cs | 8 +------- .../AdoNetWithSystemTransactionFactory.cs | 18 ++++++++++-------- 2 files changed, 11 insertions(+), 15 deletions(-) diff --git a/src/NHibernate/Engine/ISessionImplementor.cs b/src/NHibernate/Engine/ISessionImplementor.cs index 1d607af0c64..d7af7a73fbd 100644 --- a/src/NHibernate/Engine/ISessionImplementor.cs +++ b/src/NHibernate/Engine/ISessionImplementor.cs @@ -67,13 +67,7 @@ internal static IDisposable BeginProcess(this ISessionImplementor session) } internal static bool IsProcessing(this ISessionImplementor session) - { - if (session == null) - return false; - return session is AbstractSessionImpl impl - ? impl.IsProcessing - : false; - } + => session is AbstractSessionImpl impl && impl.IsProcessing; //6.0 TODO: Expose as ISessionImplementor.FutureBatch and replace method usages with property internal static IQueryBatch GetFutureBatch(this ISessionImplementor session) diff --git a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs index e113eae9b56..75ac955a69d 100644 --- a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs +++ b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs @@ -476,10 +476,11 @@ protected virtual void CompleteTransaction(bool isCommitted) // Throwing would give up attempting to close the session if need be, which may still succeed. So, // just log an error. _logger.Error( - "A synchronization timeout occurred at transaction completion: the session is still processing. Attempting " + - "to finalize the transaction concurrently, which may cause thread safety failure. You may " + - "raise {0} if it is set too low. It may also be a limitation of the data provider, like not " + - "supporting transaction scope timeouts occurring on concurrent threads.", + "A synchronization timeout occurred at transaction completion: the session is still processing. " + + "Attempting to finalize the transaction concurrently, which may cause a thread concurrency failure. " + + "You may raise {0} if it is set too low. It may also be a limitation of the data provider, " + + "like locks applied on its side while processing transaction cancellations occurring on concurrent threads, " + + "thus preventing the session to finish its current processing during a transaction cancellation.", Cfg.Environment.SystemTransactionCompletionLockTimeout); } } @@ -526,10 +527,11 @@ protected virtual void CompleteTransaction(bool isCommitted) if (isSessionProcessing) { throw new HibernateException( - "A synchronization timeout occurred at transaction completion: the session was still processing. You may " + - $"raise {Cfg.Environment.SystemTransactionCompletionLockTimeout} if it is set too low. It may also " + - "be a limitation of the data provider, like not supporting transaction scope timeouts occurring on " + - "concurrent threads."); + "A synchronization timeout occurred at transaction completion: the session was still processing. " + + $"You may raise {Cfg.Environment.SystemTransactionCompletionLockTimeout} if it is set too low. " + + "It may also be a limitation of the data provider, " + + "like locks applied on its side while processing transaction cancellations occurring on concurrent threads, " + + "thus preventing the session to finish its current processing during a transaction cancellation."); } } From 440807b81cf9b1784cbe94c096afe5dfb1b5620f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20Delaporte?= <12201973+fredericdelaporte@users.noreply.github.com> Date: Thu, 8 Feb 2024 10:35:34 +0100 Subject: [PATCH 08/22] Allow more control of synchronization failures --- build-common/teamcity-hibernate.cfg.xml | 2 + default.build | 20 +++++++++ doc/reference/modules/configuration.xml | 31 +++++++++++++- psake.ps1 | 2 + .../SapSQLAnywhere.cfg.xml | 2 + .../SystemTransactionFixture.cs | 5 ++- .../SapSQLAnywhere17TestDialect.cs | 6 --- src/NHibernate/Cfg/Environment.cs | 21 +++++++++- .../AdoNetWithSystemTransactionFactory.cs | 42 +++++++++++++++++-- src/NHibernate/nhibernate-configuration.xsd | 24 ++++++++++- teamcity.build | 2 + 11 files changed, 139 insertions(+), 18 deletions(-) diff --git a/build-common/teamcity-hibernate.cfg.xml b/build-common/teamcity-hibernate.cfg.xml index e8cb7f7e6dd..9cdad8f1e78 100644 --- a/build-common/teamcity-hibernate.cfg.xml +++ b/build-common/teamcity-hibernate.cfg.xml @@ -26,5 +26,7 @@ + + diff --git a/default.build b/default.build index c8020603e1c..2ee19e5a694 100644 --- a/default.build +++ b/default.build @@ -139,6 +139,26 @@ + + + + + + + + + + + + + + + + diff --git a/doc/reference/modules/configuration.xml b/doc/reference/modules/configuration.xml index dd0c4bd6a63..290e4e64bc0 100644 --- a/doc/reference/modules/configuration.xml +++ b/doc/reference/modules/configuration.xml @@ -1050,8 +1050,8 @@ var session = sessions.OpenSession(conn); after scope disposal. This occurs when the transaction is distributed. This notably concerns ISessionImplementor.AfterTransactionCompletion(bool, ITransaction). NHibernate protects the session from being concurrently used by the code following the scope disposal - with a lock. To prevent any application freeze, this lock has a default timeout of five seconds. If the - application appears to require longer (!) running transaction completion events, this setting allows to + with a lock. To prevent any application freeze, this lock has a default timeout of one second. If the + application appears to require longer running transaction completion events, this setting allows to raise this timeout. -1 disables the timeout. @@ -1060,6 +1060,33 @@ var session = sessions.OpenSession(conn); + + + transaction.ignore_session_synchronization_failures + + + Whether session synchronisation failures occuring during finalizations of system transaction should be + ignored or not. false by default. + + When a system transaction terminates abnormaly, especially through timeouts, it may have its + completion events running on concurrent threads while the session is still performing some processing. + To prevent threading concurrency failures, NHibernate then wait for the session to end its processing, + up to transaction.system_completion_lock_timeout. If the session processing is still ongoing + afterwards, it will by default log an error, perform transaction finalization processing concurrently, + then throw a synchronization error. This setting allows to disable that later throw. + + + Disabling the throw can be useful if the used data provider has its own locking mechanism applied + during transaction completion, preventing the session to end its processing. It may then be safe to + ignore this synchronization failure. In case of threading concurrency failure, you may then need to + raise transaction.system_completion_lock_timeout. + + + eg. + true | false + + + transaction.auto_join diff --git a/psake.ps1 b/psake.ps1 index 16f7a267f14..877321e24e3 100644 --- a/psake.ps1 +++ b/psake.ps1 @@ -29,6 +29,8 @@ Task Set-Configuration { 'connection.connection_string' = 'Server=(local)\SQL2017;Uid=sa;Pwd=Password12!;Database=nhibernateOdbc;Driver={SQL Server Native Client 11.0};Mars_Connection=yes;'; 'connection.driver_class' = 'NHibernate.Driver.OdbcDriver'; 'odbc.explicit_datetime_scale' = '3'; + 'transaction.ignore_session_synchronization_failures' = 'true'; + 'transaction.system_completion_lock_timeout' = '200'; <# We need to use a dialect that avoids mapping DbType.Time to TIME on MSSQL. On modern SQL Server this becomes TIME(7). Later, such values cannot be read back over ODBC. The error we get is "System.ArgumentException : Unknown SQL type - SS_TIME_EX.". I don't know for certain diff --git a/src/NHibernate.Config.Templates/SapSQLAnywhere.cfg.xml b/src/NHibernate.Config.Templates/SapSQLAnywhere.cfg.xml index 9512fef12d6..57e02f1a82e 100644 --- a/src/NHibernate.Config.Templates/SapSQLAnywhere.cfg.xml +++ b/src/NHibernate.Config.Templates/SapSQLAnywhere.cfg.xml @@ -17,5 +17,7 @@ for your own use before compiling tests in Visual Studio. NHibernate.Dialect.SybaseSQLAnywhere12Dialect true=1;false=0 + true + 200 diff --git a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs index 3644d2bbd64..adb753c7ed9 100644 --- a/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs +++ b/src/NHibernate.Test/SystemTransactions/SystemTransactionFixture.cs @@ -650,8 +650,9 @@ public void CanUseSessionWithManyDependentTransaction(bool explicitFlush) public void SupportsTransactionTimeout() { Assume.That(TestDialect.SupportsTransactionScopeTimeouts, Is.True, "The tested dialect is not supported for transaction scope timeouts."); - // ODBC always freezes the session during transaction scopes timeouts. - Assume.That(Sfi.ConnectionProvider.Driver, Is.Not.InstanceOf(typeof(OdbcDriver)), "ODBC is not supported for transaction scope timeouts."); + // Other special cases: ODBC succeeds this test only with transaction.ignore_session_synchronization_failures enabled. + // It freezes the session during the transaction cancellation. To avoid the test to be very long, the synchronization + // lock timeout should be lowered too. // Test case adapted from https://github.com/kaksmet/NHibBugRepro diff --git a/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs b/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs index c1d59cca066..3955f92aef7 100644 --- a/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs +++ b/src/NHibernate.Test/TestDialects/SapSQLAnywhere17TestDialect.cs @@ -43,11 +43,5 @@ public SapSQLAnywhere17TestDialect(Dialect.Dialect dialect) /// Does not support SELECT FOR UPDATE /// public override bool SupportsSelectForUpdate => false; - - /// - /// SQL Anywhere freezes on transaction scope timeout occuring on concurrent threads, always causing the - /// synchronization for end of session processing to timeout. - /// - public override bool SupportsTransactionScopeTimeouts => false; } } diff --git a/src/NHibernate/Cfg/Environment.cs b/src/NHibernate/Cfg/Environment.cs index cc107802524..c052cd64267 100644 --- a/src/NHibernate/Cfg/Environment.cs +++ b/src/NHibernate/Cfg/Environment.cs @@ -142,12 +142,29 @@ public static string Version /// after scope disposal. This occurs when the transaction is distributed. /// This notably concerns . /// NHibernate protects the session from being concurrently used by the code following the scope disposal - /// with a lock. To prevent any application freeze, this lock has a default timeout of five seconds. If the - /// application appears to require longer (!) running transaction completion events, this setting allows to + /// with a lock. To prevent any application freeze, this lock has a default timeout of one second. If the + /// application appears to require longer running transaction completion events, this setting allows to /// raise this timeout. -1 disables the timeout. /// public const string SystemTransactionCompletionLockTimeout = "transaction.system_completion_lock_timeout"; /// + /// Whether session synchronisation failures occuring during finalizations of system transaction should be + /// ignored or not. by default. + /// + /// + /// When a system transaction terminates abnormaly, especially through timeouts, it may have its + /// completion events running on concurrent threads while the session is still performing some processing. + /// To prevent threading concurrency failures, NHibernate then wait for the session to end its processing, + /// up to . If the session processing is still ongoing + /// afterwards, it will by default log an error, perform transaction finalization processing concurrently, + /// then throw a synchronization error. This setting allows to disable that later throw. + /// Disabling the throw can be useful if the used data provider has its own locking mechanism applied + /// during transaction completion, preventing the session to end its processing. It may then be safe to + /// ignore this synchronization failure. In case of threading concurrency failure, you may then need to + /// raise . + /// + public const string IgnoreSessionSynchronizationFailuresOnSystemTransaction = "transaction.ignore_session_synchronization_failures"; + /// /// When a system transaction is being prepared, is using connection during this process enabled? /// Default is , for supporting with transaction factories /// supporting system transactions. But this requires enlisting additional connections, retaining disposed diff --git a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs index 75ac955a69d..ad0703aedec 100644 --- a/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs +++ b/src/NHibernate/Transaction/AdoNetWithSystemTransactionFactory.cs @@ -24,6 +24,10 @@ public partial class AdoNetWithSystemTransactionFactory : AdoNetTransactionFacto /// protected int SystemTransactionCompletionLockTimeout { get; private set; } /// + /// See . + /// + protected bool IgnoreSessionSynchronizationFailuresOnSystemTransaction { get; private set; } + /// /// See . /// protected bool UseConnectionOnSystemTransactionPrepare { get; private set; } @@ -33,10 +37,12 @@ public override void Configure(IDictionary props) { base.Configure(props); SystemTransactionCompletionLockTimeout = - PropertiesHelper.GetInt32(Cfg.Environment.SystemTransactionCompletionLockTimeout, props, 5000); + PropertiesHelper.GetInt32(Cfg.Environment.SystemTransactionCompletionLockTimeout, props, 1000); if (SystemTransactionCompletionLockTimeout < -1) throw new HibernateException( $"Invalid {Cfg.Environment.SystemTransactionCompletionLockTimeout} value: {SystemTransactionCompletionLockTimeout}. It can not be less than -1."); + IgnoreSessionSynchronizationFailuresOnSystemTransaction = + PropertiesHelper.GetBoolean(Cfg.Environment.IgnoreSessionSynchronizationFailuresOnSystemTransaction, props, true); UseConnectionOnSystemTransactionPrepare = PropertiesHelper.GetBoolean(Cfg.Environment.UseConnectionOnSystemTransactionPrepare, props, true); } @@ -130,7 +136,7 @@ protected virtual ITransactionContext CreateAndEnlistMainContext( { var transactionContext = new SystemTransactionContext( session, transaction, SystemTransactionCompletionLockTimeout, - UseConnectionOnSystemTransactionPrepare); + UseConnectionOnSystemTransactionPrepare, IgnoreSessionSynchronizationFailuresOnSystemTransaction); transactionContext.EnlistedTransaction.EnlistVolatile( transactionContext, UseConnectionOnSystemTransactionPrepare @@ -189,6 +195,7 @@ public class SystemTransactionContext : ITransactionContext, IEnlistmentNotifica private readonly ISessionImplementor _session; private readonly bool _useConnectionOnSystemTransactionPrepare; + private readonly bool _ignoreSessionSynchronizationFailures; private readonly System.Transactions.Transaction _originalTransaction; private readonly ManualResetEventSlim _lock = new ManualResetEventSlim(true); private volatile bool _needCompletionLocking = true; @@ -204,6 +211,8 @@ public class SystemTransactionContext : ITransactionContext, IEnlistmentNotifica /// The transaction into which the context will be enlisted. /// See . /// See . + // Since 5.6 + [Obsolete("Use overload with an additionnal boolean parameter")] public SystemTransactionContext( ISessionImplementor session, System.Transactions.Transaction transaction, @@ -217,6 +226,29 @@ public SystemTransactionContext( _useConnectionOnSystemTransactionPrepare = useConnectionOnSystemTransactionPrepare; } + /// + /// Default constructor. + /// + /// The session to enlist with the transaction. + /// The transaction into which the context will be enlisted. + /// See . + /// See . + /// See . + public SystemTransactionContext( + ISessionImplementor session, + System.Transactions.Transaction transaction, + int systemTransactionCompletionLockTimeout, + bool useConnectionOnSystemTransactionPrepare, + bool ignoreSessionSynchronizationFailures) + { + _session = session ?? throw new ArgumentNullException(nameof(session)); + _originalTransaction = transaction ?? throw new ArgumentNullException(nameof(transaction)); + EnlistedTransaction = transaction.Clone(); + _systemTransactionCompletionLockTimeout = systemTransactionCompletionLockTimeout; + _useConnectionOnSystemTransactionPrepare = useConnectionOnSystemTransactionPrepare; + _ignoreSessionSynchronizationFailures = ignoreSessionSynchronizationFailures; + } + /// public virtual void Wait() { @@ -524,14 +556,16 @@ protected virtual void CompleteTransaction(bool isCommitted) Dispose(); } - if (isSessionProcessing) + if (isSessionProcessing && !_ignoreSessionSynchronizationFailures) { throw new HibernateException( "A synchronization timeout occurred at transaction completion: the session was still processing. " + $"You may raise {Cfg.Environment.SystemTransactionCompletionLockTimeout} if it is set too low. " + "It may also be a limitation of the data provider, " + "like locks applied on its side while processing transaction cancellations occurring on concurrent threads, " + - "thus preventing the session to finish its current processing during a transaction cancellation."); + "thus preventing the session to finish its current processing during a transaction cancellation. " + + $"In such case, you may enable {Cfg.Environment.IgnoreSessionSynchronizationFailuresOnSystemTransaction}, " + + $"and possibly lower {Cfg.Environment.SystemTransactionCompletionLockTimeout}."); } } diff --git a/src/NHibernate/nhibernate-configuration.xsd b/src/NHibernate/nhibernate-configuration.xsd index 08d922ad963..12abc622a52 100644 --- a/src/NHibernate/nhibernate-configuration.xsd +++ b/src/NHibernate/nhibernate-configuration.xsd @@ -233,12 +233,32 @@ after scope disposal. This occurs when the transaction is distributed. This notably concerns ISessionImplementor.AfterTransactionCompletion(bool, ITransaction). NHibernate protects the session from being concurrently used by the code following the scope disposal - with a lock. To prevent any application freeze, this lock has a default timeout of five seconds. If the - application appears to require longer (!) running transaction completion events, this setting allows to + with a lock. To prevent any application freeze, this lock has a default timeout of one second. If the + application appears to require longer running transaction completion events, this setting allows to raise this timeout. -1 disables the timeout. + + + + Whether session synchronisation failures occuring during finalizations of system transaction should be + ignored or not. false by default. + + When a system transaction terminates abnormaly, especially through timeouts, it may have its + completion events running on concurrent threads while the session is still performing some processing. + To prevent threading concurrency failures, NHibernate then wait for the session to end its processing, + up to transaction.system_completion_lock_timeout. If the session processing is still ongoing + afterwards, it will by default log an error, perform transaction finalization processing concurrently, + then throw a synchronization error. This setting allows to disable that later throw. + + Disabling the throw can be useful if the used data provider has its own locking mechanism applied + during transaction completion, preventing the session to end its processing. It may then be safe to + ignore this synchronization failure. In case of threading concurrency failure, you may then need to + raise transaction.system_completion_lock_timeout. + + + diff --git a/teamcity.build b/teamcity.build index b8125f5dfe5..9319ed389fc 100644 --- a/teamcity.build +++ b/teamcity.build @@ -50,6 +50,8 @@ + +