roachtest: kv/splits/nodes=3/quiesce=true failed

[cockroach-teamcity]

(roachtest).kv/splits/nodes=3/quiesce=true failed on master@3a03f3843a8cdf04f82c52753c61cf01b0d2ddcd:

		  | stdout:
		Wraps: (5) secondary error attachment
		  | signal: killed
		  | (1) signal: killed
		  | Error types: (1) *exec.ExitError
		Wraps: (6) context canceled
		Error types: (1) *withstack.withStack (2) *safedetails.withSafeDetails (3) *errutil.withMessage (4) *main.withCommandDetails (5) *secondary.withSecondaryError (6) *errors.errorString

	cluster.go:2467,kv.go:509,test_runner.go:757: monitor failure: unexpected node event: 3: dead
		(1) attached stack trace
		  | main.(*monitor).WaitE
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2455
		  | main.(*monitor).Wait
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2463
		  | main.registerKVSplits.func1
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/kv.go:509
		  | main.(*testRunner).runTest.func2
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/test_runner.go:757
		  | runtime.goexit
		  | 	/usr/local/go/src/runtime/asm_amd64.s:1373
		Wraps: (2) monitor failure
		Wraps: (3) unexpected node event: 3: dead
		Error types: (1) *withstack.withStack (2) *errutil.withMessage (3) *errors.errorString

	cluster.go:1512,context.go:135,cluster.go:1501,test_runner.go:829: dead node detection: /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod monitor teamcity-2054002-1593584816-12-n4cpu4 --oneshot --ignore-empty-nodes: exit status 1 4: skipped
		3: dead
		1: 8179
		2: 4080
		Error: UNCLASSIFIED_PROBLEM: 3: dead
		(1) UNCLASSIFIED_PROBLEM
		Wraps: (2) attached stack trace
		  | main.glob..func13
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachprod/main.go:1115
		  | main.wrap.func1
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachprod/main.go:266
		  | github.com/spf13/cobra.(*Command).execute
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/vendor/github.com/spf13/cobra/command.go:830
		  | github.com/spf13/cobra.(*Command).ExecuteC
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/vendor/github.com/spf13/cobra/command.go:914
		  | github.com/spf13/cobra.(*Command).Execute
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/vendor/github.com/spf13/cobra/command.go:864
		  | main.main
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachprod/main.go:1789
		  | runtime.main
		  | 	/usr/local/go/src/runtime/proc.go:203
		  | runtime.goexit
		  | 	/usr/local/go/src/runtime/asm_amd64.s:1373
		Wraps: (3) 3 safe details enclosed
		Wraps: (4) 3: dead
		Error types: (1) errors.Unclassified (2) *withstack.withStack (3) *safedetails.withSafeDetails (4) *errors.errorString

More

Artifacts: /kv/splits/nodes=3/quiesce=true

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

[cockroach-teamcity]

(roachtest).kv/splits/nodes=3/quiesce=true failed on master@456a07cfc1e53b87abc7709052e54efb1450e758:

		Wraps: (2) 2 safe details enclosed
		Wraps: (3) output in run_061912.164_n4_workload_run_kv
		Wraps: (4) /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod run teamcity-2062841-1593843322-06-n4cpu4:4 -- ./workload run kv --init --max-ops=1 --concurrency=192 --splits=300000 {pgurl:1-3} returned
		  | stderr:
		  | its
		  | I200704 06:50:05.587054 447 workload/workloadsql/workloadsql.go:179  finished 237000 of 300000 splits
		  | I200704 06:50:13.536008 447 workload/workloadsql/workloadsql.go:179  finished 238000 of 300000 splits
		  | I200704 06:50:21.599674 447 workload/workloadsql/workloadsql.go:179  finished 239000 of 300000 splits
		  | I200704 06:50:29.191523 447 workload/workloadsql/workloadsql.go:179  finished 240000 of 300000 splits
		  | I200704 06:50:36.849041 447 workload/workloadsql/workloadsql.go:179  finished 241000 of 300000 splits
		  | I200704 06:50:44.665702 447 workload/workloadsql/workloadsql.go:179  finished 242000 of 300000 splits
		  | I200704 06:50:52.591682 447 workload/workloadsql/workloadsql.go:179  finished 243000 of 300000 splits
		  | I200704 06:51:00.327842 447 workload/workloadsql/workloadsql.go:179  finished 244000 of 300000 splits
		  | I200704 06:51:08.245947 447 workload/workloadsql/workloadsql.go:179  finished 245000 of 300000 splits
		  | I200704 06:53:12.409550 447 workload/workloadsql/workloadsql.go:179  finished 246000 of 300000 splits
		  |
		  | stdout:
		Wraps: (5) secondary error attachment
		  | signal: killed
		  | (1) signal: killed
		  | Error types: (1) *exec.ExitError
		Wraps: (6) context canceled
		Error types: (1) *withstack.withStack (2) *safedetails.withSafeDetails (3) *errutil.withMessage (4) *main.withCommandDetails (5) *secondary.withSecondaryError (6) *errors.errorString

	cluster.go:2467,kv.go:509,test_runner.go:757: monitor failure: monitor task failed: t.Fatal() was called
		(1) attached stack trace
		  | main.(*monitor).WaitE
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2455
		  | main.(*monitor).Wait
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2463
		  | main.registerKVSplits.func1
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/kv.go:509
		  | main.(*testRunner).runTest.func2
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/test_runner.go:757
		Wraps: (2) monitor failure
		Wraps: (3) attached stack trace
		  | main.(*monitor).wait.func2
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2511
		Wraps: (4) monitor task failed
		Wraps: (5) attached stack trace
		  | main.init
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2425
		  | runtime.doInit
		  | 	/usr/local/go/src/runtime/proc.go:5420
		  | runtime.main
		  | 	/usr/local/go/src/runtime/proc.go:190
		  | runtime.goexit
		  | 	/usr/local/go/src/runtime/asm_amd64.s:1373
		Wraps: (6) t.Fatal() was called
		Error types: (1) *withstack.withStack (2) *errutil.withMessage (3) *withstack.withStack (4) *errutil.withMessage (5) *withstack.withStack (6) *errors.errorString

More

Artifacts: /kv/splits/nodes=3/quiesce=true

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

[cockroach-teamcity]

(roachtest).kv/splits/nodes=3/quiesce=true failed on master@3e0de239121813ea4d47873388a2828a66d9edf7:

		Wraps: (2) 2 safe details enclosed
		Wraps: (3) output in run_061501.000_n4_workload_run_kv
		Wraps: (4) /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod run teamcity-2063962-1593929497-01-n4cpu4:4 -- ./workload run kv --init --max-ops=1 --concurrency=192 --splits=300000 {pgurl:1-3} returned
		  | stderr:
		  | its
		  | I200705 06:43:57.980681 428 workload/workloadsql/workloadsql.go:179  finished 222000 of 300000 splits
		  | I200705 06:44:05.312350 428 workload/workloadsql/workloadsql.go:179  finished 223000 of 300000 splits
		  | I200705 06:44:13.037830 428 workload/workloadsql/workloadsql.go:179  finished 224000 of 300000 splits
		  | I200705 06:44:20.858298 428 workload/workloadsql/workloadsql.go:179  finished 225000 of 300000 splits
		  | I200705 06:44:28.692055 428 workload/workloadsql/workloadsql.go:179  finished 226000 of 300000 splits
		  | I200705 06:44:36.488287 428 workload/workloadsql/workloadsql.go:179  finished 227000 of 300000 splits
		  | I200705 06:44:44.289766 428 workload/workloadsql/workloadsql.go:179  finished 228000 of 300000 splits
		  | I200705 06:44:53.307467 428 workload/workloadsql/workloadsql.go:179  finished 229000 of 300000 splits
		  | I200705 06:45:49.782232 428 workload/workloadsql/workloadsql.go:179  finished 230000 of 300000 splits
		  | I200705 06:47:22.317866 428 workload/workloadsql/workloadsql.go:179  finished 231000 of 300000 splits
		  |
		  | stdout:
		Wraps: (5) secondary error attachment
		  | signal: killed
		  | (1) signal: killed
		  | Error types: (1) *exec.ExitError
		Wraps: (6) context canceled
		Error types: (1) *withstack.withStack (2) *safedetails.withSafeDetails (3) *errutil.withMessage (4) *main.withCommandDetails (5) *secondary.withSecondaryError (6) *errors.errorString

	cluster.go:2467,kv.go:509,test_runner.go:757: monitor failure: monitor task failed: t.Fatal() was called
		(1) attached stack trace
		  | main.(*monitor).WaitE
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2455
		  | main.(*monitor).Wait
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2463
		  | main.registerKVSplits.func1
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/kv.go:509
		  | main.(*testRunner).runTest.func2
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/test_runner.go:757
		Wraps: (2) monitor failure
		Wraps: (3) attached stack trace
		  | main.(*monitor).wait.func2
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2511
		Wraps: (4) monitor task failed
		Wraps: (5) attached stack trace
		  | main.init
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2425
		  | runtime.doInit
		  | 	/usr/local/go/src/runtime/proc.go:5420
		  | runtime.main
		  | 	/usr/local/go/src/runtime/proc.go:190
		  | runtime.goexit
		  | 	/usr/local/go/src/runtime/asm_amd64.s:1373
		Wraps: (6) t.Fatal() was called
		Error types: (1) *withstack.withStack (2) *errutil.withMessage (3) *withstack.withStack (4) *errutil.withMessage (5) *withstack.withStack (6) *errors.errorString

More

Artifacts: /kv/splits/nodes=3/quiesce=true

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

[cockroach-teamcity]

(roachtest).kv/splits/nodes=3/quiesce=true failed on master@9304ecd70e9f3ba4cb16b5443a10b4e17d7baee0:

		Wraps: (2) 2 safe details enclosed
		Wraps: (3) output in run_063609.865_n4_workload_run_kv
		Wraps: (4) /home/agent/work/.go/src/github.com/cockroachdb/cockroach/bin/roachprod run teamcity-2068260-1594103442-13-n4cpu4:4 -- ./workload run kv --init --max-ops=1 --concurrency=192 --splits=300000 {pgurl:1-3} returned
		  | stderr:
		  | its
		  | I200707 07:06:47.723557 425 workload/workloadsql/workloadsql.go:179  finished 235000 of 300000 splits
		  | I200707 07:06:55.522341 425 workload/workloadsql/workloadsql.go:179  finished 236000 of 300000 splits
		  | I200707 07:07:03.340287 425 workload/workloadsql/workloadsql.go:179  finished 237000 of 300000 splits
		  | I200707 07:07:12.014602 425 workload/workloadsql/workloadsql.go:179  finished 238000 of 300000 splits
		  | I200707 07:08:48.725441 425 workload/workloadsql/workloadsql.go:179  finished 239000 of 300000 splits
		  | I200707 07:22:35.315583 425 workload/workloadsql/workloadsql.go:179  finished 240000 of 300000 splits
		  | I200707 07:32:02.934803 425 workload/workloadsql/workloadsql.go:179  finished 241000 of 300000 splits
		  | I200707 07:56:15.703004 425 workload/workloadsql/workloadsql.go:179  finished 242000 of 300000 splits
		  | I200707 08:13:35.188865 425 workload/workloadsql/workloadsql.go:179  finished 243000 of 300000 splits
		  | I200707 08:18:41.208324 425 workload/workloadsql/workloadsql.go:179  finished 244000 of 300000 splits
		  |
		  | stdout:
		Wraps: (5) secondary error attachment
		  | signal: killed
		  | (1) signal: killed
		  | Error types: (1) *exec.ExitError
		Wraps: (6) context canceled
		Error types: (1) *withstack.withStack (2) *safedetails.withSafeDetails (3) *errutil.withMessage (4) *main.withCommandDetails (5) *secondary.withSecondaryError (6) *errors.errorString

	cluster.go:2471,kv.go:509,test_runner.go:757: monitor failure: monitor task failed: t.Fatal() was called
		(1) attached stack trace
		  | main.(*monitor).WaitE
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2459
		  | main.(*monitor).Wait
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2467
		  | main.registerKVSplits.func1
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/kv.go:509
		  | main.(*testRunner).runTest.func2
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/test_runner.go:757
		Wraps: (2) monitor failure
		Wraps: (3) attached stack trace
		  | main.(*monitor).wait.func2
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2515
		Wraps: (4) monitor task failed
		Wraps: (5) attached stack trace
		  | main.init
		  | 	/home/agent/work/.go/src/github.com/cockroachdb/cockroach/pkg/cmd/roachtest/cluster.go:2429
		  | runtime.doInit
		  | 	/usr/local/go/src/runtime/proc.go:5420
		  | runtime.main
		  | 	/usr/local/go/src/runtime/proc.go:190
		  | runtime.goexit
		  | 	/usr/local/go/src/runtime/asm_amd64.s:1373
		Wraps: (6) t.Fatal() was called
		Error types: (1) *withstack.withStack (2) *errutil.withMessage (3) *withstack.withStack (4) *errutil.withMessage (5) *withstack.withStack (6) *errors.errorString

More

Artifacts: /kv/splits/nodes=3/quiesce=true

See this test on roachdash
_{powered by pkg/cmd/internal/issues}

[nvb]

The test is timing out. Splits appear to get slower and slower until they push the test to exceed its timeout.

From the test history, we see that it hasn't passed in any of the past 4 times it was run on master. The last passing run on master was on 17c8048. The first failing run was on 3a03f38.

@aayushshah15 do you mind taking a look at this and seeing whether you can reproduce on that second SHA? If so, this might be straightforward enough to bisect.