Fix for channel session semaphore from thread blocking

[patrick-yates-redgate]

Reason

When running continuously over a long period of time we see after 3 or 4 days our SshConnections lock up and no longer allow us to run ssh commands. We debugged this and found it was creating a thread blocking issue

Diagnosis

After analysing the memory dumps a colleague found that the session semaphore's were causing this and we have run several tests over reasonably long periods of time which confirm to us that the fix in this PR resolves our issue.

Fix

The fix is to remove the line where we set _session to null. ISession itself does not seem to be disposed of properly so you may want to make additional changes, however simply not setting to null appears to allow the GC to clean this up anyway. This article is not describing the exact same issue, but is related: https://www.sudhanshutheone.com/posts/double-check-lock-csharp

If you have any questions about the fix or the issues we found I am happy to discuss further/put you in touch with my colleague.

[clivetong]

Just to expand on the report above. I can attach the test program that showed the issue if required.

In our reproduction, I attached windbg to a .NET process that was running a test program that was using the library to execute "ps aux" on a Linux machine from roughly ten worker threads which were looping. After 30 minutes or so, windbg reported an access violation, which if you continue is translated into a NRE.

The null was coming from the _session field in the Channel.cs class. This had been disposed, and the field set to null, even though this was later going to be accessed by the thread above. The NRE wasn't surfaced outside the library (as far as I could see), and it meant that the Semaphore was not released leading to eventual starvation.

The fix was to avoid setting the field to null in the Dispose method, which allowed this release to happen.

This manifested as the Semaphore not being released, and the SSH client eventually grinding to a halt., as shown above.

[patrick-yates-redgate]

@WojciechNagorski great to see you maintaining this project and actively looking at these PRs. I can see the performance tag added here, I think it is worth noting that this is not a performance issue, it is actually a serious bug that can entirely crash an application (as it did repeatedly for us).

It is also worth noting we have this fix now in production (running our fork) as well as having our service run continuously in a test environment to check for long term stability without issue.

I've fixed the AppVeyor issue so it is ready to be merged should you be happy to do that 😄

[WojciechNagorski]

@patrick-yates-redgate Can you describe to me what the problem is with setting the session to null?

[patrick-yates-redgate]

@patrick-yates-redgate Can you describe to me what the problem is with setting the session to null?

Hi @WojciechNagorski, thanks for getting back to me. @clivetong is the best person to discuss this with as he found the issue. His comment here explains the problem and why setting _session to null was causing it

[Rob-Hague]

There is some more info at #400

The sequence of events appears to be something like:

Main thread	Message listener thread
...	...
SshCommand.EndExecute (or Dispose?)	...
SshCommand.UnsubscribeFromEventsAndDisposeChannel	Session.OnChannelCloseReceived
ChannelSession.Dispose	Channel.OnChannelClose
Channel.Dispose	Channel.OnClose
- ChannelSession.Close (overriding Channel.Close)	ChannelSession.Close (overriding Channel.Close)
- - Channel.Close	- Channel.Close
- - ChannelSession.ReleaseSemaphore (accesses _session)
- (_session set to null and OnChannelClose unsubscribed)
	- ChannelSession.ReleaseSemaphore (accesses _session, throws NRE)

The key points being that Channel.OnChannelClose fires on the message listener thread before Channel.Dispose is called on the main thread (which unsubscribes from that event) but ChannelSession.ReleaseSemaphore fires on the message listener thread after (when _session has been set to null).

The NullReferenceException is swallowed up by the listener thread (unless the Channel.Exception event is subscribed to which it is not).

That's what I can figure out anyway. I think the one problem with this fix is that the semaphore will be released twice instead of once, which could eventually result in SemaphoreFullException. But it is probably better than what we have.

Side note: I don't really like the default policy of setting fields to null in Dispose. I hope we can stop that some day. Turning on nullable reference types could also help avoid these types of situations.

[Rob-Hague]

I think the one problem with this fix is that the semaphore will be released twice instead of once, which could eventually result in SemaphoreFullException.

Actually, it seems like the roll-your-own SemaphoreLight implementation in this library does not throw for a maximum size reached. But I was hoping to replace it with SemaphoreSlim at some point...

[Rob-Hague]

Also (sorry for the triple comment), I must be missing something above because while it explains the NRE it does not explain the thread starvation

[clivetong]

I think you may be wrong about the double release. When I had applied the fix I left it running for 7+ days (and the problem usually occurred after 30 minutes). IIRC I left the debugger attached and saw no sign of other exceptions. In our blocking case we saw the semaphore was never incremented, so threads started blocking when they tried to get the semaphore (ie its count was zero but no one owned the semaphore). We could see this in the crash dumps we took. More explicitly, the NRE stopped the release and the Semaphore lost count. We can probably provide a reproduction if you need it. The repo would hang after about 30 minutes using two small boxes running in Azure.

[Rob-Hague]

Thanks. I understand the problem, just not quite the steps which occur where the semaphore is not released at all. I will try and come up with a reproduction, and if not I will get back to you. I would be happy for this change to go in either way.

[WojciechNagorski]

@Rob-Hague it would be great.

[Rob-Hague]

Ok I think I have worked it out.

Firstly, my table above is a bit misleading: the sequence is always initiated by the listener thread receiving a channel close message. The main thread is waiting in EndExecute on a waithandle which is set in Channel.Close by the listener thread (by invoking the Closed event to which SshCommand subscribes a handler).

Secondly, there cannot be more than one release of the semaphore thanks to the interlocked logic in ReleaseSemaphore:

SSH.NET/src/Renci.SshNet/Channels/ChannelSession.cs

Lines 442 to 448 in dd2e552

	private void ReleaseSemaphore()
	{
	if (Interlocked.CompareExchange(ref _sessionSemaphoreObtained, 0, 1) == 1)
	{
	_ = SessionSemaphore.Release();
	}
	}

But there could be no releases:

The listener thread enters ReleaseSemaphore first, and passes the interlocked check.
The main thread then enters ReleaseSemaphore (via Channel.Dispose), and fails the interlocked check.
The main thread continues its disposal, setting _session = null.
The listener thread calls SessionSemaphore.Release() (equivalent to _session.SessionSemaphore.Release()) which gets NRE and the semaphore does not get released.
(The listener thread swallows the NRE and continues on as normal)

[patrick-yates-redgate]

Awesome, thank you both @Rob-Hague and @WojciechNagorski for analysing the issue and getting this merged 🤩

[Greg-Smulko]

It's indeed amazing! Thank you so much!

Well, don't take it wrong, but... ;) are there any plans for an official release anytime soon?
Is there anything we can help with? @WojciechNagorski

[WojciechNagorski]

@Greg-Smulko I need to wait a few days, so we can say it will be soon :)

[WojciechNagorski]

Version 2023.0.0 has been published https://www.nuget.org/packages/SSH.NET/2023.0.0

[patrick-yates-redgate]

Thanks so much for publishing the new release and notifying us on this ticket @WojciechNagorski. Much appreciated 🎉