From fb3950774a5819388827757dbbc8ffffc6b36f74 Mon Sep 17 00:00:00 2001 From: Tomas Weinfurt Date: Tue, 16 Jun 2020 15:44:48 -0700 Subject: [PATCH] reduce use of TRACE_VERBOSE in SslStream (#37917) * reduce use of TRACE_VERBOSE * add NetEventSource.Verbose Co-authored-by: Tomas Weinfurt --- .../Interop/Windows/SspiCli/SecuritySafeHandles.cs | 30 +++------------------- .../System/Net/Logging/NetEventSource.Common.cs | 30 ++++++++++++++++++++++ .../Net/Security/SslStream.Implementation.cs | 15 ----------- 3 files changed, 34 insertions(+), 41 deletions(-) diff --git a/src/libraries/Common/src/Interop/Windows/SspiCli/SecuritySafeHandles.cs b/src/libraries/Common/src/Interop/Windows/SspiCli/SecuritySafeHandles.cs index 382d1f6..a8d91d1 100644 --- a/src/libraries/Common/src/Interop/Windows/SspiCli/SecuritySafeHandles.cs +++ b/src/libraries/Common/src/Interop/Windows/SspiCli/SecuritySafeHandles.cs @@ -225,9 +225,7 @@ namespace System.Net.Security ref outCredential._handle, out timeStamp); -#if TRACE_VERBOSE - if (NetEventSource.IsEnabled) NetEventSource.Info(null, $"{nameof(Interop.SspiCli.AcquireCredentialsHandleW)} returns 0x{errorCode:x}, handle = {outCredential}"); -#endif + if (NetEventSource.IsEnabled) NetEventSource.Verbose(null, $"{nameof(Interop.SspiCli.AcquireCredentialsHandleW)} returns 0x{errorCode:x}, handle = {outCredential}"); if (errorCode != 0) { @@ -307,9 +305,7 @@ namespace System.Net.Security authdata.paCred = copiedPtr; } -#if TRACE_VERBOSE - if (NetEventSource.IsEnabled) NetEventSource.Info(null, $"{nameof(Interop.SspiCli.AcquireCredentialsHandleW)} returns 0x{errorCode:x}, handle = {outCredential}"); -#endif + if (NetEventSource.IsEnabled) NetEventSource.Verbose(null, $"{nameof(Interop.SspiCli.AcquireCredentialsHandleW)} returns 0x{errorCode:x}, handle = {outCredential}"); if (errorCode != 0) { @@ -401,13 +397,7 @@ namespace System.Net.Security ref SecurityBuffer outSecBuffer, ref Interop.SspiCli.ContextFlags outFlags) { -#if TRACE_VERBOSE - if (NetEventSource.IsEnabled) - { - NetEventSource.Enter(null, $"credential:{inCredentials}, crefContext:{refContext}, targetName:{targetName}, inFlags:{inFlags}, endianness:{endianness}"); - NetEventSource.Info(null, $"inSecBuffers.Length = {inSecBuffers.Length}"); - } -#endif + if (NetEventSource.IsEnabled) NetEventSource.Enter(null, $"credential:{inCredentials}, crefContext:{refContext}, targetName:{targetName}, inFlags:{inFlags}, endianness:{endianness}"); if (inCredentials == null) { @@ -639,13 +629,7 @@ namespace System.Net.Security ref SecurityBuffer outSecBuffer, ref Interop.SspiCli.ContextFlags outFlags) { -#if TRACE_VERBOSE - if (NetEventSource.IsEnabled) - { - NetEventSource.Enter(null, $"credential={inCredentials}, refContext={refContext}, inFlags={inFlags}"); - NetEventSource.Info(null, $"inSecBuffers.Length = {inSecBuffers.Length}"); - } -#endif + if (NetEventSource.IsEnabled) NetEventSource.Enter(null, $"credential={inCredentials}, refContext={refContext}, inFlags={inFlags}"); if (inCredentials == null) { @@ -900,9 +884,6 @@ namespace System.Net.Security inSecBuffer.unmanagedToken != null ? inSecBuffer.unmanagedToken.DangerousGetHandle() : inSecBuffer.token == null || inSecBuffer.token.Length == 0 ? IntPtr.Zero : (IntPtr)(pinnedToken + inSecBuffer.offset); -#if TRACE_VERBOSE - if (NetEventSource.IsEnabled) NetEventSource.Info(null, $"SecBuffer: cbBuffer:{inSecBuffer.size} BufferType: {inSecBuffer.type}"); -#endif Interop.SspiCli.CredHandle contextHandle = refContext != null ? refContext._handle : default; if (refContext == null || refContext.IsInvalid) @@ -964,9 +945,6 @@ namespace System.Net.Security inSecBuffer.unmanagedToken != null ? inSecBuffer.unmanagedToken.DangerousGetHandle() : inSecBuffer.token == null || inSecBuffer.token.Length == 0 ? IntPtr.Zero : (IntPtr)(pinnedInSecBufferToken + inSecBuffer.offset); -#if TRACE_VERBOSE - if (NetEventSource.IsEnabled) NetEventSource.Info(null, $"SecBuffer: cbBuffer:{inSecBuffer.size} BufferType:{inSecBuffer.type}"); -#endif Interop.SspiCli.CredHandle contextHandle = refContext != null ? refContext._handle : default; diff --git a/src/libraries/Common/src/System/Net/Logging/NetEventSource.Common.cs b/src/libraries/Common/src/System/Net/Logging/NetEventSource.Common.cs index fa06462..e7bc2b3 100644 --- a/src/libraries/Common/src/System/Net/Logging/NetEventSource.Common.cs +++ b/src/libraries/Common/src/System/Net/Logging/NetEventSource.Common.cs @@ -299,6 +299,36 @@ namespace System.Net WriteEvent(CriticalFailureEventId, thisOrContextObject, memberName ?? MissingMember, message); #endregion + #region Verbose + /// Logs an info message at verbose mode. + /// `this`, or another object that serves to provide context for the operation. + /// The message to be logged. + /// The calling member. + [NonEvent] + public static void Verbose(object? thisOrContextObject, FormattableString formattableString, [CallerMemberName] string? memberName = null) + { + DebugValidateArg(thisOrContextObject); + DebugValidateArg(formattableString); + if (IsEnabled) Log.ErrorMessage(IdOf(thisOrContextObject), memberName, Format(formattableString)); + } + + /// Logs an info at verbose mode. + /// `this`, or another object that serves to provide context for the operation. + /// The message to be logged. + /// The calling member. + [NonEvent] + public static void Verbose(object? thisOrContextObject, object message, [CallerMemberName] string? memberName = null) + { + DebugValidateArg(thisOrContextObject); + DebugValidateArg(message); + if (IsEnabled) Log.VerboseMessage(IdOf(thisOrContextObject), memberName, Format(message).ToString()); + } + + [Event(ErrorEventId, Level = EventLevel.Verbose, Keywords = Keywords.Default)] + private void VerboseMessage(string thisOrContextObject, string? memberName, string? message) => + WriteEvent(ErrorEventId, thisOrContextObject, memberName ?? MissingMember, message); + #endregion + #region DumpBuffer /// Logs the contents of a buffer. /// `this`, or another object that serves to provide context for the operation. diff --git a/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs b/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs index ef52738..42e8a7c 100644 --- a/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs +++ b/src/libraries/System.Net.Security/src/System/Net/Security/SslStream.Implementation.cs @@ -1093,13 +1093,6 @@ namespace System.Net.Security return Framing.Invalid; } -#if TRACE_VERBOSE - if (bytes[1] != 3 && NetEventSource.IsEnabled) - { - if (NetEventSource.IsEnabled) NetEventSource.Info(this, $"WARNING: SslState::DetectFraming() SSL protocol is > 3, trying SSL3 framing in retail = {bytes[1]:x}"); - } -#endif - version = (bytes[1] << 8) | bytes[2]; if (version < 0x300 || version >= 0x500) { @@ -1112,14 +1105,6 @@ namespace System.Net.Security return Framing.SinceSSL3; } -#if TRACE_VERBOSE - if ((bytes[0] & 0x80) == 0 && NetEventSource.IsEnabled) - { - // We have a three-byte header format - if (NetEventSource.IsEnabled) NetEventSource.Info(this, $"WARNING: SslState::DetectFraming() SSL v <=2 HELLO has no high bit set for 3 bytes header, we are broken, received byte = {bytes[0]:x}"); - } -#endif - if (bytes.Length < 3) { return Framing.Invalid; -- 2.7.4