ArgumentNullException after upgrading from 2024.0.0 to 2024.0.1

[VICTORIOUS1989]

After upgrading from version 2024.0.0 to 2024.0.1, I encountered an ArgumentNullException in the WaitOnHandle method. This issue occurs when executing an SSH command asynchronously.

background service encountered an unhandled exception
System.ArgumentNullException: Value cannot be null. (Parameter 'waitHandle')
at System.ArgumentNullException.Throw(String paramName)
at Renci.SshNet.Session.WaitOnHandle(WaitHandle waitHandle, TimeSpan timeout)
at Renci.SshNet.SshCommand.ExecuteAsync(CancellationToken cancellationToken)

[Rob-Hague]

Hi, are you able to reproduce the problem? I am guessing it is coming from here:

SSH.NET/src/Renci.SshNet/SshCommand.cs

Line 308 in a553152

_channel.Open();

and somehow _channel is already disposed (or disposing) at this point. But nothing stands out as an obvious problem

[James-LG]

Hey there, I am also having this problem although only when running on my Linux machine, not on my Windows machine which is odd - even though both are connecting to the same machine.

I referenced a local clone of this repo and added some extra logs to help track it down. Here's what it looks like when it's working

[15:16:49 INF] Sleeping for 1ms
Running command: echo Hello world!
Reusing existing ssh client.
SshCommand.ExecuteAsync: Sending exec request
ChannelSession.SendExecRequest: Sending command: echo Hello world!
ChannelSession.SendExecRequest: Waiting for response
ChannelSession.SendExecRequest: Response received
SshCommand.ExecuteAsync: Sent exec request
ChannelCloseMessage.Process
Channel.OnClose: Closing channel.
Channel.Close: Close message received.
SshCommand.SetAsyncComplete: setResult=True, _cancellationRequested=False
Channel.Dispose: Disposing channel.
ChannelSession.Dispose: Disposing channelRequestResponse
[15:16:49 INF] Result 2:3112 Hello world!

And here's what it looks like when it fails

[15:16:49 INF] Sleeping for 1ms
Running command: echo Hello world!
Reusing existing ssh client.
SshCommand.ExecuteAsync: Sending exec request
ChannelSession.SendExecRequest: Sending command: echo Hello world!
ChannelCloseMessage.Process
Channel.OnClose: Closing channel.
Channel.Close: Close message received.
SshCommand.SetAsyncComplete: setResult=True, _cancellationRequested=False
Channel.Dispose: Disposing channel.
ChannelSession.Dispose: Disposing channelRequestResponse
ChannelSession.SendExecRequest: Waiting for response
[15:16:49 ERR] BackgroundService failed
System.ArgumentNullException: Value cannot be null. (Parameter 'waitHandle')
   at System.ArgumentNullException.Throw(String paramName)
   at System.ArgumentNullException.ThrowIfNull(Object argument, String paramName)
   at Renci.SshNet.Common.ThrowHelper.ThrowIfNull(Object argument, String paramName) in D:\code\SSH.NET\src\Renci.SshNet\Common\ThrowHelper.cs:line 30
   at Renci.SshNet.Session.WaitOnHandle(WaitHandle waitHandle, TimeSpan timeout) in D:\code\SSH.NET\src\Renci.SshNet\Session.cs:line 971
   at Renci.SshNet.Session.Renci.SshNet.ISession.WaitOnHandle(WaitHandle waitHandle) in D:\code\SSH.NET\src\Renci.SshNet\Session.cs:line 847
   at Renci.SshNet.Channels.Channel.WaitOnHandle(WaitHandle waitHandle) in D:\code\SSH.NET\src\Renci.SshNet\Channels\Channel.cs:line 514
   at Renci.SshNet.Channels.ChannelSession.SendExecRequest(String command) in D:\code\SSH.NET\src\Renci.SshNet\Channels\ChannelSession.cs:line 203
   at Renci.SshNet.SshCommand.ExecuteAsync(CancellationToken cancellationToken) in D:\code\SSH.NET\src\Renci.SshNet\SshCommand.cs:line 293
   at RenciSshClient.RunCommandAsync(String commandText, CancellationToken cancellationToken) in D:\code\CSharpTestbed\Program.cs:line 226
   at HostConnection.RunCommandAsync(String commandText, CancellationToken cancellationToken) in D:\code\CSharpTestbed\Program.cs:line 145
   at RunCommandOperation.InternalInvokeAsync(String commandText, CancellationToken cancellationToken) in D:\code\CSharpTestbed\Program.cs:line 58
   at RunCommandOperation.RunCommandAsync(String commandText, CancellationToken cancellationToken) in D:\code\CSharpTestbed\Program.cs:line 53
   at SpamBackgroundService.ExecutePostStartupActionsAsync(CancellationToken stoppingToken) in D:\code\CSharpTestbed\Program.cs:line 104
   at PostStartupBackgroundService.ExecuteAsync(CancellationToken stoppingToken) in D:\code\CSharpTestbed\Program.cs:line 321
   at Microsoft.Extensions.Hosting.Internal.Host.TryExecuteBackgroundServiceAsync(BackgroundService backgroundService)

The important bit seems to be that it is responding to a channel close message before the ChannelSessions.SendExecRequest gets to WaitOnHandle(_channelRequestResponse), which means the _channelRequestResponse has already been disposed and is now null.

ref:

public bool SendExecRequest(string command)
{
    _ = _channelRequestResponse.Reset();
    Console.WriteLine("ChannelSession.SendExecRequest: Sending command: {0}", command);
    SendMessage(new ChannelRequestMessage(RemoteChannelNumber, new ExecRequestInfo(command, ConnectionInfo.Encoding)));
    Console.WriteLine("ChannelSession.SendExecRequest: Waiting for response");
    WaitOnHandle(_channelRequestResponse);
    Console.WriteLine("ChannelSession.SendExecRequest: Response received");
    return _channelRequestSucces;
}

Without the logs the error happens probably one in every 30 requests, but every log I add to SSH.NET makes it less likely to happen, which means it's some kind of timing issue that the slight pause from writing the logs is somewhat alleviating.

In case it's helpful, I've pushed a commit with the added logs so you can see exactly where they are coming from 1c66a22.

[Rob-Hague]

Thanks @James-LG for the excellent details. I understand the problem, just not decided how best to fix it. Good fun with wait handles...

[Rob-Hague]

Some unit tests are failing but I think #1596 could fix it. Unfortunately I am unable to reproduce the problem

[James-LG]

I tested your changes and it seems to be working!

[Rob-Hague]

Great, thanks for testing, I'll clean up the branch in the next week or so for merging