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

Scary-looking message about removed setParameter showing up in test logs

    • Type: Icon: Improvement Improvement
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Replication
    • None
    • Replication
    • 11

      Every test that uses a ReplSetTest is now logging a command failure message during test cleanup (example included below) about the removed 'waitForStepDownOnNonCommandShutdown' setParameter.  This has started becoming a red herring in build failure diagnosis, causing people to lose time investigating this even though it is expected.  It would be nice if we could prevent those messages from showing up in logs given that the failure is expected due to SERVER-47797.

       

      Example logs:

      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.007+0100 ReplSetTest stopSet disabling 'waitForStepDownOnNonCommandShutdown' on EC2AMAZ-DL1PJ4J:21770
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.008+0100 assert: command failed: {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.008+0100 	"ok" : 0,
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	"errmsg" : "attempted to set unrecognized parameter [waitForStepDownOnNonCommandShutdown], use help:true to see options ",
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	"$gleStats" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		"lastOpTime" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 			"ts" : Timestamp(1588916704, 15),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 			"t" : NumberLong(1)
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		},
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		"electionId" : ObjectId("7fffffff0000000000000001")
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	},
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	"lastCommittedOpTime" : Timestamp(1588916714, 12),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	"$configServerState" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		"opTime" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 			"ts" : Timestamp(1588916716, 1),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 			"t" : NumberLong(1)
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		}
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	},
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	"$clusterTime" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		"clusterTime" : Timestamp(1588916716, 1),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		"signature" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 			"hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 			"keyId" : NumberLong(0)
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 		}
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	},
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 	"operationTime" : Timestamp(1588916714, 12)
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.009+0100 }
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 _getErrorWithCode@src/mongo/shell/utils.js:25:13
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 doassert@src/mongo/shell/assert.js:18:14
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 _assertCommandWorked@src/mongo/shell/assert.js:663:17
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 assert.commandWorked@src/mongo/shell/assert.js:755:16
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 ReplSetTest/this.stopSet/<@src/mongo/shell/replsettest.js:3023:25
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 asCluster@src/mongo/shell/replsettest.js:173:20
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 ReplSetTest/this.stopSet@src/mongo/shell/replsettest.js:3017:13
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 ShardingTest/this.stop@src/mongo/shell/shardingtest.js:407:17
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 @jstests\sharding\single_shard_transaction_without_majority_reads_lagged.js:89:1
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 @jstests\sharding\single_shard_transaction_without_majority_reads_lagged.js:16:2
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 ReplSetTest stopSet disabling 'waitForStepDownOnNonCommandShutdown' on EC2AMAZ-DL1PJ4J:21771
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 assert: command failed: {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	"ok" : 0,
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	"errmsg" : "attempted to set unrecognized parameter [waitForStepDownOnNonCommandShutdown], use help:true to see options ",
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	"$gleStats" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 		"lastOpTime" : Timestamp(0, 0),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 		"electionId" : ObjectId("000000000000000000000000")
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	},
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	"lastCommittedOpTime" : Timestamp(1588916714, 12),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	"$configServerState" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 		"opTime" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 			"ts" : Timestamp(1588916703, 7),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 			"t" : NumberLong(1)
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 		}
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	},
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 	"$clusterTime" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.010+0100 		"clusterTime" : Timestamp(1588916714, 12),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 		"signature" : {
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 			"hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 			"keyId" : NumberLong(0)
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 		}
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 	},
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 	"operationTime" : Timestamp(1588916714, 12)
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 }
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 _getErrorWithCode@src/mongo/shell/utils.js:25:13
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 doassert@src/mongo/shell/assert.js:18:14
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 _assertCommandWorked@src/mongo/shell/assert.js:663:17
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 assert.commandWorked@src/mongo/shell/assert.js:755:16
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 ReplSetTest/this.stopSet/<@src/mongo/shell/replsettest.js:3023:25
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 asCluster@src/mongo/shell/replsettest.js:173:20
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 ReplSetTest/this.stopSet@src/mongo/shell/replsettest.js:3017:13
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 ShardingTest/this.stop@src/mongo/shell/shardingtest.js:407:17
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 @jstests\sharding\single_shard_transaction_without_majority_reads_lagged.js:89:1
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 @jstests\sharding\single_shard_transaction_without_majority_reads_lagged.js:16:2
      [js_test:single_shard_transaction_without_majority_reads_lagged] 2020-05-08T06:45:17.011+0100 ReplSetTest stopSet validating all replica set nodes before stopping them.
      

            Assignee:
            backlog-server-repl [DO NOT USE] Backlog - Replication Team
            Reporter:
            spencer@mongodb.com Spencer Brody (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: