Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-16368

WriteConflict on bulk insert to capped collection

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 2.8.0-rc3
    • Affects Version/s: 2.8.0-rc1
    • Component/s: Storage
    • Labels:
    • Fully Compatible
    • ALL

      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

            Assignee:
            eliot Eliot Horowitz (Inactive)
            Reporter:
            cailin.nelson@mongodb.com Cailin Nelson
            Votes:
            0 Vote for this issue
            Watchers:
            10 Start watching this issue

              Created:
              Updated:
              Resolved: