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

jstests/replsets/sync_passive2.js failing

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Closed
    • Major - P3
    • Resolution: Fixed
    • None
    • 2.3.2
    • Testing Infrastructure
    • Failures seen on Solaris build slave and Windows 64-bit.
    • ALL

    Description

      http://buildlogs.mongodb.org/Solaris-SmartOS%2064-bit/builds/759/test/recent%20failures/sync_passive2.js

      ReplSetTest await TS for connection to bs-smartos-x86-64-1.10gen.cc:31004 is 1356198556000:1 and latest is 1356198556000:1
      ReplSetTest await oplog size for connection to bs-smartos-x86-64-1.10gen.cc:31004 is 20002
      ReplSetTest await synced=true
      force 2 to sync from 3
       m31002| Sat Dec 22 17:49:56.892 [conn2] attempting to sync from bs-smartos-x86-64-1.10gen.cc:31003, but its latest opTime is 1356198504 and ours is 1356198556 so this may not work
       m31000| Sat Dec 22 17:49:57.073 [conn23] end connection 165.225.128.186:64842 (10 connections now open)
       m31002| Sat Dec 22 17:49:57.073 [rsBackgroundSync] replSet syncing to: bs-smartos-x86-64-1.10gen.cc:31003 by request
       m31003| Sat Dec 22 17:49:57.073 [initandlisten] connection accepted from 165.225.128.186:54430 #19 (6 connections now open)
       m31002| Sat Dec 22 17:49:57.074 [rsBackgroundSync] replSet syncing to: bs-smartos-x86-64-1.10gen.cc:31000
       m31003| Sat Dec 22 17:49:57.074 [conn19] end connection 165.225.128.186:54430 (5 connections now open)
       m31000| Sat Dec 22 17:49:57.074 [initandlisten] connection accepted from 165.225.128.186:47032 #30 (11 connections now open)
      {
      	"set" : "sync_passive2",
      	"date" : ISODate("2012-12-22T17:49:57Z"),
      	"myState" : 2,
      	"syncingTo" : "bs-smartos-x86-64-1.10gen.cc:31000",
      	"members" : [
      		{
      			"_id" : 0,
      			"name" : "bs-smartos-x86-64-1.10gen.cc:31000",
      			"health" : 1,
      			"state" : 1,
      			"stateStr" : "PRIMARY",
      			"uptime" : 40,
      			"optime" : {
      				"t" : 1356198556000,
      				"i" : 1
      			},
      			"optimeDate" : ISODate("2012-12-22T17:49:16Z"),
      			"lastHeartbeat" : ISODate("2012-12-22T17:49:55Z"),
      			"lastHeartbeatRecv" : ISODate("2012-12-22T17:49:56Z"),
      			"pingMs" : 0
      		},
      		{
      			"_id" : 1,
      			"name" : "bs-smartos-x86-64-1.10gen.cc:31001",
      			"health" : 1,
      			"state" : 7,
      			"stateStr" : "ARBITER",
      			"uptime" : 40,
      			"lastHeartbeat" : ISODate("2012-12-22T17:49:55Z"),
      			"lastHeartbeatRecv" : ISODate("2012-12-22T17:49:56Z"),
      			"pingMs" : 0
      		},
      		{
      			"_id" : 2,
      			"name" : "bs-smartos-x86-64-1.10gen.cc:31002",
      			"health" : 1,
      			"state" : 2,
      			"stateStr" : "SECONDARY",
      			"uptime" : 74,
      			"optime" : {
      				"t" : 1356198556000,
      				"i" : 1
      			},
      			"optimeDate" : ISODate("2012-12-22T17:49:16Z"),
      			"errmsg" : "syncing to: bs-smartos-x86-64-1.10gen.cc:31000",
      			"self" : true
      		},
      		{
      			"_id" : 3,
      			"name" : "bs-smartos-x86-64-1.10gen.cc:31003",
      			"health" : 1,
      			"state" : 2,
      			"stateStr" : "SECONDARY",
      			"uptime" : 40,
      			"optime" : {
      				"t" : 1356198504000,
      				"i" : 4242
      			},
      			"optimeDate" : ISODate("2012-12-22T17:48:24Z"),
      			"lastHeartbeat" : ISODate("2012-12-22T17:49:55Z"),
      			"lastHeartbeatRecv" : ISODate("2012-12-22T17:49:57Z"),
      			"pingMs" : 0,
      			"lastHeartbeatMessage" : "syncing to: bs-smartos-x86-64-1.10gen.cc:31000"
      		},
      		{
      			"_id" : 4,
      			"name" : "bs-smartos-x86-64-1.10gen.cc:31004",
      			"health" : 1,
      			"state" : 2,
      			"stateStr" : "SECONDARY",
      			"uptime" : 40,
      			"optime" : {
      				"t" : 1356198556000,
      				"i" : 1
      			},
      			"optimeDate" : ISODate("2012-12-22T17:49:16Z"),
      			"lastHeartbeat" : ISODate("2012-12-22T17:49:55Z"),
      			"lastHeartbeatRecv" : ISODate("2012-12-22T17:49:56Z"),
      			"pingMs" : 0,
      			"lastHeartbeatMessage" : "syncing to: bs-smartos-x86-64-1.10gen.cc:31000"
      		}
      	],
      	"ok" : 1
      }

      This test has problems at this stage. It expects to be able to see that it has successfully changed the "sync to" setting for a node and expects to see it be automatically changed to a non-slave-delayed node "within ~30 seconds". In this failure, the setting was successfully changed and was automatically reset 1 millisecond later:

       m31002| Sat Dec 22 17:49:56.892 [conn2] attempting to sync from bs-smartos-x86-64-1.10gen.cc:31003, but its latest opTime is 1356198504 and ours is 1356198556 so this may not work
       m31000| Sat Dec 22 17:49:57.073 [conn23] end connection 165.225.128.186:64842 (10 connections now open)
       m31002| Sat Dec 22 17:49:57.073 [rsBackgroundSync] replSet syncing to: bs-smartos-x86-64-1.10gen.cc:31003 by request
       m31003| Sat Dec 22 17:49:57.073 [initandlisten] connection accepted from 165.225.128.186:54430 #19 (6 connections now open)
       m31002| Sat Dec 22 17:49:57.074 [rsBackgroundSync] replSet syncing to: bs-smartos-x86-64-1.10gen.cc:31000

      This very fast reset doesn't give the script any time to see that its setting did, in fact, work.

      Attachments

        Activity

          People

            kristina Kristina Chodorow (Inactive)
            tad Tad Marshall
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: