Skip to content
This repository has been archived by the owner on Jan 23, 2023. It is now read-only.
/ corefx Public archive

Don't capture AsyncLocals into SQL global timers #26065

Merged
merged 2 commits into from
Jan 30, 2018

Conversation

benaadams
Copy link
Member

@benaadams
Copy link
Member Author

OSX

Output: Discovering: System.ComponentModel.Composition.Tests
Output: Discovered:  System.ComponentModel.Composition.Tests
Output: Starting:    System.ComponentModel.Composition.Tests
Output: /Users/dotnet-bot/dotnetbuild/work/a0f1062e-868d-4cbd-960e-402ec086e2f6/Work/dcdfb836-f373-47f7-8aa3-dc3477392788/Unzip/RunTests.sh: line 87: 44414 Segmentation fault: 11  (core dumped) $RUNTIME_PATH/dotnet xunit.console.netcore.exe 
   System.ComponentModel.Composition.Tests.dll -xml testResults.xml -notrait Benchmark=true -notrait category=nonnetcoreapptests -notrait category=nonosxtests -notrait category=OuterLoop -notrait category=failing
Output: Traceback (most recent call last):
Output:   File "/Users/dotnet-bot/.dumpling/dumpling.py", line 33, in <module>
Output:     import psutil
Output: ImportError: No module named psutil
Output: Trying to find crash dumps for project: System.ComponentModel.Composition.Tests
Output: Uploading dump file: /Users/dotnet-bot/dotnetbuild/work/a0f1062e-868d-4cbd-960e-402ec086e2f6/Work/dcdfb836-f373-47f7-8aa3-dc3477392788/Unzip/core.44414
Output: ~/dotnetbuild/work/a0f1062e-868d-4cbd-960e-402ec086e2f6/Work/dcdfb836-f373-47f7-8aa3-dc3477392788/Unzip
Output: Finished running tests. End time=16:05:35. Return value was 139
Exit Code: 139

@dotnet-bot test OSX x64 Debug Build

@karelz
Copy link
Member

karelz commented Jan 18, 2018

@saurabh500 @corivera can you please take a look?

@saurabh500
Copy link
Contributor

@benaadams The original issue thread was very long. Can you give me a short version of what is going on ?
This PR seems to suppress capturing the AsyncLocals for Timer. Couldn't this problem exist with another type? Based on the PR my understanding is that, any usage of Timer should be wrapped in the pattern you have used in this PR.

Maybe I am missing something here.

@saurabh500
Copy link
Contributor

Thanks @karelz for bumping this thread

@benaadams
Copy link
Member Author

benaadams commented Jan 18, 2018

Timer captures asynclocals; so when it runs it runs with the same execution context of the call that set up the timer; which is likely a desirable default state.

However; the pool timers are lazily set up on first time use of the a db connection (also good); but they are application wide pools, so the shouldn't capture the asynclocals of the first call making a db connection.

The issue in https://github.com/dotnet/corefx/issues/25477#issuecomment-346866897 was that the authenticated user was stored in an asynclocal; so it was restored to the execution context every time the timer fired (not desirable).

Its not a security issue as the methods the timer calls don't touch the asynclocals and are isolated; however it will both prevent them from being GC'd and as in the issue they were subscribed to AsyncLocal.OnValueChanged the were receiving notifications everytime the timer fired saying that the asynclocals had been restored.

@benaadams
Copy link
Member Author

Based on the PR my understanding is that, any usage of Timer should be wrapped in the pattern you have used in this PR.

Correct, if its an application-wide timer; rather than a timer related to the local state.

I've opened quite a few PRs to fix it #26075, #26071, #26066, #26065, #26077, #26068

@saurabh500
Copy link
Contributor

@benaadams Thanks for the explanation and context.

bool restoreFlow = false;
try
{
if (!ExecutionContext.IsFlowSuppressed())
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This code/pattern is being used at multiple places. Can this be refactored into a reusable method. AdapterUtil.cs is a good place to put such utilities in System.Data

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

@benaadams benaadams changed the title Don't capture AsyncLocals into SQL ConnPool Don't capture AsyncLocals into SQL global timers Jan 23, 2018
@@ -728,6 +730,7 @@ private DbConnectionInternal CreateObject(DbConnection owningObject, DbConnectio

// timer allocation has to be done out of CER block
Timer t = new Timer(new TimerCallback(this.ErrorCallback), null, Timeout.Infinite, Timeout.Infinite);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a one shot local timer; doesn't require the change

@@ -333,6 +333,7 @@
<Reference Include="System.Text.Encoding.Extensions" />
<Reference Include="System.Text.RegularExpressions" />
<Reference Include="System.Threading" />
<Reference Include="System.Threading.Timer" />
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why did you need to add this additional dependency?

@@ -492,5 +492,32 @@ internal static void SetCurrentTransaction(Transaction transaction)
{
Transaction.Current = transaction;
}

internal static Timer CreateGlobalTimer(TimerCallback callback, object state, int dueTime, int period)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In case this change is causing you to add an additional dependency in System.Data.Common, it would make sense to move the change to System.Data.SqlClient\src\System\Data\Common\AdapterUtil.SqlClient.cs

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was assuming I could make use of it for ODBC which has the same issue? #26066

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, the code should be shared between the two PRs.

In this case you can create a src/Common/src/System/Data/Common/AdapterUtil.Drivers.cs and add this CreateGlobalTimer function to a partial ADP class. Then you could include the reference to the file in System.Data.SqlClient and S.D.Odbc. This way the function doesn't need to be compiled into S.D.Common.

The DbConnectionPool code that is duplicated in System/Data/ProviderBase of S.D.SqlClient and S.D.Odbc should be moved to a single code as well.

A little bit of History
What is happening in .Net framework is that S.D.Odbc and S.D.SqlClient reside in System.Data.dll
While moving these assemblies to .Net core, the connection pool code got duplicated. If there was a single set of files for connection pool, then a single PR would have taken care of this issue for both Odbc and SqlClient.
Consolidation of connection pool code is outside the scope of this PR. I will open an issue to consolidate the code for Connection Pool.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

@saurabh500
Copy link
Contributor

@benaadams the changes look good functuonally. Do you know if this can impact performance in any way?

@benaadams
Copy link
Member Author

test NETFX x86 Release Build

@benaadams
Copy link
Member Author

Do you know if this can impact performance in any way?

Shouldn't greatly; the setup only happens once, and the periodic trigger of the timer will be faster as it won't be restoring and undoing the ExecutionContext - but that is pretty fast

@benaadams
Copy link
Member Author

Same netfx SQLClient tests were failing in #26612 so might be infrastructure?

@benaadams
Copy link
Member Author

02:41:43       System.Data.SqlClient.Tests.DiagnosticTest.ExecuteNonQueryTest [FAIL]
02:41:43         System.Diagnostics.RemoteExecutorTestBase+RemoteInvokeHandle+RemoteExecutionException : Remote process failed with an unhandled exception.
02:41:43         Stack Trace:
02:41:43           
02:41:43           Child exception:
02:41:43             Xunit.Sdk.TrueException: Assert.True() Failure
02:41:43           Expected: True
02:41:43           Actual:   False
02:41:43              at System.Data.SqlClient.Tests.DiagnosticTest.CollectStatisticsDiagnostics(Action`1 sqlOperation, Boolean enableServerLogging, String methodName)
02:41:43              at System.Data.SqlClient.Tests.DiagnosticTest.<>c.<ExecuteNonQueryTest>b__5_0()
02:41:43           
02:41:43           Child process:
02:41:43             System.Data.SqlClient.Tests, Version=4.3.1.0, Culture=neutral, PublicKeyToken=9d77cc7ad39b68eb System.Data.SqlClient.Tests.DiagnosticTest+<>c Int32 <ExecuteNonQueryTest>b__5_0()
02:41:43           
02:41:43           
02:41:43   Test: ExecuteNonQueryAsyncTest Enabled Listeners
02:41:48     Discovering: System.Data.Common.Tests
02:41:48         System.Diagnostics.RemoteExecutorTestBase+RemoteInvokeHandle+RemoteExecutionException : Remote process failed with an unhandled exception.
02:41:48         Stack Trace:
02:41:48           
02:41:48           Child exception:
02:41:48             Xunit.Sdk.TrueException: Assert.True() Failure
02:41:48           Expected: True
02:41:48           Actual:   False
02:41:48              at System.Data.SqlClient.Tests.DiagnosticTest.<CollectStatisticsDiagnosticsAsync>d__25.MoveNext()
02:41:48           --- End of stack trace from previous location where exception was thrown ---
02:41:48              at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
02:41:48              at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
02:41:48              at System.Data.SqlClient.Tests.DiagnosticTest.<>c.<ExecuteNonQueryAsyncTest>b__14_0()
02:41:48           
02:41:48           Child process:
02:41:48             System.Data.SqlClient.Tests, Version=4.3.1.0, Culture=neutral, PublicKeyToken=9d77cc7ad39b68eb System.Data.SqlClient.Tests.DiagnosticTest+<>c Int32 <ExecuteNonQueryAsyncTest>b__14_0()

etc

@benaadams
Copy link
Member Author

benaadams commented Jan 28, 2018

NETFX x86 failures https://github.com/dotnet/corefx/issues/26615

internal static partial class ADP
{

internal static Timer CreateGlobalTimer(TimerCallback callback, object state, int dueTime, int period)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: I would call it UnsafeCreateTimer. Then it can be replaced by Timer.UnsafeCreate if/when it's added.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Changed

// Don't capture the current ExecutionContext and its AsyncLocals onto
// a global timer causing them to live forever

Timer timer;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can just return it from within the try block rather than declaring it here, initializing it in the try, and then returning it after the finally.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Changed

_retryTimer = null;
retryTimer?.Dispose();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's not a big deal, but as long as we're doing the null check, we may as well avoid the unnecessary null write:

Timer retryTimer = _retryTimer;
if (retryTimer != null)
{
    _returnTimer = null;
    retryTimer.Dispose();
}

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Changed

@stephentoub
Copy link
Member

@dotnet-bot test NETFX x86 Release Build please

@stephentoub stephentoub merged commit 093126c into dotnet:master Jan 30, 2018
@benaadams benaadams deleted the sqlconn-pool branch January 30, 2018 15:19
@karelz karelz added this to the 2.1.0 milestone Feb 4, 2018
picenka21 pushed a commit to picenka21/runtime that referenced this pull request Feb 18, 2022
* Don't capture AsyncLocals into SQL global timers

* Feedback


Commit migrated from dotnet/corefx@093126c
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
5 participants