fix: modify how exceptions are printed to reduce noise

When an exception occurs during the connect method,
only the exception message will be printed at the Error log level.
The entire stack trace will be printed when at the Verbose level.

fixes #1273
This commit is contained in:
Andrew Welker
2025-07-25 09:13:42 -05:00
parent 43989b9588
commit 31143f56df

View File

@@ -146,31 +146,31 @@ namespace PepperDash.Core
base(key) base(key)
{ {
StreamDebugging = new CommunicationStreamDebugging(key); StreamDebugging = new CommunicationStreamDebugging(key);
CrestronEnvironment.ProgramStatusEventHandler += new ProgramStatusEventHandler(CrestronEnvironment_ProgramStatusEventHandler); CrestronEnvironment.ProgramStatusEventHandler += new ProgramStatusEventHandler(CrestronEnvironment_ProgramStatusEventHandler);
Key = key; Key = key;
Hostname = hostname; Hostname = hostname;
Port = port; Port = port;
Username = username; Username = username;
Password = password; Password = password;
AutoReconnectIntervalMs = 5000; AutoReconnectIntervalMs = 5000;
ReconnectTimer = new CTimer(o => ReconnectTimer = new CTimer(o =>
{ {
if (ConnectEnabled) if (ConnectEnabled)
{ {
Connect(); Connect();
} }
}, System.Threading.Timeout.Infinite); }, System.Threading.Timeout.Infinite);
} }
/// <summary> /// <summary>
/// S+ Constructor - Must set all properties before calling Connect /// S+ Constructor - Must set all properties before calling Connect
/// </summary> /// </summary>
public GenericSshClient() public GenericSshClient()
: base(SPlusKey) : base(SPlusKey)
{ {
CrestronEnvironment.ProgramStatusEventHandler += new ProgramStatusEventHandler(CrestronEnvironment_ProgramStatusEventHandler); CrestronEnvironment.ProgramStatusEventHandler += new ProgramStatusEventHandler(CrestronEnvironment_ProgramStatusEventHandler);
AutoReconnectIntervalMs = 5000; AutoReconnectIntervalMs = 5000;
ReconnectTimer = new CTimer(o => ReconnectTimer = new CTimer(o =>
{ {
@@ -179,18 +179,18 @@ namespace PepperDash.Core
Connect(); Connect();
} }
}, System.Threading.Timeout.Infinite); }, System.Threading.Timeout.Infinite);
} }
/// <summary> /// <summary>
/// Handles closing this up when the program shuts down /// Handles closing this up when the program shuts down
/// </summary> /// </summary>
void CrestronEnvironment_ProgramStatusEventHandler(eProgramStatusEventType programEventType) void CrestronEnvironment_ProgramStatusEventHandler(eProgramStatusEventType programEventType)
{ {
if (programEventType == eProgramStatusEventType.Stopping) if (programEventType == eProgramStatusEventType.Stopping)
{ {
if (Client != null) if (Client != null)
{ {
this.LogDebug("Program stopping. Closing connection"); this.LogDebug("Program stopping. Closing connection");
Disconnect(); Disconnect();
} }
} }
@@ -223,10 +223,7 @@ namespace PepperDash.Core
this.LogDebug("Attempting connect"); this.LogDebug("Attempting connect");
// Cancel reconnect if running. // Cancel reconnect if running.
if (ReconnectTimer != null) ReconnectTimer?.Stop();
{
ReconnectTimer.Stop();
}
// Cleanup the old client if it already exists // Cleanup the old client if it already exists
if (Client != null) if (Client != null)
@@ -268,20 +265,26 @@ namespace PepperDash.Core
if (ie is SocketException) if (ie is SocketException)
{ {
this.LogException(ie, "CONNECTION failure: Cannot reach host"); this.LogError("CONNECTION failure: Cannot reach host");
this.LogVerbose(ie, "Exception details: ");
} }
if (ie is System.Net.Sockets.SocketException socketException) if (ie is System.Net.Sockets.SocketException socketException)
{ {
this.LogException(ie, "Connection failure: Cannot reach {host} on {port}", this.LogError("Connection failure: Cannot reach {host} on {port}",
Hostname, Port); Hostname, Port);
this.LogVerbose(socketException, "SocketException details: ");
} }
if (ie is SshAuthenticationException) if (ie is SshAuthenticationException)
{ {
this.LogException(ie, "Authentication failure for username {userName}", Username); this.LogError("Authentication failure for username {userName}", Username);
this.LogVerbose(ie, "AuthenticationException details: ");
} }
else else
this.LogException(ie, "Error on connect"); {
this.LogError("Error on connect: {error}", ie.Message);
this.LogVerbose(ie, "Exception details: ");
}
DisconnectLogged = true; DisconnectLogged = true;
KillClient(SocketStatus.SOCKET_STATUS_CONNECT_FAILED); KillClient(SocketStatus.SOCKET_STATUS_CONNECT_FAILED);
@@ -291,7 +294,7 @@ namespace PepperDash.Core
ReconnectTimer.Reset(AutoReconnectIntervalMs); ReconnectTimer.Reset(AutoReconnectIntervalMs);
} }
} }
catch(SshOperationTimeoutException ex) catch (SshOperationTimeoutException ex)
{ {
this.LogWarning("Connection attempt timed out: {message}", ex.Message); this.LogWarning("Connection attempt timed out: {message}", ex.Message);
@@ -306,7 +309,8 @@ namespace PepperDash.Core
catch (Exception e) catch (Exception e)
{ {
var errorLogLevel = DisconnectLogged == true ? Debug.ErrorLogLevel.None : Debug.ErrorLogLevel.Error; var errorLogLevel = DisconnectLogged == true ? Debug.ErrorLogLevel.None : Debug.ErrorLogLevel.Error;
this.LogException(e, "Unhandled exception on connect"); this.LogError("Unhandled exception on connect: {error}", e.Message);
this.LogVerbose(e, "Exception details: ");
DisconnectLogged = true; DisconnectLogged = true;
KillClient(SocketStatus.SOCKET_STATUS_CONNECT_FAILED); KillClient(SocketStatus.SOCKET_STATUS_CONNECT_FAILED);
if (AutoReconnect) if (AutoReconnect)
@@ -323,18 +327,18 @@ namespace PepperDash.Core
} }
} }
/// <summary> /// <summary>
/// Disconnect method /// Disconnect method
/// </summary> /// </summary>
public void Disconnect() public void Disconnect()
{ {
ConnectEnabled = false; ConnectEnabled = false;
// Stop trying reconnects, if we are // Stop trying reconnects, if we are
if (ReconnectTimer != null) if (ReconnectTimer != null)
{ {
ReconnectTimer.Stop(); ReconnectTimer.Stop();
// ReconnectTimer = null; // ReconnectTimer = null;
} }
KillClient(SocketStatus.SOCKET_STATUS_BROKEN_LOCALLY); KillClient(SocketStatus.SOCKET_STATUS_BROKEN_LOCALLY);
} }
@@ -360,7 +364,7 @@ namespace PepperDash.Core
} }
catch (Exception ex) catch (Exception ex)
{ {
this.LogException(ex,"Exception in Kill Client"); this.LogException(ex, "Exception in Kill Client");
} }
} }
@@ -368,7 +372,7 @@ namespace PepperDash.Core
/// Kills the stream /// Kills the stream
/// </summary> /// </summary>
void KillStream() void KillStream()
{ {
try try
{ {
if (TheStream != null) if (TheStream != null)
@@ -384,59 +388,59 @@ namespace PepperDash.Core
{ {
this.LogException(ex, "Exception in Kill Stream:{0}"); this.LogException(ex, "Exception in Kill Stream:{0}");
} }
} }
/// <summary> /// <summary>
/// Handles the keyboard interactive authentication, should it be required. /// Handles the keyboard interactive authentication, should it be required.
/// </summary> /// </summary>
void kauth_AuthenticationPrompt(object sender, AuthenticationPromptEventArgs e) void kauth_AuthenticationPrompt(object sender, AuthenticationPromptEventArgs e)
{ {
foreach (AuthenticationPrompt prompt in e.Prompts) foreach (AuthenticationPrompt prompt in e.Prompts)
if (prompt.Request.IndexOf("Password:", StringComparison.InvariantCultureIgnoreCase) != -1) if (prompt.Request.IndexOf("Password:", StringComparison.InvariantCultureIgnoreCase) != -1)
prompt.Response = Password; prompt.Response = Password;
} }
/// <summary> /// <summary>
/// Handler for data receive on ShellStream. Passes data across to queue for line parsing. /// Handler for data receive on ShellStream. Passes data across to queue for line parsing.
/// </summary> /// </summary>
void Stream_DataReceived(object sender, ShellDataEventArgs e) void Stream_DataReceived(object sender, ShellDataEventArgs e)
{ {
if (((ShellStream)sender).Length <= 0L) if (((ShellStream)sender).Length <= 0L)
{ {
return; return;
} }
var response = ((ShellStream)sender).Read(); var response = ((ShellStream)sender).Read();
var bytesHandler = BytesReceived; var bytesHandler = BytesReceived;
if (bytesHandler != null) if (bytesHandler != null)
{ {
var bytes = Encoding.UTF8.GetBytes(response); var bytes = Encoding.UTF8.GetBytes(response);
if (StreamDebugging.RxStreamDebuggingIsEnabled) if (StreamDebugging.RxStreamDebuggingIsEnabled)
{ {
this.LogInformation("Received {1} bytes: '{0}'", ComTextHelper.GetEscapedText(bytes), bytes.Length); this.LogInformation("Received {1} bytes: '{0}'", ComTextHelper.GetEscapedText(bytes), bytes.Length);
} }
bytesHandler(this, new GenericCommMethodReceiveBytesArgs(bytes)); bytesHandler(this, new GenericCommMethodReceiveBytesArgs(bytes));
} }
var textHandler = TextReceived; var textHandler = TextReceived;
if (textHandler != null) if (textHandler != null)
{ {
if (StreamDebugging.RxStreamDebuggingIsEnabled) if (StreamDebugging.RxStreamDebuggingIsEnabled)
this.LogInformation("Received: '{0}'", ComTextHelper.GetDebugText(response)); this.LogInformation("Received: '{0}'", ComTextHelper.GetDebugText(response));
textHandler(this, new GenericCommMethodReceiveTextArgs(response)); textHandler(this, new GenericCommMethodReceiveTextArgs(response));
} }
} }
/// <summary> /// <summary>
/// Error event handler for client events - disconnect, etc. Will forward those events via ConnectionChange /// Error event handler for client events - disconnect, etc. Will forward those events via ConnectionChange
/// event /// event
/// </summary> /// </summary>
void Client_ErrorOccurred(object sender, ExceptionEventArgs e) void Client_ErrorOccurred(object sender, ExceptionEventArgs e)
{ {
CrestronInvoke.BeginInvoke(o => CrestronInvoke.BeginInvoke(o =>
{ {
if (e.Exception is SshConnectionException || e.Exception is System.Net.Sockets.SocketException) if (e.Exception is SshConnectionException || e.Exception is System.Net.Sockets.SocketException)
@@ -465,61 +469,54 @@ namespace PepperDash.Core
/// </summary> /// </summary>
void OnConnectionChange() void OnConnectionChange()
{ {
if (ConnectionChange != null) ConnectionChange?.Invoke(this, new GenericSocketStatusChageEventArgs(this));
ConnectionChange(this, new GenericSocketStatusChageEventArgs(this));
} }
#region IBasicCommunication Members #region IBasicCommunication Members
/// <summary> /// <summary>
/// Sends text to the server /// Sends text to the server
/// </summary> /// </summary>
/// <param name="text"></param> /// <param name="text">The text to send</param>
/// <summary> public void SendText(string text)
/// SendText method {
/// </summary> try
public void SendText(string text)
{
try
{
if (Client != null && TheStream != null && IsConnected)
{
if (StreamDebugging.TxStreamDebuggingIsEnabled)
this.LogInformation(
"Sending {length} characters of text: '{text}'",
text.Length,
ComTextHelper.GetDebugText(text));
TheStream.Write(text);
TheStream.Flush();
}
else
{
this.LogDebug("Client is null or disconnected. Cannot Send Text");
}
}
catch (ObjectDisposedException)
{ {
this.LogError("ObjectDisposedException sending '{message}'. Restarting connection...", text.Trim()); if (Client != null && TheStream != null && IsConnected)
{
if (StreamDebugging.TxStreamDebuggingIsEnabled)
this.LogInformation(
"Sending {length} characters of text: '{text}'",
text.Length,
ComTextHelper.GetDebugText(text));
TheStream.Write(text);
TheStream.Flush();
}
else
{
this.LogDebug("Client is null or disconnected. Cannot Send Text");
}
}
catch (ObjectDisposedException)
{
this.LogError("ObjectDisposedException sending '{message}'. Restarting connection...", text.Trim());
KillClient(SocketStatus.SOCKET_STATUS_CONNECT_FAILED); KillClient(SocketStatus.SOCKET_STATUS_CONNECT_FAILED);
ReconnectTimer.Reset(); ReconnectTimer.Reset();
} }
catch (Exception ex) catch (Exception ex)
{ {
this.LogException(ex, "Exception sending text: '{message}'", text); this.LogException(ex, "Exception sending text: '{message}'", text);
} }
} }
/// <summary> /// <summary>
/// Sends Bytes to the server /// Sends Bytes to the server
/// </summary> /// </summary>
/// <param name="bytes"></param> /// <param name="bytes">The bytes to send</param>
/// <summary> public void SendBytes(byte[] bytes)
/// SendBytes method {
/// </summary>
public void SendBytes(byte[] bytes)
{
try try
{ {
if (Client != null && TheStream != null && IsConnected) if (Client != null && TheStream != null && IsConnected)
@@ -545,38 +542,38 @@ namespace PepperDash.Core
catch (Exception ex) catch (Exception ex)
{ {
this.LogException(ex, "Exception sending {message}", ComTextHelper.GetEscapedText(bytes)); this.LogException(ex, "Exception sending {message}", ComTextHelper.GetEscapedText(bytes));
} }
} }
#endregion #endregion
} }
//***************************************************************************************************** //*****************************************************************************************************
//***************************************************************************************************** //*****************************************************************************************************
/// <summary> /// <summary>
/// Represents a SshConnectionChangeEventArgs /// Represents a SshConnectionChangeEventArgs
/// </summary> /// </summary>
public class SshConnectionChangeEventArgs : EventArgs public class SshConnectionChangeEventArgs : EventArgs
{ {
/// <summary> /// <summary>
/// Connection State /// Connection State
/// </summary> /// </summary>
public bool IsConnected { get; private set; } public bool IsConnected { get; private set; }
/// <summary> /// <summary>
/// Gets or sets the UIsConnected /// Gets or sets the UIsConnected
/// </summary> /// </summary>
public ushort UIsConnected { get { return (ushort)(Client.IsConnected ? 1 : 0); } } public ushort UIsConnected { get { return (ushort)(Client.IsConnected ? 1 : 0); } }
/// <summary> /// <summary>
/// Gets or sets the Client /// Gets or sets the Client
/// </summary> /// </summary>
public GenericSshClient Client { get; private set; } public GenericSshClient Client { get; private set; }
/// <summary> /// <summary>
/// Gets or sets the Status /// Gets or sets the Status
/// </summary> /// </summary>
public ushort Status { get { return Client.UStatus; } } public ushort Status { get { return Client.UStatus; } }
/// <summary> /// <summary>
/// S+ Constructor /// S+ Constructor