[SERVER-21736] sync2.js Created: 12/Nov/15  Updated: 03/Dec/15  Resolved: 02/Dec/15

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

Type: Bug Priority: Major - P3
Reporter: Shraya Ramani Assignee: Matt Dannenberg
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: Repl C (11/20/15), Repl D (12/11/15)
Participants:

 Description   

logs
task

[js_test:sync2] 2015-11-12T19:56:49.555+0000 b20513| 2015-11-12T19:56:49.543+0000 I NETWORK  [main] connection accepted from 10.164.161.146:56236 #146 (1 connection now open)
[js_test:sync2] 2015-11-12T19:56:49.555+0000 d20518| 2015-11-12T19:56:49.544+0000 I NETWORK  [initandlisten] connection accepted from 10.164.161.146:50220 #147 (6 connections now open)
[js_test:sync2] 2015-11-12T19:56:49.556+0000 b20513| 2015-11-12T19:56:49.545+0000 I BRIDGE   [thread142] Rejecting connection from ip-10-164-161-146:20517, end connection 10.164.161.146:56236
[js_test:sync2] 2015-11-12T19:56:49.556+0000 d20517| 2015-11-12T19:56:49.545+0000 I ASIO     [NetworkInterfaceASIO] Failed to connect to ip-10-164-161-146:20513 - HostUnreachable End of file
[js_test:sync2] 2015-11-12T19:56:49.557+0000 d20517| 2015-11-12T19:56:49.546+0000 I REPL     [ReplicationExecutor] Error in heartbeat request to ip-10-164-161-146:20513; HostUnreachable End of file
[js_test:sync2] 2015-11-12T19:56:49.557+0000 d20518| 2015-11-12T19:56:49.546+0000 I NETWORK  [conn147] end connection 10.164.161.146:50220 (5 connections now open)
[js_test:sync2] 2015-11-12T19:56:50.511+0000 d20515| 2015-11-12T19:56:50.509+0000 I COMMAND  [conn2] command foo.bar command: insert { insert: "bar", documents: [ { _id: ObjectId('5644eee417fb939b836bca96'), x: 1.0 } ], ordered: true, writeConcern: { w: 5.0, wtimeout: 30000.0 } } ntoreturn:1 ntoskip:0 ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:170 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_command 30001ms
[js_test:sync2] 2015-11-12T19:56:50.511+0000 assert: write concern failed with errors: {
[js_test:sync2] 2015-11-12T19:56:50.511+0000 	"nInserted" : 1,
[js_test:sync2] 2015-11-12T19:56:50.511+0000 	"writeConcernError" : {
[js_test:sync2] 2015-11-12T19:56:50.511+0000 		"code" : 64,
[js_test:sync2] 2015-11-12T19:56:50.512+0000 		"errInfo" : {
[js_test:sync2] 2015-11-12T19:56:50.512+0000 			"wtimeout" : true
[js_test:sync2] 2015-11-12T19:56:50.512+0000 		},
[js_test:sync2] 2015-11-12T19:56:50.512+0000 		"errmsg" : "waiting for replication timed out"
[js_test:sync2] 2015-11-12T19:56:50.512+0000 	}
[js_test:sync2] 2015-11-12T19:56:50.512+0000 }
[js_test:sync2] 2015-11-12T19:56:50.513+0000 _getErrorWithCode@src/mongo/shell/utils.js:23:13
[js_test:sync2] 2015-11-12T19:56:50.513+0000 doassert@src/mongo/shell/assert.js:13:14
[js_test:sync2] 2015-11-12T19:56:50.513+0000 assert.writeOK@src/mongo/shell/assert.js:412:9
[js_test:sync2] 2015-11-12T19:56:50.514+0000 @jstests/replsets/sync2.js:37:1
[js_test:sync2] 2015-11-12T19:56:50.514+0000 
[js_test:sync2] 2015-11-12T19:56:50.514+0000 2015-11-12T19:56:50.511+0000 E QUERY    [thread1] Error: write concern failed with errors: {
[js_test:sync2] 2015-11-12T19:56:50.514+0000 	"nInserted" : 1,
[js_test:sync2] 2015-11-12T19:56:50.514+0000 	"writeConcernError" : {
[js_test:sync2] 2015-11-12T19:56:50.514+0000 		"code" : 64,
[js_test:sync2] 2015-11-12T19:56:50.514+0000 		"errInfo" : {
[js_test:sync2] 2015-11-12T19:56:50.514+0000 			"wtimeout" : true
[js_test:sync2] 2015-11-12T19:56:50.514+0000 		},
[js_test:sync2] 2015-11-12T19:56:50.515+0000 		"errmsg" : "waiting for replication timed out"
[js_test:sync2] 2015-11-12T19:56:50.515+0000 	}
[js_test:sync2] 2015-11-12T19:56:50.515+0000 } :
[js_test:sync2] 2015-11-12T19:56:50.515+0000 _getErrorWithCode@src/mongo/shell/utils.js:23:13
[js_test:sync2] 2015-11-12T19:56:50.515+0000 doassert@src/mongo/shell/assert.js:13:14
[js_test:sync2] 2015-11-12T19:56:50.515+0000 assert.writeOK@src/mongo/shell/assert.js:412:9
[js_test:sync2] 2015-11-12T19:56:50.515+0000 @jstests/replsets/sync2.js:37:1
[js_test:sync2] 2015-11-12T19:56:50.515+0000 
[js_test:sync2] 2015-11-12T19:56:50.516+0000 failed to load: jstests/replsets/sync2.js



 Comments   
Comment by Githook User [ 02/Dec/15 ]

Author:

{u'username': u'dannenberg', u'name': u'matt dannenberg', u'email': u'matt.dannenberg@10gen.com'}

Message: SERVER-21736 disable sync2.js in the replica_sets_legacy task
Branch: master
https://github.com/mongodb/mongo/commit/7177f576c74e13c8d6707da3004276cfef578ce9

Comment by Matt Dannenberg [ 19/Nov/15 ]

kaloian.manassiev I think that here we just need to adapt the test to restore the spanning tree prior to waiting for a w:5 write. We made a similar change to resolve a similar failure in tags.js.

In backup_restore.js (or at least the instance linked, as the test has multiple failure modes at the moment), nodes are starting up slowly and no election completes successfully in time. See BF-1348.

Comment by Kaloian Manassiev [ 19/Nov/15 ]

Happens more in the recent runs. I am also wondering whether it might be related to the failures in the backup_restore tests as well - https://logkeeper.mongodb.org/build/564e06e7be07c42d838d00cf/test/564e06f79041304df68d3942

Comment by Shraya Ramani [ 17/Nov/15 ]

failed again:
Task
Logs

Comment by Daniel Pasette (Inactive) [ 12/Nov/15 ]

Looks like this has been failing intermittently for around a week.

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