Azure / Azure/azure-functions-host
CosmosDb out binding fails intermittently with InvalidOperationException : Cannot bind parameter 'document' to type Document&
- Dominant language
- C#
- Stars
- 2k
- Forks
- 482
- Avg merge
- 2d 12h
- Merged PRs (30d)
- 38
Description
I have an Azure function CentralLoggingMessageReceived with a ServiceBusTrigger and an out binding to CosmosDb.
If I run function this from Visual Studio it executes correctly (when I put a message on the topic, it is correctly inserted into CosmosDb collection).
If I deploy it to Azure using Azure DevOps, it works fine until I stop and restart the function.
#### Investigative information
Please provide the following:
- Timestamp: 2018-11-02T18:39:14 UTC
- Function App version (1.0 or 2.0): 2.0
- Function App name: AZF-EAI-UTIL-CentralLogging-dev
- Function name(s) (as appropriate): CentralLoggingMessageReceived
- Invocation ID: not applicable
- Region: westus2
#### Repro steps
Here are the steps I have performed several times to reproduce this:
1) Deploy the function app using the Azure DevOps task "Azure App Service Deploy"
2) Using Service Bus Explorer, push a message to the topic associated with the Service Bus trigger.
3) Verify in Service Bus Explorer that the message has been picked up.
4) Verify in Data Explorer for CosmosDb that the message resulted in a record being created in the collection.
5) Restart the function app.
6) Using Service Bus Explorer, push a message to the topic associated with the Service Bus trigger.
7) See in Service Bus Explorer that the message has is NOT picked up.
8) Verify in Data Explorer for CosmosDb that the message did NOT result in a record being created in the collection.
9) Check the log file under Functions/Host. See the following error:
2018-11-02T18:39:14.710 [Information] Stopping JobHost
2018-11-02T18:39:14.795 [Information] Job host stopped
2018-11-02T18:39:39.449 [Information] Initializing Host.
2018-11-02T18:39:39.459 [Information] Host initialization: ConsecutiveErrors=0, StartupCount=6
2018-11-02T18:39:39.490 [Information] Starting JobHost
2018-11-02T18:39:39.496 [Information] Starting Host (HostId=azf-eai-util-centrallogging-dev, InstanceId=6d59e930-53eb-4fed-af3d-92fa1c07eddd, Version=2.0.12134.0, ProcessId=4260, AppDomainId=1, Debug=True, FunctionsExtensionVersion=~2)
2018-11-02T18:39:39.565 [Information] Loading functions metadata
2018-11-02T18:39:39.767 [Information] 6 functions loaded
2018-11-02T18:39:40.072 [Information] Generating 6 job function(s)
2018-11-02T18:39:40.187 [Error] Error indexing method 'CentralLoggingMessageReceived.Run'
Microsoft.Azure.WebJobs.Host.Indexers.FunctionIndexingException : Error indexing method 'CentralLoggingMessageReceived.Run' ---> System.InvalidOperationException : Cannot bind parameter 'document' to type Document&. Make sure the parameter Type is supported by the binding. If you're using binding extensions (e.g. Azure Storage, ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. builder.AddAzureStorage(), builder.AddServiceBus(), builder.AddTimers(), etc.).
at async Microsoft.Azure.WebJobs.Host.Indexers.FunctionIndexer.IndexMethodAsyncCore(MethodInfo method,IFunctionIndexCollector index,CancellationToken cancellationToken) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Indexers\FunctionIndexer.cs : 272
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at async Microsoft.Azure.WebJobs.Host.Indexers.FunctionIndexer.IndexMethodAsync(MethodInfo method,IFunctionIndexCollector index,CancellationToken cancellationToken) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Indexers\FunctionIndexer.cs : 167
End of inner exception
at async Microsoft.Azure.WebJobs.Host.Indexers.FunctionIndexer.IndexMethodAsync(MethodInfo method,IFunctionIndexCollector index,CancellationToken cancellationToken) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Indexers\FunctionIndexer.cs : 175
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at async Microsoft.Azure.WebJobs.Host.Indexers.FunctionIndexer.IndexTypeAsync(Type type,IFunctionIndexCollector index,CancellationToken cancellationToken) at C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Indexers\FunctionIndexer.cs : 103
2018-11-02T18:39:40.226 [Warning] Function 'CentralLoggingMessageReceived.Run' failed indexing and will be disabled.
2018-11-02T18:39:40.288 [Information] Found the following functions:
TransAlta.Eai.Util.CentralLogging.LogMessageReceiver.Run
TransAlta.Eai.Util.CentralLoggingToCosmosDb.LogMessageRouter.Run
TransAlta.Eai.Util.CentralLogging.CentralLoggingDataDeletion.Run
TransAlta.Eai.Util.CentralLogging.SmokeTest.Run
TransAlta.Eai.Util.CentralLoggingToCosmosDb.SmokeTest.Run
2018-11-02T18:39:40.288 [Information] Host initialized (791ms)
2018-11-02T18:39:40.294 [Information] Function 'ReceiveMessageFromQueue' is disabled
2018-11-02T18:39:40.411 [Information] Function 'RunScheduledDataCleanup' is disabled
2018-11-02T18:39:40.427 [Information] Host started (929ms)
2018-11-02T18:39:40.427 [Information] Job host started
As mentioned above, if I redeploy from Azure Devops, it will work again until restarted.
#### Expected behavior
After restarting the function app, I expect the message to be picked up from service bus and inserted into CosmosDb
#### Actual behavior
Function fails to start when restarted.
#### Known workarounds
After a restart, redeploy the FunctionApp from Azure DevOps
#### Related information
Provide any related information
* Programming language used: C#
* Links to source
* Bindings used: ServiceBusTrigger and an out binding to CosmosDb
Source
```csharp
public const string FunctionName = "CentralLoggingMessageReceived";
[FunctionName(FunctionName)]
public static void Run(
[ServiceBusTrigger(
"%CentralLoggingServiceBus-TopicName%", "ToCosmosDb", Connection = "CentralLoggingServiceBus-TopicConn")]
string logMessage,
[CosmosDB(
databaseName: "%CentralLogging_CosmosDbName%",
collectionName: "BizTalkLogMessage",
ConnectionStringSetting = "CentralLogging_CosmosDbConnection")]out Document document,
ILogger log)
{
log.LogInformation($"{FunctionName}: Started for message: {logMessage}");
BizTalkLogMessage bizTalkLogMessage = new BizTalkLogMessage();
try
{
IBizTalkLogMessageProcessor bizTalkLogMessageProcessorNoAction = new BizTalkLogMessageProcessorNoAction();
log.LogInformation($"{FunctionName}: Completed successfully for message: {logMessage}");
ReturnStatus returnStatus = ReceivedBizTalkLogMessageProcessor.ProcessReceivedMessage(
logMessage, bizTalkLogMessageProcessorNoAction, log,
out bizTalkLogMessage);
if (!returnStatus.WasSuccess)
{
throw new Exception($"{FunctionName}: Failed to process the BizTalk Log Message: {logMessage}. " +
$"ReturnStatus={returnStatus.StatusMessage}.");
}
Document doc = new Document();
bool success = CentralLoggingToCosmosDbHelper.TryCreateDynamicJsonLogMessage(
bizTalkLogMessage, out string statusMessage, out document);
if (!success)
{
throw new Exception(statusMessage);
}
}
catch (Exception ex)
{
CentralLoggingToCosmosDbHelper.SetBizTalkLogMessageForException(
bizTalkLogMessage, logMessage, ex);
CentralLoggingToCosmosDbHelper.TryCreateDynamicJsonLogMessage(
bizTalkLogMessage, out string statusMessage, out document);
log.LogError($"{FunctionName}: Secondary exception occurred while trying " +
$"to process initial exception: {ex.Message}. Secondary error: {statusMessage}");
}
}
```
Contributor guide
Research direction
Start with FunctionIndexer.cs at the indexing path named in the stack trace, then inspect the Run entry point's CosmosDB out Document and ServiceBusTrigger parameters. Reproduce the listed deployment, message, and restart sequence; done when the function remains indexed and messages are inserted into CosmosDB after restart.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- azure, csharp
- Domain
- backend, cloud
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100