Tweak diagnostics (#1241)

* Make it work (it needs the TRACE symbol defined - lots of head scratching without it)

* Expose publicly, but still in DEBUG (to allow programmatic configuration necessary in Core)

* Document how to use it

* Tweak usage (add some logs, remove key/iv information, override ToString on some Message types)

Co-authored-by: Wojciech Nagórski <wojtpl2@gmail.com>

src/Renci.SshNet/Abstractions/DiagnosticAbstraction.cs

@@ -1,27 +1,65 @@
-using System.Diagnostics;
+using System.ComponentModel;
+using System.Diagnostics;
 
 namespace Renci.SshNet.Abstractions
 {
-    internal static class DiagnosticAbstraction
+    /// <summary>
+    /// Provides access to the <see cref="System.Diagnostics"/> internals of SSH.NET.
+    /// </summary>
+    [EditorBrowsable(EditorBrowsableState.Never)]
+    public static class DiagnosticAbstraction
     {
-        private static readonly SourceSwitch SourceSwitch = new SourceSwitch("SshNetSwitch");
-
-        public static bool IsEnabled(TraceEventType traceEventType)
-        {
-            return SourceSwitch.ShouldTrace(traceEventType);
-        }
-
-        private static readonly TraceSource Loggging =
 #if DEBUG
-            new TraceSource("SshNet.Logging", SourceLevels.All);
-#else
-            new TraceSource("SshNet.Logging");
-#endif // DEBUG
+        /// <summary>
+        /// The <see cref="TraceSource"/> instance used by SSH.NET.
+        /// </summary>
+        /// <remarks>
+        /// <para>
+        /// Configuration on .NET Core must be done programmatically, e.g.
+        /// <code>
+        /// DiagnosticAbstraction.Source.Switch = new SourceSwitch("sourceSwitch", "Verbose");
+        /// DiagnosticAbstraction.Source.Listeners.Remove("Default");
+        /// DiagnosticAbstraction.Source.Listeners.Add(new ConsoleTraceListener());
+        /// DiagnosticAbstraction.Source.Listeners.Add(new TextWriterTraceListener("trace.log"));
+        /// </code>
+        /// </para>
+        /// <para>
+        /// On .NET Framework, it is possible to configure via App.config, e.g.
+        /// <code>
+        /// <![CDATA[
+        /// <configuration>
+        ///     <system.diagnostics>
+        ///         <trace autoflush="true"/>
+        ///         <sources>
+        ///             <source name="SshNet.Logging" switchValue="Verbose">
+        ///                 <listeners>
+        ///                     <remove name="Default" />
+        ///                     <add name="console"
+        ///                          type="System.Diagnostics.ConsoleTraceListener" />
+        ///                     <add name="logFile"
+        ///                          type="System.Diagnostics.TextWriterTraceListener"
+        ///                          initializeData="SshNetTrace.log" />
+        ///                 </listeners>
+        ///             </source>
+        ///         </sources>
+        ///     </system.diagnostics>
+        /// </configuration>
+        /// ]]>
+        /// </code>
+        /// </para>
+        /// </remarks>
+        public static readonly TraceSource Source = new TraceSource("SshNet.Logging");
+#endif
 
+        /// <summary>
+        /// Logs a message to <see cref="Source"/> at the <see cref="TraceEventType.Verbose"/>
+        /// level.
+        /// </summary>
+        /// <param name="text">The message to log.</param>
         [Conditional("DEBUG")]
         public static void Log(string text)
         {
-            Loggging.TraceEvent(TraceEventType.Verbose,
+            Source.TraceEvent(TraceEventType.Verbose,
                                 System.Environment.CurrentManagedThreadId,
                                 text);
         }

src/Renci.SshNet/Messages/Authentication/FailureMessage.cs

@@ -60,5 +60,13 @@ namespace Renci.SshNet.Messages.Authentication
         {
             session.OnUserAuthenticationFailureReceived(this);
         }
+
+        /// <inheritdoc/>
+        public override string ToString()
+        {
+#pragma warning disable MA0089 // Optimize string method usage
+            return $"SSH_MSG_USERAUTH_FAILURE {string.Join(",", AllowedAuthentications)} ({nameof(PartialSuccess)}:{PartialSuccess})";
+#pragma warning restore MA0089 // Optimize string method usage
+        }
     }
 }

src/Renci.SshNet/Messages/Authentication/PublicKeyMessage.cs

@@ -60,5 +60,11 @@
             WriteBinaryString(PublicKeyAlgorithmName);
             WriteBinaryString(PublicKeyData);
         }
+
+        /// <inheritdoc/>
+        public override string ToString()
+        {
+            return $"SSH_MSG_USERAUTH_PK_OK ({Ascii.GetString(PublicKeyAlgorithmName)})";
+        }
     }
 }

src/Renci.SshNet/Messages/Authentication/RequestMessage.cs

@@ -106,5 +106,11 @@ namespace Renci.SshNet.Messages.Authentication
         {
             throw new NotImplementedException();
         }
+
+        /// <inheritdoc/>
+        public override string ToString()
+        {
+            return $"SSH_MSG_USERAUTH_REQUEST ({MethodName})";
+        }
     }
 }

src/Renci.SshNet/Messages/Authentication/RequestMessagePublicKey.cs

@@ -96,5 +96,11 @@
                 WriteBinaryString(Signature);
             }
         }
+
+        /// <inheritdoc/>
+        public override string ToString()
+        {
+            return $"{base.ToString()} {Ascii.GetString(PublicKeyAlgorithmName)} {(Signature != null ? "with" : "without")} signature.";
+        }
     }
 }

src/Renci.SshNet/Renci.SshNet.csproj

@@ -6,7 +6,7 @@
   </PropertyGroup>
 
   <PropertyGroup Condition=" '$(TargetFramework)' == 'net462' ">
-    <DefineConstants>FEATURE_BINARY_SERIALIZATION;FEATURE_SOCKET_EAP;FEATURE_SOCKET_APM;FEATURE_DNS_SYNC;FEATURE_HASH_RIPEMD160_CREATE;FEATURE_HMAC_RIPEMD160</DefineConstants>
+    <DefineConstants>$(DefineConstants);FEATURE_BINARY_SERIALIZATION;FEATURE_SOCKET_EAP;FEATURE_SOCKET_APM;FEATURE_DNS_SYNC;FEATURE_HASH_RIPEMD160_CREATE;FEATURE_HMAC_RIPEMD160</DefineConstants>
   </PropertyGroup>
 
   <ItemGroup Condition=" '$(TargetFramework)' == 'netstandard2.0' or '$(TargetFramework)' == 'netstandard2.1' or '$(TargetFramework)' == 'net6.0' or '$(TargetFramework)' == 'net7.0' ">
@@ -18,6 +18,6 @@
   </ItemGroup>
 
   <PropertyGroup Condition=" '$(TargetFramework)' == 'netstandard2.0' or '$(TargetFramework)' == 'netstandard2.1' or '$(TargetFramework)' == 'net6.0' or '$(TargetFramework)' == 'net7.0' ">
-    <DefineConstants>FEATURE_SOCKET_TAP;FEATURE_SOCKET_APM;FEATURE_SOCKET_EAP;FEATURE_DNS_SYNC;FEATURE_DNS_APM;FEATURE_DNS_TAP</DefineConstants>
+    <DefineConstants>$(DefineConstants);FEATURE_SOCKET_TAP;FEATURE_SOCKET_APM;FEATURE_SOCKET_EAP;FEATURE_DNS_SYNC;FEATURE_DNS_APM;FEATURE_DNS_TAP</DefineConstants>
   </PropertyGroup>
 </Project>

src/Renci.SshNet/Security/KeyExchange.cs

@@ -183,11 +183,9 @@ namespace Renci.SshNet.Security
 
             serverKey = GenerateSessionKey(SharedKey, ExchangeHash, serverKey, _serverCipherInfo.KeySize / 8);
 
-            DiagnosticAbstraction.Log(string.Format("[{0}] Creating server cipher (Name:{1},Key:{2},IV:{3})",
+            DiagnosticAbstraction.Log(string.Format("[{0}] Creating {1} server cipher.",
                                                     Session.ToHex(Session.SessionId),
-                                                    Session.ConnectionInfo.CurrentServerEncryption,
-                                                    Session.ToHex(serverKey),
-                                                    Session.ToHex(serverVector)));
+                                                    Session.ConnectionInfo.CurrentServerEncryption));
 
             // Create server cipher
             return _serverCipherInfo.Cipher(serverKey, serverVector);
@@ -210,6 +208,10 @@ namespace Renci.SshNet.Security
 
             clientKey = GenerateSessionKey(SharedKey, ExchangeHash, clientKey, _clientCipherInfo.KeySize / 8);
 
+            DiagnosticAbstraction.Log(string.Format("[{0}] Creating {1} client cipher.",
+                                                    Session.ToHex(Session.SessionId),
+                                                    Session.ConnectionInfo.CurrentClientEncryption));
+
             // Create client cipher
             return _clientCipherInfo.Cipher(clientKey, clientVector);
         }
@@ -230,6 +232,10 @@ namespace Renci.SshNet.Security
                                                Hash(GenerateSessionKey(SharedKey, ExchangeHash, 'F', sessionId)),
                                                _serverHashInfo.KeySize / 8);
 
+            DiagnosticAbstraction.Log(string.Format("[{0}] Creating {1} server hmac algorithm.",
+                                                    Session.ToHex(Session.SessionId),
+                                                    Session.ConnectionInfo.CurrentServerHmacAlgorithm));
+
             return _serverHashInfo.HashAlgorithm(serverKey);
         }
 
@@ -249,6 +255,10 @@ namespace Renci.SshNet.Security
                                                Hash(GenerateSessionKey(SharedKey, ExchangeHash, 'E', sessionId)),
                                                _clientHashInfo.KeySize / 8);
 
+            DiagnosticAbstraction.Log(string.Format("[{0}] Creating {1} client hmac algorithm.",
+                                                    Session.ToHex(Session.SessionId),
+                                                    Session.ConnectionInfo.CurrentClientHmacAlgorithm));
+
             return _clientHashInfo.HashAlgorithm(clientKey);
         }
 
@@ -265,6 +275,10 @@ namespace Renci.SshNet.Security
                 return null;
             }
 
+            DiagnosticAbstraction.Log(string.Format("[{0}] Creating {1} client compressor.",
+                                                    Session.ToHex(Session.SessionId),
+                                                    Session.ConnectionInfo.CurrentClientCompressionAlgorithm));
+
             var compressor = _compressionType.CreateInstance<Compressor>();
 
             compressor.Init(Session);
@@ -285,6 +299,10 @@ namespace Renci.SshNet.Security
                 return null;
             }
 
+            DiagnosticAbstraction.Log(string.Format("[{0}] Creating {1} server decompressor.",
+                                                    Session.ToHex(Session.SessionId),
+                                                    Session.ConnectionInfo.CurrentServerCompressionAlgorithm));
+
             var decompressor = _decompressionType.CreateInstance<Compressor>();
 
             decompressor.Init(Session);

src/Renci.SshNet/Session.cs

@@ -616,7 +616,7 @@ namespace Renci.SshNet
                     ServerVersion = ConnectionInfo.ServerVersion = serverIdentification.ToString();
                     ConnectionInfo.ClientVersion = ClientVersion;
 
-                    DiagnosticAbstraction.Log(string.Format("Server version '{0}' on '{1}'.", serverIdentification.ProtocolVersion, serverIdentification.SoftwareVersion));
+                    DiagnosticAbstraction.Log(string.Format("Server version '{0}'.", serverIdentification));
 
                     if (!(serverIdentification.ProtocolVersion.Equals("2.0") || serverIdentification.ProtocolVersion.Equals("1.99")))
                     {
@@ -728,7 +728,7 @@ namespace Renci.SshNet
             ServerVersion = ConnectionInfo.ServerVersion = serverIdentification.ToString();
             ConnectionInfo.ClientVersion = ClientVersion;
 
-            DiagnosticAbstraction.Log(string.Format("Server version '{0}' on '{1}'.", serverIdentification.ProtocolVersion, serverIdentification.SoftwareVersion));
+            DiagnosticAbstraction.Log(string.Format("Server version '{0}'.", serverIdentification));
 
             if (!(serverIdentification.ProtocolVersion.Equals("2.0") || serverIdentification.ProtocolVersion.Equals("1.99")))
             {
@@ -1397,6 +1397,8 @@ namespace Renci.SshNet
 
             ConnectionInfo.CurrentKeyExchangeAlgorithm = _keyExchange.Name;
 
+            DiagnosticAbstraction.Log(string.Format("[{0}] Performing {1} key exchange.", ToHex(SessionId), ConnectionInfo.CurrentKeyExchangeAlgorithm));
+
             _keyExchange.HostKeyReceived += KeyExchange_HostKeyReceived;
 
             // Start the algorithm implementation