Cosmos DB throws "Resource Not Found" error after implementing custom BotState service

Question

We have recently updated our bot to migrate from the soon-to-be deprecated default BotState service into Azure Cosmos DB storage using following article: https://learn.microsoft.com/en-us/bot-framework/dotnet/bot-builder-dotnet-state-azure-cosmosdb

Following module is registered within Conversation Container in Application_Start method:

public class CustomBotStateServiceModule : Module
{
    protected override void Load(ContainerBuilder builder)
    {
        var stateStore = new DocumentDbBotDataStore(
            new Uri(ConfigurationManager.AppSettings.Get("EndpointUri")),
            ConfigurationManager.AppSettings.Get("PrimaryKey"),
            ConfigurationManager.AppSettings.Get("DatabaseId"),
            "BotState");

        builder.Register(c => stateStore)
               .Keyed<IBotDataStore<BotData>>(AzureModule.Key_DataStore)
               .AsSelf()
               .SingleInstance();

        builder.Register(c => new CachingBotDataStore(stateStore, CachingBotDataStoreConsistencyPolicy.ETagBasedConsistency))
               .As<IBotDataStore<BotData>>()
               .AsSelf()
               .InstancePerLifetimeScope();
    }
}

During our local tests using Bot Channel Emulator we noticed, that whenever the BotState is being accessed for the first time, following errors are printed into Debug Output of the Visual Studio:

DocDBTrace Information: 0 : DocumentClient with id 1 initialized at endpoint: https://<our-instance>.documents.azure.com/ with ConnectionMode: Gateway, connection Protocol: Https, and consistency level: null
DocDBTrace Information: 0 : RefreshLocationAsync() refreshing locations
DocDBTrace Information: 0 : Set WriteEndpoint https://<our-instance>-westus.documents.azure.com/ ReadEndpoint https://<our-instance>-westus.documents.azure.com/
DocDBTrace Error: 0 : DocumentClientException with status code: NotFound, message: Message: {"Errors":["Resource Not Found"]}
ActivityId: <activity-id>, Request URI: /apps/<app-id>/services/<service-id>/partitions/<partition-id>/replicas/<replica-id>/, RequestStats: 
ResponseTime: 2018-01-25T08:20:59.3067000Z, StoreReadResult: StorePhysicalAddress: rntbd://<docdb-location>.documents.azure.com:14043/apps/<app-id>/services/<service-id>/partitions/<partition-id>/replicas/<replica-id>/, LSN: 154, GlobalCommittedLsn: 151, PartitionKeyRangeId: 0, IsValid: True, StatusCode: 0, IsGone: False, IsNotFound: True, RequestCharge: 1, ItemLSN: -1, ResourceType: Document, OperationType: Read
, SDK: Microsoft.Azure.Documents.Common/1.19.162.2, and response headers: {
"x-ms-last-state-change-utc": "Wed, 24 Jan 2018 00:00:51.902 GMT",
"x-ms-schemaversion": "1.4",
"x-ms-xp-role": "1",
"x-ms-global-Committed-lsn": "151",
"x-ms-number-of-read-regions": "0",
"x-ms-request-charge": "1",
"x-ms-serviceversion": "version=1.19.162.2",
"x-ms-activity-id": "<activity-id>",
"Strict-Transport-Security": "max-age=31536000",
"x-ms-gatewayversion": "version=1.19.162.2",
"X-Cache": "MISS from <node>",
"Transfer-Encoding": "chunked",
"Connection": "keep-alive",
"Date": "Thu, 25 Jan 2018 08:20:58 GMT",
"Server": "Microsoft-HTTPAPI/2.0",
"Via": "1.1 <node> (squid)",
}
DocDBTrace Error: 0 : Operation will NOT be retried. Current attempt 0, Exception: Microsoft.Azure.Documents.DocumentClientException: Message: {"Errors":["Resource Not Found"]}
ActivityId: <activity-id>, Request URI: /apps/<app-id>/services/<service-id>/partitions/<partition-id>/replicas/<replica-id>/, RequestStats: 
ResponseTime: 2018-01-25T08:20:59.3067000Z, StoreReadResult: StorePhysicalAddress: rntbd://<docdb-location>.documents.azure.com:14043/apps/<app-id>/services/<service-id>/partitions/<partition-id>/replicas/<replica-id>/, LSN: 154, GlobalCommittedLsn: 151, PartitionKeyRangeId: 0, IsValid: True, StatusCode: 0, IsGone: False, IsNotFound: True, RequestCharge: 1, ItemLSN: -1, ResourceType: Document, OperationType: Read
, SDK: Microsoft.Azure.Documents.Common/1.19.162.2, documentdb-dotnet-sdk/1.19.1 Host/32-bit MicrosoftWindowsNT6.1.7601ServicePack1
   at Microsoft.Azure.Documents.Client.ClientExtensions.<ParseResponseAsync>d__4.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 System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Microsoft.Azure.Documents.GatewayStoreModel.<>c__DisplayClass10.<<InvokeAsync>b__f>d__12.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__DisplayClass2.<<ExecuteAsync>b__0>d__4.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()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Documents.BackoffRetryUtility`1.<ExecuteRetry>d__1b.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.<ExecuteAsync>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.GatewayStoreModel.<InvokeAsync>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.GatewayStoreModel.<ProcessMessageAsync>d__2.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.Client.DocumentClient.<ReadAsync>d__30c.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.Client.DocumentClient.<ReadDocumentPrivateAsync>d__18d.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__DisplayClass2.<<ExecuteAsync>b__0>d__4.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() 

These errors are printed about 1-2 more times shortly afterwards. Despite this, it seems that our custom BotState service is working correctly since we can see the entries being created in relevant Cosmos DB collection.

Note: We are not using our Cosmos DB exclusively to store the BotState data. We use it to also store bot activity data, logs, etc. It currently has two databases with multiple collections.

What is the root cause of these errors? Is it something which we should consider alarming? As soon as we unplug our custom BotState service from the container registration, the errors are gone.

Answer 1

I can reproduce the issue on my side, based on my test and study, I find that Azure SDK help us to check if document is existing when we want to store state data to an Azure Cosmos DB collection, so you can see that output message: "Resource Not Found" in your Visual studio Output window when your bot application store data at first time.

If you use Fiddler to capture the traffic, you can find SDK make a request to detect if the document is existing in that collection.

As you found, it’s just output message that written by SDK, which do not cause any code exceptions in your code.