workflow-core icon indicating copy to clipboard operation
workflow-core copied to clipboard

RunnablePoller 'duplicate key' Exceptions when Calling ScheduleCommand

Open ClarenceR89 opened this issue 3 years ago • 0 comments

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"
}

ClarenceR89 avatar Feb 11 '22 09:02 ClarenceR89