From 2b4e6d25f575adcc19dfea2ea08ceb3b7f602abc Mon Sep 17 00:00:00 2001 From: "Jason E. Aten" Date: Tue, 20 Oct 2020 09:12:27 -0500 Subject: [PATCH] CI catches red blue-green tests. Qcx write flag - fix a CI/Makefile issue that was hiding red tests in CI. - the testv and testv-race targets now require /bin/bash - In executor.go, the top-level query context Qcx now has a write flag. It will upgrade read-Tx to write-Tx when Store() wraps some inner local-read operations, to avoid deadlocking against its own query. This deadlock happens in TestExecutor_Execute_SetRow/Set_NewRow under rbf_lmdb blue-green testing without the upgrade. --- Makefile | 121 +++------------------------------------------------ dbshard.go | 4 +- executor.go | 1 + txfactory.go | 13 ++++++ 4 files changed, 22 insertions(+), 117 deletions(-) diff --git a/Makefile b/Makefile index e3e29ded7..b1b7d567c 100644 --- a/Makefile +++ b/Makefile @@ -207,131 +207,20 @@ pilosa-fsck: 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) ./... +# 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 - go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.roar + $(eval SHELL:=/bin/bash) set -o pipefail; go test -v -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-bolt: - mv log.topt.bolt log.topt.bolt.prev || true - PILOSA_TXSRC=bolt go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.bolt - @echo " log.topt.bolt green: \c"; cat log.topt.bolt | grep PASS |wc -l - @echo " log.topt.bolt red: \c"; cat log.topt.bolt | grep '\-\-\- FAIL' |wc -l - -topt-bolt-race: - mv log.topt.bolt-race log.topt.bolt-race.prev || true - PILOSA_TXSRC=bolt go test -race -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.bolt-race - @echo " log.topt.bolt-race green: \c"; cat log.topt.bolt-race | grep PASS |wc -l - @echo " log.topt.bolt-race red: \c"; cat log.topt.bolt-race | grep '\-\-\- FAIL' |wc -l - -topt-rbf: - mv log.topt.rbf log.topt.rbf.prev || true - PILOSA_TXSRC=rbf go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.rbf - @echo " log.topt.rbf green: \c"; cat log.topt.rbf | grep PASS |wc -l - @echo " log.topt.rbf red: \c"; cat log.topt.rbf | grep '\-\-\- FAIL' |wc -l - -topt-rbf-race: - mv log.topt.rbf-race log.topt.rbf-race.prev || true - PILOSA_TXSRC=rbf go test -race -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) -timeout 120m 2>&1 | tee log.topt.rbf-race - @echo " log.topt.rbf-race green: \c"; cat log.topt.rbf-race | grep PASS |wc -l - @echo " log.topt.rbf-race red: \c"; cat log.topt.rbf-race | grep '\-\-\- FAIL' |wc -l - -topt-lmdb: - mv log.topt.lmdb log.topt.lmdb.prev || true - PILOSA_TXSRC=lmdb go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.lmdb - @echo " log.topt.lmdb green: \c"; cat log.topt.lmdb | grep PASS |wc -l - @echo " log.topt.lmdb red: \c"; cat log.topt.lmdb | grep '\-\-\- FAIL' |wc -l - -topt-lmdb-race: - mv log.topt.lmdb log.topt.lmdb.prev || true - PILOSA_TXSRC=lmdb go test -race -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.lmdb-race - @echo " log.topt.lmdb-race green: \c"; cat log.topt.lmdb-race | grep PASS |wc -l - @echo " log.topt.lmdb-race red: \c"; cat log.topt.lmdb-race | grep '\-\-\- FAIL' |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 - go test -race -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.race + $(eval SHELL:=/bin/bash) set -o pipefail; go test -race -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 - -# blue-green checks. These run two different storage engines (rbf, roaring, or bolt) -# and compare each transaction for a result. - -bt-rr: # shorthand for bluegreen test with A:bolt; B:roaring - mv log.bt-rr log.bt-rr.prev || true - PILOSA_TXSRC=bolt_roaring go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.bt-rr - @echo " log.bt-rr green: \c"; cat log.bt-rr | grep PASS |wc -l - @echo " log.bt-rr red: \c"; cat log.bt-rr | grep '\-\-\- FAIL' |wc -l - -rr-bt: # bluegreen with A:roaring; B:bolt (B's values are returned). - mv log.bt.roar_bt log.bt.roar_bt.prev || true - PILOSA_TXSRC=roaring_bolt go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.rr-bt - @echo " log.rr-bt green: \c"; cat log.rr-bt | grep PASS |wc -l - @echo " log.rr-bt red: \c"; cat log.rr-bt | grep '\-\-\- FAIL' |wc -l - -rbf-rr: - mv log.rbf-rr log.rbf-rr.prev || true - PILOSA_TXSRC=rbf_roaring go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.rbf-rr - @echo " log.rbf-rr green: \c"; cat log.rbf-rr | grep PASS |wc -l - @echo " log.rbf-rr red: \c"; cat log.rbf-rr | grep '\-\-\- FAIL' |wc -l - -rr-rbf: - mv log.rr-rbf log.rr-rbf.prev || true - PILOSA_TXSRC=roaring_rbf go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.rr-rbf - @echo " log.rr-rbf green: \c"; cat log.rr-rbf | grep PASS |wc -l - @echo " log.rr-rbf red: \c"; cat log.rr-rbf | grep '\-\-\- FAIL' |wc -l - -rbf-bt: - mv log.rbf-bt log.rbf-bt.prev || true - PILOSA_TXSRC=rbf_bolt go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.rbf-bt - @echo " log.rbf-bt green: \c"; cat log.rbf-bt | grep PASS |wc -l - @echo " log.rbf-bt red: \c"; cat log.rbf-bt | grep '\-\-\- FAIL' |wc -l - -bt-rbf: - mv log.bt-rbf log.bt-rbf.prev || true - PILOSA_TXSRC=bolt_rbf go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.bt-rbf - @echo " log.bt-rbf green: \c"; cat log.bt-rbf | grep PASS |wc -l - @echo " log.bt-rbf red: \c"; cat log.bt-rbf | grep '\-\-\- FAIL' |wc -l - -rbf-lm: - mv log.rbf-lm log.rbf-lm.prev || true - PILOSA_TXSRC=rbf_lmdb go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.rbf-lm - @echo " log.rbf-lm green: \c"; cat log.rbf-lm | grep PASS |wc -l - @echo " log.rbf-lm red: \c"; cat log.rbf-lm | grep '\-\-\- FAIL' |wc -l - -lm-rbf: - mv log.lm-rbf log.lm-rbf.prev || true - PILOSA_TXSRC=lmdb_rbf go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.lm-rbf - @echo " log.lm-rbf green: \c"; cat log.lm-rbf | grep PASS |wc -l - @echo " log.lm-rbf red: \c"; cat log.lm-rbf | grep '\-\-\- FAIL' |wc -l - -lm-rr: - mv log.lm-rr log.lm-rr.prev || true - PILOSA_TXSRC=lmdb_roaring go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.lm-rr - @echo " log.lm-rr green: \c"; cat log.lm-rr | grep PASS |wc -l - @echo " log.lm-rr red: \c"; cat log.lm-rr | grep '\-\-\- FAIL' |wc -l - -rr-lm: - mv log.rr-lm log.rr-lm.prev || true - PILOSA_TXSRC=roaring_lmdb go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.rr-lm - @echo " log.rr-lm green: \c"; cat log.rr-lm | grep PASS |wc -l - @echo " log.rr-lm red: \c"; cat log.rr-lm | grep '\-\-\- FAIL' |wc -l - -bt-lm: - mv log.topt.bt-lm log.topt.bt-lm.prev || true - PILOSA_TXSRC=bolt_lmdb go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.bt-lm - @echo " log.topt.bt-lm green: \c"; cat log.topt.bt-lm | grep PASS |wc -l - @echo " log.topt.bt-lm red: \c"; cat log.topt.bt-lm | grep '\-\-\- FAIL' |wc -l - -lm-bt: - mv log.topt.lm-bt log.topt.lm-bt.prev || true - PILOSA_TXSRC=lmdb_bolt go test -v -tags='$(BUILD_TAGS) $(TEST_TAGS)' $(TESTFLAGS) 2>&1 | tee log.topt.lm-bt - @echo " log.topt.lm-bt green: \c"; cat log.topt.lm-bt | grep PASS |wc -l - @echo " log.topt.lm-bt red: \c"; cat log.topt.lm-bt | grep '\-\-\- FAIL' |wc -l - + @echo " log.topt.race red: \c"; cat log.topt.race | grep '\-\-\- FAIL' | wc -l # Run golangci-lint golangci-lint: require-golangci-lint diff --git a/dbshard.go b/dbshard.go index 7db0c4dcd..b4322e1b0 100644 --- a/dbshard.go +++ b/dbshard.go @@ -134,7 +134,7 @@ func (dbs *DBShard) Cleanup(tx Tx) { if dbs == nil { return // some tests are using Tx only, no dbs available. } - //vv("top of DBShard %v Cleanup for tx.Sn = %v; dbs=%p; is 2nd: %v; type='%v'; dbs.stypes='%#v'", dbs.Shard, tx.Sn(), dbs, tx.Type() == dbs.stypes[1], tx.Type(), dbs.stypes) + //vv("gid %v top of DBShard %v Cleanup for tx.Sn = %v; dbs=%p; is 2nd: %v; type='%v'; dbs.stypes='%#v'", curGID(), dbs.Shard, tx.Sn(), dbs, tx.Type() == dbs.stypes[1], tx.Type(), dbs.stypes) if !dbs.hasRoaring { if dbs.isBlueGreen { // only release on the 2nd Tx's cleanup @@ -158,11 +158,13 @@ func (dbs *DBShard) NewTx(write bool, initialIndexName string, o Txo) (tx Tx, er // the Tx finishes. This makes the two Tx in the blue-green Tx atomic. if !dbs.hasRoaring { if write { + //vv("shard %v about to write lock by gid %v; stack =\n%v", dbs.Shard, curGID(), stack()) dbs.mut.Lock() //vv("shard %v was write locked by gid %v; stack =\n%v", dbs.Shard, curGID(), stack()) } else { //vv("shard %v about to be read locked by gid %v; stack=\n%v", dbs.Shard, curGID(), stack()) dbs.mut.RLock() + //vv("shard %v was read locked by gid %v; stack=\n%v", dbs.Shard, curGID(), stack()) } } } diff --git a/executor.go b/executor.go index 08d0feb47..d9129b534 100644 --- a/executor.go +++ b/executor.go @@ -211,6 +211,7 @@ func (e *executor) Execute(ctx context.Context, index string, q *pql.Query, shar // Can't do NewTx() this high up, because we need a specific shard. // So start a ccx with a TxGroup and pass it down. qcx := idx.holder.txf.NewQcx() + qcx.write = needWriteTxn defer qcx.Abort() results, err := e.execute(ctx, qcx, index, q, shards, opt) diff --git a/txfactory.go b/txfactory.go index 36ed6194d..09f80e44a 100644 --- a/txfactory.go +++ b/txfactory.go @@ -131,6 +131,11 @@ type Qcx struct { Direct bool isRoaring bool + + // top-level context is for a write, so re-use a + // writable tx for all reads and writes on each given + // shard + write bool } // Finish commits/rollsback all stored Tx and resets the @@ -177,6 +182,8 @@ func (q *Qcx) reset() { } // NewQcxWithGroup allocates a freshly allocated and empty Grp. +// The top-level executor will set qcx.write = true manually +// if the overall query is a write. func (f *TxFactory) NewQcx() (qcx *Qcx) { qcx = &Qcx{ Grp: f.NewTxGroup(), @@ -240,6 +247,12 @@ func (qcx *Qcx) GetTx(o Txo) (tx Tx, finisher func(perr *error)) { return qcx.Txf.NewTx(o), NoopFinisher } + // qcx.write reflects the top executor determination + // if a write will be done at the end, so we upgrade + // the "local" read Tx to be writes, so that they + // don't deadlock against themselves under blue-green. + o.Write = o.Write || qcx.write + // note: write Tx were re-using Tx across different goroutines, // which lmdb will not be pleased with. For reads this // should be okay, as the docs say