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

_id with $prefix field causes replication failure due to unvalidated insert

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Critical - P2 Critical - P2
    • 2.4.11, 2.6.0-rc0
    • Affects Version/s: 2.4.8, 2.4.9, 2.5.4
    • Component/s: Replication
    • None
    • Environment:
      Linux ip-10-xxx-xxx-xxx 3.4.37-40.44.amzn1.x86_64 #1 SMP Thu Mar 21 01:17:08 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux
    • Minor Change
    • ALL

      Server died while using Genghis on primary server in two-node replication set. Both running on m1.large instances in EC2. Storage on EBS.

      Was testing scope of namespace for duplicate _id. Add was allowed and sync killed secondary.

      Fri Dec 27 01:10:33.835 [initandlisten] MongoDB starting : pid=19511 port=27017 dbpath=/usr/local/var/mongod/db 64-bit host=ip-10-238-205-161
      Fri Dec 27 01:10:33.836 [initandlisten] db version v2.4.6
      Fri Dec 27 01:10:33.836 [initandlisten] git version: b9925db5eac369d77a3a5f5d98a145eaaacd9673
      Fri Dec 27 01:10:33.836 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
      Fri Dec 27 01:10:33.836 [initandlisten] allocator: tcmalloc
      Fri Dec 27 01:10:33.836 [initandlisten] options:

      { bind_ip: "0.0.0.0", config: "/etc/mongod.conf", dbpath: "/usr/local/var/mongod/db", fork: "true", logappend: "true", logpath: "/log/mongodb-2.log", replSet: "knrs" }

      Fri Dec 27 01:10:33.844 [initandlisten] journal dir=/usr/local/var/mongod/db/journal
      Fri Dec 27 01:10:33.844 [initandlisten] recover begin
      Fri Dec 27 01:10:33.844 [initandlisten] recover lsn: 0
      Fri Dec 27 01:10:33.844 [initandlisten] recover /usr/local/var/mongod/db/journal/j._0
      Fri Dec 27 01:10:33.852 [initandlisten] recover cleaning up
      Fri Dec 27 01:10:33.852 [initandlisten] removeJournalFiles
      Fri Dec 27 01:10:34.132 [initandlisten] recover done
      Fri Dec 27 01:10:34.132 [initandlisten] preallocating a journal file /usr/local/var/mongod/db/journal/prealloc.0
      Fri Dec 27 01:11:49.551 [initandlisten] waiting for connections on port 27017
      Fri Dec 27 01:11:49.552 [websvr] admin web console waiting for connections on port 28017
      Fri Dec 27 01:11:49.562 [rsStart] replSet I am ec2-54-227-255-57.compute-1.amazonaws.com:27017
      Fri Dec 27 01:11:49.562 [rsStart] replSet STARTUP2
      Fri Dec 27 01:11:49.564 [rsMgr] replSet total number of votes is even - add arbiter or give one member an extra vote
      Fri Dec 27 01:11:49.565 [rsHealthPoll] replset info ec2-54-227-252-146.compute-1.amazonaws.com:27017 thinks that we are down
      Fri Dec 27 01:11:49.565 [rsHealthPoll] replSet member ec2-54-227-252-146.compute-1.amazonaws.com:27017 is up
      Fri Dec 27 01:11:49.565 [rsHealthPoll] replSet member ec2-54-227-252-146.compute-1.amazonaws.com:27017 is now in state SECONDARY
      Fri Dec 27 01:11:50.564 [rsSync] replSet still syncing, not yet to minValid optime 52bcad0e:1
      Fri Dec 27 01:11:50.857 [initandlisten] connection accepted from 10.138.56.84:41413 #1 (1 connection now open)
      Fri Dec 27 01:11:50.857 [conn1] end connection 10.138.56.84:41413 (0 connections now open)
      Fri Dec 27 01:11:50.858 [initandlisten] connection accepted from 10.138.56.84:41414 #2 (1 connection now open)
      Fri Dec 27 01:11:56.563 [rsBackgroundSync] replSet syncing to: ec2-54-227-252-146.compute-1.amazonaws.com:27017
      Fri Dec 27 01:11:56.565 [rsSync] replSet still syncing, not yet to minValid optime 52bcad0e:1
      Fri Dec 27 01:11:56.579 [repl writer worker 1] ERROR: writer worker caught exception: invalid operator: $oid on: { ts: Timestamp 1388096782000|1, h: -6012491477194752701, v: 2, op: "i", ns: "kn1.accounts", o: { _id:

      { $oid: "5283fe3ea782c9aff9d96654" }

      , api_key: "604f5baa-fbc2-453a-ad9d-6e09a7d5e713", billing: {}, customEvents: {}, defaultDS: "ds.4444444.sample.internetTraffic", filters: [ { _id:

      { $oid: "5283fe3e9d46cd49718b457b" }

      , days_in_week: {}, desc: "Filter out non-business hours", hours_in_day: [ 17, 19, 20, 21, 22, 23, 0, 1, 2, 3, 4, 5, 6, 7, 8, 9 ], name: "Business Hours", type: "hourDayMonth", visibility: "account" }, { _id:

      { $oid: "5283fe3e9d46cd49718b457c" }

      , days_in_week: [ 0, 6 ], desc: "Filter out any data from Saturday and Sunday.", hours_in_day: {}, name: "No Weekends", type: "hourDayMonth", visibility: "account" } ], knId: "4945496", kn_subscription:

      { subscriptionType: "", startDate: "", endDate: "", autoRenew: false }

      , name: "Know Normal, Inc.", nr_account_id: "279085", nr_api_key: "4cdafbfa8a636aefc1be23e0a21bbc027605ee8ed754d4a", nr_data_key: "52086bb8297a0bf139511477b0f77dbb4dee674cd754d4a", nr_event_feed_uri: "/account_feeds/52086bb8297a0bf139511477b0f77dbb4dee674cd754d4a/events.rss", nr_subscription: { annual-renewal-on: { @attributes:

      { nil: "true" }

      }, expires-on: { @attributes:

      { nil: "true" }

      }, number-of-hosts: "1", starts-on: "2013-03-22", state: "paid", product-name: "Pro" }, owner: "nr@knownormal.com", sources: [

      { knColName: "ds.4444444.sample.wx", knDesc: "Raleigh-Durham, North Carolina Hourly Weather for 2012", knCustomName: "Weather Data", knSourceType: "sample", knFieldNames: [ "TmpF", "DPf", "RH", "CC", "Wind" ], knDateField: "Date", knTimeField: "Time", knDateTimeField: -1 }

      ,

      { knColName: "ds.4444444.sample.internetTraffic", knDesc: "Internet traffic data (in bits) from United Kingdom academic network backbone (19 November 2004 thru 27 January 2005). Hourly data.", knCustomName: "ISP Network Traffic", knSourceType: "sample", knFieldNames: [ "bits" ], knDateField: null, knTimeField: null, knDateTimeField: "Time" }

      ,

      { knSourceType: "NR", knSourceSubType: "summary", knColName: "ds.kn.279085.summary", knEventSource: "events.4945496.nr.279085", knCustomName: "KN App", knDesc: "", nrAppId: 1368487, nrAppName: "KN App", nrOverviewUrl: "https://rpm.newrelic.com/accounts/279085/applications/1368487", nrServerUrl: "https://rpm.newrelic.com/api/v1/accounts/279085/applications/1368487/servers" }

      ,

      { knSourceType: "NR", knSourceSubType: "summary", knColName: "ds.4945496.nr.279085.1783546.summary.hour", knEventSource: "events.4945496.nr.279085", knCustomName: "KN App Dev Maury", knDesc: "", nrAppId: 1783546, nrAppName: "KN App Dev Maury", nrOverviewUrl: "https://rpm.newrelic.com/accounts/279085/applications/1783546", nrServerUrl: "https://rpm.newrelic.com/api/v1/accounts/279085/applications/1783546/servers" }

      ,

      { knSourceType: "NR", knSourceSubType: "summary", knColName: "ds.4945496.nr.279085.1942741.summary.hour", knEventSource: "events.4945496.nr.279085", knCustomName: "My Application", knDesc: "", nrAppId: 1942741, nrAppName: "My Application", nrOverviewUrl: "https://rpm.newrelic.com/accounts/279085/applications/1942741", nrServerUrl: "https://rpm.newrelic.com/api/v1/accounts/279085/applications/1942741/servers" }

      ], users: [

      { knId: "4819339", role: "owner" }

      ] } }
      Fri Dec 27 01:11:56.579 [repl writer worker 1] Fatal Assertion 16360
      0xdddd81 0xd9dc13 0xc26bfc 0xdab721 0xe26609 0x7fb086d29c6b 0x7fb0860cf5ed
      /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xdddd81]
      /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xa3) [0xd9dc13]
      /usr/bin/mongod(_ZN5mongo7replset14multiSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x12c) [0xc26bfc]
      /usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x281) [0xdab721]
      /usr/bin/mongod() [0xe26609]
      /lib64/libpthread.so.0(+0x7c6b) [0x7fb086d29c6b]
      /lib64/libc.so.6(clone+0x6d) [0x7fb0860cf5ed]
      Fri Dec 27 01:11:56.583 [repl writer worker 1]

      ***aborting after fassert() failure

      Fri Dec 27 01:11:56.583 Got signal: 6 (Aborted).

      Fri Dec 27 01:11:56.586 Backtrace:
      0xdddd81 0x6d0d29 0x7fb0860219c0 0x7fb086021945 0x7fb08602325b 0xd9dc4e 0xc26bfc 0xdab721 0xe26609 0x7fb086d29c6b 0x7fb0860cf5ed
      /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xdddd81]
      /usr/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x6d0d29]
      /lib64/libc.so.6(+0x349c0) [0x7fb0860219c0]
      /lib64/libc.so.6(gsignal+0x35) [0x7fb086021945]
      /lib64/libc.so.6(abort+0x17b) [0x7fb08602325b]
      /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xde) [0xd9dc4e]
      /usr/bin/mongod(_ZN5mongo7replset14multiSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x12c) [0xc26bfc]
      /usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x281) [0xdab721]
      /usr/bin/mongod() [0xe26609]
      /lib64/libpthread.so.0(+0x7c6b) [0x7fb086d29c6b]
      /lib64/libc.so.6(clone+0x6d) [0x7fb0860cf5ed]

            Votes:
            0 Vote for this issue
            Watchers:
            12 Start watching this issue

              Created:
              Updated:
              Resolved: