diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIStreams.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIStreams.cs index eb8661d022..174f563ecd 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIStreams.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SNI/SNIStreams.cs @@ -33,6 +33,11 @@ public override async Task ReadAsync(byte[] buffer, int offset, int count, { return await base.ReadAsync(buffer, offset, count, cancellationToken).ConfigureAwait(false); } + catch (System.Exception e) + { + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNISslStream), EventType.ERR, "Internal Exception occurred while reading data: {0}", args0: e?.Message); + throw; + } finally { _readAsyncSemaphore.Release(); @@ -47,6 +52,11 @@ public override async Task WriteAsync(byte[] buffer, int offset, int count, Canc { await base.WriteAsync(buffer, offset, count, cancellationToken).ConfigureAwait(false); } + catch (System.Exception e) + { + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNISslStream), EventType.ERR, "Internal Exception occurred while writing data: {0}", args0: e?.Message); + throw; + } finally { _writeAsyncSemaphore.Release(); @@ -76,6 +86,11 @@ public override async Task ReadAsync(byte[] buffer, int offset, int count, { return await base.ReadAsync(buffer, offset, count, cancellationToken).ConfigureAwait(false); } + catch (System.Exception e) + { + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNINetworkStream), EventType.ERR, "Internal Exception occurred while reading data: {0}", args0: e?.Message); + throw; + } finally { _readAsyncSemaphore.Release(); @@ -90,6 +105,11 @@ public override async Task WriteAsync(byte[] buffer, int offset, int count, Canc { await base.WriteAsync(buffer, offset, count, cancellationToken).ConfigureAwait(false); } + catch (System.Exception e) + { + SqlClientEventSource.Log.TrySNITraceEvent(nameof(SNINetworkStream), EventType.ERR, "Internal Exception occurred while writing data: {0}", args0: e?.Message); + throw; + } finally { _writeAsyncSemaphore.Release(); diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlCommand.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlCommand.cs index 238e5d7221..17de6e97ec 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlCommand.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlCommand.cs @@ -253,6 +253,9 @@ internal bool IsActiveConnectionValid(SqlConnection activeConnection) internal void ResetAsyncState() { + SqlClientEventSource.Log.TryTraceEvent("CachedAsyncState.ResetAsyncState | API | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _cachedAsyncConnection?.ObjectID, _cachedAsyncConnection?.ClientConnectionId, + _cachedAsyncConnection?.Parser?.MARSOn, _cachedAsyncConnection?.AsyncCommandInProgress); _cachedAsyncCloseCount = -1; _cachedAsyncResult = null; if (_cachedAsyncConnection != null) @@ -270,6 +273,7 @@ internal void SetActiveConnectionAndResult(TaskCompletionSource completi { Debug.Assert(activeConnection != null, "Unexpected null connection argument on SetActiveConnectionAndResult!"); TdsParser parser = activeConnection?.Parser; + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.SetActiveConnectionAndResult | API | ObjectId {0}, Client Connection Id {1}, MARS={2}", activeConnection?.ObjectID, activeConnection?.ClientConnectionId, parser?.MARSOn); if ((parser == null) || (parser.State == TdsParserState.Closed) || (parser.State == TdsParserState.Broken)) { throw ADP.ClosedConnectionError(); @@ -1011,8 +1015,12 @@ protected override DbParameter CreateDbParameter() protected override void Dispose(bool disposing) { if (disposing) - { // release managed objects + { + // release managed objects _cachedMetaData = null; + + // reset async cache information to allow a second async execute + _cachedAsyncState?.ResetAsyncState(); } // release unmanaged objects base.Dispose(disposing); @@ -1271,14 +1279,22 @@ private void BeginExecuteNonQueryInternalReadStage(TaskCompletionSource cachedAsyncState.SetActiveConnectionAndResult(completion, nameof(EndExecuteNonQuery), _activeConnection); _stateObj.ReadSni(completion); } + + catch (System.OutOfMemoryException e) + { + _activeConnection.Abort(e); + throw; + } + catch (System.StackOverflowException e) + { + _activeConnection.Abort(e); + throw; + } catch (Exception) { // Similarly, if an exception occurs put the stateObj back into the pool. // and reset async cache information to allow a second async execute - if (null != _cachedAsyncState) - { - _cachedAsyncState.ResetAsyncState(); - } + _cachedAsyncState?.ResetAsyncState(); ReliablePutStateObject(); throw; } @@ -1287,7 +1303,9 @@ private void BeginExecuteNonQueryInternalReadStage(TaskCompletionSource private void VerifyEndExecuteState(Task completionTask, string endMethod, bool fullCheckForColumnEncryption = false) { Debug.Assert(completionTask != null); - + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.VerifyEndExecuteState | API | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); if (completionTask.IsCanceled) { if (_stateObj != null) @@ -1460,6 +1478,9 @@ private int EndExecuteNonQueryInternal(IAsyncResult asyncResult) private object InternalEndExecuteNonQuery(IAsyncResult asyncResult, bool isInternal, [CallerMemberName] string endMethod = "") { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.InternalEndExecuteNonQuery | INFO | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); VerifyEndExecuteState((Task)asyncResult, endMethod); WaitForAsyncResults(asyncResult, isInternal); @@ -1544,6 +1565,9 @@ private object InternalEndExecuteNonQuery(IAsyncResult asyncResult, bool isInter private Task InternalExecuteNonQuery(TaskCompletionSource completion, bool sendToPipe, int timeout, out bool usedCache, bool asyncWrite = false, bool inRetry = false, [CallerMemberName] string methodName = "") { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.InternalExecuteNonQuery | INFO | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); bool isAsync = (null != completion); usedCache = false; @@ -1780,14 +1804,23 @@ private void BeginExecuteXmlReaderInternalReadStage(TaskCompletionSource _cachedAsyncState.SetActiveConnectionAndResult(completion, nameof(EndExecuteXmlReader), _activeConnection); _stateObj.ReadSni(completion); } + catch (System.OutOfMemoryException e) + { + _activeConnection.Abort(e); + completion.TrySetException(e); + throw; + } + catch (System.StackOverflowException e) + { + _activeConnection.Abort(e); + completion.TrySetException(e); + throw; + } catch (Exception e) { // Similarly, if an exception occurs put the stateObj back into the pool. // and reset async cache information to allow a second async execute - if (null != _cachedAsyncState) - { - _cachedAsyncState.ResetAsyncState(); - } + _cachedAsyncState?.ResetAsyncState(); ReliablePutStateObject(); completion.TrySetException(e); } @@ -2034,6 +2067,9 @@ internal SqlDataReader EndExecuteReaderAsync(IAsyncResult asyncResult) private SqlDataReader EndExecuteReaderInternal(IAsyncResult asyncResult) { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.EndExecuteReaderInternal | API | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); SqlStatistics statistics = null; bool success = false; int? sqlExceptionNumber = null; @@ -2404,6 +2440,7 @@ long firstAttemptStart private void BeginExecuteReaderInternalReadStage(TaskCompletionSource completion) { Debug.Assert(completion != null, "CompletionSource should not be null"); + SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlCommand.BeginExecuteReaderInternalReadStage | INFO | Correlation | Object Id {0}, Activity Id {1}, Client Connection Id {2}, Command Text '{3}'", ObjectID, ActivityCorrelator.Current, Connection?.ClientConnectionId, CommandText); // Read SNI does not have catches for async exceptions, handle here. try { @@ -2411,14 +2448,23 @@ private void BeginExecuteReaderInternalReadStage(TaskCompletionSource co cachedAsyncState.SetActiveConnectionAndResult(completion, nameof(EndExecuteReader), _activeConnection); _stateObj.ReadSni(completion); } + catch (System.OutOfMemoryException e) + { + _activeConnection.Abort(e); + completion.TrySetException(e); + throw; + } + catch (System.StackOverflowException e) + { + _activeConnection.Abort(e); + completion.TrySetException(e); + throw; + } catch (Exception e) { // Similarly, if an exception occurs put the stateObj back into the pool. // and reset async cache information to allow a second async execute - if (null != _cachedAsyncState) - { - _cachedAsyncState.ResetAsyncState(); - } + _cachedAsyncState?.ResetAsyncState(); ReliablePutStateObject(); completion.TrySetException(e); } @@ -2426,6 +2472,9 @@ private void BeginExecuteReaderInternalReadStage(TaskCompletionSource co private SqlDataReader InternalEndExecuteReader(IAsyncResult asyncResult, bool isInternal, string endMethod) { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.InternalEndExecuteReader | INFO | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); VerifyEndExecuteState((Task)asyncResult, endMethod); WaitForAsyncResults(asyncResult, isInternal); diff --git a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs index 8645cee07e..1944d93a88 100644 --- a/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs +++ b/src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/TdsParserStateObject.cs @@ -2873,6 +2873,7 @@ public void ReadAsyncCallback(IntPtr key, PacketHandle packet, uint error) // to the outstanding GCRoot until AppDomain.Unload. // We live with the above for the time being due to the constraints of the current // reliability infrastructure provided by the CLR. + SqlClientEventSource.Log.TryTraceEvent("TdsParserStateObject.ReadAsyncCallback | Info | State Object Id {0}, received error {1} on idle connection", _objectID, (int)error); TaskCompletionSource source = _networkPacketTaskSource; #if DEBUG diff --git a/src/Microsoft.Data.SqlClient/netfx/src/Microsoft/Data/SqlClient/SqlCommand.cs b/src/Microsoft.Data.SqlClient/netfx/src/Microsoft/Data/SqlClient/SqlCommand.cs index 19fd0902f3..80cc71e709 100644 --- a/src/Microsoft.Data.SqlClient/netfx/src/Microsoft/Data/SqlClient/SqlCommand.cs +++ b/src/Microsoft.Data.SqlClient/netfx/src/Microsoft/Data/SqlClient/SqlCommand.cs @@ -223,6 +223,9 @@ internal bool IsActiveConnectionValid(SqlConnection activeConnection) [ReliabilityContract(Consistency.WillNotCorruptState, Cer.Success)] internal void ResetAsyncState() { + SqlClientEventSource.Log.TryTraceEvent("CachedAsyncState.ResetAsyncState | API | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _cachedAsyncConnection?.ObjectID, _cachedAsyncConnection?.ClientConnectionId, + _cachedAsyncConnection?.Parser?.MARSOn, _cachedAsyncConnection?.AsyncCommandInProgress); _cachedAsyncCloseCount = -1; _cachedAsyncResult = null; if (_cachedAsyncConnection != null) @@ -240,6 +243,7 @@ internal void SetActiveConnectionAndResult(TaskCompletionSource completi { Debug.Assert(activeConnection != null, "Unexpected null connection argument on SetActiveConnectionAndResult!"); TdsParser parser = activeConnection.Parser; + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.SetActiveConnectionAndResult | API | ObjectId {0}, Client Connection Id {1}, MARS={2}", activeConnection?.ObjectID, activeConnection?.ClientConnectionId, parser?.MARSOn); if ((parser == null) || (parser.State == TdsParserState.Closed) || (parser.State == TdsParserState.Broken)) { throw ADP.ClosedConnectionError(); @@ -1334,6 +1338,9 @@ protected override void Dispose(bool disposing) if (disposing) { // release managed objects _cachedMetaData = null; + + // reset async cache information to allow a second async execute + _cachedAsyncState?.ResetAsyncState(); } // release unmanaged objects base.Dispose(disposing); @@ -1645,6 +1652,9 @@ private void BeginExecuteNonQueryInternalReadStage(TaskCompletionSource private void VerifyEndExecuteState(Task completionTask, string endMethod, bool fullCheckForColumnEncryption = false) { Debug.Assert(completionTask != null); + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.VerifyEndExecuteState | API | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); if (completionTask.IsCanceled) { @@ -1812,6 +1822,9 @@ private int EndExecuteNonQueryInternal(IAsyncResult asyncResult) private object InternalEndExecuteNonQuery(IAsyncResult asyncResult, string endMethod, bool isInternal) { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.InternalEndExecuteNonQuery | INFO | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); TdsParser bestEffortCleanupTarget = null; RuntimeHelpers.PrepareConstrainedRegions(); @@ -1932,6 +1945,9 @@ private object InternalEndExecuteNonQuery(IAsyncResult asyncResult, string endMe private Task InternalExecuteNonQuery(TaskCompletionSource completion, string methodName, bool sendToPipe, int timeout, out bool usedCache, bool asyncWrite = false, bool inRetry = false) { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.InternalExecuteNonQuery | INFO | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); bool async = (null != completion); usedCache = false; @@ -2550,6 +2566,9 @@ private SqlDataReader EndExecuteReaderAsync(IAsyncResult asyncResult) private SqlDataReader EndExecuteReaderInternal(IAsyncResult asyncResult) { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.EndExecuteReaderInternal | API | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); SqlStatistics statistics = null; bool success = false; int? sqlExceptionNumber = null; @@ -2801,6 +2820,7 @@ private bool TriggerInternalEndAndRetryIfNecessary(CommandBehavior behavior, obj private void BeginExecuteReaderInternalReadStage(TaskCompletionSource completion) { Debug.Assert(completion != null, "CompletionSource should not be null"); + SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlCommand.BeginExecuteReaderInternalReadStage | INFO | Correlation | Object Id {0}, Activity Id {1}, Client Connection Id {2}, Command Text '{3}'", ObjectID, ActivityCorrelator.Current, Connection?.ClientConnectionId, CommandText); // Read SNI does not have catches for async exceptions, handle here. TdsParser bestEffortCleanupTarget = null; RuntimeHelpers.PrepareConstrainedRegions(); @@ -2862,6 +2882,9 @@ private void BeginExecuteReaderInternalReadStage(TaskCompletionSource co private SqlDataReader InternalEndExecuteReader(IAsyncResult asyncResult, string endMethod, bool isInternal) { + SqlClientEventSource.Log.TryTraceEvent("SqlCommand.InternalEndExecuteReader | INFO | ObjectId {0}, Client Connection Id {1}, MARS={2}, AsyncCommandInProgress={3}", + _activeConnection?.ObjectID, _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, _activeConnection?.AsyncCommandInProgress); VerifyEndExecuteState((Task)asyncResult, endMethod); WaitForAsyncResults(asyncResult, isInternal);