Tests Fail with Timeout - System.Net.Sockets.SocketException (61): Connection refused

[edubsi]

Hi,

we noticed our builds to fail from time to time due to timeout exception on our GitLab runners.
The weird thing is that we do not see any correlation to specific runners or servers causing problems but the same runner would succeed three times and the next time it fails.

I was trying to reproduce this error on my machine (macbook) and found that the tests always succeed when running from my IDE (Rider) but they will fail if I run "dotnet test" from the console.

We found that our tests have a significant overhead if we create a runner for every test as recommended by the docs.
So for our case a Fixture worked great in terms of Unit Test speed but is now causing the trouble if multiple test projects contain the fixture.

public class MongoDbFixture : IDisposable
{
    public MongoDbFixture()
    {
        // Workaround to fix the Problem :shrug:
        //using (MongoDbRunner.Start()) { }
        mongoRunner = MongoDbRunner.Start();
    }

    private readonly MongoDbRunner mongoRunner;
    
    public void ClearAll()
    {
      // clean db before each test
    }

    public void Dispose()
    {
        mongoRunner?.Dispose();
    }
}

The issue we run into is the following and we see this pattern for every failing test. The address in use won't show up in the successful runs.

...
2020-11-13T11:20:34.585+0100 E STORAGE  [initandlisten] Failed to set up listener: SocketException: Address already in use
...
[xUnit.net 00:00:36.26]     ... ShouldPassPublishExceptions [FAIL]
  Failed  ... ShouldPassPublishExceptions [1 ms]
  Error Message:
   System.TimeoutException : A timeout occured after 30000ms selecting a server using CompositeServerSelector{ Selectors = MongoDB.Driver.MongoClient+AreSessionsSupportedServerSelector, LatencyLimitingServerSelector{ AllowedLatencyRange = 00:00:00.0150000 } }. Client view of cluster state is { ClusterId : "1", ConnectionMode : "Automatic", Type : "Unknown", State : "Disconnected", Servers : [{ ServerId: "{ ClusterId : 1, EndPoint : "127.0.0.1:27018" }", EndPoint: "127.0.0.1:27018", ReasonChanged: "Heartbeat", State: "Disconnected", ServerVersion: , TopologyVersion: , Type: "Unknown", HeartbeatException: "MongoDB.Driver.MongoConnectionException: An exception occurred while opening a connection to the server.
 ---> System.Net.Sockets.SocketException (61): Connection refused
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Threading.Tasks.ValueTask.ValueTaskSourceAsTask.<>c.<.cctor>b__4_0(Object state)
--- End of stack trace from previous location ---
   at MongoDB.Driver.Core.Connections.TcpStreamFactory.ConnectAsync(Socket socket, EndPoint endPoint, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.TcpStreamFactory.CreateStreamAsync(EndPoint endPoint, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.OpenHelperAsync(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at MongoDB.Driver.Core.Connections.BinaryConnection.OpenHelperAsync(CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Servers.ServerMonitor.InitializeConnectionAsync(CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Servers.ServerMonitor.HeartbeatAsync(CancellationToken cancellationToken)", LastHeartbeatTimestamp: "2020-11-13T10:21:08.3182250Z", LastUpdateTimestamp: "2020-11-13T10:21:08.3182250Z" }] }.
  Stack Trace:
     at MongoDB.Driver.Core.Clusters.Cluster.ThrowTimeoutException(IServerSelector selector, ClusterDescription description)
   at MongoDB.Driver.Core.Clusters.Cluster.WaitForDescriptionChangedHelper.HandleCompletedTask(Task completedTask)
   at MongoDB.Driver.Core.Clusters.Cluster.WaitForDescriptionChanged(IServerSelector selector, ClusterDescription description, Task descriptionChangedTask, TimeSpan timeout, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Clusters.Cluster.SelectServer(IServerSelector selector, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoClient.AreSessionsSupportedAfterServerSelection(CancellationToken cancellationToken)
   at MongoDB.Driver.MongoClient.AreSessionsSupported(CancellationToken cancellationToken)
   at MongoDB.Driver.MongoClient.StartImplicitSession(CancellationToken cancellationToken)
   at MongoDB.Driver.OperationExecutor.StartImplicitSession(CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.UsingImplicitSession[TResult](Func`2 func, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.BulkWrite(IEnumerable`1 requests, BulkWriteOptions options, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionBase`1.<>c__DisplayClass31_0.<DeleteMany>b__0(IEnumerable`1 requests)
   at MongoDB.Driver.MongoCollectionBase`1.DeleteMany(FilterDefinition`1 filter, DeleteOptions options, Func`2 bulkWriteFunc)
   at MongoDB.Driver.MongoCollectionBase`1.DeleteMany(FilterDefinition`1 filter, DeleteOptions options, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionBase`1.DeleteMany(FilterDefinition`1 filter, CancellationToken cancellationToken)
   ...

For me it looks like the check "is the port is already in use" fails if multiple projects contains the fixture. Not sure why (maybe the dispose pattern is implemented wrong?).
I tried to fix the issue and following things kinda "worked"

• using (MongoDbRunner.Start()) { } // before starting the actual runner. Not sure why it fixed it but it does (for us)
• use MongoDbRunner.StartUnitTest() and pass an IPortPool implementation using a random port (27020-27999)
  • but its marked as obsolete

So I am wondering if the "IsPortAvailable" check is working correctly and we run into a timing issue. Do both tests start at the exact same time and try to access the same port?
It would help us to fix the issue if we could decide which Port the runner tries to use, maybe allowing to set the "_startPort" or even pass a custom IPortPool implementation. A "start to probe at random Port" option would do it too.
Edit we use the latest version 2.2.14 with dotnet core 5.0. We saw the same problem on dotnet core 3.1 as well.

[u-ashikov]

Hi, is there any progress on this? We are facing the same issue.

[JohannesHoppe]

Nope, I do not have any spare private time to fix this on my own.

But I'm hoping that somebody from the community will fix this and send a PR. Please ask your manager to invest some time into this! 😉👍

[edubsi]

The using variant failed for us in our ci/cd pipeline as well. So we went with the random Port & deprecated API.
I'll post the workaround here. Be careful, since it's not 100% fail safe and uses pseudo random Ports but it works for us and never failed again.

Start Mongo Runner with Own PortPool

mongoRunner = MongoDbRunner.StartUnitTest(Mongo2GoPortPool.GetInstance, new FileSystem(),
                new MongoDbProcessStarter(), new MongoBinaryLocator(null, null));

// Copied from Mongo2Go PortPool + Random start port
    public sealed class Mongo2GoPortPool : IPortPool
    {
        private readonly object @lock = new object();
        private static readonly Mongo2GoPortPool Instance = new Mongo2GoPortPool();
        private int startPort;

        private Mongo2GoPortPool()
        {
            startPort = new Random().Next(27020, 27999);
        }

        public static Mongo2GoPortPool GetInstance => Instance;

        public int GetNextOpenPort()
        {
            var obj = @lock;
            var lockTaken = false;
            try
            {
                Monitor.Enter(obj, ref lockTaken);
                var openPort = PortWatcherFactory.CreatePortWatcher().FindOpenPort(startPort);
                startPort = openPort + 1;
                return openPort;
            }
            finally
            {
                if (lockTaken)
                    Monitor.Exit(obj);
            }
        }
    }

Maybe that helps. Can't find time to implement a clean PR too :/

[Ben238]

I have the same issue and exact same error since moving to net5 and Mongo2Go 3.0. I have tried the above workaround(s) but it hasn't worked for me :( or at least not on our build machine (Jenkins pipeline).
Anyone having found another workaround by any chance 😅 ?

[JohannesHoppe]

Failed to set up listener: SocketException: Address already in use

this is very much related to #116 and #115 as discovered by @realLiangshiwei.

In my initial implementation I used a simple lock and incremented the ports. But rider and friends can set the number of assemblies in parallel, when multiple processes get available ports, mong2go returns duplicate ports and throw an exception.

PR #116 should fix this. Please report any ongoing issues if 3.1.1 does not resolve your problem. I'm closing this issue for now.