Azure DocumentDB sporadically throws SocketException / GoneException

Question

UPDATE (2/8/17):

See answer below.

UPDATE (2/7/17):

I've found that a restart can allow me to successfully run the web app from Visual Studio 2015, and hit the endpoint several times. However, when I stop the app and restart it, it will most likely fail. It will then fail repeatedly until I restart the computer. Restarting VS'15 is not good enough.

Once it begins to fail, running the app from VS Code or from command line with dotnet.exe exhibits the same behavior.

ORIGINAL POST:

We have a microservices system set up that calls a DocumentDB collection from a couple APIs and Azure Functions. It fails intermittently with a SocketException (GoneException nested within) from the API side. As far as we can tell, given that it works occasionally, the code to call it is mostly correct. The Azure Functions work without issue.

EDIT for clarification: by "intermittently," I mean it works briefly maybe once or twice a day, and then enters a fail state for the rest of the day where no calls go through. This isn't like 1 out of every 100 or so calls fail. This is more like nonstop failures after 1 or 2 successful calls.

I was able to recreate the same exception by writing a simple console app to read from the DocumentDB and print the results to the Debug output. This runs one or two times without any problem, then begins throwing the below exception every time. It will do this for sometimes a few hours before allowing a couple more calls through, then throwing again.

While the tester below is primitive, the main API takes full advantage of the vNext project structure. It uses a singleton DocumentClient to connect (injected via the native DI), and it's almost fully async from the controller down to the service layer that calls the db. We use a separate library to manage access to the DocumentDB (creating collections if they don't exist, adding extension methods, simple CRUD operations, etc.), but calling directly as shown below yields the same results.

One thing I've noticed is that it succeeds far more regularly for the Core version of the DocumentDB client ("Microsoft.Azure.DocumentDB.Core": "1.0.0") than it does for the net46 version. Our API needs 4.6 due to other libraries.

I could recreate this on multiple machines, multiple networks, multiple connection types.

Question: Why are we getting this exception and how do we fix it?

Azure information:

• East US 2
• 1000 RU/s
• Standard tier
• Session consistency

• Lazy indexing policy:

  { "indexingMode": "lazy", "automatic": true, "includedPaths": [{ "path": "/*", "indexes": [{ "kind": "Range", "dataType": "Number", "precision": -1 },{ "kind": "Hash", "dataType": "String", "precision": 3 }] }], "excludedPaths": [] }

Test class

using System;
using System.Diagnostics;
using System.Threading.Tasks;
using Microsoft.Azure.Documents.Client;
using Microsoft.Azure.Documents.Linq;
using Newtonsoft.Json;

namespace TestConnection
{
    public class Program
    {
        public static void Main(string[] args)
        {
            try
            {
                using (var client = new DocumentClient(
                    new Uri("https://<our-docdb-name>.documents.azure.com:443/"),
                    "our access key",
                    new ConnectionPolicy
                    {
                        ConnectionMode = ConnectionMode.Direct,
                        ConnectionProtocol = Protocol.Tcp
                    }))
                {
                    var query = client.CreateDocumentQuery(UriFactory.CreateCollectionUri("Imports", "User"),
                        "SELECT * FROM c where c.importId = \"816d8e92-bd08-4705-9989-09a0ece5892a\"");
                    var docQuery = query.AsDocumentQuery();
                    GetResults(docQuery).Wait();
                    Debug.WriteLine("done");
                }
            }
            catch (Exception e)
            {
                Debug.WriteLine(e);
            }
        }

        private static async Task GetResults(IDocumentQuery<dynamic> docQuery)
        {
            Debug.WriteLine("getting");
            var results = await docQuery.ExecuteNextAsync();
            Debug.WriteLine(JsonConvert.SerializeObject(results));
        }
    }
}

project.json

{
    "version": "1.0.0-*",
    "buildOptions": {
        "debugType": "portable",
        "emitEntryPoint": true
    },
    "dependencies": {
        "Microsoft.Azure.DocumentDB": "1.11.3"
    },
    "frameworks": {
        "net46": {}
    }
}

Exception

'TestConnection.exe' (CLR v4.0.30319: DefaultDomain): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: DefaultDomain): Loaded 'C:\projects\TestConnection\src\TestConnection\bin\Debug\net46\win7-x64\TestConnection.exe'. Symbols loaded.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\projects\TestConnection\src\TestConnection\bin\Debug\net46\win7-x64\Microsoft.Azure.Documents.Client.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System\v4.0_4.0.0.0__b77a5c561934e089\System.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Core\v4.0_4.0.0.0__b77a5c561934e089\System.Core.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Configuration\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Configuration.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Net.Http\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Net.Http.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Xml\v4.0_4.0.0.0__b77a5c561934e089\System.Xml.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\projects\TestConnection\src\TestConnection\bin\Debug\net46\win7-x64\Newtonsoft.Json.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
DocDBTrace Information: 0 : DocumentClient with id 1 initialized at endpoint: https://<our-docdb-name>.documents.azure.com/ with ConnectionMode: Direct, connection Protocol: Tcp, and consistency level: null
getting
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\Microsoft.CSharp\v4.0_4.0.0.0__b03f5f7f11d50a3a\Microsoft.CSharp.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Numerics\v4.0_4.0.0.0__b77a5c561934e089\System.Numerics.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Runtime.Serialization\v4.0_4.0.0.0__b77a5c561934e089\System.Runtime.Serialization.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_MSIL\System.Xml.Linq\v4.0_4.0.0.0__b77a5c561934e089\System.Xml.Linq.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
'TestConnection.exe' (CLR v4.0.30319: TestConnection.exe): Loaded 'C:\WINDOWS\Microsoft.Net\assembly\GAC_64\System.Data\v4.0_4.0.0.0__b77a5c561934e089\System.Data.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled.
DocDBTrace Information: 0 : Set WriteEndpoint https://<our-docdb-name>-eastus2.documents.azure.com/ ReadEndpoint https://<our-docdb-name>-eastus2.documents.azure.com/
DocDBTrace Information: 0 : Mapped resourceName dbs/Imports/colls/User to resourceId u81pAO1OFwA=. '00000000-0000-0000-0000-000000000000'
DocDBTrace Information: 0 : Mapped resourceName dbs/Imports/colls/User to resourceId u81pAO1OFwA=. '00000000-0000-0000-0000-000000000000'
The thread 0x3888 has exited with code 0 (0x0).
The thread 0x2c20 has exited with code 0 (0x0).
The thread 0x39fc has exited with code 0 (0x0).
The thread 0x3610 has exited with code 0 (0x0).
The thread 0x3824 has exited with code 0 (0x0).
The thread 0x33d8 has exited with code 0 (0x0).
The thread 0x38d0 has exited with code 0 (0x0).
DocDBTrace Information: 0 : GetOpenConnection failed: RID: dbs/Imports/colls/User, ResourceType Document, Op: (operationType: Query, resourceType: Document), Address: rntbd://bn6prdddc05-docdb-1.documents.azure.com:18817/apps/d54f0cf3-23d7-4050-9810-99d319d441a8/services/d77a45f3-5611-4c1d-a08e-0f3ef60a31d9/partitions/wkjhgkwj-c85a-4b08-b026-6bc8010b1bb5/replicas/131287308072454308s/, Exception: Microsoft.Azure.Documents.GoneException: Message: The requested resource is no longer available at the server.
ActivityId: d71bc76d-1411-414d-a844-9f76a46ebcfd, Request URI: rntbd://bn6prdddc05-docdb-1.documents.azure.com:18817/apps/d54f0cf3-23d7-4050-9810-99d319d441a8/services/d77a45f3-5611-4c1d-a08e-0f3ef60a31d9/partitions/wkjhgkwj-c85a-4b08-b026-6bc8010b1bb5/replicas/131287308072454308s/ ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 13.68.28.135:18817
   at System.Net.Sockets.Socket.EndConnect(IAsyncResult asyncResult)
   at System.Net.Sockets.TcpClient.EndConnect(IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdConnection.<OpenSocket>d__1c.MoveNext()
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Documents.RntbdConnection.<OpenSocket>d__1c.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdConnection.<Open>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdConnectionDispenser.<OpenNewConnection>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.ConnectionPool.<GetOpenConnection>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.ConnectionPoolManager.<GetOpenConnection>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdTransportClient.<InvokeStoreAsync>d__0.MoveNext()
DocDBTrace Information: 0 : Exception Microsoft.Azure.Documents.GoneException: Message: The requested resource is no longer available at the server.
ActivityId: d71bc76d-1411-414d-a844-9f76a46ebcfd, Request URI: rntbd://bn6prdddc05-docdb-1.documents.azure.com:18817/apps/d54f0cf3-23d7-4050-9810-99d319d441a8/services/d77a45f3-5611-4c1d-a08e-0f3ef60a31d9/partitions/wkjhgkwj-c85a-4b08-b026-6bc8010b1bb5/replicas/131287308072454308s/ ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 13.68.28.135:18817
   at System.Net.Sockets.Socket.EndConnect(IAsyncResult asyncResult)
   at System.Net.Sockets.TcpClient.EndConnect(IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdConnection.<OpenSocket>d__1c.MoveNext()
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Documents.RntbdConnection.<OpenSocket>d__1c.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdConnection.<Open>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdConnectionDispenser.<OpenNewConnection>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.ConnectionPool.<GetOpenConnection>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.ConnectionPoolManager.<GetOpenConnection>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdTransportClient.<InvokeStoreAsync>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.StoreReader.<CompleteActivity>d__1f.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.StoreReader.<ReadMultipleReplicasInternalAsync>d__a.MoveNext() is thrown while doing readMany
DocDBTrace Warning: 0 : Received gone exception, will retry, Microsoft.Azure.Documents.GoneException: Message: The requested resource is no longer available at the server.
ActivityId: d71bc76d-1411-414d-a844-9f76a46ebcfd, Request URI: rntbd://bn6prdddc05-docdb-1.documents.azure.com:18817/apps/d54f0cf3-23d7-4050-9810-99d319d441a8/services/d77a45f3-5611-4c1d-a08e-0f3ef60a31d9/partitions/wkjhgkwj-c85a-4b08-b026-6bc8010b1bb5/replicas/131287308072454308s/ ---> System.Net.Sockets.SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 13.68.28.135:18817
   at System.Net.Sockets.Socket.EndConnect(IAsyncResult asyncResult)
   at System.Net.Sockets.TcpClient.EndConnect(IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.RntbdConnection.<OpenSocket>d__1c.MoveNext()
   --- End of inner exception stack trace ---
   at Microsoft.Azure.Documents.StoreReader.<ReadMultipleReplicasInternalAsync>d__a.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.StoreReader.<ReadMultipleReplicaAsync>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.ConsistencyReader.<ReadSessionAsync>d__8.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.ReplicatedResourceClient.<InvokeAsync>d__b.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.ReplicatedResourceClient.<>c__DisplayClass1.<<InvokeAsync>b__0>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.BackoffRetryUtility`1.<>c__DisplayClassf`1.<<ExecuteAsync>b__d>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Azure.Documents.BackoffRetryUtility`1.<ExecuteRetry>d__1b.MoveNext()
The thread 0x36e4 has exited with code 0 (0x0).
The thread 0x3adc has exited with code 0 (0x0).
The thread 0x3a68 has exited with code 0 (0x0).
The thread 0x18b0 has exited with code 0 (0x0).
...
/* The above repeats about 3 more times.*/
...
The program '[14648] TestConnection.exe' has exited with code 0 (0x0).

Answer 1

It turned out to be our enterprise Bitdefender Endpoint Security causing the issue. We initially didn't suspect it, since it pretty clearly logged that dotnet.exe was whitelisted and allowed to communicate on the appropriate ports whenever we ran the app. We uninstalled it and the issue went away. We're looking into what exactly it blocked to cause the issue in the first place, but at least we know there's a temporary solution and that the original problem wasn't code-related. Hope this helps someone.