Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical - P2
    • Resolution: Duplicate
    • Affects Version/s: 3.2.7
    • Fix Version/s: None
    • Component/s: Replication
    • Labels:
      None
    • Operating System:
      ALL

      Description

      I used 3.2.7 mongo. first i shutdown primary,then the secodary become the primary. wait a miniutes, i restart the old primary,so the old primary become the primary. the seondary and the hidden begin to rollback, finallly the rollback is fail .

      the primary log:

      2017-02-18T17:26:23.717+0800 I REPL     [ReplicationExecutor] This node is 192.168.1.55:8637 in the config
      2017-02-18T17:26:23.717+0800 I REPL     [ReplicationExecutor] transition to STARTUP2
      2017-02-18T17:26:23.717+0800 I REPL     [ReplicationExecutor] Starting replication applier threads
      2017-02-18T17:26:23.717+0800 I REPL     [ReplicationExecutor] transition to RECOVERING
      2017-02-18T17:26:23.719+0800 I REPL     [ReplicationExecutor] transition to SECONDARY
      2017-02-18T17:26:23.725+0800 I ASIO     [NetworkInterfaceASIO-Replication-0] Successfully connected to 192.168.1.70:8637
      2017-02-18T17:26:23.726+0800 I REPL     [ReplicationExecutor] Member 192.168.1.70:8637 is now in state SECONDARY
      2017-02-18T17:26:23.727+0800 I ASIO     [NetworkInterfaceASIO-Replication-0] Successfully connected to 192.168.1.59:8637
      2017-02-18T17:26:23.728+0800 I REPL     [ReplicationExecutor] Member 192.168.1.59:8637 is now in state PRIMARY
      2017-02-18T17:26:23.728+0800 I REPL     [ReplicationExecutor] Scheduling priority takeover at 2017-02-18T17:26:33.728+0800
      2017-02-18T17:26:24.005+0800 I FTDC     [ftdc] Unclean full-time diagnostic data capture shutdown detected, found interim file, some metrics may have been lost. OK
      2017-02-18T17:26:24.728+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.59:55555 #1 (1 connection now open)
      2017-02-18T17:26:24.735+0800 I ACCESS   [conn1]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.59,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:25.426+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.70:18786 #2 (2 connections now open)
      2017-02-18T17:26:25.432+0800 I ACCESS   [conn2]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.70,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:29.720+0800 I REPL     [ReplicationExecutor] syncing from: 192.168.1.59:8637
      2017-02-18T17:26:29.727+0800 I REPL     [SyncSourceFeedback] setting syncSourceFeedback to 192.168.1.59:8637
      2017-02-18T17:26:29.735+0800 I ASIO     [NetworkInterfaceASIO-BGSync-0] Successfully connected to 192.168.1.59:8637
      2017-02-18T17:26:29.784+0800 I INDEX    [repl writer worker 2] build index on: mgo3.mycollection2 properties: { v: 1, key: { _id: "hashed" }, name: "_id_hashed", ns: "mgo3.mycollection2" }
      2017-02-18T17:26:29.784+0800 I INDEX    [repl writer worker 2] 	 building index using bulk method
      2017-02-18T17:26:29.784+0800 I INDEX    [repl writer worker 2] build index done.  scanned 0 total records. 0 secs
      2017-02-18T17:26:29.807+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.53:64373 #3 (3 connections now open)
      2017-02-18T17:26:29.813+0800 I ACCESS   [conn3]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.53,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:31.203+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.59:55556 #4 (4 connections now open)
      2017-02-18T17:26:31.209+0800 I ACCESS   [conn4]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.59,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:33.084+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.56:24303 #5 (5 connections now open)
      2017-02-18T17:26:33.086+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.62:49972 #6 (6 connections now open)
      2017-02-18T17:26:33.090+0800 I ACCESS   [conn5]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.56,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:33.093+0800 I ACCESS   [conn6]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.62,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:33.262+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.54:52862 #7 (7 connections now open)
      2017-02-18T17:26:33.268+0800 I ACCESS   [conn7]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.54,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:33.728+0800 I REPL     [ReplicationExecutor] Canceling priority takeover callback
      2017-02-18T17:26:33.728+0800 I REPL     [ReplicationExecutor] Starting an election for a priority takeover
      2017-02-18T17:26:33.728+0800 I REPL     [ReplicationExecutor] conducting a dry run election to see if we could be elected
      2017-02-18T17:26:33.729+0800 I REPL     [ReplicationExecutor] dry election run succeeded, running for election
      2017-02-18T17:26:33.730+0800 I REPL     [ReplicationExecutor] election succeeded, assuming primary role in term 9
      2017-02-18T17:26:33.730+0800 I REPL     [ReplicationExecutor] transition to PRIMARY
      2017-02-18T17:26:33.730+0800 I SHARDING [rsSync] Sharding state recovery process found document { _id: "minOpTimeRecovery", configsvrConnectionString: "CONFIGSVR-1/192.168.1.74:8636,192.168.1.77:8636", shardName: "SHARD-1", minOpTime: { ts: Timestamp 1487409916000|15, t: 3 }, minOpTimeUpdaters: 0 }
      2017-02-18T17:26:33.730+0800 I SHARDING [ShardingState initialization] first cluster operation detected, adding sharding hook to enable versioning and authentication to remote servers
      2017-02-18T17:26:33.733+0800 I SHARDING [ShardingState initialization] Updating config server connection string to: CONFIGSVR-1/192.168.1.74:8636,192.168.1.77:8636
      2017-02-18T17:26:33.733+0800 I NETWORK  [ShardingState initialization] Starting new replica set monitor for CONFIGSVR-1/192.168.1.74:8636,192.168.1.77:8636
      2017-02-18T17:26:33.733+0800 I NETWORK  [ReplicaSetMonitorWatcher] starting
      2017-02-18T17:26:33.735+0800 I SHARDING [thread1] creating distributed lock ping thread for process zkn-az1-3-mongodb-7c99-member-SHARD-1-3:8637:1487409993:-1148270023 (sleeping for 30000ms)
      2017-02-18T17:26:33.739+0800 I ASIO     [NetworkInterfaceASIO-Replication-0] Successfully connected to 192.168.1.59:8637
      2017-02-18T17:26:33.740+0800 I ASIO     [NetworkInterfaceASIO-Replication-0] Successfully connected to 192.168.1.59:8637
      2017-02-18T17:26:33.742+0800 I ASIO     [NetworkInterfaceASIO-Replication-0] Successfully connected to 192.168.1.59:8637
      2017-02-18T17:26:33.751+0800 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Successfully connected to 192.168.1.74:8636
      2017-02-18T17:26:33.756+0800 W SHARDING [replSetDistLockPinger] pinging failed for distributed lock pinger :: caused by :: LockStateChangeFailed: findAndModify query predicate didn't match any lock document
      2017-02-18T17:26:33.807+0800 I NETWORK  [ShardingState initialization] Starting new replica set monitor for SHARD-1/192.168.1.55:8637,192.168.1.59:8637
      2017-02-18T17:26:33.807+0800 I NETWORK  [ShardingState initialization] Starting new replica set monitor for SHARD-2/192.168.1.54:8637,192.168.1.56:8637
      2017-02-18T17:26:33.807+0800 I SHARDING [rsSync] remote client  initialized this host as shard SHARD-1
      2017-02-18T17:26:33.808+0800 I REPL     [rsSync] transition to primary complete; database writes are now permitted
      2017-02-18T17:26:33.895+0800 I NETWORK  [conn4] end connection 192.168.1.59:55556 (6 connections now open)
      2017-02-18T17:26:33.929+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.62:49974 #8 (7 connections now open)
      2017-02-18T17:26:33.935+0800 I ACCESS   [conn8]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.62,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:33.937+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.62:49975 #9 (8 connections now open)
      2017-02-18T17:26:33.937+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.53:64375 #10 (9 connections now open)
      2017-02-18T17:26:33.940+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.62:49976 #11 (10 connections now open)
      2017-02-18T17
      

      the secondary log:

      2017-02-18T17:26:29.493+0800 I ACCESS   [conn205]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.55,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:29.642+0800 I NETWORK  [conn202] end connection 192.168.1.55:23686 (39 connections now open)
      2017-02-18T17:26:29.645+0800 I REPL     [ReplicationExecutor] stepping down from primary, because a new term has begun: 9
      2017-02-18T17:26:29.645+0800 I REPL     [replExecDBWorker-2] transition to SECONDARY
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn133] end connection 192.168.1.59:12214 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn136] end connection 192.168.1.59:12219 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn203] end connection 192.168.1.55:23687 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn205] end connection 192.168.1.55:23689 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn132] end connection 192.168.1.53:42855 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn158] end connection 192.168.1.62:53959 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn116] end connection 192.168.1.62:53826 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn159] end connection 192.168.1.62:53960 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn135] end connection 192.168.1.53:42857 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn115] end connection 192.168.1.59:12144 (38 connections now open)
      2017-02-18T17:26:29.645+0800 I NETWORK  [conn166] end connection 192.168.1.62:53964 (36 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn118] end connection 192.168.1.54:48174 (35 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn102] end connection 192.168.1.62:53818 (34 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn130] end connection 192.168.1.54:48239 (33 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn134] end connection 192.168.1.53:42856 (32 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn104] end connection 192.168.1.62:53820 (32 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn169] end connection 192.168.1.62:53967 (29 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn106] end connection 192.168.1.53:42750 (29 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn129] end connection 192.168.1.53:42854 (27 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn110] end connection 192.168.1.70:55705 (27 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn113] end connection 192.168.1.70:55708 (25 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn174] end connection 192.168.1.59:12330 (22 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn131] end connection 192.168.1.62:53935 (22 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn114] end connection 192.168.1.53:42751 (22 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn117] end connection 192.168.1.56:26951 (32 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn204] end connection 192.168.1.55:23688 (19 connections now open)
      2017-02-18T17:26:29.646+0800 I NETWORK  [conn167] end connection 192.168.1.62:53965 (22 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.70:55982 #206 (19 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn171] end connection 192.168.1.53:42882 (18 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn160] end connection 192.168.1.62:53961 (15 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn168] end connection 192.168.1.62:53966 (14 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn161] end connection 192.168.1.54:48254 (10 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn128] end connection 192.168.1.53:42846 (8 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn140] end connection 192.168.1.70:55777 (7 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn170] end connection 192.168.1.53:42881 (7 connections now open)
      2017-02-18T17:26:29.648+0800 I NETWORK  [conn172] end connection 192.168.1.54:48269 (5 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn201] end connection 192.168.1.55:23685 (17 connections now open)
      2017-02-18T17:26:29.648+0800 I NETWORK  [conn137] end connection 192.168.1.54:48240 (5 connections now open)
      2017-02-18T17:26:29.647+0800 I NETWORK  [conn163] end connection 192.168.1.62:53962 (17 connections now open)
      2017-02-18T17:26:29.648+0800 I NETWORK  [conn120] SocketException handling request, closing client connection: 9001 socket exception [SEND_ERROR] server [192.168.1.70:55722] 
      2017-02-18T17:26:29.653+0800 I ACCESS   [conn206]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.70,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:29.672+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.62:53998 #207 (2 connections now open)
      2017-02-18T17:26:29.677+0800 I ACCESS   [conn207]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.62,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:29.681+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.53:42911 #208 (3 connections now open)
      2017-02-18T17:26:29.686+0800 I ACCESS   [conn208]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.53,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:30.492+0800 I REPL     [ReplicationExecutor] Member 192.168.1.55:8637 is now in state PRIMARY
      2017-02-18T17:26:30.681+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.70:55987 #209 (4 connections now open)
      2017-02-18T17:26:30.686+0800 I ACCESS   [conn209]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.70,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:30.687+0800 I NETWORK  [conn209] end connection 192.168.1.70:55987 (3 connections now open)
      2017-02-18T17:26:30.687+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.70:55988 #210 (4 connections now open)
      2017-02-18T17:26:30.687+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.70:55989 #211 (5 connections now open)
      2017-02-18T17:26:30.693+0800 I ACCESS   [conn210]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.70,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:30.693+0800 I ACCESS   [conn211]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.70,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:30.698+0800 I NETWORK  [conn210] end connection 192.168.1.70:55988 (4 connections now open)
      2017-02-18T17:26:31.189+0800 I REPL     [ReplicationExecutor] syncing from: 192.168.1.55:8637
      2017-02-18T17:26:31.197+0800 I REPL     [SyncSourceFeedback] setting syncSourceFeedback to 192.168.1.55:8637
      2017-02-18T17:26:31.203+0800 I ASIO     [NetworkInterfaceASIO-BGSync-0] Successfully connected to 192.168.1.55:8637
      2017-02-18T17:26:31.204+0800 I REPL     [rsBackgroundSync] Starting rollback due to OplogStartMissing: our last op time fetched: (term: 8, timestamp: Feb 18 17:26:29:a). source's GTE: (term: 9, timestamp: Feb 18 17:26:33:2) hashes: (-2724116090579412714/-4865368491621293515)
      2017-02-18T17:26:31.205+0800 I REPL     [rsBackgroundSync] beginning rollback
      2017-02-18T17:26:31.205+0800 I REPL     [rsBackgroundSync] rollback 0
      2017-02-18T17:26:31.205+0800 I REPL     [ReplicationExecutor] transition to ROLLBACK
      2017-02-18T17:26:31.205+0800 I REPL     [rsBackgroundSync] rollback 1
      2017-02-18T17:26:31.205+0800 I NETWORK  [conn207] end connection 192.168.1.62:53998 (3 connections now open)
      2017-02-18T17:26:31.205+0800 I NETWORK  [conn208] end connection 192.168.1.53:42911 (3 connections now open)
      2017-02-18T17:26:31.205+0800 I NETWORK  [conn206] end connection 192.168.1.70:55982 (3 connections now open)
      2017-02-18T17:26:31.205+0800 I NETWORK  [conn211] end connection 192.168.1.70:55989 (0 connections now open)
      2017-02-18T17:26:31.211+0800 I REPL     [rsBackgroundSync] rollback 2 FindCommonPoint
      2017-02-18T17:26:31.212+0800 I REPL     [rsBackgroundSync] rollback our last optime:   Feb 18 17:26:29:a
      2017-02-18T17:26:31.212+0800 I REPL     [rsBackgroundSync] rollback their last optime: Feb 18 17:26:35:9
      2017-02-18T17:26:31.212+0800 I REPL     [rsBackgroundSync] rollback diff in end of log times: -6 seconds
      2017-02-18T17:26:31.212+0800 I REPL     [rsBackgroundSync] rollback 3 fixup
      2017-02-18T17:26:31.213+0800 I REPL     [rsBackgroundSync] rollback 3.5
      2017-02-18T17:26:31.213+0800 I REPL     [rsBackgroundSync] rollback 4 n:1
      2017-02-18T17:26:31.213+0800 I REPL     [rsBackgroundSync] minvalid=(term: 9, timestamp: Feb 18 17:26:35:9)
      2017-02-18T17:26:31.213+0800 I REPL     [rsBackgroundSync] rollback 4.6
      2017-02-18T17:26:31.213+0800 I REPL     [rsBackgroundSync] rollback 4.7
      2017-02-18T17:26:31.214+0800 I REPL     [rsBackgroundSync] rollback 5 d:0 u:1
      2017-02-18T17:26:31.214+0800 I REPL     [rsBackgroundSync] rollback 6
      2017-02-18T17:26:31.214+0800 I REPL     [rsBackgroundSync] rollback done
      2017-02-18T17:26:31.214+0800 I REPL     [rsBackgroundSync] rollback finished
      2017-02-18T17:26:31.214+0800 I NETWORK  [SyncSourceFeedback] Socket  send() errno:9 Bad file descriptor 192.168.1.55:8637
      2017-02-18T17:26:31.214+0800 I REPL     [SyncSourceFeedback] SyncSourceFeedback error sending update: socket exception [SEND_ERROR] for 192.168.1.55:8637
      2017-02-18T17:26:31.214+0800 I REPL     [SyncSourceFeedback] updateUpstream failed: Location9001: socket exception [SEND_ERROR] for 192.168.1.55:8637, will retry
      2017-02-18T17:26:31.224+0800 I REPL     [ReplicationExecutor] transition to RECOVERING
      2017-02-18T17:26:31.224+0800 I REPL     [ReplicationExecutor] syncing from: 192.168.1.70:8637
      2017-02-18T17:26:31.231+0800 I REPL     [SyncSourceFeedback] setting syncSourceFeedback to 192.168.1.70:8637
      2017-02-18T17:26:31.237+0800 I ASIO     [NetworkInterfaceASIO-BGSync-0] Successfully connected to 192.168.1.70:8637
      2017-02-18T17:26:31.240+0800 I REPL     [ReplicationExecutor] could not find member to sync from
      2017-02-18T17:26:31.241+0800 I ASIO     [ReplicationExecutor] dropping unhealthy pooled connection to 192.168.1.70:8637
      2017-02-18T17:26:31.241+0800 I ASIO     [ReplicationExecutor] after drop, pool was empty, going to spawn some connections
      2017-02-18T17:26:31.247+0800 I ASIO     [NetworkInterfaceASIO-Replication-0] Successfully connected to 192.168.1.70:8637
      2017-02-18T17:26:31.247+0800 I REPL     [ReplicationExecutor] Member 192.168.1.70:8637 is now in state RECOVERING
      2017-02-18T17:26:31.494+0800 I NETWORK  [initandlisten] connection accepted from 192.168.1.55:23700 #212 (1 connection now open)
      2017-02-18T17:26:31.499+0800 I ACCESS   [conn212]  authenticate db: $external { authenticate: 1, mechanism: "MONGODB-X509", user: "CN=192.168.1.55,OU=889748ef-e4b4-4d6c-a19d-59df5372abf0,O=huawei,L=xian,ST=shanxi,C=CN" }
      2017-02-18T17:26:32.241+0800 I REPL     [ReplicationExecutor] syncing from: 192.168.1.55:8637
      2017-02-18T17:26:32.248+0800 I REPL     [SyncSourceFeedback] setting syncSourceFeedback to 192.168.1.55:8637
      2017-02-18T17:26:32.249+0800 I REPL     [rsBackgroundSync] Starting rollback due to OplogStartMissing: our last op time fetched: (term: 8, timestamp: Feb 18 17:26:29:a). source's GTE: (term: 9, timestamp: Feb 18 17:26:33:2) hashes: (-2724116090579412714/-4865368491621293515)
      2017-02-18T17:26:32.249+0800 I -        [rsBackgroundSync] Fatal assertion 18750 UnrecoverableRollbackError: need to rollback, but in inconsistent state. minvalid: (term: 9, timestamp: Feb 18 17:26:35:9) > our last optime: (term: 8, timestamp: Feb 18 17:26:29:a)
      2017-02-18T17:26:32.249+0800 I -        [rsBackgroundSync] 
       
      ***aborting after fassert() failure
      

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: