[SERVER-21337] Add awaitSecondaryNodes() in election_timing_test.js to prevent testing failover without eligible secondary Created: 06/Nov/15  Updated: 17/Nov/15  Resolved: 06/Nov/15

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 3.2.0-rc3

Type: Bug Priority: Major - P3
Reporter: Spencer Brody (Inactive) Assignee: Michael Grundy
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Backwards Compatibility: Fully Compatible
Operating System: ALL
Sprint: TIG C (11/20/15)
Participants:

 Description   

task
logs

[js_test:election_timing] 2015-11-06T15:41:34.239+0000 2015-11-06T15:41:25.173+0000 E QUERY    [thread1] Error: [object Object] :
[js_test:election_timing] 2015-11-06T15:41:34.239+0000 @jstests/replsets/election_timing.js:71:1
[js_test:election_timing] 2015-11-06T15:41:34.239+0000 @jstests/replsets/election_timing.js:61:5
[js_test:election_timing] 2015-11-06T15:41:34.240+0000 @jstests/replsets/election_timing.js:4:2
[js_test:election_timing] 2015-11-06T15:41:34.240+0000 
[js_test:election_timing] 2015-11-06T15:41:34.240+0000 failed to load: jstests/replsets/election_timing.js



 Comments   
Comment by Githook User [ 06/Nov/15 ]

Author:

{u'username': u'mgrundy', u'name': u'Mike Grundy', u'email': u'michael.grundy@10gen.com'}

Message: SERVER-21337 Add awaitSecondaryNodes() in election_timing_test.js
Branch: master
https://github.com/mongodb/mongo/commit/0f1dd0940092687f30812a123907df397aacf90c

Comment by Michael Grundy [ 06/Nov/15 ]

Seems to be related to SERVER-21129, going to add awaitSecondaryNodes() before awaitReplication(). In the first instance we shut down the Primary before the other node had transitioned to secondary.

Comment by Spencer Brody (Inactive) [ 06/Nov/15 ]

Another failure of the same test, but with a different failure mode: https://evergreen.mongodb.com/task/mongodb_mongo_master_amazon_replicasets_WT_6543f0dea026b6ff9ad6f701a8f6ca62f0679613_15_11_06_18_00_21

[js_test:election_timing] 2015-11-06T18:51:24.072+0000 ReplSetTest awaitReplication: timestamp for ip-10-31-53-83:20263 is newer, resetting latest to Timestamp(1446835847, 2)
[js_test:election_timing] 2015-11-06T18:51:24.072+0000 d20265| 2015-11-06T18:51:21.120+0000 I COMMAND  [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.072+0000 assert.soon failed, msg:awaiting replication
[js_test:election_timing] 2015-11-06T18:51:24.072+0000 d20264| 2015-11-06T18:51:21.093+0000 I COMMAND  [conn5] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.072+0000 d20265| 2015-11-06T18:51:21.280+0000 I COMMAND  [conn5] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20264", fromId: 1, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.073+0000 d20265| 2015-11-06T18:51:21.620+0000 I COMMAND  [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.073+0000 d20265| 2015-11-06T18:51:22.370+0000 I COMMAND  [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.073+0000 d20265| 2015-11-06T18:51:23.121+0000 I COMMAND  [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.073+0000 d20265| 2015-11-06T18:51:23.280+0000 I COMMAND  [conn5] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20264", fromId: 1, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.073+0000 d20265| 2015-11-06T18:51:23.620+0000 I COMMAND  [conn7] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.073+0000 d20264| 2015-11-06T18:51:21.120+0000 I COMMAND  [conn3] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 d20264| 2015-11-06T18:51:21.620+0000 I COMMAND  [conn3] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 d20264| 2015-11-06T18:51:21.843+0000 I COMMAND  [conn5] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 d20264| 2015-11-06T18:51:22.370+0000 I COMMAND  [conn3] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 doassert@src/mongo/shell/assert.js:15:14
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 assert.soon@src/mongo/shell/assert.js:200:13
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 ReplSetTest.prototype.awaitReplication@src/mongo/shell/replsettest.js:551:1
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 ElectionTimingTest.prototype._runTimingTest@jstests/libs/election_timing_test.js:90:9
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 ElectionTimingTest@jstests/libs/election_timing_test.js:46:5
[js_test:election_timing] 2015-11-06T18:51:24.074+0000 @jstests/replsets/election_timing.js:62:23
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 @jstests/replsets/election_timing.js:61:5
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 @jstests/replsets/election_timing.js:4:2
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 d20264| 2015-11-06T18:51:22.594+0000 I COMMAND  [conn5] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 d20264| 2015-11-06T18:51:23.121+0000 I COMMAND  [conn3] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 d20264| 2015-11-06T18:51:23.345+0000 I COMMAND  [conn5] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 d20264| 2015-11-06T18:51:23.620+0000 I COMMAND  [conn3] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20263", fromId: 0, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.075+0000 d20263| 2015-11-06T18:51:21.138+0000 I COMMAND  [conn12] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 2015-11-06T18:51:24.039+0000 E QUERY    [thread1] Error: assert.soon failed, msg:awaiting replication :
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 doassert@src/mongo/shell/assert.js:15:14
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 assert.soon@src/mongo/shell/assert.js:200:13
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 ReplSetTest.prototype.awaitReplication@src/mongo/shell/replsettest.js:551:1
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 ElectionTimingTest.prototype._runTimingTest@jstests/libs/election_timing_test.js:90:9
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 ElectionTimingTest@jstests/libs/election_timing_test.js:46:5
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 @jstests/replsets/election_timing.js:62:23
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 @jstests/replsets/election_timing.js:61:5
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 @jstests/replsets/election_timing.js:4:2
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 
[js_test:election_timing] 2015-11-06T18:51:24.076+0000 d20263| 2015-11-06T18:51:21.889+0000 I COMMAND  [conn12] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.077+0000 d20263| 2015-11-06T18:51:22.628+0000 I COMMAND  [conn10] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20264", fromId: 1, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.077+0000 d20263| 2015-11-06T18:51:22.639+0000 I COMMAND  [conn12] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.077+0000 d20263| 2015-11-06T18:51:23.390+0000 I COMMAND  [conn12] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "testV1StopTimeout1500", configVersion: 1, from: "ip-10-31-53-83:20265", fromId: 2, term: 2 } ntoreturn:1 ntoskip:0 keyUpdates:0 writeConflicts:0 numYields:0 reslen:332 locks:{} protocol:op_command 0ms
[js_test:election_timing] 2015-11-06T18:51:24.077+0000 failed to load: jstests/replsets/election_timing.js

Generated at Thu Feb 08 03:57:03 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.