-
Type:
Bug
-
Resolution: Done
-
Priority:
Major - P3
-
Affects Version/s: 2.8.0-rc1
-
Component/s: Storage
-
Fully Compatible
-
ALL
-
None
-
3
-
None
-
None
-
None
-
None
-
None
-
None
I've noticed the application frequently getting WriteConflict errors when doing batch saves of logs to a capped collection. Application error:
[java] 2014-12-01T19:08:34.253+0000 [AutomationAgentLogs-2] gid: WARN com.xgen.svc.atm.svc.AutomationAgentLogSvc$LogWriter [bulkInsertBatch:219] - Failure on insert of 24 automation agent logs [java] com.mongodb.BulkWriteException: Bulk write operation error on server ip-10-169-132-210.ec2.internal:27018. Write errors: [BulkWriteError{index=0, code=112, message='WriteConflict', details={ }}] . [java] at com.mongodb.BulkWriteBatchCombiner.throwOnError(BulkWriteBatchCombiner.java:125) ~[mongo.jar:na] [java] at com.mongodb.BulkWriteBatchCombiner.getResult(BulkWriteBatchCombiner.java:115) ~[mongo.jar:na] [java] at com.mongodb.DBCollectionImpl.executeBulkWriteOperation(DBCollectionImpl.java:160) ~[mongo.jar:na]
Primary logs:
2014-12-01T19:08:31.712+0000 I QUERY [conn17673] command mmsdbautomationlog.$cmd command: insert { $msg: "query not recording (too large)" } keyUpdates:0 reslen:80 2345ms 2014-12-01T19:08:31.846+0000 I WRITE [conn17871] insert mmsdbautomationlog.agentLogs query: { _id: ObjectId('547cbcafe4b087d54e96dba1'), groupId: ObjectId('5479fde1e4b0e88a8f89cf91'), timestamp: 14174609 02000, level: "info", thread: "main/components/agent.go:352", logger: "", message: "All 1 Mongo processes are in goal state, Monitoring agent in goal state, Backup agent in goal state", hostname: "green-2.c luste.5479ff83e4b0e88a8f89e619.mongodbdns.com", process: null, threw: "" } ninserted:0 keyUpdates:0 exception: WriteConflict code:112 194ms 2014-12-01T19:08:31.848+0000 I QUERY [conn18043] command backupjobs.$cmd command: findAndModify { findandmodify: "blockstore_jobs", query: { finished: false, workingOn: false, type: "groom", $or: [ { pri orities: { $elemMatch: { lastResort: true, runEligibleTs: { $lt: 1417460911720 } } } } ] }, sort: { submittedAt: 1 }, update: { $set: { workingOn: { heartbeat: 1417460911723, machine: { machine: "mms-dev-da emon-2", head: "/data2/backups/daemon/" } } } } } keyUpdates:0 reslen:44 123ms 2014-12-01T19:08:31.848+0000 I QUERY [conn18039] command backupjobs.$cmd command: findAndModify { findandmodify: "blockstore_jobs", query: { finished: false, workingOn: false, type: "groom", $or: [ { pri orities: { $elemMatch: { lastResort: true, runEligibleTs: { $lt: 1417460911722 } } } } ] }, sort: { submittedAt: 1 }, update: { $set: { workingOn: { heartbeat: 1417460911723, machine: { machine: "mms-dev-da emon-2", head: "/data/backups/daemon/" } } } } } keyUpdates:0 reslen:44 119ms 2014-12-01T19:08:31.967+0000 I WRITE [conn17871] insert mmsdbautomationlog.agentLogs query: { _id: ObjectId('547cbcafe4b087d54e96dba2'), groupId: ObjectId('5479fde1e4b0e88a8f89cf91'), timestamp: 14174609 02000, level: "info", thread: "main/components/agent.go:354", logger: "", message: "All 1 Mongo processes are in goal state, Monitoring agent in goal state, Backup agent in goal state", hostname: "green-2.c luste.5479ff83e4b0e88a8f89e619.mongodbdns.com", process: null, threw: "" } ninserted:1 keyUpdates:0 121ms
Primary: 2.8.0rc1 (wiredtiger)
Secondaries: 2.8.0rc1 (mmapv1)
Same replica set as SERVER-16366