Skip to content

Commit

Permalink
Part 2 - Event Source trace revision
Browse files Browse the repository at this point in the history
  • Loading branch information
@cheenamalhotra
cheenamalhotra committed Jan 7, 2021
1 parent 743c6df commit 6b71c02
Show file tree
Hide file tree
Showing 10 changed files with 125 additions and 124 deletions.
50 changes: 27 additions & 23 deletions src/Microsoft.Data.SqlClient/netcore/src/Microsoft/Data/SqlClient/SqlConnection.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -942,7 +942,7 @@ public SqlTransaction BeginTransaction(string transactionName)
[SuppressMessage("Microsoft.Reliability", "CA2004:RemoveCallsToGCKeepAlive")]
override protected DbTransaction BeginDbTransaction(System.Data.IsolationLevel isolationLevel)
{
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("<prov.SqlConnection.BeginDbTransaction|API> {0}, isolationLevel={1}", ObjectID, (int)isolationLevel);
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("SqlConnection.BeginDbTransaction | API | Object Id {0}, Isolation Level {1}", ObjectID, (int)isolationLevel);
try
{
DbTransaction transaction = BeginTransaction(isolationLevel);
Expand All @@ -966,7 +966,7 @@ public SqlTransaction BeginTransaction(System.Data.IsolationLevel iso, string tr
{
WaitForPendingReconnection();
SqlStatistics statistics = null;
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("<sc.SqlConnection.BeginTransaction|API> {0}, iso={1}, transactionName='{2}'", ObjectID, (int)iso, transactionName);
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("SqlConnection.BeginTransaction | API | Object Id {0}, Iso {1}, Transaction Name '{2}'", ObjectID, (int)iso, transactionName);
try
{
statistics = SqlStatistics.StartTimer(Statistics);
Expand Down Expand Up @@ -1000,7 +1000,7 @@ public override void ChangeDatabase(string database)
{
SqlStatistics statistics = null;
RepairInnerConnection();
SqlClientEventSource.Log.TryCorrelationTraceEvent("<sc.SqlConnection.ChangeDatabase|API|Correlation> ObjectID{0}, ActivityID {1}", ObjectID, ActivityCorrelator.Current);
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.ChangeDatabase | API | Correlation | Object Id {0}, Activity Id {1}, Database {2}", ObjectID, ActivityCorrelator.Current, database);
try
{
statistics = SqlStatistics.StartTimer(Statistics);
Expand Down Expand Up @@ -1045,8 +1045,8 @@ private void CloseInnerConnection()
/// <include file='../../../../../../../doc/snippets/Microsoft.Data.SqlClient/SqlConnection.xml' path='docs/members[@name="SqlConnection"]/Close/*' />
public override void Close()
{
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("<sc.SqlConnection.Close|API> {0}", ObjectID);
SqlClientEventSource.Log.TryCorrelationTraceEvent("<sc.SqlConnection.Close|API|Correlation> ObjectID {0}, ActivityID {1}", ObjectID, ActivityCorrelator.Current);
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("SqlConnection.Close | API | Object Id {0}", ObjectID);
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.Close | API | Correlation | Object Id {0}, Activity Id {1}, Client Connection Id {2}", ObjectID, ActivityCorrelator.Current, ClientConnectionId);
try
{
ConnectionState previousState = State;
Expand Down Expand Up @@ -1165,8 +1165,8 @@ public override void Open()
/// <include file='../../../../../../../doc/snippets/Microsoft.Data.SqlClient/SqlConnection.xml' path='docs/members[@name="SqlConnection"]/OpenWithOverrides/*' />
public void Open(SqlConnectionOverrides overrides)
{
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("<sc.SqlConnection.Open|API|Correlation> ObjectID {0}, ActivityID {1}", ObjectID, ActivityCorrelator.Current);
SqlClientEventSource.Log.TryCorrelationTraceEvent("<sc.SqlConnection.Open|API|Correlation> ObjectID {0}, ActivityID {1}", ObjectID, ActivityCorrelator.Current);
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("SqlConnection.Open | API | Correlation | Object Id {0}, Activity Id {1}", ObjectID, ActivityCorrelator.Current);
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.Open | API | Correlation | Object Id {0}, Activity Id {1}", ObjectID, ActivityCorrelator.Current);
try
{
Guid operationId = s_diagnosticListener.WriteConnectionOpenBefore(this);
Expand Down Expand Up @@ -1240,7 +1240,7 @@ private async Task ReconnectAsync(int timeout)
{
if (ctoken.IsCancellationRequested)
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.ReconnectAsync|INFO> Original ClientConnectionID: {0} - reconnection cancelled.", _originalConnectionId);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.ReconnectAsync | Info | Original Client Connection Id {0}, reconnection cancelled.", _originalConnectionId);
return;
}
try
Expand All @@ -1259,15 +1259,15 @@ private async Task ReconnectAsync(int timeout)
{
ForceNewConnection = false;
}
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.ReconnectIfNeeded|INFO> Reconnection succeeded. ClientConnectionID {0} -> {1}", _originalConnectionId, ClientConnectionId);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.ReconnectAsync | Info | Reconnection succeeded. Client Connection Id {0} -> {1}", _originalConnectionId, ClientConnectionId);
return;
}
catch (SqlException e)
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.ReconnectAsyncINFO> Original ClientConnectionID {0} - reconnection attempt failed error {1}", _originalConnectionId, e.Message);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.ReconnectAsync | Info | Original Client Connection Id {0}, reconnection attempt failed error {1}", _originalConnectionId, e.Message);
if (attempt == retryCount - 1)
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.ReconnectAsync|INFO> Original ClientConnectionID {0} - give up reconnection", _originalConnectionId);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.ReconnectAsync | Info | Original Client Connection Id {0}, give up reconnection", _originalConnectionId);
throw SQL.CR_AllAttemptsFailed(e, _originalConnectionId);
}
if (timeout > 0 && ADP.TimerRemaining(commandTimeoutExpiration) < ADP.TimerFromSeconds(ConnectRetryInterval))
Expand Down Expand Up @@ -1340,7 +1340,7 @@ internal Task ValidateAndReconnect(Action beforeDisconnect, int timeout)
{
// could change since the first check, but now is stable since connection is know to be broken
_originalConnectionId = ClientConnectionId;
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.ReconnectIfNeeded|INFO> Connection ClientConnectionID {0} is invalid, reconnecting", _originalConnectionId);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.ValidateAndReconnect | Info | Connection Client Connection Id {0} is invalid, reconnecting", _originalConnectionId);
_recoverySessionData = cData;
if (beforeDisconnect != null)
{
Expand Down Expand Up @@ -1433,8 +1433,8 @@ private void CancelOpenAndWait()
/// <include file='../../../../../../../doc/snippets/Microsoft.Data.SqlClient/SqlConnection.xml' path='docs/members[@name="SqlConnection"]/OpenAsync/*' />
public override Task OpenAsync(CancellationToken cancellationToken)
{
long scopeID = SqlClientEventSource.Log.TryPoolerScopeEnterEvent("<sc.SqlConnection.OpenAsync|API> {0}", ObjectID);
SqlClientEventSource.Log.TryCorrelationTraceEvent("<sc.SqlConnection.OpenAsync|API|Correlation> ObjectID {0}, ActivityID {1}", ObjectID, ActivityCorrelator.Current);
long scopeID = SqlClientEventSource.Log.TryPoolerScopeEnterEvent("SqlConnection.OpenAsync | API | Object Id {0}", ObjectID);
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.OpenAsync | API | Correlation | Object Id {0}, Activity Id {1}", ObjectID, ActivityCorrelator.Current);
try
{
Guid operationId = s_diagnosticListener.WriteConnectionOpenBefore(this);
Expand Down Expand Up @@ -1521,10 +1521,12 @@ private static void OpenAsyncComplete(Task<object> task, object state)
SqlConnection connection = (SqlConnection)task.AsyncState;
if (task.Exception != null)
{
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.OpenAsyncComplete | Error | Correlation | Activity Id {0}, Exception {1}", ActivityCorrelator.Current, task.Exception.Message);
s_diagnosticListener.WriteConnectionOpenError(operationId, connection, task.Exception);
}
else
{
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.OpenAsyncComplete | Info | Correlation | Activity Id {0}, Client Connection Id {1}", ActivityCorrelator.Current, connection.ClientConnectionId);
s_diagnosticListener.WriteConnectionOpenAfter(operationId, connection);
}
}
Expand All @@ -1549,6 +1551,7 @@ public override DataTable GetSchema(string collectionName)
/// <include file='../../../../../../../doc/snippets/Microsoft.Data.SqlClient/SqlConnection.xml' path='docs/members[@name="SqlConnection"]/GetSchemaCollectionNameRestrictionValues/*' />
public override DataTable GetSchema(string collectionName, string[] restrictionValues)
{
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.GetSchema | Info | Object Id {0}, Collection Name '{1}'", ObjectID, collectionName);
return InnerConnection.GetSchema(ConnectionFactory, PoolGroup, this, collectionName, restrictionValues);
}

Expand All @@ -1565,11 +1568,12 @@ public OpenAsyncRetry(SqlConnection parent, TaskCompletionSource<DbConnectionInt
_retry = retry;
_result = result;
_registration = registration;
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.OpenAsyncRetry | Info | Object Id {0}", _parent?.ObjectID);
}

internal void Retry(Task<DbConnectionInternal> retryTask)
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.OpenAsyncRetry|Info> {0}", _parent.ObjectID);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.Retry | Info | Object Id {0}", _parent?.ObjectID);
_registration.Dispose();
try
{
Expand Down Expand Up @@ -1832,7 +1836,7 @@ internal void OnError(SqlException exception, bool breakConnection, Action<Actio
{
if (capturedCloseCount == _closeCount)
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.OnError|INFO> {0}, Connection broken.", ObjectID);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.OnError | Info | Object Id {0}, Connection broken.", ObjectID);
Close();
}
};
Expand All @@ -1841,7 +1845,7 @@ internal void OnError(SqlException exception, bool breakConnection, Action<Actio
}
else
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.OnError|INFO> {0}, Connection broken.", ObjectID);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.OnError | Info | Object Id {0}, Connection broken.", ObjectID);
Close();
}
}
Expand Down Expand Up @@ -1892,7 +1896,7 @@ internal void OnInfoMessage(SqlInfoMessageEventArgs imevent)

internal void OnInfoMessage(SqlInfoMessageEventArgs imevent, out bool notified)
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.OnInfoMessage|API|INFO> {0}, Message='{1}'", ObjectID, imevent.Message);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.OnInfoMessage | API | Info | Object Id {0}, Message '{1}'", ObjectID, imevent.Message);
SqlInfoMessageEventHandler handler = InfoMessage;
if (null != handler)
{
Expand All @@ -1918,8 +1922,8 @@ internal void OnInfoMessage(SqlInfoMessageEventArgs imevent, out bool notified)
/// <include file='../../../../../../../doc/snippets/Microsoft.Data.SqlClient/SqlConnection.xml' path='docs/members[@name="SqlConnection"]/ChangePasswordConnectionStringNewPassword/*' />
public static void ChangePassword(string connectionString, string newPassword)
{
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("<sc.SqlConnection.ChangePassword|API>");
SqlClientEventSource.Log.TryCorrelationTraceEvent("<sc.SqlConnection.ChangePassword|API|Correlation> ActivityID {0}", ActivityCorrelator.Current);
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("SqlConnection.ChangePassword | API | Password change requested.");
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.ChangePassword | API | Correlation | ActivityID {0}", ActivityCorrelator.Current);
try
{
if (string.IsNullOrEmpty(connectionString))
Expand Down Expand Up @@ -1958,8 +1962,8 @@ public static void ChangePassword(string connectionString, string newPassword)
/// <include file='../../../../../../../doc/snippets/Microsoft.Data.SqlClient/SqlConnection.xml' path='docs/members[@name="SqlConnection"]/ChangePasswordConnectionStringCredentialNewSecurePassword/*' />
public static void ChangePassword(string connectionString, SqlCredential credential, SecureString newSecurePassword)
{
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("<sc.SqlConnection.ChangePassword|API>");
SqlClientEventSource.Log.TryCorrelationTraceEvent("<sc.SqlConnection.ChangePassword|API|Correlation> ActivityID {0}", ActivityCorrelator.Current);
long scopeID = SqlClientEventSource.Log.TryScopeEnterEvent("SqlConnection.ChangePassword | API | Password change requested.");
SqlClientEventSource.Log.TryCorrelationTraceEvent("SqlConnection.ChangePassword | API | Correlation | ActivityID {0}", ActivityCorrelator.Current);
try
{
if (string.IsNullOrEmpty(connectionString))
Expand Down Expand Up @@ -2138,7 +2142,7 @@ private Assembly ResolveTypeAssembly(AssemblyName asmRef, bool throwOnError)
{
if (asmRef.Version != TypeSystemAssemblyVersion && SqlClientEventSource.Log.IsTraceEnabled())
{
SqlClientEventSource.Log.TryTraceEvent("<sc.SqlConnection.ResolveTypeAssembly> SQL CLR type version change: Server sent {0}, client will instantiate {1}", asmRef.Version, TypeSystemAssemblyVersion);
SqlClientEventSource.Log.TryTraceEvent("SqlConnection.ResolveTypeAssembly | SQL CLR type version change: Server sent {0}, client will instantiate {1}", asmRef.Version, TypeSystemAssemblyVersion);
}
asmRef.Version = TypeSystemAssemblyVersion;
}
Expand Down
Loading

0 comments on commit 6b71c02

Please sign in to comment.