Tests failing (flakily) at HEAD

[swsnider]

using commit 17eebbc, I see this when running make test from a clean checkout.

curl -o /prometheus/.build/cache/go1.4.2.linux-amd64.tar.gz -L https://golang.org/dl/go1.4.2.linux-amd64.tar.gz
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 59.5M  100 59.5M    0     0  7821k      0  0:00:07  0:00:07 --:--:-- 8385k
tar -C /prometheus/.build/root -xzf /prometheus/.build/cache/go1.4.2.linux-amd64.tar.gz
touch /prometheus/.build/root/go/bin/go
cp -a /prometheus/Godeps/_workspace "/prometheus/.build/root/gopath"
ln -s /prometheus /prometheus/.build/root/gopath/src/github.com/prometheus/prometheus
TMPDIR=/tmp GOROOT=/prometheus/.build/root/go GOPATH=/prometheus/.build/root/gopath /prometheus/.build/root/go/bin/go test -short ./...
?       _/prometheus/cmd/prometheus [no test files]
?       _/prometheus/cmd/promtool   [no test files]
ok      _/prometheus/config 0.317s
ok      _/prometheus/notification   0.007s
ok      _/prometheus/promql 0.532s
ok      _/prometheus/retrieval  0.757s
ok      _/prometheus/retrieval/discovery    0.191s
ok      _/prometheus/rules  0.121s
?       _/prometheus/storage    [no test files]
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing fingerprint mappings..." file=persistence.go line=1423
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing fingerprint mappings in 5.356602ms." file=persistence.go line=1442
time="2015-07-29T21:28:08Z" level=info msg="Collision detected for fingerprint 0000000000100001, metric {bar=\"foo\"}, mapping to new fingerprint 0000000000000001." file=mapper.go line=166
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing fingerprint mappings..." file=persistence.go line=1423
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing fingerprint mappings in 8.527062ms." file=persistence.go line=1442
time="2015-07-29T21:28:08Z" level=info msg="Collision detected for fingerprint 0000000000100001, metric {foo=\"bar\"}, mapping to new fingerprint 0000000000000002." file=mapper.go line=151
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing fingerprint mappings..." file=persistence.go line=1423
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing fingerprint mappings in 7.670836ms." file=persistence.go line=1442
time="2015-07-29T21:28:08Z" level=info msg="Collision detected for fingerprint 0000000000100002, metric {bar=\"bumms\", dings=\"foo\"}, mapping to new fingerprint 0000000000000003." file=mapper.go line=166
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing fingerprint mappings..." file=persistence.go line=1423
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing fingerprint mappings in 6.450006ms." file=persistence.go line=1442
time="2015-07-29T21:28:08Z" level=info msg="Collision detected for fingerprint 0000000000000001, metric {bumms=\"dings\"}, mapping to new fingerprint 0000000000000004." file=mapper.go line=166
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing fingerprint mappings..." file=persistence.go line=1423
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing fingerprint mappings in 9.170572ms." file=persistence.go line=1442
time="2015-07-29T21:28:08Z" level=info msg="Collision detected for fingerprint 0000000000000001, metric {bar=\"foo\", bumms=\"dings\"}, mapping to new fingerprint 0000000000000005." file=mapper.go line=151
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing fingerprint mappings..." file=persistence.go line=1423
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing fingerprint mappings in 7.359983ms." file=persistence.go line=1442
time="2015-07-29T21:28:08Z" level=info msg="Collision detected for fingerprint 0000000000100002, metric {dings=\"bar\", foo=\"bumms\"}, mapping to new fingerprint 0000000000000006." file=mapper.go line=151
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing in-memory metrics and chunks in 9.55745ms." file=persistence.go line=561
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing in-memory metrics and chunks in 8.275451ms." file=persistence.go line=561
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing fingerprint mappings..." file=persistence.go line=1423
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing fingerprint mappings in 5.073244ms." file=persistence.go line=1442
time="2015-07-29T21:28:08Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:08Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:08Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:08Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:08Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:08Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:08Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing in-memory metrics and chunks in 11.195402ms." file=persistence.go line=561
time="2015-07-29T21:28:08Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:08Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:08Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:08Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:08Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:08Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:08Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:08Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing in-memory metrics and chunks in 3.290871ms." file=persistence.go line=561
time="2015-07-29T21:28:08Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:08Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:08Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:08Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:08Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:08Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:08Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:08Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:08Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:08Z" level=info msg="Done checkpointing in-memory metrics and chunks in 3.327973ms." file=persistence.go line=561
time="2015-07-29T21:28:08Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:08Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:08Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:09Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:09Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:09Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:09Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:09Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:09Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:09Z" level=info msg="Done checkpointing in-memory metrics and chunks in 39.560664ms." file=persistence.go line=561
time="2015-07-29T21:28:09Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:09Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:09Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:11Z" level=info msg="test done, closing" file="storage_test.go" line=595
time="2015-07-29T21:28:11Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:11Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:11Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:11Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:11Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:11Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:11Z" level=info msg="Done checkpointing in-memory metrics and chunks in 27.364523ms." file=persistence.go line=561
time="2015-07-29T21:28:11Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:11Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:11Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:11Z" level=info msg="test done, closing" file="storage_test.go" line=595
time="2015-07-29T21:28:11Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:11Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:11Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:11Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:11Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:11Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:11Z" level=info msg="Done checkpointing in-memory metrics and chunks in 8.337773ms." file=persistence.go line=561
time="2015-07-29T21:28:11Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:11Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:11Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:11Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:11Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:11Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:11Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:11Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:11Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:11Z" level=info msg="Done checkpointing in-memory metrics and chunks in 2.353546ms." file=persistence.go line=561
time="2015-07-29T21:28:11Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:11Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:11Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:11Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:11Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:11Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:11Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:11Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:11Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:11Z" level=info msg="Done checkpointing in-memory metrics and chunks in 2.150993ms." file=persistence.go line=561
time="2015-07-29T21:28:11Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:11Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:11Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:11Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:11Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:11Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:11Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:11Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:11Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:11Z" level=info msg="Done checkpointing in-memory metrics and chunks in 2.483505ms." file=persistence.go line=561
time="2015-07-29T21:28:11Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:11Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:11Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:12Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:12Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:12Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:12Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:12Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:12Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:12Z" level=info msg="Done checkpointing in-memory metrics and chunks in 2.332055ms." file=persistence.go line=561
time="2015-07-29T21:28:12Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:12Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:12Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:12Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:12Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:12Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:12Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:12Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:12Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:12Z" level=info msg="Done checkpointing in-memory metrics and chunks in 1.574226ms." file=persistence.go line=561
time="2015-07-29T21:28:12Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:12Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:12Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:12Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:12Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:12Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:12Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:12Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:12Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:12Z" level=info msg="Done checkpointing in-memory metrics and chunks in 17.140377ms." file=persistence.go line=561
time="2015-07-29T21:28:12Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:12Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:12Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:12Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:12Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:12Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:12Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:12Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:12Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:12Z" level=info msg="Done checkpointing in-memory metrics and chunks in 2.006689ms." file=persistence.go line=561
time="2015-07-29T21:28:12Z" level=info msg="Local storage stopped." file=storage.go line=302
--- FAIL: TestEvictAndLoadChunkDescsType0 (0.04s)
    storage_test.go:1176: Expected number of chunkDescs to decrease, old number 79, current number 79.
time="2015-07-29T21:28:12Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:12Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:12Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:12Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:12Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:12Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:12Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:12Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:12Z" level=info msg="Done checkpointing in-memory metrics and chunks in 2.780466ms." file=persistence.go line=561
time="2015-07-29T21:28:12Z" level=info msg="Local storage stopped." file=storage.go line=302
time="2015-07-29T21:28:12Z" level=info msg="Loading series map and head chunks..." file=storage.go line=263
time="2015-07-29T21:28:12Z" level=info msg="0 series loaded." file=storage.go line=268
time="2015-07-29T21:28:12Z" level=warning msg="Ignoring sample with out-of-order timestamp for fingerprint d8889b7402187e08 (out_of_order): 0.002 is not after 0.002" file=storage.go line=564
time="2015-07-29T21:28:12Z" level=warning msg="Ignoring sample with out-of-order timestamp for fingerprint d8889b7402187e08 (out_of_order): 0.001 is not after 0.002" file=storage.go line=564
time="2015-07-29T21:28:12Z" level=info msg="Stopping local storage..." file=storage.go line=284
time="2015-07-29T21:28:12Z" level=info msg="Stopping maintenance loop..." file=storage.go line=286
time="2015-07-29T21:28:12Z" level=info msg="Maintenance loop stopped." file=storage.go line=858
time="2015-07-29T21:28:12Z" level=info msg="Stopping chunk eviction..." file=storage.go line=290
time="2015-07-29T21:28:12Z" level=info msg="Chunk eviction stopped." file=storage.go line=678
time="2015-07-29T21:28:12Z" level=info msg="Checkpointing in-memory metrics and chunks..." file=persistence.go line=541
time="2015-07-29T21:28:12Z" level=info msg="Done checkpointing in-memory metrics and chunks in 1.67177ms." file=persistence.go line=561
time="2015-07-29T21:28:12Z" level=info msg="Local storage stopped." file=storage.go line=302
FAIL
FAIL    _/prometheus/storage/local  4.515s
ok      _/prometheus/storage/local/codable  0.004s
?       _/prometheus/storage/local/index    [no test files]
ok      _/prometheus/storage/metric 0.004s
ok      _/prometheus/storage/remote 0.020s
ok      _/prometheus/storage/remote/influxdb    0.013s
ok      _/prometheus/storage/remote/opentsdb    0.009s
ok      _/prometheus/template   0.054s
?       _/prometheus/util/cli   [no test files]
ok      _/prometheus/util/flock 0.003s
?       _/prometheus/util/httputil  [no test files]
?       _/prometheus/util/route [no test files]
?       _/prometheus/util/stats [no test files]
?       _/prometheus/util/strutil   [no test files]
?       _/prometheus/util/testutil  [no test files]
?       _/prometheus/version    [no test files]
ok      _/prometheus/web    0.055s
ok      _/prometheus/web/api/legacy 0.144s
ok      _/prometheus/web/api/v1 0.052s
?       _/prometheus/web/blob   [no test files]
make: *** [test] Error 1

[beorn7]

This might have to do with the new out-of-order detection...

(And sadly, we have a number of flaky, timing-dependent tests...)

[lock]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.