From 6495e3f211d0e9f298921c3e585afd5ac3fde62c Mon Sep 17 00:00:00 2001 From: Malcolm Daigle Date: Wed, 12 Aug 2026 10:06:20 -0700 Subject: [PATCH] Use parameterized trace calls instead of eager interpolated strings (#4528) Backport of #4528 to release/7.0. 119 SqlClientEventSource.Log.Try*Event call sites were converted to C# interpolated strings during the netfx/netcore unification. Those overloads guard internally on the enablement check, but an interpolated string is built at the call site before the call, so the guard saves nothing and every traced operation allocates even with tracing off. This restores the format string plus arguments style used in 6.1.6. Also carries the correctness fixes from the original PR: - OnFeatureExtAck logged $"Object ID {0}", which always reported 0 because {0} is the expression 0 inside an interpolated string. - Two sites kept a redundant trailing format argument that could raise a FormatException from inside tracing. - Three fed auth sites relied on a {1:T} specifier, which the generic overloads drop because they ToString() arguments before string.Format. These are guarded and pass pre-formatted time strings. Conflicts: 5 whitespace-only hunks in SqlCommand.NonQuery.cs and SqlCommand.Xml.cs, resolved to the parameterized form. The AsyncHelper.cs site was dropped because that file does not exist on release/7.0. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- .../Connection/SqlConnectionInternal.cs | 488 +++++++++++------- .../SqlAuthenticationProviderManager.cs | 47 +- .../Data/SqlClient/SqlCommand.NonQuery.cs | 135 +++-- .../Data/SqlClient/SqlCommand.Reader.cs | 150 ++++-- .../Data/SqlClient/SqlCommand.Scalar.cs | 33 +- .../Data/SqlClient/SqlCommand.Xml.cs | 76 ++- .../Microsoft/Data/SqlClient/SqlCommand.cs | 137 +++-- 7 files changed, 669 insertions(+), 397 deletions(-) diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/Connection/SqlConnectionInternal.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/Connection/SqlConnectionInternal.cs index c9b069cd21..f603beff68 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/Connection/SqlConnectionInternal.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/Connection/SqlConnectionInternal.cs @@ -474,9 +474,10 @@ internal SqlConnectionInternal( } SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.ctor | ADV | " + - $"Object ID {ObjectID}, " + - $"constructed new TDS internal connection"); + "SqlInternalConnectionTds.ctor | ADV | " + + "Object ID {0}, " + + "constructed new TDS internal connection", + ObjectID); } #endregion @@ -903,9 +904,10 @@ internal SqlTransaction BeginSqlTransaction( internal void BreakConnection() { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.BreakConnection | RES | CPOOL " + - $"Object ID {ObjectID}, " + - $"Breaking connection."); + "SqlInternalConnectionTds.BreakConnection | RES | CPOOL " + + "Object ID {0}, " + + "Breaking connection.", + ObjectID); DoomThisConnection(); // Mark connection as unusable, so it will be destroyed Connection?.Close(); @@ -980,8 +982,9 @@ internal void DisconnectTransaction(SqlInternalTransaction internalTransaction) public override void Dispose() { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.Dispose | ADV | " + - $"Object ID {ObjectID} disposing"); + "SqlInternalConnectionTds.Dispose | ADV | " + + "Object ID {0} disposing", + ObjectID); try { @@ -1012,9 +1015,10 @@ public override void Dispose() internal void EnlistNull() { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnection.EnlistNull | ADV | " + - $"Object ID {ObjectID}, " + - $"unenlisting."); + "SqlInternalConnection.EnlistNull | ADV | " + + "Object ID {0}, " + + "unenlisting.", + ObjectID); // We were in a transaction, but now we are not - so send message to server with empty // transaction - confirmed proper behavior from Sameet Agarwal. @@ -1032,9 +1036,10 @@ internal void EnlistNull() EnlistedTransaction = null; SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnection.EnlistNull | ADV | " + - $"Object ID {ObjectID}, " + - $"unenlisted."); + "SqlInternalConnection.EnlistNull | ADV | " + + "Object ID {0}, " + + "unenlisted.", + ObjectID); // The EnlistTransaction above will return an TransactionEnded event, which causes the // TdsParser to clear the current transaction. In either case, when we're working with @@ -1242,9 +1247,10 @@ internal void OnEnvChange(SqlEnvChange rec) case TdsEnums.ENV_ROUTING: SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnEnvChange | ADV | " + - $"Object ID {ObjectID}, " + - $"Received routing info"); + "SqlInternalConnectionTds.OnEnvChange | ADV | " + + "Object ID {0}, " + + "Received routing info", + ObjectID); if (string.IsNullOrEmpty(rec._newRoutingInfo.ServerName) || rec._newRoutingInfo.Protocol != 0 || @@ -1258,9 +1264,10 @@ internal void OnEnvChange(SqlEnvChange rec) case TdsEnums.ENV_ENHANCEDROUTING: SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnEnvChange | ADV | " + - $"Object ID {ObjectID}, " + - $"Received enhanced routing info"); + "SqlInternalConnectionTds.OnEnvChange | ADV | " + + "Object ID {0}, " + + "Received enhanced routing info", + ObjectID); if (string.IsNullOrEmpty(rec._newRoutingInfo.ServerName) || string.IsNullOrEmpty(rec._newRoutingInfo.DatabaseName) || @@ -1382,16 +1389,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_GLOBALTRANSACTIONS: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for GlobalTransactions"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for GlobalTransactions", + ObjectID); if (data.Length < 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown version number for GlobalTransactions"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown version number for GlobalTransactions", + ObjectID); throw SQL.ParsingError(); } @@ -1408,16 +1417,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_FEDAUTH: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {0}, " + - $"Received feature extension acknowledgement for federated authentication"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for federated authentication", + ObjectID); if (!_federatedAuthenticationRequested) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Did not request federated authentication"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Did not request federated authentication", + ObjectID); throw SQL.ParsingErrorFeatureId(ParsingErrorState.UnrequestedFeatureAckReceived, featureId); } @@ -1433,9 +1444,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if (data.Length != 0) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Federated authentication feature extension ack for MSAL and Security Token includes extra data"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Federated authentication feature extension ack for MSAL and Security Token includes extra data", + ObjectID); throw SQL.ParsingError(ParsingErrorState.FedAuthFeatureAckContainsExtraData); } @@ -1444,9 +1456,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) default: SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Attempting to use unknown federated authentication library"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Attempting to use unknown federated authentication library", + ObjectID); Debug.Fail("Unknown _fedAuthLibrary type"); throw SQL.ParsingErrorLibraryType( @@ -1484,17 +1497,19 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if (newAuthenticationContextInCacheAfterAddOrUpdate == _newDbConnectionPoolAuthenticationContext) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Updated the new dbAuthenticationContext in the _dbConnectionPool.AuthenticationContexts."); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Updated the new dbAuthenticationContext in the _dbConnectionPool.AuthenticationContexts.", + ObjectID); } else { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID }, " + - $"AddOrUpdate attempted on _dbConnectionPool.AuthenticationContexts, " + - $"but it did not update the new value."); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "AddOrUpdate attempted on _dbConnectionPool.AuthenticationContexts, " + + "but it did not update the new value.", + ObjectID); } #endif } @@ -1504,16 +1519,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_TCE: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for TCE"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for TCE", + ObjectID); if (data.Length < 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown version number for TCE"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown version number for TCE", + ObjectID); throw SQL.ParsingError(ParsingErrorState.TceUnknownVersion); } @@ -1522,9 +1539,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if (supportedTceVersion == 0 || supportedTceVersion > TdsEnums.MAX_SUPPORTED_TCE_VERSION) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Invalid version number for TCE"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Invalid version number for TCE", + ObjectID); throw SQL.ParsingErrorValue(ParsingErrorState.TceInvalidVersion, supportedTceVersion); } @@ -1548,9 +1566,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_AZURESQLSUPPORT: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for AzureSQLSupport"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for AzureSQLSupport", + ObjectID); if (data.Length < 1) { @@ -1564,9 +1583,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if ((data[0] & 1) == 1 && SqlClientEventSource.Log.IsTraceEnabled()) { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"FailoverPartner enabled with Readonly intent for AzureSQL DB"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "FailoverPartner enabled with Readonly intent for AzureSQL DB", + ObjectID); } break; @@ -1574,16 +1594,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_DATACLASSIFICATION: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for DATACLASSIFICATION"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for DATACLASSIFICATION", + ObjectID); if (data.Length < 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown token for DATACLASSIFICATION"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown token for DATACLASSIFICATION", + ObjectID); throw SQL.ParsingError(ParsingErrorState.CorruptedTdsStream); } @@ -1593,9 +1615,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) supportedDataClassificationVersion > TdsEnums.DATA_CLASSIFICATION_VERSION_MAX_SUPPORTED) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Invalid version number for DATACLASSIFICATION"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Invalid version number for DATACLASSIFICATION", + ObjectID); throw SQL.ParsingErrorValue( ParsingErrorState.DataClassificationInvalidVersion, @@ -1605,9 +1628,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if (data.Length != 2) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown token for DATACLASSIFICATION"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown token for DATACLASSIFICATION", + ObjectID); throw SQL.ParsingError(ParsingErrorState.CorruptedTdsStream); } @@ -1623,16 +1647,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_UTF8SUPPORT: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for UTF8 support"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for UTF8 support", + ObjectID); if (data.Length < 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown value for UTF8 support", ObjectID); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown value for UTF8 support", + ObjectID); throw SQL.ParsingError(); } @@ -1641,16 +1667,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_SQLDNSCACHING: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for SQLDNSCACHING"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for SQLDNSCACHING", + ObjectID); if (data.Length < 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown token for SQLDNSCACHING"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown token for SQLDNSCACHING", + ObjectID); throw SQL.ParsingError(ParsingErrorState.CorruptedTdsStream); } @@ -1681,16 +1709,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_JSONSUPPORT: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for JSONSUPPORT"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for JSONSUPPORT", + ObjectID); if (data.Length != 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown token for JSONSUPPORT"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown token for JSONSUPPORT", + ObjectID); throw SQL.ParsingError(ParsingErrorState.CorruptedTdsStream); } @@ -1699,9 +1729,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if (jsonSupportVersion == 0 || jsonSupportVersion > TdsEnums.MAX_SUPPORTED_JSON_VERSION) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Invalid version number for JSONSUPPORT"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Invalid version number for JSONSUPPORT", + ObjectID); throw SQL.ParsingError(); } @@ -1712,16 +1743,18 @@ internal void OnFeatureExtAck(int featureId, byte[] data) case TdsEnums.FEATUREEXT_VECTORSUPPORT: { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for VECTORSUPPORT"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for VECTORSUPPORT", + ObjectID); if (data.Length != 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown token for VECTORSUPPORT"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown token for VECTORSUPPORT", + ObjectID); throw SQL.ParsingError(ParsingErrorState.CorruptedTdsStream); } @@ -1730,10 +1763,13 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if (vectorSupportVersion == 0 || vectorSupportVersion > TdsEnums.MAX_SUPPORTED_VECTOR_VERSION) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Invalid version number {vectorSupportVersion} for VECTORSUPPORT, " + - $"Max supported version is {TdsEnums.MAX_SUPPORTED_VECTOR_VERSION}"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Invalid version number {1} for VECTORSUPPORT, " + + "Max supported version is {2}", + ObjectID, + vectorSupportVersion, + TdsEnums.MAX_SUPPORTED_VECTOR_VERSION); throw SQL.ParsingError(); } @@ -1747,9 +1783,10 @@ internal void OnFeatureExtAck(int featureId, byte[] data) if (data.Length != 1) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + - $"Object ID {ObjectID}, " + - $"Unknown token for ENHANCEDROUTINGSUPPORT"); + "SqlInternalConnectionTds.OnFeatureExtAck | ERR | " + + "Object ID {0}, " + + "Unknown token for ENHANCEDROUTINGSUPPORT", + ObjectID); throw SQL.ParsingError(ParsingErrorState.CorruptedTdsStream); } @@ -1758,19 +1795,22 @@ internal void OnFeatureExtAck(int featureId, byte[] data) IsEnhancedRoutingSupportEnabled = data[0] == 1; SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for " + - $"ENHANCEDROUTINGSUPPORT = {IsEnhancedRoutingSupportEnabled}"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for " + + "ENHANCEDROUTINGSUPPORT = {1}", + ObjectID, + IsEnhancedRoutingSupportEnabled); break; } case TdsEnums.FEATUREEXT_USERAGENT: { // Unexpected ack from server but we ignore it entirely SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + - $"Object ID {ObjectID}, " + - $"Received feature extension acknowledgement for USERAGENTSUPPORT (ignored)"); + "SqlInternalConnectionTds.OnFeatureExtAck | ADV | " + + "Object ID {0}, " + + "Received feature extension acknowledgement for USERAGENTSUPPORT (ignored)", + ObjectID); break; } @@ -1842,13 +1882,19 @@ internal void OnFedAuthInfo(SqlFedAuthInfo fedAuthInfo) // If the authentication context is expiring within next 10 minutes, lets // just re-create a token for this connection attempt. And on successful // login, try to update the cache with the new token. - SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFedAuthInfo | " + - $"Object ID {ObjectID}, " + - $"The expiration time is less than 10 mins, trying to get new access " + - $"token regardless of if an other thread is also trying to update it. " + - $"The expiration time is {dbConnectionPoolAuthenticationContext.ExpirationTime:T}. " + - $"Current Time is {DateTime.UtcNow:T}."); + if (SqlClientEventSource.Log.IsTraceEnabled()) + { + SqlClientEventSource.Log.TryTraceEvent( + "SqlInternalConnectionTds.OnFedAuthInfo | " + + "Object ID {0}, " + + "The expiration time is less than 10 mins, trying to get new access " + + "token regardless of if an other thread is also trying to update it. " + + "The expiration time is {1}. " + + "Current Time is {2}.", + ObjectID, + dbConnectionPoolAuthenticationContext.ExpirationTime.ToString("T"), + DateTime.UtcNow.ToString("T")); + } attemptRefreshTokenUnLocked = true; } #if DEBUG @@ -1870,12 +1916,18 @@ internal void OnFedAuthInfo(SqlFedAuthInfo fedAuthInfo) // If the token is expiring within the next 45 mins, try to fetch a new // token, if there is no thread already doing it. If a thread is already // doing the refresh, just use the existing token in the cache and proceed. - SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFedAuthInfo | ADV | " + - $"Object ID {ObjectID}, " + - $"The authentication context needs a refresh. " + - $"The expiration time is {dbConnectionPoolAuthenticationContext.ExpirationTime:T}. " + - $"Current Time is {DateTime.UtcNow:T}."); + if (SqlClientEventSource.Log.IsAdvancedTraceOn()) + { + SqlClientEventSource.Log.TryAdvancedTraceEvent( + "SqlInternalConnectionTds.OnFedAuthInfo | ADV | " + + "Object ID {0}, " + + "The authentication context needs a refresh. " + + "The expiration time is {1}. " + + "Current Time is {2}.", + ObjectID, + dbConnectionPoolAuthenticationContext.ExpirationTime.ToString("T"), + DateTime.UtcNow.ToString("T")); + } // Call the function which tries to acquire a lock over the authentication // context before trying to update. If the lock could not be obtained, it @@ -1898,17 +1950,19 @@ internal void OnFedAuthInfo(SqlFedAuthInfo fedAuthInfo) if (attemptRefreshTokenLocked) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.OnFedAuthInfo | " + - $"Object ID {ObjectID}, " + - $"The attempt to get a new access token succeeded under the locked mode."); + "SqlInternalConnectionTds.OnFedAuthInfo | " + + "Object ID {0}, " + + "The attempt to get a new access token succeeded under the locked mode.", + ObjectID); } } SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.OnFedAuthInfo | " + - $"Object ID {ObjectID}, " + - $"Found an authentication context in the cache that does not need a refresh at this time. " + - $"Re-using the cached token."); + "SqlInternalConnectionTds.OnFedAuthInfo | " + + "Object ID {0}, " + + "Found an authentication context in the cache that does not need a refresh at this time. " + + "Re-using the cached token.", + ObjectID); } } @@ -2070,9 +2124,11 @@ protected override void Deactivate() try { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnection.Deactivate | ADV | " + - $"Object ID {ObjectID} deactivating, " + - $"Client Connection Id {Connection?.ClientConnectionId}"); + "SqlInternalConnection.Deactivate | ADV | " + + "Object ID {0} deactivating, " + + "Client Connection Id {1}", + ObjectID, + Connection?.ClientConnectionId); SqlReferenceCollection referenceCollection = (SqlReferenceCollection)ReferenceCollection; referenceCollection?.Deactivate(); @@ -2275,18 +2331,20 @@ private void CompleteLogin(bool enlistOK) // @TODO: Rename as per guidelines if (_federatedAuthenticationRequested && !_federatedAuthenticationAcknowledged) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.CompleteLogin | ERR | " + - $"Object ID {ObjectID}, " + - $"Server did not acknowledge the federated authentication request"); + "SqlInternalConnectionTds.CompleteLogin | ERR | " + + "Object ID {0}, " + + "Server did not acknowledge the federated authentication request", + ObjectID); throw SQL.ParsingError(ParsingErrorState.FedAuthNotAcknowledged); } if (_federatedAuthenticationInfoRequested && !_federatedAuthenticationInfoReceived) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.CompleteLogin | ERR | " + - $"Object ID {ObjectID}, " + - $"Server never sent the requested federated authentication info"); + "SqlInternalConnectionTds.CompleteLogin | ERR | " + + "Object ID {0}, " + + "Server never sent the requested federated authentication info", + ObjectID); throw SQL.ParsingError(ParsingErrorState.FedAuthInfoNotReceived); } @@ -2403,10 +2461,12 @@ private void EnlistNonNull(Transaction transaction) Debug.Assert(transaction != null, "null transaction?"); SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnection.EnlistNonNull | ADV | " + - $"Object ID {ObjectID}, " + - $"Transaction Id {transaction?.TransactionInformation?.LocalIdentifier}, " + - $"attempting to delegate."); + "SqlInternalConnection.EnlistNonNull | ADV | " + + "Object ID {0}, " + + "Transaction Id {1}, " + + "attempting to delegate.", + ObjectID, + transaction?.TransactionInformation?.LocalIdentifier); bool hasDelegatedTransaction = false; SqlDelegatedTransaction delegatedTransaction = new(this, transaction); @@ -2465,11 +2525,15 @@ private void EnlistNonNull(Transaction transaction) { DelegatedTransaction = delegatedTransaction; SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnection.EnlistNonNull | ADV | " + - $"Object ID {ObjectID}, " + - $"Client Connection Id {Connection?.ClientConnectionId} " + - $"delegated to transaction {delegatedTransaction?.ObjectID} " + - $"with transactionId {delegatedTransaction?.Transaction?.TransactionInformation?.LocalIdentifier}"); + "SqlInternalConnection.EnlistNonNull | ADV | " + + "Object ID {0}, " + + "Client Connection Id {1} " + + "delegated to transaction {2} " + + "with transactionId {3}", + ObjectID, + Connection?.ClientConnectionId, + delegatedTransaction?.ObjectID, + delegatedTransaction?.Transaction?.TransactionInformation?.LocalIdentifier); } } catch (SqlException e) @@ -2499,9 +2563,10 @@ private void EnlistNonNull(Transaction transaction) if (!hasDelegatedTransaction) { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnection.EnlistNonNull | ADV | " + - $"Object ID {ObjectID}, " + - $"delegation not possible, enlisting."); + "SqlInternalConnection.EnlistNonNull | ADV | " + + "Object ID {0}, " + + "delegation not possible, enlisting.", + ObjectID); byte[] cookie = null; @@ -2530,10 +2595,13 @@ private void EnlistNonNull(Transaction transaction) IsEnlistedInTransaction = true; SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnection.EnlistNonNull | ADV | " + - $"Object ID {ObjectID}, " + - $"Client Connection Id {Connection?.ClientConnectionId}, " + - $"Enlisted in transaction with transactionId {transaction?.TransactionInformation?.LocalIdentifier}"); + "SqlInternalConnection.EnlistNonNull | ADV | " + + "Object ID {0}, " + + "Client Connection Id {1}, " + + "Enlisted in transaction with transactionId {2}", + ObjectID, + Connection?.ClientConnectionId, + transaction?.TransactionInformation?.LocalIdentifier); } // Tell the base class about our enlistment @@ -3120,8 +3188,9 @@ private void Login( private void LoginFailure() { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.LoginFailure | RES | CPOOL | " + - $"Object ID {ObjectID}"); + "SqlInternalConnectionTds.LoginFailure | RES | CPOOL | " + + "Object ID {0}", + ObjectID); // If the parser was allocated, and we failed, then we must have failed on either the // Connect or Login, either way we should call Disconnect. Disconnect can be called if @@ -3160,9 +3229,11 @@ private void LoginNoFailover( ServerInfo originalServerInfo = serverInfo; SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.LoginNoFailover | ADV | " + - $"Object ID {ObjectID}, " + - $"Host={serverInfo.UserServerName}"); + "SqlInternalConnectionTds.LoginNoFailover | ADV | " + + "Object ID {0}, " + + "Host={1}", + ObjectID, + serverInfo.UserServerName); // Milliseconds to sleep (back off) between attempts. int sleepInterval = 100; @@ -3300,15 +3371,16 @@ private void LoginNoFailover( if (!string.IsNullOrEmpty(RoutingInfo.DatabaseName) && !IsEnhancedRoutingSupportEnabled) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.LoginNoFailover | " + - $"Ignoring enhanced routing info because the server did not acknowledge the feature."); + "SqlInternalConnectionTds.LoginNoFailover | " + + "Ignoring enhanced routing info because the server did not acknowledge the feature."); RoutingInfo = null; break; } SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.LoginNoFailover | " + - $"Routed to {serverInfo.ExtendedServerName}"); + "SqlInternalConnectionTds.LoginNoFailover | " + + "Routed to {0}", + serverInfo.ExtendedServerName); if (routingAttempts > MaxNumberOfRedirectRoute) { @@ -3413,9 +3485,11 @@ private void LoginNoFailover( // Sleep for a bit to prevent clogging the network with requests, then update sleep // interval for next iteration (max 1 second interval) SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.LoginNoFailover | ADV " + - $"Object ID {ObjectID}, " + - $"Sleeping {sleepInterval}ms"); + "SqlInternalConnectionTds.LoginNoFailover | ADV " + + "Object ID {0}, " + + "Sleeping {1}ms", + ObjectID, + sleepInterval); Thread.Sleep(sleepInterval); @@ -3478,11 +3552,15 @@ private void LoginWithFailover( "MultiSubnetFailover should not be set if failover partner is used"); SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.LoginWithFailover | ADV | " + - $"Object ID {ObjectID}, " + - $"useFailover={useFailoverHost}, " + - $"primary={primaryServerInfo.UserServerName}, " + - $"failover={failoverHost}"); + "SqlInternalConnectionTds.LoginWithFailover | ADV | " + + "Object ID {0}, " + + "useFailover={1}, " + + "primary={2}, " + + "failover={3}", + ObjectID, + useFailoverHost, + primaryServerInfo.UserServerName, + failoverHost); #if NETFRAMEWORK string protocol = ConnectionOptions.NetworkLibrary; @@ -3564,17 +3642,21 @@ private void LoginWithFailover( if (LocalAppContextSwitches.IgnoreServerProvidedFailoverPartner) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.LoginWithFailover | ADV | " + - $"Object ID {ObjectID}, " + - $"Ignoring server provided failover partner '{ServerProvidedFailoverPartner}' " + - $"due to IgnoreServerProvidedFailoverPartner AppContext switch."); + "SqlInternalConnectionTds.LoginWithFailover | ADV | " + + "Object ID {0}, " + + "Ignoring server provided failover partner '{1}' " + + "due to IgnoreServerProvidedFailoverPartner AppContext switch.", + ObjectID, + ServerProvidedFailoverPartner); } else { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.LoginWithFailover | ADV | " + - $"Object ID {ObjectID}, " + - $"new failover partner={ServerProvidedFailoverPartner}"); + "SqlInternalConnectionTds.LoginWithFailover | ADV | " + + "Object ID {0}, " + + "new failover partner={1}", + ObjectID, + ServerProvidedFailoverPartner); #if NET failoverServerInfo.SetDerivedNames(string.Empty, ServerProvidedFailoverPartner); @@ -3612,8 +3694,8 @@ private void LoginWithFailover( if (!string.IsNullOrEmpty(RoutingInfo.DatabaseName) && !IsEnhancedRoutingSupportEnabled) { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.LoginWithFailover | " + - $"Ignoring enhanced routing info because the server did not acknowledge the feature."); + "SqlInternalConnectionTds.LoginWithFailover | " + + "Ignoring enhanced routing info because the server did not acknowledge the feature."); RoutingInfo = null; continue; } @@ -3625,8 +3707,9 @@ private void LoginWithFailover( routingAttempts++; SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.LoginWithFailover | " + - $"Routed to {RoutingInfo.ServerName}", RoutingInfo.ServerName); + "SqlInternalConnectionTds.LoginWithFailover | " + + "Routed to {0}", + RoutingInfo.ServerName); _parser?.Disconnect(); _parser = new TdsParser(ConnectionOptions.MARS, connectionOptions.Asynchronous); @@ -3702,9 +3785,11 @@ private void LoginWithFailover( if (attemptNumber % 2 == 1) { SqlClientEventSource.Log.TryAdvancedTraceEvent( - $"SqlInternalConnectionTds.LoginWithFailover | ADV | " + - $"Object ID {ObjectID}, " + - $"sleeping {sleepInterval}ms"); + "SqlInternalConnectionTds.LoginWithFailover | ADV | " + + "Object ID {0}, " + + "sleeping {1}ms", + ObjectID, + sleepInterval); Thread.Sleep(sleepInterval); @@ -4026,21 +4111,28 @@ private bool TryGetFedAuthTokenLocked( // proceed forward with the existing token in the cache. if (dbConnectionPoolAuthenticationContext.LockToUpdate()) { - SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.TryGetFedAuthTokenLocked | " + - $"Object ID {ObjectID}, " + - $"Acquired the lock to update the authentication context. " + - $"The expiration time is {dbConnectionPoolAuthenticationContext.ExpirationTime:T}. " + - $"Current Time is {DateTime.UtcNow:T}."); + if (SqlClientEventSource.Log.IsTraceEnabled()) + { + SqlClientEventSource.Log.TryTraceEvent( + "SqlInternalConnectionTds.TryGetFedAuthTokenLocked | " + + "Object ID {0}, " + + "Acquired the lock to update the authentication context. " + + "The expiration time is {1}. " + + "Current Time is {2}.", + ObjectID, + dbConnectionPoolAuthenticationContext.ExpirationTime.ToString("T"), + DateTime.UtcNow.ToString("T")); + } authenticationContextLocked = true; } else { SqlClientEventSource.Log.TryTraceEvent( - $"SqlInternalConnectionTds.TryGetFedAuthTokenLocked | " + - $"Object ID {ObjectID}, " + - $"Refreshing the context is already in progress by another thread."); + "SqlInternalConnectionTds.TryGetFedAuthTokenLocked | " + + "Object ID {0}, " + + "Refreshing the context is already in progress by another thread.", + ObjectID); } if (authenticationContextLocked) diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlAuthenticationProviderManager.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlAuthenticationProviderManager.cs index 4c77fbe8df..082a5599ce 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlAuthenticationProviderManager.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlAuthenticationProviderManager.cs @@ -68,8 +68,9 @@ static SqlAuthenticationProviderManager() SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Attempting to load Azure extension assembly={azureAssemblyName} with " + - "expected public key token=" + + ": Attempting to load Azure extension assembly={0} with " + + "expected public key token={1}", + azureAssemblyName, BitConverter.ToString(s_azurePublicKeyToken).Replace("-", "")); var qualifiedName = new AssemblyName(azureAssemblyName); @@ -96,9 +97,10 @@ static SqlAuthenticationProviderManager() { SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Azure extension assembly={assembly.GetName()} has an " + + ": Azure extension assembly={0} has an " + "unexpected public key token; " + - "no default Active Directory provider installed"); + "no default Active Directory provider installed", + assembly.GetName()); return; } } @@ -108,8 +110,9 @@ static SqlAuthenticationProviderManager() SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Attempting to load Azure extension assembly={azureAssemblyName} without " + - "strong name verification; ensure this assembly is from a trusted source"); + ": Attempting to load Azure extension assembly={0} without " + + "strong name verification; ensure this assembly is from a trusted source", + azureAssemblyName); var assembly = Assembly.Load(azureAssemblyName); @@ -119,16 +122,18 @@ static SqlAuthenticationProviderManager() { SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Azure extension assembly={azureAssemblyName} not found; " + - "no default Active Directory provider installed"); + ": Azure extension assembly={0} not found; " + + "no default Active Directory provider installed", + azureAssemblyName); return; } SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Azure extension assembly={assembly.GetName()} found; " + + ": Azure extension assembly={0} found; " + "attempting to set as default provider for all Active " + - "Directory authentication methods"); + "Directory authentication methods", + assembly.GetName()); // Look for the authentication provider class. const string className = "Microsoft.Data.SqlClient.ActiveDirectoryAuthenticationProvider"; @@ -138,8 +143,9 @@ static SqlAuthenticationProviderManager() { SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Azure extension does not contain class={className}; " + - "no default Active Directory provider installed"); + ": Azure extension does not contain class={0}; " + + "no default Active Directory provider installed", + className); return; } @@ -171,8 +177,9 @@ static SqlAuthenticationProviderManager() { SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Failed to instantiate Azure extension class={className}; " + - "no default Active Directory provider installed"); + ": Failed to instantiate Azure extension class={0}; " + + "no default Active Directory provider installed", + className); return; } @@ -197,8 +204,9 @@ static SqlAuthenticationProviderManager() SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Azure extension class={className} installed as " + - "provider for all Active Directory authentication methods"); + ": Azure extension class={0} installed as " + + "provider for all Active Directory authentication methods", + className); } // All of these exceptions mean we couldn't find or instantiate the // Azure extension's authentication provider, in which case we @@ -221,9 +229,12 @@ TypeInitializationException or { SqlClientEventSource.Log.TryTraceEvent( nameof(SqlAuthenticationProviderManager) + - $": Azure extension assembly={azureAssemblyName} not found or " + + ": Azure extension assembly={0} not found or " + "not usable; no default provider installed; " + - $"{ex.GetType().Name}: {ex.Message}"); + "{1}: {2}", + azureAssemblyName, + ex.GetType().Name, + ex.Message); } // Any other exceptions are fatal. } diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.NonQuery.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.NonQuery.cs index 36d727575c..82bcdb3641 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.NonQuery.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.NonQuery.cs @@ -45,10 +45,14 @@ public IAsyncResult BeginExecuteNonQuery(AsyncCallback callback, object stateObj SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.BeginExecuteNonQuery | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); return BeginExecuteNonQueryInternal( CommandBehavior.Default, @@ -69,10 +73,14 @@ public int EndExecuteNonQuery(IAsyncResult asyncResult) { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.EndExecuteNonQuery | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); } } @@ -92,10 +100,14 @@ public override int ExecuteNonQuery() using var eventScope = SqlClientEventScope.Create($"SqlCommand.ExecuteNonQuery | API | Object Id {ObjectID}"); SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.ExecuteNonQuery | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); SqlStatistics statistics = null; bool success = false; @@ -160,11 +172,15 @@ private IAsyncResult BeginExecuteNonQueryAsync(AsyncCallback callback, object st { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.BeginExecuteNonQueryAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); - + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); + return BeginExecuteNonQueryInternal( CommandBehavior.Default, callback, @@ -351,10 +367,14 @@ private int EndExecuteNonQueryAsync(IAsyncResult asyncResult) SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.EndExecuteNonQueryAsync | Info | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); Exception asyncException = ((Task)asyncResult).Exception; if (asyncException is not null) @@ -429,11 +449,15 @@ private object InternalEndExecuteNonQuery( { SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.InternalEndExecuteNonQuery | INFO | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"MARS={_activeConnection?.Parser.MARSOn}, " + - $"AsyncCommandInProgress={_activeConnection?.AsyncCommandInProgress}"); - + "Object Id {0}, " + + "Client Connection Id {1}, " + + "MARS={2}, " + + "AsyncCommandInProgress={3}", + ObjectID, + _activeConnection?.ClientConnectionId, + _activeConnection?.Parser.MARSOn, + _activeConnection?.AsyncCommandInProgress); + VerifyEndExecuteState((Task)asyncResult, endMethod); WaitForAsyncResults(asyncResult, isInternal); @@ -534,9 +558,12 @@ private Task InternalExecuteNonQuery( { SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.InternalExecuteNonQuery | INFO | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"AsyncCommandInProgress={_activeConnection?.AsyncCommandInProgress}"); + "Object Id {0}, " + + "Client Connection Id {1}, " + + "AsyncCommandInProgress={2}", + ObjectID, + _activeConnection?.ClientConnectionId, + _activeConnection?.AsyncCommandInProgress); bool isAsync = completion is not null; usedCache = false; @@ -583,10 +610,14 @@ private Task InternalExecuteNonQuery( Debug.Assert(!isRetry); SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.InternalExecuteNonQuery | INFO | " + - $"Object Id {ObjectID}," + - $" RPC execute method name {methodName}, " + - $"isAsync {isAsync}, " + - $"isRetry {isRetry}"); + "Object Id {0}," + + " RPC execute method name {1}, " + + "isAsync {2}, " + + "isRetry {3}", + ObjectID, + methodName, + isAsync, + isRetry); task = RunExecuteNonQueryTds(methodName, isAsync, timeout, asyncWrite); } @@ -595,10 +626,14 @@ private Task InternalExecuteNonQuery( // Otherwise, use a full-fledged execute that can handle parameters and sprocs SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.InternalExecuteNonQuery | INFO | " + - $"Object Id {ObjectID}, " + - $"RPC execute method name {methodName}, " + - $"isAsync {isAsync}, " + - $"isRetry {isRetry}"); + "Object Id {0}, " + + "RPC execute method name {1}, " + + "isAsync {2}, " + + "isRetry {3}", + ObjectID, + methodName, + isAsync, + isRetry); SqlDataReader reader = RunExecuteReader( CommandBehavior.Default, @@ -640,11 +675,15 @@ private Task InternalExecuteNonQueryAsync(CancellationToken cancellationTok SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.InternalExecuteNonQueryAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); - + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); + Guid operationId = s_diagnosticListener.WriteCommandBefore(this, _transaction); // Connection can be used as state in RegisterForConnectionCloseNotification continuation @@ -798,10 +837,14 @@ private Task RunExecuteNonQueryTds(string methodName, bool isAsync, int timeout, // no data reader is returned. SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.RunExecuteNonQueryTds | Info | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command executed as SQLBATCH, Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command executed as SQLBATCH, Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); Task executeTask = _stateObj.Parser.TdsExecuteSQLBatch( CommandText, diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Reader.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Reader.cs index d9f6c33233..a4322adc76 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Reader.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Reader.cs @@ -71,10 +71,14 @@ public SqlDataReader EndExecuteReader(IAsyncResult asyncResult) { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.EndExecuteReader | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); } } @@ -83,10 +87,14 @@ public SqlDataReader EndExecuteReader(IAsyncResult asyncResult) { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.ExecuteReader | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); SqlStatistics statistics = null; try @@ -212,10 +220,14 @@ protected override DbDataReader ExecuteDbDataReader(CommandBehavior behavior) // @TODO: Yknow, we use this all over the place. It could be factored out. SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.ExecuteDbDataReader | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); return ExecuteReader(behavior); } @@ -373,10 +385,14 @@ private void BeginExecuteReaderInternalReadStage(TaskCompletionSource co SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.BeginExecuteReaderInternalReadStage | INFO | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); // Read SNI does not have catches for async exceptions, handle here. try @@ -662,10 +678,14 @@ private SqlDataReader EndExecuteReaderAsync(IAsyncResult asyncResult) SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.EndExecuteReaderAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); Exception asyncException = ((Task)asyncResult).Exception; if (asyncException is not null) @@ -694,10 +714,14 @@ private SqlDataReader EndExecuteReaderInternal(IAsyncResult asyncResult) { SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.EndExecuteReaderInternal | API | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"MARS={_activeConnection?.Parser?.MARSOn}, " + - $"AsyncCommandInProgress={_activeConnection?.AsyncCommandInProgress}"); + "Object Id {0}, " + + "Client Connection Id {1}, " + + "MARS={2}, " + + "AsyncCommandInProgress={3}", + ObjectID, + _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, + _activeConnection?.AsyncCommandInProgress); SqlStatistics statistics = null; bool success = false; @@ -945,16 +969,24 @@ private Task InternalExecuteReaderAsync( { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.InternalExecuteReaderAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Behavior {(int)commandBehavior}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Behavior {1}, " + + "Activity Id {2}, " + + "Client Connection Id {3}, " + + "Command Text '{4}'", + ObjectID, + (int)commandBehavior, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.InternalExecuteReaderAsync | INFO | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Client Connection Id {1}, " + + "Command Text '{2}'", + ObjectID, + _activeConnection?.ClientConnectionId, + CommandText); Guid operationId = !_parentOperationStarted ? s_diagnosticListener.WriteCommandBefore(this, _transaction) : Guid.Empty; @@ -1049,10 +1081,14 @@ private SqlDataReader InternalEndExecuteReader(IAsyncResult asyncResult, bool is { SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.InternalEndExecuteReader | INFO | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"MARS={_activeConnection?.Parser?.MARSOn}, " + - $"AsyncCommandInProgress={_activeConnection?.AsyncCommandInProgress}"); + "Object Id {0}, " + + "Client Connection Id {1}, " + + "MARS={2}, " + + "AsyncCommandInProgress={3}", + ObjectID, + _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, + _activeConnection?.AsyncCommandInProgress); VerifyEndExecuteState((Task)asyncResult, endMethod); WaitForAsyncResults(asyncResult, isInternal); @@ -1376,11 +1412,15 @@ private SqlDataReader RunExecuteReaderTds( { SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.RunExecuteReaderTds | Info | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command executed as SQLBATCH, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command executed as SQLBATCH, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); } string text = GetCommandText(cmdBehavior) + GetOptionsResetString(cmdBehavior); @@ -1463,11 +1503,15 @@ private SqlDataReader RunExecuteReaderTds( { SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.RunExecuteReaderTds | Info | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command executed as RPC, " + - $"RPC Name '{rpc.rpcName}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command executed as RPC, " + + "RPC Name '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + rpc.rpcName); } Debug.Assert(_rpcArrayOf1[0] == rpc); @@ -1497,11 +1541,15 @@ private SqlDataReader RunExecuteReaderTds( { SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.RunExecuteReaderTds | Info | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command executed as RPC, " + - $"RPC Name '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command executed as RPC, " + + "RPC Name '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); } // Turn set options ON diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Scalar.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Scalar.cs index 2a47e1466f..ae87b4cf71 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Scalar.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Scalar.cs @@ -34,10 +34,14 @@ public override object ExecuteScalar() using var eventScope = SqlClientEventScope.Create($"SqlCommand.ExecuteScalar | API | Object Id {ObjectID}"); SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.ExecuteScalar | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); SqlStatistics statistics = null; bool success = false; @@ -225,15 +229,22 @@ private Task ExecuteScalarAsyncInternal(CancellationToken cancellationTo { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.InternalExecuteScalarAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.ExecuteScalarAsyncInternal | API " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Client Connection Id {1}, " + + "Command Text '{2}'", + ObjectID, + _activeConnection?.ClientConnectionId, + CommandText); Guid operationId = s_diagnosticListener.WriteCommandBefore(this, _transaction); _parentOperationStarted = true; diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Xml.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Xml.cs index c025e1d3b7..e22a2e3ba7 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Xml.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.Xml.cs @@ -46,10 +46,14 @@ public IAsyncResult BeginExecuteXmlReader(AsyncCallback callback, object stateOb SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.BeginExecuteXmlReader | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); return BeginExecuteXmlReaderInternal( CommandBehavior.SequentialAccess, @@ -71,10 +75,14 @@ public XmlReader EndExecuteXmlReader(IAsyncResult asyncResult) { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.EndExecuteXmlReader | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection.ClientConnectionId, + CommandText); } } @@ -94,10 +102,14 @@ public XmlReader ExecuteXmlReader() using var eventScope = SqlClientEventScope.Create($"SqlCommand.ExecuteXmlReader | API | Object Id {ObjectID}"); SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.ExecuteXmlReader | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); SqlStatistics statistics = null; bool success = false; @@ -189,11 +201,15 @@ private IAsyncResult BeginExecuteXmlReaderAsync(AsyncCallback callback, object s { SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.BeginExecuteXmlReaderAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); - + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); + return BeginExecuteXmlReaderInternal( CommandBehavior.SequentialAccess, callback, @@ -388,10 +404,14 @@ private XmlReader EndExecuteXmlReaderAsync(IAsyncResult asyncResult) SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.EndExecuteXmlReaderAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); Exception asyncException = ((Task)asyncResult).Exception; if (asyncException is not null) @@ -463,11 +483,15 @@ private Task InternalExecuteXmlReaderAsync(CancellationToken cancella SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.InternalExecuteXmlReaderAsync | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); - + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); + Guid operationId = s_diagnosticListener.WriteCommandBefore(this, _transaction); // Connection can be used as state in RegisterForConnectionCloseNotification continuation diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.cs index d276f27738..29fc27a2c2 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlCommand.cs @@ -552,9 +552,12 @@ public override int CommandTimeout SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Set_CommandTimeout | API | " + - $"Object Id {ObjectID}, " + - $"Command Timeout value {value}, " + - $"Client Connection Id {Connection?.ClientConnectionId}"); + "Object Id {0}, " + + "Command Timeout value {1}, " + + "Client Connection Id {2}", + ObjectID, + value, + Connection?.ClientConnectionId); } } @@ -576,9 +579,12 @@ public override string CommandText SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Set_CommandText | API | " + - $"Object Id {ObjectID}, " + - $"String Value = '{value}', " + - $"Client Connection Id {Connection?.ClientConnectionId}"); + "Object Id {0}, " + + "String Value = '{1}', " + + "Client Connection Id {2}", + ObjectID, + value, + Connection?.ClientConnectionId); } } @@ -610,9 +616,12 @@ public override CommandType CommandType // @TODO: Either move this outside the if block or move all the other instances inside the if block. SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Set_CommandType | API | " + - $"Object Id {ObjectID}, " + - $"Command Type value {(int)value}, " + - $"Client Connection Id {Connection?.ClientConnectionId}"); + "Object Id {0}, " + + "Command Type value {1}, " + + "Client Connection Id {2}", + ObjectID, + (int)value, + Connection?.ClientConnectionId); } } } @@ -673,8 +682,10 @@ public override CommandType CommandType SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Set_Connection | API | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {value?.ClientConnectionId}"); + "Object Id {0}, " + + "Client Connection Id {1}", + ObjectID, + value?.ClientConnectionId); } } @@ -713,7 +724,8 @@ public SqlNotificationRequest Notification _notification = value; SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Set_Notification | API | " + - $"Object Id {ObjectID}"); + "Object Id {0}", + ObjectID); } } @@ -790,9 +802,12 @@ public SqlRetryLogicBaseProvider RetryLogicProvider SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Set_Transaction | API | " + - $"Object Id {ObjectID}, " + - $"Internal Transaction Id {value?.InternalTransaction?.TransactionId}, " + - $"Client Connection Id {Connection?.ClientConnectionId}"); + "Object Id {0}, " + + "Internal Transaction Id {1}, " + + "Client Connection Id {2}", + ObjectID, + value?.InternalTransaction?.TransactionId, + Connection?.ClientConnectionId); } } @@ -819,9 +834,12 @@ public override UpdateRowSource UpdatedRowSource SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.UpdatedRowSource | API | " + - $"Object Id {ObjectID}, " + - $"Updated Row Source value {(int)value}, " + - $"Client Connection Id {Connection?.ClientConnectionId}"); + "Object Id {0}, " + + "Updated Row Source value {1}, " + + "Client Connection Id {2}", + ObjectID, + (int)value, + Connection?.ClientConnectionId); } } @@ -942,8 +960,10 @@ protected override DbTransaction DbTransaction Transaction = (SqlTransaction)value; SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Set_DbTransaction | API | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {Connection?.ClientConnectionId}"); + "Object Id {0}, " + + "Client Connection Id {1}", + ObjectID, + Connection?.ClientConnectionId); } } @@ -1066,10 +1086,14 @@ public override void Cancel() using var eventScope = SqlClientEventScope.Create($"SqlCommand.Cancel | API | Object Id {ObjectID}"); SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.Cancel | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"Activity Id {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"Command Text '{CommandText}'"); + "Object Id {0}, " + + "Activity Id {1}, " + + "Client Connection Id {2}, " + + "Command Text '{3}'", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId, + CommandText); SqlStatistics statistics = null; try @@ -1157,9 +1181,12 @@ public SqlCommand Clone() SqlCommand clone = new SqlCommand(this); SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.Clone | API | " + - $"Object Id {ObjectID}, " + - $"Clone Object Id {clone.ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}"); + "Object Id {0}, " + + "Clone Object Id {1}, " + + "Client Connection Id {2}", + ObjectID, + clone.ObjectID, + _activeConnection?.ClientConnectionId); return clone; } @@ -1178,9 +1205,12 @@ public override void Prepare() using var eventScope = SqlClientEventScope.Create($"SqlCommand.Prepare | API | Object Id {ObjectID}"); SqlClientEventSource.Log.TryCorrelationTraceEvent( "SqlCommand.Prepare | API | Correlation | " + - $"Object Id {ObjectID}, " + - $"ActivityID {ActivityCorrelator.Current}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}"); + "Object Id {0}, " + + "ActivityID {1}, " + + "Client Connection Id {2}", + ObjectID, + ActivityCorrelator.Current, + _activeConnection?.ClientConnectionId); // Reset _pendingCancel upon entry into any Execute - used to synchronize state // between entry into Execute* API and the thread obtaining the stateObject. @@ -1822,10 +1852,13 @@ internal void OnStatementCompleted(int recordCount) try { SqlClientEventSource.Log.TryTraceEvent( - $"SqlCommand.OnStatementCompleted | Info | " + - $"Object Id {ObjectID}, " + - $"Record Count {recordCount}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}"); + "SqlCommand.OnStatementCompleted | Info | " + + "Object Id {0}, " + + "Record Count {1}, " + + "Client Connection Id {2}", + ObjectID, + recordCount, + _activeConnection?.ClientConnectionId); handler(this, new StatementCompletedEventArgs(recordCount)); } @@ -2907,8 +2940,10 @@ private void Unprepare() SqlClientEventSource.Log.TryTraceEvent( "SqlCommand.UnPrepare | Info | " + - $"Object Id {ObjectID}, " + - $"Current Prepared Handle {_prepareHandle}"); + "Object Id {0}, " + + "Current Prepared Handle {1}", + ObjectID, + _prepareHandle); _execType = EXECTYPE.PREPAREPENDING; @@ -2924,8 +2959,9 @@ private void Unprepare() _cachedMetaData = null; SqlClientEventSource.Log.TryTraceEvent( - $"SqlCommand.UnPrepare | Info | " + - $"Object Id {ObjectID}, Command unprepared."); + "SqlCommand.UnPrepare | Info | " + + "Object Id {0}, Command unprepared.", + ObjectID); } private void ValidateAsyncCommand() @@ -3031,11 +3067,15 @@ private void VerifyEndExecuteState( Debug.Assert(completionTask is not null); SqlClientEventSource.Log.TryTraceEvent( - $"SqlCommand.VerifyEndExecuteState | API | " + - $"Object Id {ObjectID}, " + - $"Client Connection Id {_activeConnection?.ClientConnectionId}, " + - $"MARS={_activeConnection?.Parser?.MARSOn}, " + - $"AsyncCommandInProgress={_activeConnection?.AsyncCommandInProgress}"); + "SqlCommand.VerifyEndExecuteState | API | " + + "Object Id {0}, " + + "Client Connection Id {1}, " + + "MARS={2}, " + + "AsyncCommandInProgress={3}", + ObjectID, + _activeConnection?.ClientConnectionId, + _activeConnection?.Parser?.MARSOn, + _activeConnection?.AsyncCommandInProgress); if (completionTask.IsCanceled) { @@ -3231,10 +3271,13 @@ internal void SetActiveConnectionAndResult(TaskCompletionSource completi TdsParser parser = activeConnection?.Parser; SqlClientEventSource.Log.TryTraceEvent( - $"SqlCommand.SetActiveConnectionAndResult | API | " + - $"Object ID {activeConnection.ObjectID}, " + - $"Client Connection ID {activeConnection.ClientConnectionId}, " + - $"MARS={parser?.MARSOn}"); + "SqlCommand.SetActiveConnectionAndResult | API | " + + "Object ID {0}, " + + "Client Connection ID {1}, " + + "MARS={2}", + activeConnection.ObjectID, + activeConnection.ClientConnectionId, + parser?.MARSOn); if (parser == null || parser.State == TdsParserState.Closed || parser.State == TdsParserState.Broken) {