Running make with -j2 GOPATH set to /home/ubuntu/cockroach_work go test -tags ' make s390x_linux_gnu' -ldflags '-X github.com/cockroachdb/cockroach/pkg/build.typ=development -extldflags "" -X "github.com/cockroachdb/cockroach/pkg/build.tag=v2.1.6-dirty" -X "github.com/cockroachdb/cockroach/pkg/build.rev=f53d12936efd36ea51eab6f191725d1dca2ceff3" -X "github.com/cockroachdb/cockroach/pkg/build.cgoTargetTriple=s390x-linux-gnu" ' -run "." -timeout 8m ./pkg/ts -v === RUN TestStoreTimeSeries === RUN TestStoreTimeSeries/Row_Format I190430 07:56:40.403623 13 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.403878 13 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestStoreTimeSeries/Column_Format I190430 07:56:40.457997 83 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.458130 83 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestStoreTimeSeries (0.11s) --- PASS: TestStoreTimeSeries/Row_Format (0.05s) --- PASS: TestStoreTimeSeries/Column_Format (0.05s) === RUN TestPollSource === RUN TestPollSource/Row_Format I190430 07:56:40.513620 31 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.513739 31 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestPollSource/Column_Format I190430 07:56:40.565594 166 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.566110 166 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestPollSource (0.06s) --- PASS: TestPollSource/Row_Format (0.05s) --- PASS: TestPollSource/Column_Format (0.01s) === RUN TestDisableStorage === RUN TestDisableStorage/Row_Format I190430 07:56:40.573908 223 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.574046 223 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestDisableStorage/Column_Format I190430 07:56:40.627219 274 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.627366 274 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestDisableStorage (0.11s) --- PASS: TestDisableStorage/Row_Format (0.05s) --- PASS: TestDisableStorage/Column_Format (0.05s) === RUN TestPruneThreshold === RUN TestPruneThreshold/Row_Format I190430 07:56:40.683360 319 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.683682 319 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 I190430 07:56:40.683816 319 util/stop/stopper.go:537 quiescing; tasks left: 3 storage.Replica: acquiring lease to gossip 1 [async] storage.pendingLeaseRequest: requesting lease I190430 07:56:40.684009 319 util/stop/stopper.go:537 quiescing; tasks left: 3 storage.Replica: acquiring lease to gossip I190430 07:56:40.684086 319 util/stop/stopper.go:537 quiescing; tasks left: 2 storage.Replica: acquiring lease to gossip === RUN TestPruneThreshold/Column_Format I190430 07:56:40.688237 362 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.688321 362 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 I190430 07:56:40.688388 362 util/stop/stopper.go:537 quiescing; tasks left: 1 storage.Replica: acquiring lease to gossip 1 [async] storage.pendingLeaseRequest: requesting lease 1 [async] closedts-rangefeed-subscriber W190430 07:56:40.688547 389 storage/store.go:1654 [n1,s1,r1/1:/M{in-ax}] could not gossip node liveness: node unavailable; try another peer I190430 07:56:40.688617 362 util/stop/stopper.go:537 quiescing; tasks left: 1 storage.Replica: acquiring lease to gossip 1 [async] storage.pendingLeaseRequest: requesting lease W190430 07:56:40.688797 388 storage/store.go:1654 [n1,s1,r1/1:/M{in-ax}] could not gossip system config: node unavailable; try another peer W190430 07:56:40.688872 387 storage/store.go:1654 [n1,s1,r1/1:/M{in-ax}] could not gossip first range descriptor: [NotLeaseHolderError] r1: replica (n1,s1):1 not lease holder; lease holder unknown --- PASS: TestPruneThreshold (0.06s) --- PASS: TestPruneThreshold/Row_Format (0.00s) --- PASS: TestPruneThreshold/Column_Format (0.00s) === RUN TestMakeInternalData --- PASS: TestMakeInternalData (0.00s) === RUN TestTimeSeriesSpanIteratorMovement === RUN TestTimeSeriesSpanIteratorMovement/row_only === RUN TestTimeSeriesSpanIteratorMovement/columns_only === RUN TestTimeSeriesSpanIteratorMovement/mixed_rows_and_columns --- PASS: TestTimeSeriesSpanIteratorMovement (0.00s) --- PASS: TestTimeSeriesSpanIteratorMovement/row_only (0.00s) --- PASS: TestTimeSeriesSpanIteratorMovement/columns_only (0.00s) --- PASS: TestTimeSeriesSpanIteratorMovement/mixed_rows_and_columns (0.00s) === RUN TestTimeSeriesSpanIteratorValues === RUN TestTimeSeriesSpanIteratorValues/value === RUN TestTimeSeriesSpanIteratorValues/value#01 === RUN TestTimeSeriesSpanIteratorValues/value#02 === RUN TestTimeSeriesSpanIteratorValues/value#03 --- PASS: TestTimeSeriesSpanIteratorValues (0.00s) --- PASS: TestTimeSeriesSpanIteratorValues/value (0.00s) --- PASS: TestTimeSeriesSpanIteratorValues/value#01 (0.00s) --- PASS: TestTimeSeriesSpanIteratorValues/value#02 (0.00s) --- PASS: TestTimeSeriesSpanIteratorValues/value#03 (0.00s) === RUN TestDownsampleSpans === RUN TestDownsampleSpans/0:Row === RUN TestDownsampleSpans/0:Column === RUN TestDownsampleSpans/0:Mixed === RUN TestDownsampleSpans/1:Row === RUN TestDownsampleSpans/1:Column === RUN TestDownsampleSpans/1:Mixed === RUN TestDownsampleSpans/2:Row === RUN TestDownsampleSpans/2:Column === RUN TestDownsampleSpans/2:Mixed === RUN TestDownsampleSpans/3:Row === RUN TestDownsampleSpans/3:Column === RUN TestDownsampleSpans/3:Mixed === RUN TestDownsampleSpans/4:Row === RUN TestDownsampleSpans/4:Column === RUN TestDownsampleSpans/4:Mixed === RUN TestDownsampleSpans/5:Row === RUN TestDownsampleSpans/5:Column === RUN TestDownsampleSpans/5:Mixed === RUN TestDownsampleSpans/6:Row === RUN TestDownsampleSpans/6:Column === RUN TestDownsampleSpans/6:Mixed === RUN TestDownsampleSpans/7:Row === RUN TestDownsampleSpans/7:Column === RUN TestDownsampleSpans/7:Mixed --- PASS: TestDownsampleSpans (0.00s) --- PASS: TestDownsampleSpans/0:Row (0.00s) --- PASS: TestDownsampleSpans/0:Column (0.00s) --- PASS: TestDownsampleSpans/0:Mixed (0.00s) --- PASS: TestDownsampleSpans/1:Row (0.00s) --- PASS: TestDownsampleSpans/1:Column (0.00s) --- PASS: TestDownsampleSpans/1:Mixed (0.00s) --- PASS: TestDownsampleSpans/2:Row (0.00s) --- PASS: TestDownsampleSpans/2:Column (0.00s) --- PASS: TestDownsampleSpans/2:Mixed (0.00s) --- PASS: TestDownsampleSpans/3:Row (0.00s) --- PASS: TestDownsampleSpans/3:Column (0.00s) --- PASS: TestDownsampleSpans/3:Mixed (0.00s) --- PASS: TestDownsampleSpans/4:Row (0.00s) --- PASS: TestDownsampleSpans/4:Column (0.00s) --- PASS: TestDownsampleSpans/4:Mixed (0.00s) --- PASS: TestDownsampleSpans/5:Row (0.00s) --- PASS: TestDownsampleSpans/5:Column (0.00s) --- PASS: TestDownsampleSpans/5:Mixed (0.00s) --- PASS: TestDownsampleSpans/6:Row (0.00s) --- PASS: TestDownsampleSpans/6:Column (0.00s) --- PASS: TestDownsampleSpans/6:Mixed (0.00s) --- PASS: TestDownsampleSpans/7:Row (0.00s) --- PASS: TestDownsampleSpans/7:Column (0.00s) --- PASS: TestDownsampleSpans/7:Mixed (0.00s) === RUN TestDataKeys --- PASS: TestDataKeys (0.00s) === RUN TestGetMaxTimespan === RUN TestGetMaxTimespan/#00 === RUN TestGetMaxTimespan/#01 === RUN TestGetMaxTimespan/#02 === RUN TestGetMaxTimespan/#03 === RUN TestGetMaxTimespan/#04 === RUN TestGetMaxTimespan/#05 === RUN TestGetMaxTimespan/#06 === RUN TestGetMaxTimespan/#07 === RUN TestGetMaxTimespan/#08 === RUN TestGetMaxTimespan/#09 === RUN TestGetMaxTimespan/#10 --- PASS: TestGetMaxTimespan (0.00s) --- PASS: TestGetMaxTimespan/#00 (0.00s) --- PASS: TestGetMaxTimespan/#01 (0.00s) --- PASS: TestGetMaxTimespan/#02 (0.00s) --- PASS: TestGetMaxTimespan/#03 (0.00s) --- PASS: TestGetMaxTimespan/#04 (0.00s) --- PASS: TestGetMaxTimespan/#05 (0.00s) --- PASS: TestGetMaxTimespan/#06 (0.00s) --- PASS: TestGetMaxTimespan/#07 (0.00s) --- PASS: TestGetMaxTimespan/#08 (0.00s) --- PASS: TestGetMaxTimespan/#09 (0.00s) --- PASS: TestGetMaxTimespan/#10 (0.00s) === RUN TestTimeSeriesWriteMetrics I190430 07:56:40.756729 456 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.756894 456 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestTimeSeriesWriteMetrics (0.06s) === RUN TestTimeSeriesModelTest I190430 07:56:40.816806 502 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:40.816921 502 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestTimeSeriesModelTest (3.51s) === RUN TestTimeSeriesRollupModelTest I190430 07:56:44.329576 548 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:44.330294 548 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- FAIL: TestTimeSeriesRollupModelTest (2.30s) model_test.go:249: ["\x04tsd\x12metric2\x00\x01\x8a\xf7D{source3"].RawBytes[80]: 52 != 53 model_test.go:249: ["\x04tsd\x12metric2\x00\x01\x8a\xf7D{source2"].RawBytes[80]: 203 != 204 model_test.go:249: ["\x04tsd\x12metric1\x00\x01\x8a\xf7D{source2"].RawBytes[80]: 246 != 244 model_test.go:249: ["\x04tsd\x12metric2\x00\x01\x8a\xf7D{source1"].RawBytes[80]: 44 != 43 model_test.go:249: ["\x04tsd\x12metric2\x00\x01\x8a\xf7D{source4"].RawBytes[80]: 85 != 88 === RUN TestContainsTimeSeries --- PASS: TestContainsTimeSeries (0.01s) === RUN TestFindTimeSeries I190430 07:56:46.645522 573 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.645610 573 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestFindTimeSeries (0.05s) === RUN TestPruneTimeSeries === RUN TestPruneTimeSeries/Row_Format I190430 07:56:46.701012 653 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.701140 653 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestPruneTimeSeries/Column_Format I190430 07:56:46.708042 706 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.708172 706 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestPruneTimeSeries (0.02s) --- PASS: TestPruneTimeSeries/Row_Format (0.01s) --- PASS: TestPruneTimeSeries/Column_Format (0.01s) === RUN TestMaintainTimeSeriesWithRollups I190430 07:56:46.721017 743 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.721080 743 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestMaintainTimeSeriesWithRollups (0.11s) === RUN TestMaintainTimeSeriesNoRollups I190430 07:56:46.830881 798 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.831542 798 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestMaintainTimeSeriesNoRollups (0.01s) === RUN TestQueryBasic === RUN TestQueryBasic/Row_Format I190430 07:56:46.848360 844 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.848946 844 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestQueryBasic/Column_Format I190430 07:56:46.856945 896 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.857493 896 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestQueryBasic (0.03s) --- PASS: TestQueryBasic/Row_Format (0.02s) --- PASS: TestQueryBasic/Column_Format (0.01s) === RUN TestQueryDownsampling === RUN TestQueryDownsampling/Row_Format I190430 07:56:46.867677 934 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.868273 934 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestQueryDownsampling/Column_Format I190430 07:56:46.872553 971 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.873065 971 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestQueryDownsampling (0.02s) --- PASS: TestQueryDownsampling/Row_Format (0.00s) --- PASS: TestQueryDownsampling/Column_Format (0.00s) === RUN TestInterpolationLimit === RUN TestInterpolationLimit/Row_Format I190430 07:56:46.887671 1029 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.888207 1029 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestInterpolationLimit/Column_Format I190430 07:56:46.893645 1082 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.894219 1082 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestInterpolationLimit (0.07s) --- PASS: TestInterpolationLimit/Row_Format (0.01s) --- PASS: TestInterpolationLimit/Column_Format (0.01s) === RUN TestQueryWorkerMemoryConstraint === RUN TestQueryWorkerMemoryConstraint/Row_Format I190430 07:56:46.953313 1120 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.953441 1120 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestQueryWorkerMemoryConstraint/Column_Format I190430 07:56:46.963461 1173 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.963590 1173 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestQueryWorkerMemoryConstraint (0.02s) --- PASS: TestQueryWorkerMemoryConstraint/Row_Format (0.01s) --- PASS: TestQueryWorkerMemoryConstraint/Column_Format (0.01s) === RUN TestQueryWorkerMemoryMonitor === RUN TestQueryWorkerMemoryMonitor/Row_Format I190430 07:56:46.973024 1211 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.973146 1211 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 I190430 07:56:46.973991 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 400 B (+400) I190430 07:56:46.974087 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 800 B (+400) I190430 07:56:46.974183 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 1.1 KiB (+300) I190430 07:56:46.974276 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 100 KiB (+102400) I190430 07:56:46.974520 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 400 B (+400) I190430 07:56:46.974606 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 800 B (+400) I190430 07:56:46.974721 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 1.1 KiB (+300) I190430 07:56:46.974917 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 400 B (+400) I190430 07:56:46.975003 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 800 B (+400) I190430 07:56:46.975099 1211 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 1.1 KiB (+300) === RUN TestQueryWorkerMemoryMonitor/Column_Format I190430 07:56:46.978289 1266 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.978362 1266 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 I190430 07:56:46.979296 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 300 B (+300) I190430 07:56:46.979348 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 600 B (+300) I190430 07:56:46.979390 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 1.2 KiB (+300) I190430 07:56:46.979444 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 100 KiB (+102400) I190430 07:56:46.979636 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 300 B (+300) I190430 07:56:46.979688 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 600 B (+300) I190430 07:56:46.979731 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 1.2 KiB (+300) I190430 07:56:46.979863 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 300 B (+300) I190430 07:56:46.979911 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 600 B (+300) I190430 07:56:46.979955 1266 util/mon/bytes_usage.go:606 timeseries-test-limited: bytes usage increases to 1.2 KiB (+300) --- PASS: TestQueryWorkerMemoryMonitor (0.01s) --- PASS: TestQueryWorkerMemoryMonitor/Row_Format (0.01s) query_test.go:522: total allocations for query: 15512 query_test.go:523: maximum allocations for query monitor: 1400 --- PASS: TestQueryWorkerMemoryMonitor/Column_Format (0.00s) query_test.go:522: total allocations for query: 15128 query_test.go:523: maximum allocations for query monitor: 1200 === RUN TestQueryBadRequests === RUN TestQueryBadRequests/Row_Format I190430 07:56:46.985168 1314 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:46.985764 1314 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestQueryBadRequests/Column_Format I190430 07:56:46.994035 1371 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestQueryBadRequests (0.01s) --- PASS: TestQueryBadRequests/Row_Format (0.01s) --- PASS: TestQueryBadRequests/Column_Format (0.00s) === RUN TestQueryNearCurrentTime === RUN TestQueryNearCurrentTime/Row_Format I190430 07:56:47.000031 1409 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.000590 1409 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestQueryNearCurrentTime/Column_Format I190430 07:56:47.004609 1450 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.004668 1450 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestQueryNearCurrentTime (0.12s) --- PASS: TestQueryNearCurrentTime/Row_Format (0.00s) --- PASS: TestQueryNearCurrentTime/Column_Format (0.06s) === RUN TestQueryRollup I190430 07:56:47.120896 1514 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.121528 1514 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestQueryRollup (0.01s) === RUN TestComputeRollupFromData === RUN TestComputeRollupFromData/#00 I190430 07:56:47.128103 1473 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.128165 1473 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 === RUN TestComputeRollupFromData/#01 I190430 07:56:47.177768 1600 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.177889 1600 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestComputeRollupFromData (0.06s) --- PASS: TestComputeRollupFromData/#00 (0.05s) --- PASS: TestComputeRollupFromData/#01 (0.00s) === RUN TestRollupBasic I190430 07:56:47.183958 1650 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.184082 1650 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestRollupBasic (0.03s) === RUN TestRollupMemoryConstraint I190430 07:56:47.209922 1703 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.210054 1703 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"" started_at:0 --- PASS: TestRollupMemoryConstraint (0.02s) === RUN TestToInternal --- PASS: TestToInternal (0.00s) === RUN TestDiscardEarlierSamples --- PASS: TestDiscardEarlierSamples (0.00s) === RUN TestServerQuery W190430 07:56:47.240817 1742 server/status/runtime.go:295 [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006" I190430 07:56:47.246818 1742 server/server.go:852 [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled I190430 07:56:47.246998 1742 base/addr_validation.go:279 [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.247089 1742 base/addr_validation.go:319 [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.256032 1742 server/config.go:494 [n?] 1 storage engine initialized I190430 07:56:47.256133 1742 server/config.go:497 [n?] RocksDB cache size: 128 MiB I190430 07:56:47.256210 1742 server/config.go:497 [n?] store 0: in-memory, size 0 B I190430 07:56:47.257476 1742 util/stop/stopper.go:537 [n?] quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber I190430 07:56:47.257635 1742 server/node.go:370 [n?] **** cluster c1ce9aed-a103-457e-849b-ab4d3d72ff91 has been created I190430 07:56:47.257730 1742 server/server.go:1398 [n?] **** add additional nodes by specifying --join=127.0.0.1:34365 I190430 07:56:47.257871 1742 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"v2.1.6-dirty" started_at:1556611007257846747 I190430 07:56:47.258285 1742 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.258515 1742 server/node.go:474 [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=7.0 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7183.00 p25=7183.00 p50=7183.00 p75=7183.00 p90=7183.00 pMax=7183.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00} I190430 07:56:47.258595 1742 storage/stores.go:242 [n1] read 0 node addresses from persistent storage I190430 07:56:47.258749 1742 server/node.go:697 [n1] connecting to gossip network to verify cluster ID... I190430 07:56:47.258795 1742 server/node.go:722 [n1] node connected via gossip and verified as part of cluster "c1ce9aed-a103-457e-849b-ab4d3d72ff91" I190430 07:56:47.258855 1742 server/node.go:546 [n1] node=1: started with [=] engine(s) and attributes [] I190430 07:56:47.259042 1742 server/status/recorder.go:609 [n1] available memory from cgroups (8.0 EiB) exceeds system memory 3.9 GiB, using system memory I190430 07:56:47.259092 1742 server/server.go:1828 [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined I190430 07:56:47.259990 1866 storage/replica_command.go:348 [n1,split,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2] I190430 07:56:47.263402 1873 storage/replica_command.go:348 [n1,split,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3] I190430 07:56:47.266298 1895 storage/replica_command.go:348 [n1,split,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4] I190430 07:56:47.259156 1742 server/server.go:1533 [n1] starting https server at 127.0.0.1:33331 (use: 127.0.0.1:33331) I190430 07:56:47.267057 1742 server/server.go:1535 [n1] starting grpc/postgres server at 127.0.0.1:34365 I190430 07:56:47.267096 1742 server/server.go:1536 [n1] advertising CockroachDB node at 127.0.0.1:34365 W190430 07:56:47.267139 1742 jobs/registry.go:316 [n1] unable to get node liveness: node not in the liveness table I190430 07:56:47.281856 1908 storage/replica_command.go:348 [n1,split,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5] W190430 07:56:47.286249 1917 storage/intent_resolver.go:687 [n1,s1] failed to push during intent resolution: failed to push "unnamed" id=a3495162 key=/Table/SystemConfigSpan/Start rw=true pri=0.04183445 iso=SERIALIZABLE stat=PENDING epo=0 ts=1556611007.280155277,0 orig=1556611007.280155277,0 max=1556611007.280155277,0 wto=false rop=false seq=6 I190430 07:56:47.286378 1938 storage/replica_command.go:348 [n1,split,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6] I190430 07:56:47.287866 1905 sql/event_log.go:126 [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root} I190430 07:56:47.290899 1930 storage/replica_command.go:348 [n1,split,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7] I190430 07:56:47.294577 1948 storage/replica_command.go:348 [n1,split,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8] I190430 07:56:47.298204 1927 sql/event_log.go:126 [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.1 User:root} I190430 07:56:47.301748 1975 storage/replica_command.go:348 [n1,split,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9] I190430 07:56:47.305113 1972 sql/event_log.go:126 [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root} I190430 07:56:47.306092 1965 storage/replica_command.go:348 [n1,split,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10] I190430 07:56:47.309124 1996 storage/replica_command.go:348 [n1,split,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11] I190430 07:56:47.314493 2022 sql/event_log.go:126 [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:df365e3e-eb4e-4b00-9bf3-53e6cba79e80 User:root} I190430 07:56:47.314641 2029 storage/replica_command.go:348 [n1,split,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12] I190430 07:56:47.317425 2042 storage/replica_command.go:348 [n1,split,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13] I190430 07:56:47.319576 2050 storage/replica_command.go:348 [n1,split,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14] I190430 07:56:47.321968 2064 storage/replica_command.go:348 [n1,split,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15] I190430 07:56:47.324409 2067 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root} I190430 07:56:47.324983 2074 storage/replica_command.go:348 [n1,split,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16] I190430 07:56:47.327719 2108 storage/replica_command.go:348 [n1,split,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17] I190430 07:56:47.327945 2095 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root} I190430 07:56:47.329281 1742 server/server.go:1589 [n1] done ensuring all necessary migrations have run I190430 07:56:47.329327 1742 server/server.go:1592 [n1] serving sql connections I190430 07:56:47.329520 1742 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.331093 1742 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.331448 2147 storage/replica_command.go:348 [n1,split,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18] I190430 07:56:47.332344 2113 server/server_update.go:67 [n1] no need to upgrade, cluster already at the newest version I190430 07:56:47.335200 2162 storage/replica_command.go:348 [n1,split,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19] I190430 07:56:47.337836 2175 storage/replica_command.go:348 [n1,split,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20] I190430 07:56:47.341678 2198 storage/replica_command.go:348 [n1,split,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21] I190430 07:56:47.344831 2212 storage/replica_command.go:348 [n1,split,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22] I190430 07:56:47.347913 2131 sql/event_log.go:126 [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:34365} Attrs: Locality: ServerVersion:2.1 BuildTag:v2.1.6-dirty StartedAt:1556611007257846747 LocalityAddress:[]} ClusterID:c1ce9aed-a103-457e-849b-ab4d3d72ff91 StartedAt:1556611007257846747 LastUp:1556611007257846747} I190430 07:56:47.361525 1742 util/stop/stopper.go:537 quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber --- PASS: TestServerQuery (0.13s) === RUN TestServerQueryStarvation W190430 07:56:47.367822 2247 server/status/runtime.go:295 [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006" I190430 07:56:47.373258 2247 server/server.go:852 [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled I190430 07:56:47.373396 2247 base/addr_validation.go:279 [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.373467 2247 base/addr_validation.go:319 [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.374572 2247 server/config.go:494 [n?] 1 storage engine initialized I190430 07:56:47.374653 2247 server/config.go:497 [n?] RocksDB cache size: 128 MiB I190430 07:56:47.374724 2247 server/config.go:497 [n?] store 0: in-memory, size 0 B I190430 07:56:47.375743 2247 util/stop/stopper.go:537 [n?] quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber I190430 07:56:47.375900 2247 server/node.go:370 [n?] **** cluster dc95d110-d0a4-45d2-b8f0-968bf331dcdf has been created I190430 07:56:47.375955 2247 server/server.go:1398 [n?] **** add additional nodes by specifying --join=127.0.0.1:46513 I190430 07:56:47.376044 2247 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"v2.1.6-dirty" started_at:1556611007376022205 I190430 07:56:47.376375 2247 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.376443 2247 server/node.go:474 [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=7.0 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7183.00 p25=7183.00 p50=7183.00 p75=7183.00 p90=7183.00 pMax=7183.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00} I190430 07:56:47.376494 2247 storage/stores.go:242 [n1] read 0 node addresses from persistent storage I190430 07:56:47.376549 2247 server/node.go:697 [n1] connecting to gossip network to verify cluster ID... I190430 07:56:47.377072 2247 server/node.go:722 [n1] node connected via gossip and verified as part of cluster "dc95d110-d0a4-45d2-b8f0-968bf331dcdf" I190430 07:56:47.377122 2247 server/node.go:546 [n1] node=1: started with [=] engine(s) and attributes [] I190430 07:56:47.377257 2247 server/status/recorder.go:609 [n1] available memory from cgroups (8.0 EiB) exceeds system memory 3.9 GiB, using system memory I190430 07:56:47.377306 2247 server/server.go:1828 [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined I190430 07:56:47.377361 2247 server/server.go:1533 [n1] starting https server at 127.0.0.1:34873 (use: 127.0.0.1:34873) I190430 07:56:47.377397 2247 server/server.go:1535 [n1] starting grpc/postgres server at 127.0.0.1:46513 I190430 07:56:47.377437 2247 server/server.go:1536 [n1] advertising CockroachDB node at 127.0.0.1:46513 I190430 07:56:47.392481 2397 storage/replica_command.go:348 [n1,split,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2] I190430 07:56:47.399035 2393 sql/event_log.go:126 [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root} I190430 07:56:47.402538 2419 storage/replica_command.go:348 [n1,split,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3] I190430 07:56:47.405963 2410 storage/replica_command.go:348 [n1,split,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4] I190430 07:56:47.409585 2432 storage/replica_command.go:348 [n1,split,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5] I190430 07:56:47.412709 2421 sql/event_log.go:126 [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.1 User:root} I190430 07:56:47.413367 2440 storage/replica_command.go:348 [n1,split,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6] I190430 07:56:47.417826 2448 storage/replica_command.go:348 [n1,split,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7] I190430 07:56:47.421193 2443 sql/event_log.go:126 [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root} I190430 07:56:47.424730 2461 storage/replica_command.go:348 [n1,split,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8] I190430 07:56:47.427654 2477 storage/replica_command.go:348 [n1,split,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9] I190430 07:56:47.430606 2493 storage/replica_command.go:348 [n1,split,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10] I190430 07:56:47.433275 2520 storage/replica_command.go:348 [n1,split,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11] I190430 07:56:47.436107 2535 storage/replica_command.go:348 [n1,split,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12] I190430 07:56:47.439136 2547 storage/replica_command.go:348 [n1,split,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13] W190430 07:56:47.441604 2559 storage/intent_resolver.go:687 [n1,s1] failed to push during intent resolution: failed to push "split" id=4a45ce94 key=/Local/Range/Table/15/RangeDescriptor rw=true pri=0.01400262 iso=SERIALIZABLE stat=PENDING epo=0 ts=1556611007.439172924,0 orig=1556611007.439172924,0 max=1556611007.439172924,0 wto=false rop=false seq=1 I190430 07:56:47.442329 2562 storage/replica_command.go:348 [n1,split,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14] I190430 07:56:47.445853 2581 storage/replica_command.go:348 [n1,split,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15] I190430 07:56:47.448257 2505 sql/event_log.go:126 [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:a595f2ab-6747-4ad8-b520-4969811fc139 User:root} I190430 07:56:47.450218 2591 storage/replica_command.go:348 [n1,split,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16] I190430 07:56:47.452749 2600 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root} I190430 07:56:47.452830 2627 storage/replica_command.go:348 [n1,split,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17] I190430 07:56:47.455542 2615 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root} I190430 07:56:47.456717 2643 storage/replica_command.go:348 [n1,split,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18] I190430 07:56:47.456929 2247 server/server.go:1589 [n1] done ensuring all necessary migrations have run I190430 07:56:47.456971 2247 server/server.go:1592 [n1] serving sql connections I190430 07:56:47.457553 2247 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.459338 2651 storage/replica_command.go:348 [n1,split,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19] I190430 07:56:47.459568 2658 server/server_update.go:67 [n1] no need to upgrade, cluster already at the newest version I190430 07:56:47.462635 2660 sql/event_log.go:126 [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:46513} Attrs: Locality: ServerVersion:2.1 BuildTag:v2.1.6-dirty StartedAt:1556611007376022205 LocalityAddress:[]} ClusterID:dc95d110-d0a4-45d2-b8f0-968bf331dcdf StartedAt:1556611007376022205 LastUp:1556611007376022205} I190430 07:56:47.463320 2681 storage/replica_command.go:348 [n1,split,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20] I190430 07:56:47.463648 2247 server/testserver.go:446 had 19 ranges at startup, expected 22 I190430 07:56:47.463908 2247 server/testserver.go:446 had 19 ranges at startup, expected 22 I190430 07:56:47.466235 2683 storage/replica_command.go:348 [n1,split,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21] I190430 07:56:47.466443 2247 server/testserver.go:446 had 20 ranges at startup, expected 22 I190430 07:56:47.466927 2247 server/testserver.go:446 had 20 ranges at startup, expected 22 I190430 07:56:47.467367 2247 server/testserver.go:446 had 20 ranges at startup, expected 22 I190430 07:56:47.468897 2710 storage/replica_command.go:348 [n1,split,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22] I190430 07:56:47.469113 2247 server/testserver.go:446 had 21 ranges at startup, expected 22 I190430 07:56:47.514028 2247 util/stop/stopper.go:537 quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber --- PASS: TestServerQueryStarvation (0.15s) === RUN TestServerQueryMemoryManagement W190430 07:56:47.524391 2788 server/status/runtime.go:295 [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006" I190430 07:56:47.528869 2788 server/server.go:852 [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled I190430 07:56:47.529020 2788 base/addr_validation.go:279 [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.529092 2788 base/addr_validation.go:319 [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.530395 2788 server/config.go:494 [n?] 1 storage engine initialized I190430 07:56:47.530477 2788 server/config.go:497 [n?] RocksDB cache size: 128 MiB I190430 07:56:47.530571 2788 server/config.go:497 [n?] store 0: in-memory, size 0 B I190430 07:56:47.531818 2788 util/stop/stopper.go:537 [n?] quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber I190430 07:56:47.532032 2788 server/node.go:370 [n?] **** cluster bf21ffe9-e146-4a00-ac5c-f5372503764a has been created I190430 07:56:47.532119 2788 server/server.go:1398 [n?] **** add additional nodes by specifying --join=127.0.0.1:37903 I190430 07:56:47.532293 2788 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"v2.1.6-dirty" started_at:1556611007532261237 I190430 07:56:47.532661 2788 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.532733 2788 server/node.go:474 [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=7.0 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7183.00 p25=7183.00 p50=7183.00 p75=7183.00 p90=7183.00 pMax=7183.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00} I190430 07:56:47.532785 2788 storage/stores.go:242 [n1] read 0 node addresses from persistent storage I190430 07:56:47.532841 2788 server/node.go:697 [n1] connecting to gossip network to verify cluster ID... I190430 07:56:47.533390 2788 server/node.go:722 [n1] node connected via gossip and verified as part of cluster "bf21ffe9-e146-4a00-ac5c-f5372503764a" I190430 07:56:47.533438 2788 server/node.go:546 [n1] node=1: started with [=] engine(s) and attributes [] I190430 07:56:47.533590 2788 server/status/recorder.go:609 [n1] available memory from cgroups (8.0 EiB) exceeds system memory 3.9 GiB, using system memory I190430 07:56:47.533629 2788 server/server.go:1828 [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined I190430 07:56:47.533682 2788 server/server.go:1533 [n1] starting https server at 127.0.0.1:39285 (use: 127.0.0.1:39285) I190430 07:56:47.533718 2788 server/server.go:1535 [n1] starting grpc/postgres server at 127.0.0.1:37903 I190430 07:56:47.533758 2788 server/server.go:1536 [n1] advertising CockroachDB node at 127.0.0.1:37903 I190430 07:56:47.558689 2938 storage/replica_command.go:348 [n1,split,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2] I190430 07:56:47.563010 2934 sql/event_log.go:126 [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root} I190430 07:56:47.564870 2942 storage/replica_command.go:348 [n1,split,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3] I190430 07:56:47.582192 2849 storage/replica_command.go:348 [n1,split,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4] I190430 07:56:47.583702 2945 sql/event_log.go:126 [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.1 User:root} I190430 07:56:47.585998 2957 storage/replica_command.go:348 [n1,split,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5] I190430 07:56:47.589659 2976 storage/replica_command.go:348 [n1,split,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6] I190430 07:56:47.591002 2953 sql/event_log.go:126 [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root} I190430 07:56:47.594276 2986 storage/replica_command.go:348 [n1,split,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7] I190430 07:56:47.596370 3010 storage/replica_command.go:348 [n1,split,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8] I190430 07:56:47.598725 3017 storage/replica_command.go:348 [n1,split,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9] I190430 07:56:47.601117 3032 storage/replica_command.go:348 [n1,split,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10] I190430 07:56:47.602125 3014 sql/event_log.go:126 [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:f3012689-3504-435b-8033-e7a8f9c3edc5 User:root} W190430 07:56:47.605088 3048 storage/intent_resolver.go:687 [n1,s1] failed to push during intent resolution: failed to push "split" id=bd1f9324 key=/Local/Range/Table/12/RangeDescriptor rw=true pri=0.01179227 iso=SERIALIZABLE stat=PENDING epo=0 ts=1556611007.601152360,0 orig=1556611007.601152360,0 max=1556611007.601152360,0 wto=false rop=false seq=1 I190430 07:56:47.605539 3050 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root} I190430 07:56:47.605912 3059 storage/replica_command.go:348 [n1,split,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11] I190430 07:56:47.607600 3055 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root} I190430 07:56:47.609073 2788 server/server.go:1589 [n1] done ensuring all necessary migrations have run I190430 07:56:47.609127 2788 server/server.go:1592 [n1] serving sql connections I190430 07:56:47.610672 3083 server/server_update.go:67 [n1] no need to upgrade, cluster already at the newest version I190430 07:56:47.611621 3085 sql/event_log.go:126 [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:37903} Attrs: Locality: ServerVersion:2.1 BuildTag:v2.1.6-dirty StartedAt:1556611007532261237 LocalityAddress:[]} ClusterID:bf21ffe9-e146-4a00-ac5c-f5372503764a StartedAt:1556611007532261237 LastUp:1556611007532261237} I190430 07:56:47.611704 3090 storage/replica_command.go:348 [n1,split,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12] I190430 07:56:47.612026 2788 server/testserver.go:446 had 11 ranges at startup, expected 22 I190430 07:56:47.614201 3099 storage/replica_command.go:348 [n1,split,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13] I190430 07:56:47.617058 3126 storage/replica_command.go:348 [n1,split,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14] I190430 07:56:47.617086 2788 server/testserver.go:446 had 13 ranges at startup, expected 22 I190430 07:56:47.617862 2788 server/testserver.go:446 had 13 ranges at startup, expected 22 I190430 07:56:47.617992 2788 server/testserver.go:446 had 13 ranges at startup, expected 22 I190430 07:56:47.618108 2788 server/testserver.go:446 had 13 ranges at startup, expected 22 I190430 07:56:47.618227 2788 server/testserver.go:446 had 13 ranges at startup, expected 22 I190430 07:56:47.618354 2788 server/testserver.go:446 had 13 ranges at startup, expected 22 I190430 07:56:47.619445 3119 storage/replica_command.go:348 [n1,split,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15] I190430 07:56:47.619658 2788 server/testserver.go:446 had 14 ranges at startup, expected 22 I190430 07:56:47.620419 2788 server/testserver.go:446 had 14 ranges at startup, expected 22 I190430 07:56:47.620549 2788 server/testserver.go:446 had 14 ranges at startup, expected 22 I190430 07:56:47.620688 2788 server/testserver.go:446 had 14 ranges at startup, expected 22 I190430 07:56:47.620820 2788 server/testserver.go:446 had 14 ranges at startup, expected 22 I190430 07:56:47.620942 2788 server/testserver.go:446 had 14 ranges at startup, expected 22 I190430 07:56:47.622179 3139 storage/replica_command.go:348 [n1,split,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16] I190430 07:56:47.625855 3170 storage/replica_command.go:348 [n1,split,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17] I190430 07:56:47.626913 2788 server/testserver.go:446 had 15 ranges at startup, expected 22 I190430 07:56:47.627203 2788 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.627571 2788 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.627758 2788 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.628036 2788 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.628544 2788 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.629861 3186 storage/replica_command.go:348 [n1,split,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18] I190430 07:56:47.630396 2788 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.631124 2788 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.632328 3182 storage/replica_command.go:348 [n1,split,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19] I190430 07:56:47.632919 2788 server/testserver.go:446 had 18 ranges at startup, expected 22 I190430 07:56:47.636104 3205 storage/replica_command.go:348 [n1,split,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20] I190430 07:56:47.636970 2788 server/testserver.go:446 had 19 ranges at startup, expected 22 I190430 07:56:47.638684 3227 storage/replica_command.go:348 [n1,split,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21] I190430 07:56:47.640971 3216 storage/replica_command.go:348 [n1,split,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22] I190430 07:56:47.720025 2788 util/stop/stopper.go:537 quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber --- PASS: TestServerQueryMemoryManagement (0.20s) === RUN TestServerDump W190430 07:56:47.728444 3322 server/status/runtime.go:295 [n?] Could not parse build timestamp: parsing time "" as "2006/01/02 15:04:05": cannot parse "" as "2006" I190430 07:56:47.732151 3322 server/server.go:852 [n?] monitoring forward clock jumps based on server.clock.forward_jump_check_enabled I190430 07:56:47.732294 3322 base/addr_validation.go:279 [n?] server certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.732369 3322 base/addr_validation.go:319 [n?] web UI certificate addresses: IP=127.0.0.1,::1; DNS=localhost,*.local; CN=node I190430 07:56:47.740781 3322 server/config.go:494 [n?] 1 storage engine initialized I190430 07:56:47.740870 3322 server/config.go:497 [n?] RocksDB cache size: 128 MiB I190430 07:56:47.741008 3322 server/config.go:497 [n?] store 0: in-memory, size 0 B I190430 07:56:47.742211 3322 util/stop/stopper.go:537 [n?] quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber I190430 07:56:47.742297 3322 server/node.go:370 [n?] **** cluster 56596412-faef-40d7-a48d-2af0c8604e24 has been created I190430 07:56:47.742342 3322 server/server.go:1398 [n?] **** add additional nodes by specifying --join=127.0.0.1:37671 I190430 07:56:47.742421 3322 gossip/gossip.go:395 [n1] NodeDescriptor set to node_id:1 address: attrs:<> locality:<> ServerVersion: build_tag:"v2.1.6-dirty" started_at:1556611007742397858 I190430 07:56:47.742740 3322 storage/store.go:1549 [n1,s1] [n1,s1]: failed initial metrics computation: [n1,s1]: system config not yet available I190430 07:56:47.742803 3322 server/node.go:474 [n1] initialized store [n1,s1]: disk (capacity=512 MiB, available=512 MiB, used=0 B, logicalBytes=7.0 KiB), ranges=1, leases=0, queries=0.00, writes=0.00, bytesPerReplica={p10=7183.00 p25=7183.00 p50=7183.00 p75=7183.00 p90=7183.00 pMax=7183.00}, writesPerReplica={p10=0.00 p25=0.00 p50=0.00 p75=0.00 p90=0.00 pMax=0.00} I190430 07:56:47.742850 3322 storage/stores.go:242 [n1] read 0 node addresses from persistent storage I190430 07:56:47.742903 3322 server/node.go:697 [n1] connecting to gossip network to verify cluster ID... I190430 07:56:47.743411 3322 server/node.go:722 [n1] node connected via gossip and verified as part of cluster "56596412-faef-40d7-a48d-2af0c8604e24" I190430 07:56:47.743456 3322 server/node.go:546 [n1] node=1: started with [=] engine(s) and attributes [] I190430 07:56:47.743587 3322 server/status/recorder.go:609 [n1] available memory from cgroups (8.0 EiB) exceeds system memory 3.9 GiB, using system memory I190430 07:56:47.743625 3322 server/server.go:1828 [n1] Could not start heap profiler worker due to: directory to store profiles could not be determined I190430 07:56:47.743691 3322 server/server.go:1533 [n1] starting https server at 127.0.0.1:33375 (use: 127.0.0.1:33375) I190430 07:56:47.743728 3322 server/server.go:1535 [n1] starting grpc/postgres server at 127.0.0.1:37671 I190430 07:56:47.743785 3322 server/server.go:1536 [n1] advertising CockroachDB node at 127.0.0.1:37671 I190430 07:56:47.745774 3462 storage/replica_command.go:348 [n1,split,s1,r1/1:/M{in-ax}] initiating a split of this range at key /System/"" [r2] I190430 07:56:47.762464 3468 storage/replica_command.go:348 [n1,split,s1,r2/1:/{System/-Max}] initiating a split of this range at key /System/NodeLiveness [r3] I190430 07:56:47.763764 3452 sql/event_log.go:126 [n1,intExec=optInToDiagnosticsStatReporting] Event: "set_cluster_setting", target: 0, info: {SettingName:diagnostics.reporting.enabled Value:true User:root} I190430 07:56:47.765283 3471 storage/replica_command.go:348 [n1,split,s1,r3/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/NodeLivenessMax [r4] I190430 07:56:47.768893 3484 storage/replica_command.go:348 [n1,split,s1,r4/1:/{System/NodeL…-Max}] initiating a split of this range at key /System/tsd [r5] I190430 07:56:47.773132 3515 storage/replica_command.go:348 [n1,split,s1,r5/1:/{System/tsd-Max}] initiating a split of this range at key /System/"tse" [r6] I190430 07:56:47.774096 3482 sql/event_log.go:126 [n1,intExec=set-setting] Event: "set_cluster_setting", target: 0, info: {SettingName:version Value:2.1 User:root} I190430 07:56:47.776994 3519 storage/replica_command.go:348 [n1,split,s1,r6/1:/{System/tse-Max}] initiating a split of this range at key /Table/SystemConfigSpan/Start [r7] I190430 07:56:47.780140 3541 storage/replica_command.go:348 [n1,split,s1,r7/1:/{Table/System…-Max}] initiating a split of this range at key /Table/11 [r8] I190430 07:56:47.781685 3500 sql/event_log.go:126 [n1,intExec=disableNetTrace] Event: "set_cluster_setting", target: 0, info: {SettingName:trace.debug.enable Value:false User:root} I190430 07:56:47.783208 3546 storage/replica_command.go:348 [n1,split,s1,r8/1:/{Table/11-Max}] initiating a split of this range at key /Table/12 [r9] I190430 07:56:47.785457 3553 storage/replica_command.go:348 [n1,split,s1,r9/1:/{Table/12-Max}] initiating a split of this range at key /Table/13 [r10] I190430 07:56:47.788044 3577 storage/replica_command.go:348 [n1,split,s1,r10/1:/{Table/13-Max}] initiating a split of this range at key /Table/14 [r11] I190430 07:56:47.790954 3589 storage/replica_command.go:348 [n1,split,s1,r11/1:/{Table/14-Max}] initiating a split of this range at key /Table/15 [r12] I190430 07:56:47.790946 3580 sql/event_log.go:126 [n1,intExec=initializeClusterSecret] Event: "set_cluster_setting", target: 0, info: {SettingName:cluster.secret Value:44176b9d-afce-442f-a1b8-8231858a0dbc User:root} W190430 07:56:47.793352 3608 storage/intent_resolver.go:687 [n1,s1] failed to push during intent resolution: failed to push "split" id=9642fad6 key=/Local/Range/Table/14/RangeDescriptor rw=true pri=0.00288379 iso=SERIALIZABLE stat=PENDING epo=0 ts=1556611007.791031553,0 orig=1556611007.791031553,0 max=1556611007.791031553,0 wto=false rop=false seq=1 I190430 07:56:47.794218 3610 storage/replica_command.go:348 [n1,split,s1,r12/1:/{Table/15-Max}] initiating a split of this range at key /Table/16 [r13] I190430 07:56:47.795298 3623 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 50, info: {DatabaseName:defaultdb Statement:CREATE DATABASE IF NOT EXISTS defaultdb User:root} I190430 07:56:47.800043 3652 storage/replica_command.go:348 [n1,split,s1,r13/1:/{Table/16-Max}] initiating a split of this range at key /Table/17 [r14] I190430 07:56:47.803640 3673 storage/replica_command.go:348 [n1,split,s1,r14/1:/{Table/17-Max}] initiating a split of this range at key /Table/18 [r15] I190430 07:56:47.799447 3630 sql/event_log.go:126 [n1,intExec=create-default-db] Event: "create_database", target: 51, info: {DatabaseName:postgres Statement:CREATE DATABASE IF NOT EXISTS postgres User:root} I190430 07:56:47.807425 3694 storage/replica_command.go:348 [n1,split,s1,r15/1:/{Table/18-Max}] initiating a split of this range at key /Table/19 [r16] I190430 07:56:47.809304 3322 server/server.go:1589 [n1] done ensuring all necessary migrations have run I190430 07:56:47.809395 3322 server/server.go:1592 [n1] serving sql connections I190430 07:56:47.810617 3322 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.810904 3718 storage/replica_command.go:348 [n1,split,s1,r16/1:/{Table/19-Max}] initiating a split of this range at key /Table/20 [r17] I190430 07:56:47.811754 3701 server/server_update.go:67 [n1] no need to upgrade, cluster already at the newest version I190430 07:56:47.812139 3322 server/testserver.go:446 had 16 ranges at startup, expected 22 I190430 07:56:47.813227 3703 sql/event_log.go:126 [n1] Event: "node_join", target: 1, info: {Descriptor:{NodeID:1 Address:{NetworkField:tcp AddressField:127.0.0.1:37671} Attrs: Locality: ServerVersion:2.1 BuildTag:v2.1.6-dirty StartedAt:1556611007742397858 LocalityAddress:[]} ClusterID:56596412-faef-40d7-a48d-2af0c8604e24 StartedAt:1556611007742397858 LastUp:1556611007742397858} I190430 07:56:47.813946 3713 storage/replica_command.go:348 [n1,split,s1,r17/1:/{Table/20-Max}] initiating a split of this range at key /Table/21 [r18] I190430 07:56:47.814235 3322 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.814908 3322 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.815002 3322 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.815095 3322 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.815186 3322 server/testserver.go:446 had 17 ranges at startup, expected 22 I190430 07:56:47.818892 3736 storage/replica_command.go:348 [n1,split,s1,r18/1:/{Table/21-Max}] initiating a split of this range at key /Table/22 [r19] I190430 07:56:47.819374 3322 server/testserver.go:446 had 18 ranges at startup, expected 22 I190430 07:56:47.820915 3322 server/testserver.go:446 had 18 ranges at startup, expected 22 I190430 07:56:47.821024 3322 server/testserver.go:446 had 18 ranges at startup, expected 22 I190430 07:56:47.822759 3741 storage/replica_command.go:348 [n1,split,s1,r19/1:/{Table/22-Max}] initiating a split of this range at key /Table/23 [r20] I190430 07:56:47.825140 3322 server/testserver.go:446 had 19 ranges at startup, expected 22 I190430 07:56:47.825995 3771 storage/replica_command.go:348 [n1,split,s1,r20/1:/{Table/23-Max}] initiating a split of this range at key /Table/50 [r21] I190430 07:56:47.826240 3322 server/testserver.go:446 had 20 ranges at startup, expected 22 I190430 07:56:47.828092 3791 storage/replica_command.go:348 [n1,split,s1,r21/1:/{Table/50-Max}] initiating a split of this range at key /Table/51 [r22] I190430 07:56:47.828306 3322 server/testserver.go:446 had 21 ranges at startup, expected 22 I190430 07:56:47.829021 3322 server/testserver.go:446 had 21 ranges at startup, expected 22 I190430 07:56:47.829242 3322 server/testserver.go:446 had 21 ranges at startup, expected 22 I190430 07:56:47.829423 3322 server/testserver.go:446 had 21 ranges at startup, expected 22 I190430 07:56:47.829743 3322 server/testserver.go:446 had 21 ranges at startup, expected 22 I190430 07:56:47.863949 3322 util/stop/stopper.go:537 quiescing; tasks left: 1 [async] closedts-rangefeed-subscriber --- PASS: TestServerDump (0.14s) FAIL FAIL github.com/cockroachdb/cockroach/pkg/ts 7.540s Makefile:836: recipe for target 'test' failed make: *** [test] Error 1