Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

sql: nightly benchmark broken #8081

Closed
jordanlewis opened this issue Jul 27, 2016 · 16 comments
Closed

sql: nightly benchmark broken #8081

jordanlewis opened this issue Jul 27, 2016 · 16 comments

Comments

@jordanlewis
Copy link
Member

jordanlewis commented Jul 27, 2016 •
edited by tamird
Loading

The nightly benchmark seems to have stalled during the sql.test portion. The sql.test.stderr log is growing forever with the following log lines:

I160727 10:14:34.148590 server/status/runtime.go:189  runtime stats: 1.5 GiB RSS, 92 goroutines, 20 MiB/1.1 GiB/1.2 GiB GO alloc/idle/total, 81 MiB/147 MiB CGO alloc/total, 205.60c
go/sec, 0.03/0.01 %(u/s)time, 0.00 %gc (1x)
W160727 10:14:34.158639 ts/db.go:104  node unavailable; try another peer
W160727 10:14:34.158665 server/node.go:642  error recording status summaries: node unavailable; try another peer
W160727 10:14:42.055111 gossip/gossip.go:942  not connected to cluster; use --join to specify a connected node
I160727 10:14:44.028505 server/status/runtime.go:189  runtime stats: 1.5 GiB RSS, 94 goroutines, 21 MiB/1.1 GiB/1.2 GiB GO alloc/idle/total, 81 MiB/147 MiB CGO alloc/total, 215.81c
go/sec, 0.02/0.01 %(u/s)time, 0.00 %gc (0x)

The test invocation on TeamCity is here: https://teamcity.cockroachdb.com/viewLog.html?buildId=5068&buildTypeId=Cockroach_BenchmarkTests&tab=buildLog
he nightly benchmark seems to have stalled during the sql.test portion. The sql.test.stderr log is growing forever with the following log lines:

I160727 10:14:34.148590 server/status/runtime.go:189  runtime stats: 1.5 GiB RSS, 92 goroutines, 20 MiB/1.1 GiB/1.2 GiB GO alloc/idle/total, 81 MiB/147 MiB CGO alloc/total, 205.60c
go/sec, 0.03/0.01 %(u/s)time, 0.00 %gc (1x)
W160727 10:14:34.158639 ts/db.go:104  node unavailable; try another peer
W160727 10:14:34.158665 server/node.go:642  error recording status summaries: node unavailable; try another peer
W160727 10:14:42.055111 gossip/gossip.go:942  not connected to cluster; use --join to specify a connected node
I160727 10:14:44.028505 server/status/runtime.go:189  runtime stats: 1.5 GiB RSS, 94 goroutines, 21 MiB/1.1 GiB/1.2 GiB GO alloc/idle/total, 81 MiB/147 MiB CGO alloc/total, 215.81c
go/sec, 0.02/0.01 %(u/s)time, 0.00 %gc (0x)

The test invocation on TeamCity is here: https://teamcity.cockroachdb.com/viewLog.html?buildId=5068&buildTypeId=Cockroach_BenchmarkTests&tab=buildLog

UPDATE: current issue is that sql.BenchmarkPgbenchExec_{Cockroach,Postgres} fail in the absence of pgbench, which we do not install anywhere.
@jordanlewis
Copy link
Member Author

I stopped the build but left the instance running in case someone wants to do forensics.

https://console.cloud.google.com/compute/instancesDetail/zones/us-east1-b/instances/benchmark-static-tests-0?project=cockroach-shared&graph=GCE_CPU&duration=P4D

@cuongdo
Copy link
Contributor

cuongdo commented Jul 28, 2016

Seems like an issue shutting down the server after a test. Not much else to go on.

@jordanlewis
Copy link
Member Author

@WillHaack seems to have more details on this. Could you chime in?

@WillHaack
Copy link
Contributor

I believe @cuongdo is correct. Some tests may timeout, and when they do I'm not sure they close down the servers properly so the subsequent tests may have trouble binding to ports. (Also, I'm not even sure that they close their connections properly when they successfully run.) I'll try to work on fixing this today. If all else fails it may be worth making it so that multinode tests only run with the -multinode flag until further notice. (IMO it's not a big deal to keep multinode tests that are failing, but it is a big deal if they are causing other tests to fail.)

@WillHaack
Copy link
Contributor

#8075 likely fixed the issue. The benchmark tests have been running for 7+ hours now. They were failing consistently in about 2.5hrs before.

@jordanlewis
Copy link
Member Author

@WillHaack I think they're broken in a different way now. Can you please investigate? They've now been running for 30 hours -- seems like they might have stalled again. https://teamcity.cockroachdb.com/viewLog.html?buildId=7571&tab=buildResultsDiv&buildTypeId=Cockroach_BenchmarkTests

@tamird tamird mentioned this issue Aug 8, 2016
Merged
@tamird tamird reopened this Aug 9, 2016
@tamird tamird mentioned this issue Sep 29, 2016
Closed
@tamird tamird mentioned this issue Oct 25, 2016
Closed
@tbg tbg mentioned this issue Oct 26, 2016
Merged
@tbg
Copy link
Member

tbg commented Oct 27, 2016

Do they now pass, with #10237 in?

@tamird
Copy link
Contributor

tamird commented Oct 27, 2016

Looks like they are broken by the move to azure builders? Tonight's run failed with "terraform is not in your path": https://teamcity.cockroachdb.com/viewLog.html?tab=buildLog&logTab=tree&filter=debug&expand=all&buildId=37243#_focus=724

Probably we should run this orchestration from inside the builder container instead of adding terraform to the TC builders. cc @jordanlewis

@jordanlewis
Copy link
Member Author

The benchmark tests still fail. It seems that a bunch of tests fail that require Postgres to be installed. Did we used to ignore these somehow? The move to Azure didn't affect what is installed and running on the benchmark machines.

@tamird tamird mentioned this issue Nov 1, 2016
Merged
@tamird tamird changed the title benchmark: nightly benchmark stalled sql: nightly benchmark broken Nov 2, 2016
@tamird tamird assigned dt Nov 2, 2016
@tamird
Copy link
Contributor

tamird commented Nov 2, 2016 •
edited
Loading

Current issue is that sql.BenchmarkPgbenchExec_{Cockroach,Postgres} fail in the absence of pgbench, which we do not install anywhere. Updated the description and assigned @dt.

@dt dt mentioned this issue Nov 7, 2016
Merged
dt added a commit to dt/cockroach that referenced this issue Nov 7, 2016
@dt
sql: skip pgbench if not on PATH
e871713 
Currently blocking cockroachdb#8081
@jordanlewis
Copy link
Member Author

The Pgbench tests now do not fail - thanks @dt. The last remaining failures are runs of BenchmarkInsertDistinct100Multinode_Cockroach. The logs don't have anything particularly useful, but here they are for completeness:

BenchmarkInsertDistinct100Multinode_Cockroach-16                --- FAIL: BenchmarkInsertDistinct100Multinode_Cockroach-16
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
BenchmarkInsertDistinct100Multinode_Cockroach-16                --- FAIL: BenchmarkInsertDistinct100Multinode_Cockroach-16
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
BenchmarkInsertDistinct100Multinode_Cockroach-16                    1000       1026240 ns/op      877898 B/op       4798 allocs/op
BenchmarkInsertDistinct100Multinode_Cockroach-16                --- FAIL: BenchmarkInsertDistinct100Multinode_Cockroach-16
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
BenchmarkInsertDistinct100Multinode_Cockroach-16                    2000        992051 ns/op      811930 B/op       4099 allocs/op
BenchmarkInsertDistinct100Multinode_Cockroach-16                --- FAIL: BenchmarkInsertDistinct100Multinode_Cockroach-16
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
BenchmarkInsertDistinct100Multinode_Cockroach-16                     100      46957150 ns/op     2767293 B/op      23394 allocs/op
BenchmarkInsertDistinct100Multinode_Cockroach-16                    2000       1023041 ns/op      821077 B/op       4196 allocs/op
BenchmarkInsertDistinct100Multinode_Cockroach-16                --- FAIL: BenchmarkInsertDistinct100Multinode_Cockroach-16
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn
    bench_test.go:1221: pq: replay txn

@jordanlewis
Copy link
Member Author

I spoke too soon: in the stderr log, we have the following exciting panic:

panic: nil clock is forbidden

goroutine 1619880 [running]:
panic(0x1745440, 0xc427428630)
    /usr/local/go/src/runtime/panic.go:500 +0x1a1
github.com/cockroachdb/cockroach/pkg/rpc.NewContext(0x0, 0x0, 0x0, 0x0, 0xc42dbae280, 0x0, 0xc42f988000, 0x0)
    /go/src/github.com/cockroachdb/cockroach/pkg/rpc/context.go:118 +0x962
github.com/cockroachdb/cockroach/pkg/sql_test.newKVNative(0xc42fafe280, 0x6, 0x19154b9)
    /go/src/github.com/cockroachdb/cockroach/pkg/sql/kv_test.go:69 +0x31f
github.com/cockroachdb/cockroach/pkg/sql_test.runKVBenchmark(0xc42fafe280, 0x19154b9, 0x6, 0x1915d5f, 0x6, 0x1)
    /go/src/github.com/cockroachdb/cockroach/pkg/sql/kv_test.go:289 +0x717
github.com/cockroachdb/cockroach/pkg/sql_test.BenchmarkKVInsert1_Native(0xc42fafe280)
    /go/src/github.com/cockroachdb/cockroach/pkg/sql/kv_test.go:322 +0x5e
testing.(*B).runN(0xc42fafe280, 0x1)
    /usr/local/go/src/testing/benchmark.go:139 +0xaa
testing.(*B).run1.func1(0xc42fafe280)
    /usr/local/go/src/testing/benchmark.go:208 +0x5a
created by testing.(*B).run1
    /usr/local/go/src/testing/benchmark.go:209 +0x7f

@jordanlewis jordanlewis mentioned this issue Nov 7, 2016
Merged
jordanlewis added a commit to jordanlewis/cockroach that referenced this issue Nov 8, 2016
@jordanlewis
sql: don't pass a nil clock in kv_test
e955b27 
The Benchmark tests panic due to `kv_test` passing a `nil` clock to
`rpc.NewContext`. Fix this. See cockroachdb#8081
@jordanlewis
Copy link
Member Author

Okay, the nil clock panic is fixed but the above failures remain.

@jordanlewis
Copy link
Member Author

Tracking the above failures in #10551.

@jordanlewis
Copy link
Member Author

After ignoring the problems in #10551, a new set of problems turned up. The sql benchmarks now pass, but the storage benchmarks seem to hang indefinitely on the very first iteration of BenchmarkReplicaSnapshot-16. stderr is pretty sparse:

I161110 01:45:45.896322 1 rand.go:76  Random seed: -8566366354663296610
I161110 01:45:45.901316 44 gossip/gossip.go:237  [n?] initial resolvers: []
W161110 01:45:45.901389 44 gossip/gossip.go:1055  [n?] no resolvers found; use --join to specify a connected node
I161110 01:45:45.901466 44 base/node_id.go:62  NodeID set to 1
I161110 01:45:45.901753 44 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161110 01:45:45.924072 51 storage/replica_proposal.go:328  [s1,r1/1:/M{in-ax}] new range lease replica {1 1 1} 197
0-01-01 00:00:00 +0000 UTC 410761h45m46.820924177s following replica {0 0 0} 1970-01-01 00:00:00 +0000 UTC 0s [phys
icalTime=2016-11-10 01:45:45.923900995 +0000 UTC]
I161110 01:46:02.682472 44 storage/replica_raftstorage.go:445  [s1,r1/1:/M{in-ax}] generated snapshot ffacc4de at i
ndex 58289 in 209.989µs.
I161110 01:46:02.682550 44 util/stop/stopper.go:396  stop has been called, stopping or quiescing all running tasks
I161110 01:46:02.687700 101 gossip/gossip.go:237  [n?] initial resolvers: []
W161110 01:46:02.687724 101 gossip/gossip.go:1055  [n?] no resolvers found; use --join to specify a connected node
I161110 01:46:02.687763 101 base/node_id.go:62  NodeID set to 1
I161110 01:46:02.687814 101 storage/engine/rocksdb.go:340  opening in memory rocksdb instance
I161110 01:46:02.690377 110 storage/replica_proposal.go:328  [s1,r1/1:/M{in-ax}] new range lease replica {1 1 1} 19
70-01-01 00:00:00 +0000 UTC 410761h46m3.589595495s following replica {0 0 0} 1970-01-01 00:00:00 +0000 UTC 0s [phys
icalTime=2016-11-10 01:46:02.690335401 +0000 UTC]
I161110 01:46:19.191801 101 storage/replica_raftstorage.go:445  [s1,r1/1:/M{in-ax}] generated snapshot 43717985 at 
index 58288 in 143.803µs.
E161110 01:56:02.691713 189 storage/queue.go:579  [replicate,s1,r1/1:/M{in-ax}] purgatory: 0 of 0 stores with an at
tribute matching []; likely not enough nodes in cluster
E161110 02:06:02.692100 349 storage/queue.go:646  [replicate] 1 replicas failing with "0 of 0 stores with an attrib
ute matching []; likely not enough nodes in cluster"
E161110 02:16:02.692040 349 storage/queue.go:646  [replicate] 1 replicas failing with "0 of 0 stores with an attrib
ute matching []; likely not enough nodes in cluster"
E161110 02:26:02.692106 349 storage/queue.go:646  [replicate] 1 replicas failing with "0 of 0 stores with an attrib
ute matching []; likely not enough nodes in cluster"

These errors repeat every ten minutes.

@tamird tamird mentioned this issue Nov 10, 2016
Merged
@jordanlewis
Copy link
Member Author

The nightly benchmarks pass most of the time now. Closing this in favor of more targeted issues for occasional failures.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@dt @jordanlewis @WillHaack @tamird @cuongdo @tbg