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

Fassert after removing and re-adding node from replset

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Replication
    • None
    • ALL

      2014-10-21T16:32:54.978-0400 I REPLSETS Cannot find self in new replica set configuration; I must be removed; NodeNotFound No host described in new configuration 18 for replica set mySet maps to this node
      2014-10-21T16:32:54.979-0400 I REPLSETS transition to REMOVED
      2014-10-21T16:32:54.979-0400 I NETWORK  [conn4] end connection 127.0.0.1:51366 (2 connections now open)
      2014-10-21T16:32:55.727-0400 I REPLSETS [rsSync] Received exception while syncing: 28524 Node not a member of the current set configuration
      2014-10-21T16:33:05.727-0400 I REPLSETS [rsSync] initial sync pending
      2014-10-21T16:33:05.728-0400 I REPLSETS [rsSync] no valid sync sources found in current replset to do an initial sync
      2014-10-21T16:33:08.729-0400 I REPLSETS [rsSync] initial sync pending
      2014-10-21T16:33:08.729-0400 I REPLSETS [rsSync] no valid sync sources found in current replset to do an initial sync
      2014-10-21T16:33:10.523-0400 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:46975 #17 (3 connections now open)
      2014-10-21T16:33:10.523-0400 I NETWORK  [conn17] end connection 127.0.0.1:46975 (2 connections now open)
      2014-10-21T16:33:10.993-0400 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:46978 #18 (3 connections now open)
      2014-10-21T16:33:10.994-0400 I NETWORK  [conn18] end connection 127.0.0.1:46978 (2 connections now open)
      2014-10-21T16:33:10.996-0400 I REPLSETS transition to SECONDARY
      2014-10-21T16:33:11.731-0400 I REPLSETS [rsSync] initial sync pending
      2014-10-21T16:33:11.731-0400 I REPLSETS replSet syncing from: ubuntu:20002
      2014-10-21T16:33:11.731-0400 I REPLSETS syncing from: ubuntu:20002
      2014-10-21T16:33:11.733-0400 I REPLSETS [rsSync] initial sync drop all databases
      2014-10-21T16:33:11.734-0400 I STORAGE  [rsSync] dropAllDatabasesExceptLocal 2
      2014-10-21T16:33:11.771-0400 I JOURNAL  [rsSync] removeJournalFiles
      2014-10-21T16:33:11.798-0400 I REPLSETS [rsSync] initial sync clone all databases
      2014-10-21T16:33:11.799-0400 I REPLSETS [rsSync] initial sync cloning db: test
      2014-10-21T16:33:11.802-0400 I INDEXING [rsSync] allocating new ns file /data/replset/db3/test.ns, filling with zeroes...
      2014-10-21T16:33:11.896-0400 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:46984 #19 (3 connections now open)
      2014-10-21T16:33:11.897-0400 I NETWORK  [conn19] end connection 127.0.0.1:46984 (2 connections now open)
      2014-10-21T16:33:11.898-0400 I STORAGE  [FileAllocator] allocating new datafile /data/replset/db3/test.0, filling with zeroes...
      2014-10-21T16:33:11.899-0400 I STORAGE  [FileAllocator] creating directory /data/replset/db3/_tmp
      2014-10-21T16:33:11.919-0400 I STORAGE  [FileAllocator] done allocating datafile /data/replset/db3/test.0, size: 64MB,  took 0.01 secs
      2014-10-21T16:33:11.919-0400 I STORAGE  [rsSync] datafileheader::init initializing /data/replset/db3/test.0 n:0
      2014-10-21T16:33:11.949-0400 I INDEXING [rsSync] build index on: test.foo properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "test.foo" }
      2014-10-21T16:33:11.949-0400 I INDEXING [rsSync] 	 building index using bulk method
      2014-10-21T16:33:11.950-0400 I INDEXING [rsSync] build index done.  scanned 2 total records. 0 secs
      2014-10-21T16:33:11.950-0400 I REPLSETS [rsSync] initial sync data copy, starting syncup
      2014-10-21T16:33:11.950-0400 I REPLSETS [rsSync] oplog sync 1 of 3
      2014-10-21T16:33:11.951-0400 I REPLSETS [rsSync] oplog sync 2 of 3
      2014-10-21T16:33:11.951-0400 I REPLSETS [rsSync] initial sync building indexes
      2014-10-21T16:33:11.951-0400 I REPLSETS [rsSync] initial sync cloning indexes for : test
      2014-10-21T16:33:11.955-0400 I STORAGE  [rsSync] copying indexes for: { name: "foo", options: { flags: 1 } }
      2014-10-21T16:33:11.956-0400 I REPLSETS [rsSync] oplog sync 3 of 3
      2014-10-21T16:33:11.957-0400 I REPLSETS [rsSync] initial sync finishing up
      2014-10-21T16:33:11.957-0400 I REPLSETS [rsSync] replSet set minValid=5446c306:1
      2014-10-21T16:33:11.958-0400 I REPLSETS [rsSync] initial sync done
      2014-10-21T16:33:11.959-0400 I REPLSETS transition to RECOVERING
      2014-10-21T16:33:11.965-0400 I REPLSETS transition to SECONDARY
      2014-10-21T16:33:11.982-0400 I NETWORK  [rsBackgroundSync] Socket flush send() errno:9 Bad file descriptor 127.0.1.1:20002
      2014-10-21T16:33:11.982-0400 I -        [rsBackgroundSync] caught exception (socket exception [SEND_ERROR] for 127.0.1.1:20002) in destructor (~PiggyBackData)
      2014-10-21T16:33:11.982-0400 I REPLSETS replSet could not find member to sync from
      2014-10-21T16:33:23.986-0400 I REPLSETS replSet syncing from: ubuntu:20002
      2014-10-21T16:33:23.986-0400 I REPLSETS syncing from: ubuntu:20002
      2014-10-21T16:33:23.988-0400 I REPLSETS [SyncSourceFeedbackThread] replset setting syncSourceFeedback to ubuntu:20002
      2014-10-21T16:33:23.989-0400 F REPLSETS [rsSync] replication oplog stream went back in time. previous timestamp: 5446c306:1 newest timestamp: 5446c2f6:1
      2014-10-21T16:33:23.989-0400 I -        [rsSync] Fatal Assertion 18905
      2014-10-21T16:33:23.989-0400 I -        [rsSync] 
      
      ***aborting after fassert() failure
      

            Assignee:
            spencer@mongodb.com Spencer Brody (Inactive)
            Reporter:
            spencer@mongodb.com Spencer Brody (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated:
              Resolved: