danielgerlag / danielgerlag/workflow-core
RunnablePoller 'duplicate key' Exceptions when Calling ScheduleCommand
- Dominant language
- C#
- Stars
- 5.9k
- Forks
- 1.3k
- Avg merge
- 1d 1h
- Merged PRs (30d)
- 5
Description
There is an issue with ScheduleCommand where we are seeing excessive logging of an exception(see below) regarding UniqueIndex when writing to MongoDB(also when using redis queue provider with mongo persistence)
If possible change the Error to a warning/info as if the item is already written to the scheduled_commands queue surely we don't need to know about a duplicate entry that failed.
Setup:
3 Workers each running WorkflowCore with the following setup
```
services.AddWorkflow(cfg =>
{
cfg.UseMongoDB(options.MongoConnection, options.Prefix);
cfg.UseRedisLocking(redisConnection);
cfg.UseElasticsearch(esConnection.DisableDirectStreaming(disableDirectStreaming), $"{prefix}-wf");
});
```
Here is the Exception Message
```
{
"_id": {
"$oid": "62062fa86620540001558f86"
},
"Timestamp": {
"$date": "2022-02-11T09:43:03.037Z"
},
"Level": "Error",
"MessageTemplate": "A write operation resulted in an error.\n E11000 duplicate key error collection: db.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }",
"RenderedMessage": "A write operation resulted in an error.\n E11000 duplicate key error collection: db.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }",
"Exception": "MongoDB.Driver.MongoWriteException: A write operation resulted in an error.\n E11000 duplicate key error collection: db.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }\n ---> MongoDB.Driver.MongoBulkWriteException`1[WorkflowCore.Models.ScheduledCommand]: A bulk write operation resulted in one or more errors.\n E11000 duplicate key error collection: db.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }\n at MongoDB.Driver.MongoCollectionImpl`1.BulkWriteAsync(IClientSessionHandle session, IEnumerable`1 requests, BulkWriteOptions options, CancellationToken cancellationToken)\n at MongoDB.Driver.MongoCollectionImpl`1.UsingImplicitSessionAsync[TResult](Func`2 funcAsync, CancellationToken cancellationToken)\n at MongoDB.Driver.MongoCollectionBase`1.InsertOneAsync(TDocument document, InsertOneOptions options, Func`3 bulkWriteAsync)\n --- End of inner exception stack trace ---\n at MongoDB.Driver.MongoCollectionBase`1.InsertOneAsync(TDocument document, InsertOneOptions options, Func`3 bulkWriteAsync)\n at WorkflowCore.Persistence.MongoDB.Services.MongoPersistenceProvider.ScheduleCommand(ScheduledCommand command)\n at WorkflowCore.Services.BackgroundTasks.RunnablePoller.PollWorkflows()",
"Properties": {
"SourceContext": "WorkflowCore.Services.BackgroundTasks.RunnablePoller",
"ExceptionDetail": {
"HResult": -2146233088,
"Message": "A write operation resulted in an error.\n E11000 duplicate key error collection: db.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }",
"Source": "MongoDB.Driver",
"InnerException": {
"HResult": -2146233088,
"Message": "A bulk write operation resulted in one or more errors.\n E11000 duplicate key error collection: artemis-wf.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }",
"Source": "MongoDB.Driver",
"Result": {
"DeletedCount": 0,
"InsertedCount": 0,
"IsAcknowledged": true,
"IsModifiedCountAvailable": true,
"MatchedCount": 0,
"ModifiedCount": 0,
"Upserts": [],
"ProcessedRequests": [{
"Document": {
"CommandName": "ProcessWorkflow",
"Data": "6204fe4837c69d0001d62432",
"ExecuteTime": {
"$numberLong": "637801693830185380"
}
},
"ModelType": "InsertOne"
}],
"RequestCount": 1
},
"UnprocessedRequests": [],
"WriteConcernError": null,
"WriteErrors": [{
"Index": 0,
"Category": "DuplicateKey",
"Code": 11000,
"Details": null,
"Message": "E11000 duplicate key error collection: artemis-wf.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }"
}],
"ErrorLabels": [],
"Type": "MongoDB.Driver.MongoBulkWriteException`1[[WorkflowCore.Models.ScheduledCommand, WorkflowCore, Version=3.6.0.0, Culture=neutral, PublicKeyToken=null]]"
},
"WriteConcernError": null,
"WriteError": {
"Index": 0,
"Category": "DuplicateKey",
"Code": 11000,
"Details": null,
"Message": "E11000 duplicate key error collection: db.wfc.scheduled_commands index: idx_key dup key: { CommandName: \"ProcessWorkflow\", Data: \"6204fe4837c69d0001d62432\" }"
},
"ErrorLabels": [],
"Type": "MongoDB.Driver.MongoWriteException"
}
},
"UtcTimestamp": "2022-02-11 09:43:03Z"
}
```
Contributor guide
No contributing guide indexed for this repository
Research direction
Start by tracing MongoPersistenceProvider.ScheduleCommand from the duplicate-key exception and its caller, RunnablePoller.PollWorkflows, using the MongoDB setup described in the issue. Confirm how duplicate scheduled commands are handled, then verify that expected duplicates no longer produce error-level logging while scheduling continues normally.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- csharp, mongodb, redis
- Domain
- backend, databases
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 45/100