sql: TestDropDatabaseDeleteData failed

[tbg]

It was hanging for 20 minutes in make test here:

	if _, err := sqlDB.Exec(`DROP DATABASE t CASCADE`); err != nil {
		t.Fatal(err)
	}

The only other goroutine I see doing anything interesting is trying to push. Full test output here. This was running basically at 954fe69.

Smells of something KV'ey, since we have made changes to the concurrency handling just now. cc @nvanbenschoten

goroutine 196719 [select]:
github.com/cockroachdb/cockroach/pkg/kv/kvserver/txnwait.(*Queue).MaybeWaitForPush(0xc00602f9a0, 0x4388300, 0xc005ca1e30, 0xc00447e960, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/txnwait/queue.go:513 +0xf95
github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).maybeInterceptReq(0xc003e24d40, 0x4388300, 0xc005ca1e30, 0x0, 0x15f9b12ea10357c4, 0x0, 0x0, 0x0, 0xc003a2e680, 0x1, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/concurrency_manager.go:189 +0xa9
github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).sequenceReqWithGuard(0xc003e24d40, 0x4388300, 0xc005ca1e30, 0xc004da6a80, 0x0, 0x15f9b12ea10357c4, 0x0, 0x0, 0x0, 0xc003a2e680, ...)

....


github.com/cockroachdb/cockroach/pkg/internal/client.(*DB).send(...)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:736
github.com/cockroachdb/cockroach/pkg/internal/client.sendAndFill(0x4388300, 0xc0051b1e60, 0xc00145d5f8, 0xc000f5bb80, 0xc00145dc18, 0xc00145d860)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:672 +0xf7
github.com/cockroachdb/cockroach/pkg/internal/client.(*DB).Run(0xc0004ca800, 0x4388300, 0xc0051b1e60, 0xc000f5bb80, 0x19, 0xc00145d830)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:695 +0x9c
github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).MaybePushTransactions(0xc003945790, 0x4388300, 0xc0051b1e60, 0xc00145dc18, 0x15f9b12ea067963f, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:357 +0x6e9
github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver.(*IntentResolver).PushTransaction(0xc003945790, 0x4388300, 0xc0051b1e60, 0xc004a77278, 0x15f9b12ea067963f, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/intentresolver/intent_resolver.go:267 +0x170
github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).pushLockTxn(0xc0019b43c0, 0x4388300, 0xc0051b1e60, 0xc0017c99e0, 0x15f9b12ea067963f, 0x0, 0x0, 0x0, 0xc000bb4380, 0x1, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:331 +0x132
github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*lockTableWaiterImpl).WaitOn(0xc0019b43c0, 0x4388300, 0xc0051b1e60, 0xc0017c99e0, 0x15f9b12ea067963f, 0x0, 0x0, 0x0, 0xc000bb4380, 0x1, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/lock_table_waiter.go:270 +0x24e
github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).sequenceReqWithGuard(0xc003bf9800, 0x4388300, 0xc0051b1e60, 0xc00081a230, 0xc0017c9b00, 0x15f9b12ea067963f, 0x0, 0x0, 0x0, 0xc000bb4380, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/concurrency_manager.go:170 +0x43e
github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency.(*managerImpl).SequenceReq(0xc003bf9800, 0x4388300, 0xc0051b1e60, 0xc00081a230, 0xc0017c9b00, 0x15f9b12ea067963f, 0x0, 0x0, 0x0, 0xc000bb4380, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/concurrency/concurrency_manager.go:121 +0xfb
github.com/cockroachdb/cockroach/pkg/kv/kvserver.(*Replica).executeBatchWithConcurrencyRetries(0xc003c28300, 0x4388300, 0xc0051b1e60, 0xc000bb4500, 0x3cf2c00, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/kv/kvserver/replica_send.go:192 +0x270

...


github.com/cockroachdb/cockroach/pkg/internal/client.(*Txn).Run(0xc0078b6bd0, 0x4388300, 0xc0051b0300, 0xc000fa7180, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/txn.go:538 +0xfa
github.com/cockroachdb/cockroach/pkg/internal/client.(*Txn).Get(0xc0078b6bd0, 0x4388300, 0xc0051b0300, 0x391f980, 0xc000232e00, 0xc001462810, 0x1, 0x1, 0xc0014627f0, 0xc000435bb0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/txn.go:348 +0xbc
github.com/cockroachdb/cockroach/pkg/sql/sqlbase.LookupObjectID(0x4388300, 0xc0051b0300, 0xc0078b6bd0, 0x0, 0x633c274, 0x1, 0xc0032e0c38, 0x43dcc60, 0xc0032e0ca0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/sqlbase/namespace.go:165 +0x1cb
github.com/cockroachdb/cockroach/pkg/sql/sqlbase.LookupDatabaseID(...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/sqlbase/namespace.go:215
github.com/cockroachdb/cockroach/pkg/sql.getDatabaseID(0x4388300, 0xc0051b0300, 0xc0078b6bd0, 0x633c274, 0x1, 0x0, 0x0, 0xc001462968, 0x76a18c)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/database.go:82 +0x7e
github.com/cockroachdb/cockroach/pkg/sql.(*databaseCache).getDatabaseID.func1(0x4388300, 0xc0051b0300, 0xc0078b6bd0, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/database.go:226 +0x62
github.com/cockroachdb/cockroach/pkg/internal/client.(*DB).Txn.func1(0x4388300, 0xc0051b0300, 0xc0078b6bd0, 0x440cc20, 0xc0032e0900)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:717 +0x43
github.com/cockroachdb/cockroach/pkg/internal/client.(*Txn).exec(0xc0078b6bd0, 0x4388300, 0xc0051b0300, 0xc001beacf0, 0xc0078b6bd0, 0x28)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/txn.go:759 +0xd9
github.com/cockroachdb/cockroach/pkg/internal/client.(*DB).Txn(0xc0004ca800, 0x4388300, 0xc0051b0300, 0xc0051b1ad0, 0x1, 0xc0051b1ad0)
	/go/src/github.com/cockroachdb/cockroach/pkg/internal/client/db.go:716 +0xd1
github.com/cockroachdb/cockroach/pkg/sql.(*databaseCache).getDatabaseID(0xc005211110, 0x4388300, 0xc0051b0300, 0xc001462e28, 0x633c274, 0x1, 0x0, 0xc004468d80, 0x0, 0xc001462e90)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/database.go:224 +0x19d
github.com/cockroachdb/cockroach/pkg/sql.(*TableCollection).getMutableTableDescriptor(0xc0007ae228, 0x4388300, 0xc0051b0300, 0xc003bedc20, 0xc0007ae8c0, 0x10000, 0x0, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/table.go:204 +0x49b
github.com/cockroachdb/cockroach/pkg/sql.(*CachedPhysicalAccessor).GetObjectDesc(0xc008713f20, 0x4388300, 0xc0051b0300, 0xc003bedc20, 0xc000351500, 0xc0007ae8c0, 0x10000, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/physical_schema_accessors.go:302 +0xa2
github.com/cockroachdb/cockroach/pkg/sql.(*LogicalSchemaAccessor).GetObjectDesc(0xc008713f60, 0x4388300, 0xc0051b0300, 0xc003bedc20, 0xc000351500, 0xc0007ae8c0, 0x10000, 0x6, 0x101, 0xc001463bb8, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/logical_schema_accessors.go:100 +0x619
github.com/cockroachdb/cockroach/pkg/sql.(*planner).LookupObject(0xc0007ae3e8, 0x4388300, 0xc0051b0300, 0x10000, 0x633c274, 0x1, 0x3b6bc37, 0x6, 0xc0055445fd, 0x2, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/resolver.go:300 +0x19d
github.com/cockroachdb/cockroach/pkg/sql/sem/tree.(*TableName).ResolveExisting(0xc004a77110, 0x4388300, 0xc0051b0300, 0x7f22e774dbc8, 0xc0007ae3e8, 0x10000, 0x3b72528, 0x9, 0xc001deacf0, 0x1, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/sem/tree/name_resolution.go:287 +0x7c9
github.com/cockroachdb/cockroach/pkg/sql.resolveExistingObjectImpl(0x4388300, 0xc0051b0300, 0x43ddf20, 0xc0007ae3e8, 0xc004a77110, 0x7f0000010000, 0x0, 0x20, 0xc000232dc0, 0xc008713f60, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/resolver.go:136 +0x176
github.com/cockroachdb/cockroach/pkg/sql.ResolveMutableExistingObject(0x4388300, 0xc0051b0300, 0x43ddf20, 0xc0007ae3e8, 0xc004a77110, 0xc001463e00, 0x0, 0x20, 0x37bcc80, 0x62f9d01)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/resolver.go:122 +0x7e
github.com/cockroachdb/cockroach/pkg/sql.(*planner).ResolveMutableTableDescriptor(...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/resolver.go:205
github.com/cockroachdb/cockroach/pkg/sql.(*planner).prepareDrop(0xc0007ae3e8, 0x4388300, 0xc0051b0300, 0xc004a77110, 0xc004a77000, 0x0, 0x2, 0x2, 0x1)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/drop_table.go:174 +0x75
github.com/cockroachdb/cockroach/pkg/sql.(*planner).DropDatabase(0xc0007ae3e8, 0x4388300, 0xc0051b0300, 0xc007dfbb20, 0xc001590e10, 0xc0043f1540, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/drop_database.go:102 +0x4ee
github.com/cockroachdb/cockroach/pkg/sql.buildOpaque(0x4388300, 0xc0051b0300, 0xc0007ae3f8, 0xc0007ae4c8, 0x43a0e00, 0xc007dfbb20, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/opaque.go:81 +0x1a84
github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder.(*Builder).tryBuildOpaque(0xc00439a180, 0x43a0e00, 0xc007dfbb20, 0xc00326fc00, 0xc0007ae4c8)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder/opaque.go:70 +0x131
github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder.(*Builder).buildStmt(0xc00439a180, 0x43a0e00, 0xc007dfbb20, 0x0, 0x0, 0x0, 0xc00326fc00, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder/builder.go:322 +0x2f7
github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder.(*Builder).buildStmtAtRoot(0xc00439a180, 0x43a0e00, 0xc007dfbb20, 0x0, 0x0, 0x0, 0xc00326fc00, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder/builder.go:217 +0xe3
github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder.(*Builder).Build(0xc00439a180, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/opt/optbuilder/builder.go:188 +0x172
github.com/cockroachdb/cockroach/pkg/sql.(*optPlanningCtx).buildExecMemo(0xc0007aead0, 0x4388300, 0xc0051b0300, 0x3a04280, 0x43f24a0, 0x660e0d0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/plan_opt.go:421 +0x14f
github.com/cockroachdb/cockroach/pkg/sql.(*planner).makeOptimizerPlan(0xc0007ae3e8, 0x4388300, 0xc0051b0300, 0xc0014646c8, 0x726776)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/plan_opt.go:159 +0x7d
github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).makeExecPlan(0xc0007ae000, 0x4388300, 0xc0051b0300, 0xc0007ae3e8, 0x1, 0xc001464790)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:772 +0xc2
github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).dispatchToExecutionEngine(0xc0007ae000, 0x4388300, 0xc0051b0300, 0xc0007ae3e8, 0x7f22e7682cf0, 0xc002fe1c80, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:665 +0xf9
github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).execStmtInOpenState(0xc0007ae000, 0x4388300, 0xc0051b0300, 0x43a0e00, 0xc007dfbb20, 0xc0036721ad, 0x17, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:455 +0xac8
github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).execStmt(0xc0007ae000, 0x4388300, 0xc0051b0300, 0x43a0e00, 0xc007dfbb20, 0xc0036721ad, 0x17, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:117 +0x4f6
github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).execCmd(0xc0007ae000, 0x4388240, 0xc006199440, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1396 +0x1aa8
github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).run(0xc0007ae000, 0x4388240, 0xc002ec4b40, 0xc004874e80, 0x5400, 0x15000, 0xc004874f18, 0xc001deac50, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1325 +0x1f2
github.com/cockroachdb/cockroach/pkg/sql.(*Server).ServeConn(0xc0038a6680, 0x4388240, 0xc002ec4b40, 0xc0007ae000, 0x5400, 0x15000, 0xc004874f18, 0xc001deac50, 0x0, 0x0)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:479 +0x104
github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*conn).processCommandsAsync.func1(0xc0035dc589, 0xc008713e60, 0x4388240, 0xc002ec4b40, 0xc001deac50, 0xc0038a6680, 0xc002fe1600, 0x439f7c0, 0xc008713e40, 0xc001d52420, ...)
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:566 +0x2e8
created by github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*conn).processCommandsAsync
	/go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:498 +0x17e

[tbg]

Oh I totally missed these messages:

W200306 10:46:57.827002 196719 kv/kvserver/txnwait/queue.go:517 [n1,s1,r6/1:/Table/{SystemCon…-11}] pusher f713d97f: have been waiting 60.00s for pushee 2be15fb8

That confirms what I suspected, though I don't understand what's going on.

[tbg]

I guess if we also had a "transaction X has been active for ..." message (at least in tests), we could have an easier time here. We could print that message from the heartbeat loop (with a stacktrace from the Send call that started the heartbeat loop, which will give us a good idea of who's running the txn).