diff --git a/.gitlab/.gitlab-ci.yml b/.gitlab/.gitlab-ci.yml index 793e70aae..09987cadd 100644 --- a/.gitlab/.gitlab-ci.yml +++ b/.gitlab/.gitlab-ci.yml @@ -66,7 +66,7 @@ run go tests: - if: '$CI_PIPELINE_SOURCE == "push" || $CI_PIPELINE_SOURCE == "schedule" || $CI_PIPELINE_SOURCE == "web"' script: - echo "Running featurebase unit tests..." - - go test ./... + - go test -timeout=30m ./... tags: - aws @@ -77,7 +77,7 @@ run go tests race: - if: '$CI_PIPELINE_SOURCE == "push" || $CI_PIPELINE_SOURCE == "schedule" || $CI_PIPELINE_SOURCE == "web"' script: - echo "Running featurebase race tests..." - - go test -race -timeout=30m ./... + - go test -race -timeout=90m ./... tags: - aws @@ -88,10 +88,10 @@ run go tests shardwidth22: - if: '$CI_PIPELINE_SOURCE == "push" || $CI_PIPELINE_SOURCE == "schedule" || $CI_PIPELINE_SOURCE == "web"' script: - echo "Running featurebase race tests..." - - go test -tags=shardwidth22 ./... + - go test -timeout=30m -tags=shardwidth22 ./... tags: - aws - + # we do coverage reporting from the future tests because the json # output is very difficult to human-read. The alternative would be to # run the regular tests twice and also run the future tests. @@ -103,7 +103,7 @@ run go tests future: script: - echo "Running featurebase unit tests..." - PKG_LIST=$(go list ./... | grep -v internal/clustertests | paste -s -d, -) - - go test -json -coverprofile=coverage.out -covermode=atomic -coverpkg=${PKG_LIST} ./... | tee test-report.out + - go test -timeout=30m -json -coverprofile=coverage.out -covermode=atomic -coverpkg=${PKG_LIST} ./... | tee test-report.out artifacts: paths: - coverage.out diff --git a/Makefile b/Makefile index 8545c0cb8..540c1f9b7 100644 --- a/Makefile +++ b/Makefile @@ -19,6 +19,8 @@ DOCKER_BUILD= # set to 1 to use `docker-build` instead of `build` when creating BUILD_TAGS += shardwidth$(SHARD_WIDTH) TEST_TAGS = roaringparanoia UNAME := $(shell uname -s) +TEST_TIMEOUT=30m +RACE_TEST_TIMEOUT=90m ifeq ($(UNAME), Darwin) IS_MACOS:=1 else @@ -45,11 +47,11 @@ version: # Run test suite test: - $(GO) test ./... -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -v + $(GO) test ./... -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -v -timeout $(TEST_TIMEOUT) # Run test suite with race flag test-race: - CGO_ENABLED=1 $(GO) test ./... -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -race -timeout 60m -v + CGO_ENABLED=1 $(GO) test ./... -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -race -timeout $(RACE_TEST_TIMEOUT) -v testv: topt testvsub @@ -64,7 +66,7 @@ testvsub: set -e; for i in boltdb client ctl http pg pql rbf roaring server sql txkey; do \ echo; echo "___ testing subpkg $$i"; \ cd $$i; pwd; \ - $(GO) test -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -v -timeout 60m || break; \ + $(GO) test -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -v -timeout $(RACE_TEST_TIMEOUT) || break; \ echo; echo "999 done testing subpkg $$i"; \ cd ..; \ done @@ -73,7 +75,7 @@ testvsub-race: set -e; for i in boltdb client ctl http pg pql rbf roaring server sql txkey; do \ echo; echo "___ testing subpkg $$i -race"; \ cd $$i; pwd; \ - CGO_ENABLED=1 $(GO) test -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -v -race -timeout 60m || break; \ + CGO_ENABLED=1 $(GO) test -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -v -race -timeout $(RACE_TEST_TIMEOUT) || break; \ echo; echo "999 done testing subpkg $$i -race"; \ cd ..; \ done @@ -248,20 +250,20 @@ pilosa-fsck: # Run Pilosa tests inside Docker container docker-test: - docker run --rm -v $(PWD):/go/src/$(CLONE_URL) -w /go/src/$(CLONE_URL) golang:$(GO_VERSION) go test -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) ./... + docker run --rm -v $(PWD):/go/src/$(CLONE_URL) -w /go/src/$(CLONE_URL) golang:$(GO_VERSION) go test -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -timeout $(TEST_TIMEOUT) ./... # Must use bash in order to -o pipefail; otherwise the tee will hide red tests. # run top tests, not subdirs. print summary red/green after. # The \-\-\- FAIL avoids counting the extra two FAIL strings at then bottom of log.topt. topt: mv log.topt.roar log.topt.roar.prev || true - $(eval SHELL:=/bin/bash) set -o pipefail; $(GO) test -v -timeout 60m -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.roar + $(eval SHELL:=/bin/bash) set -o pipefail; $(GO) test -v -timeout $(RACE_TEST_TIMEOUT) -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.roar @echo " log.topt.roar green: \c"; cat log.topt.roar | grep PASS |wc -l @echo " log.topt.roar red: \c"; cat log.topt.roar | grep '\-\-\- FAIL' | wc -l topt-race: mv log.topt.race log.topt.race.prev || true - $(eval SHELL:=/bin/bash) set -o pipefail; CGO_ENABLED=1 $(GO) test -race -timeout 60m -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.race + $(eval SHELL:=/bin/bash) set -o pipefail; CGO_ENABLED=1 $(GO) test -race -timeout $(RACE_TEST_TIMEOUT) -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.race @echo " log.topt.race green: \c"; cat log.topt.race | grep PASS |wc -l @echo " log.topt.race red: \c"; cat log.topt.race | grep '\-\-\- FAIL' | wc -l diff --git a/ctl/backup.go b/ctl/backup.go index 302041dfe..519a604fd 100644 --- a/ctl/backup.go +++ b/ctl/backup.go @@ -60,7 +60,7 @@ func NewBackupCommand(stdin io.Reader, stdout, stderr io.Writer) *BackupCommand CmdIO: pilosa.NewCmdIO(stdin, stdout, stderr), Concurrency: 1, RetryPeriod: time.Minute, - Pprof: "localhost:43809", + Pprof: "localhost:0", } } diff --git a/ctl/restore.go b/ctl/restore.go index 9c12434f8..6cbf700b0 100644 --- a/ctl/restore.go +++ b/ctl/restore.go @@ -56,7 +56,7 @@ func NewRestoreCommand(stdin io.Reader, stdout, stderr io.Writer) *RestoreComman CmdIO: pilosa.NewCmdIO(stdin, stdout, stderr), RetryPeriod: time.Second * 30, Concurrency: 1, - Pprof: "localhost:43809", + Pprof: "localhost:0", } } diff --git a/ctl/util.go b/ctl/util.go index 60ac082c9..2a5611df6 100644 --- a/ctl/util.go +++ b/ctl/util.go @@ -40,7 +40,7 @@ func startProfilingServer(addr string, logger logger.Logger) (close func() error return nil, err } go func() { - logger.Printf("Listening for /debug/pprof/ and /debug/fgprof on '%s'", addr) + logger.Printf("Listening for /debug/pprof/ and /debug/fgprof on '%s'", ln.Addr().String()) logger.Printf("%v", s.Serve(ln)) }() diff --git a/etcd/embed.go b/etcd/embed.go index 0167f6b42..696c85df2 100644 --- a/etcd/embed.go +++ b/etcd/embed.go @@ -187,6 +187,22 @@ func (e *Etcd) Close() error { // New feature: retryClient can also retry on errTimeout. const etcdRetryTimes = 3 +// newClient requests a new client which is different from the one +// passed in. if we've already changed our client (say, because someone +// else already did that) we just return that new one. +func (e *Etcd) newClient(cli *clientv3.Client) *clientv3.Client { + e.cliMu.Lock() + defer e.cliMu.Unlock() + if cli != e.cli { + cli = e.cli + // someone else already reopened. retry. + return cli + } + _ = cli.Close() + e.cli = v3client.New(e.e.Server) + return e.cli +} + func (e *Etcd) retryClient(fn func(cli *clientv3.Client) error) (err error) { e.cliMu.Lock() cli := e.cli @@ -196,29 +212,24 @@ func (e *Etcd) retryClient(fn func(cli *clientv3.Client) error) (err error) { err = fn(cli) switch err { case etcdserver.ErrLeaderChanged: - // we can't do much with an error from closing e.cli at this point, so - // we try again. - e.cliMu.Lock() - if cli != e.cli { - cli = e.cli - e.cliMu.Unlock() - // someone else already reopened. retry. - continue - } - _ = cli.Close() - cli = v3client.New(e.e.Server) - e.cli = cli - e.cliMu.Unlock() + cli = e.newClient(cli) break case nil: return nil default: msg := err.Error() - if !strings.HasPrefix(msg, "etcdserver: request timed out") { + // this shouldn't be necessary, but empirically, we sometimes + // get an error message which has this text, but the error itself + // isn't actually etcdserver.ErrLeaderChanged. + if strings.Contains(msg, "etcdserver: leader changed") { + cli = e.newClient(cli) + break + } + if !strings.Contains(msg, "etcdserver: request timed out") { // not a known error, also not a wrapped timeout return errors.Wrap(err, "non-retryable error") } - fallthrough // treat this as being like a timeout error + fallthrough // treat this as being one of the ErrTimeout derivatives, possibly wrapped. case etcdserver.ErrTimeout, etcdserver.ErrTimeoutDueToLeaderFail, etcdserver.ErrTimeoutDueToConnectionLost, etcdserver.ErrTimeoutLeaderTransfer: // sporadic timeouts are concerning but not necessarily fatal // and can usually be retried. diff --git a/etcd/leasedkv_test.go b/etcd/leasedkv_test.go index 5d8a9444f..0366d7dd2 100644 --- a/etcd/leasedkv_test.go +++ b/etcd/leasedkv_test.go @@ -3,7 +3,8 @@ package etcd import ( "context" - "errors" + "fmt" + "net" "os" "testing" "time" @@ -11,16 +12,48 @@ import ( "github.com/molecula/featurebase/v2/disco" "github.com/molecula/featurebase/v2/logger" "github.com/molecula/featurebase/v2/testhook" + "github.com/pkg/errors" "go.etcd.io/etcd/embed" "go.etcd.io/etcd/etcdserver/api/v3client" + "go.etcd.io/etcd/pkg/types" ) const initVal = "test" const newVal = "newValue" +// listenerWithURL builds a TCP listener and corresponding http://localhost:%d +// URL, and returns those. Identical to the copy in /test, except we can't +// import that because it imports us. +func listenerWithURL() (listener *net.TCPListener, url string, err error) { + l, err := net.Listen("tcp", ":0") + if err != nil { + return listener, url, err + } + listener = l.(*net.TCPListener) + port := listener.Addr().(*net.TCPAddr).Port + url = fmt.Sprintf("http://localhost:%d", port) + return listener, url, err +} + func TestLeasedKv(t *testing.T) { cfg := embed.NewConfig() + clientListener, clientURL, err := listenerWithURL() + if err != nil { + t.Fatal(errors.Wrap(err, "creating client listener")) + } + peerListener, peerURL, err := listenerWithURL() + if err != nil { + t.Fatal(errors.Wrap(err, "creating peer listener")) + } + cfg.LPUrls = types.MustNewURLs([]string{peerURL}) + cfg.LPeerSocket = []*net.TCPListener{peerListener} + cfg.APUrls = types.MustNewURLs([]string{peerURL}) + cfg.LCUrls = types.MustNewURLs([]string{clientURL}) + cfg.LClientSocket = []*net.TCPListener{clientListener} + cfg.ACUrls = types.MustNewURLs([]string{clientURL}) + cfg.InitialCluster = cfg.Name + "=" + peerURL + dir, err := testhook.TempDir(t, "leasedkv-*") if err != nil { t.Fatal(err) diff --git a/rbf/tx_test.go b/rbf/tx_test.go index 14626ce00..6f98a0fb0 100644 --- a/rbf/tx_test.go +++ b/rbf/tx_test.go @@ -140,14 +140,14 @@ func TestTx_CommitRollback(t *testing.T) { select { case <-ch1: t.Fatal("second tx started while first tx active") - case <-time.After(10 * time.Millisecond): + case <-time.After(50 * time.Millisecond): } // Finish first transaction. close(ch0) select { case <-ch1: - case <-time.After(10 * time.Millisecond): + case <-time.After(10 * time.Second): t.Fatal("second tx should have started after first tx closed") } }) diff --git a/test/disco.go b/test/disco.go index 847d78258..7609fea9f 100644 --- a/test/disco.go +++ b/test/disco.go @@ -38,7 +38,7 @@ func (ports *Ports) Close() error { return err3 } -// listenerPortURL builds a TCP listener and corresponding http://localhost:%d +// listenerWithURL builds a TCP listener and corresponding http://localhost:%d // URL, and returns those. func listenerWithURL() (listener *net.TCPListener, url string, err error) { l, err := net.Listen("tcp", ":0")