Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

sql/pgwire: TestConnResultsBufferSize failed #57162

Closed
cockroach-teamcity opened this issue Nov 26, 2020 · 5 comments · Fixed by #57222
Closed

sql/pgwire: TestConnResultsBufferSize failed #57162

cockroach-teamcity opened this issue Nov 26, 2020 · 5 comments · Fixed by #57222
Assignees
@knz
Labels
branch-master Failures and bugs on the master branch. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.

Comments

@cockroach-teamcity
Copy link
Member

(sql/pgwire).TestConnResultsBufferSize failed on master@fe5da5c2df069dc7f820f5c3e2f3e03f1cb7b661:

  github.com/cockroachdb/cockroach/pkg/sql.cleanupAndFinishOnError()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_fsm.go:472 +0x127
  github.com/cockroachdb/cockroach/pkg/util/fsm.Transitions.apply()
      /go/src/github.com/cockroachdb/cockroach/pkg/util/fsm/fsm.go:106 +0x203
  github.com/cockroachdb/cockroach/pkg/util/fsm.(*Machine).ApplyWithPayload()
      /go/src/github.com/cockroachdb/cockroach/pkg/util/fsm/fsm.go:135 +0x2db
  github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).txnStateTransitionsApplyWrapper()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:2215 +0xd2
  github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).execCmd()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1591 +0xe64
  github.com/cockroachdb/cockroach/pkg/sql.(*connExecutor).run()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1372 +0x40c
  github.com/cockroachdb/cockroach/pkg/sql.(*Server).ServeConn()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:481 +0x139
  github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*conn).processCommandsAsync.func1()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:626 +0x3a4

Goroutine 177 (running) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1168 +0x5bb
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:1439 +0xa6
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1123 +0x202
  testing.runTests()
      /usr/local/go/src/testing/testing.go:1437 +0x612
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1345 +0x3b3
  github.com/cockroachdb/cockroach/pkg/sql/pgwire_test.TestMain()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/main_test.go:33 +0xdb
  main.main()
      _testmain.go:171 +0x271

Goroutine 242 (running) created at:
  github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*conn).processCommandsAsync()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:554 +0x1f7
  github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*conn).serveImpl()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:280 +0x8e4
  github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*Server).serveConn()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:154 +0x30a
  github.com/cockroachdb/cockroach/pkg/sql/pgwire.(*Server).ServeConn()
      /go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/server.go:589 +0xa84
  github.com/cockroachdb/cockroach/pkg/server.(*sqlServer).startServeSQL.func1.1()
      /go/src/github.com/cockroachdb/cockroach/pkg/server/server.go:1964 +0x1a4
  github.com/cockroachdb/cockroach/pkg/util/netutil.(*Server).ServeWith.func1()
      /go/src/github.com/cockroachdb/cockroach/pkg/util/netutil/net.go:148 +0x11d
==================
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestConnResultsBufferSize324537989
    testing.go:1038: race detected during execution of test
--- FAIL: TestConnResultsBufferSize (0.73s)
More

Parameters:

  • TAGS=
  • GOFLAGS=-race -parallel=4
make stressrace TESTS=TestConnResultsBufferSize PKG=./pkg/sql/pgwire TESTTIMEOUT=5m STRESSFLAGS='-timeout 5m' 2>&1

See this test on roachdash
powered by pkg/cmd/internal/issues
@cockroach-teamcity cockroach-teamcity added branch-master Failures and bugs on the master branch. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot. labels Nov 26, 2020
@knz knz unassigned tbg Nov 26, 2020
@knz
Copy link
Contributor

knz commented Nov 26, 2020

cc @otan for triage

@otan
Copy link
Contributor

otan commented Nov 26, 2020

this seems like a race with the log package rather than the test itself - a defer of defer log.Scope(t).Close(t) races with closing a kv transaction somewhere else. i feel as if this is a problem with the log package not locking before accepting final logging from the DB.

[08:07:21][Step 2/2]   sync/atomic.StoreInt32()
[08:07:21][Step 2/2]       /usr/local/go/src/runtime/race_amd64.s:229 +0xb
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/util/log/logpb.(*Severity).SetValue()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/util/log/logpb/severity.go:26 +0xc4
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/util/log.(*TestLogScope).restoreStderrThreshold()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/util/log/test_log_scope.go:173 +0x8b
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/util/log.(*TestLogScope).Close()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/util/log/test_log_scope.go:189 +0x8a
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/sql/pgwire.TestConnResultsBufferSize()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn_test.go:1203 +0x136d


[08:07:21][Step 2/2] Previous read at 0x00000a229310 by goroutine 242:
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/util/log.(*loggerT).outputLogEntry()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/util/log/clog.go:276 +0x1e8
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/util/log.addStructured()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/util/log/structured.go:48 +0x19b
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/util/log.logDepth()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/util/log/log.go:48 +0x297
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/util/log.Warningf()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/util/log/log_channels_generated.go:65 +0x237
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/kv.(*Txn).CleanupOnError()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/kv/txn.go:618 +0x1f0
[08:07:21][Step 2/2]   github.com/cockroachdb/cockroach/pkg/sql.cleanupAndFinishOnError()
[08:07:21][Step 2/2]       /go/src/github.com/cockroachdb/cockroach/pkg/sql/conn_fsm.go:472 +0x127

@otan otan mentioned this issue Nov 26, 2020
Closed
@otan
Copy link
Contributor

otan commented Nov 26, 2020

i think it's #57000 cc @knz

@irfansharif
Copy link
Contributor

Confirmed it is.

@irfansharif irfansharif mentioned this issue Nov 26, 2020
Merged
craig bot pushed a commit that referenced this issue Nov 26, 2020
@irfansharif
Merge #57178
87cf74e 
57178: Revert "util/log: more misc cleanups" r=irfansharif a=irfansharif

This reverts #57000, which introduced a race to crdb. Was able to
reproduce it using

  make stressrace PKG=./pkg/sql/pgwire TESTS=TestConnResultsBufferSize

The buggy commit in question appears to be ffd7f68.
Touches #57162 and #57161.

Release note: None

Co-authored-by: irfan sharif <[email protected]>
@otan
Copy link
Contributor

otan commented Nov 26, 2020

Resolves by #57178

@otan otan closed this as completed Nov 26, 2020
@knz knz reopened this Nov 30, 2020
@knz knz mentioned this issue Nov 30, 2020
Merged
@craig craig bot closed this as completed in 13ce0e8 Nov 30, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@knz knz

Labels
branch-master Failures and bugs on the master branch. C-test-failure Broken test (automatically or manually discovered). O-robot Originated from a bot.
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Revert "Revert "util/log: more misc cleanups"" knz/cockroach
5 participants
@knz @otan @tbg @irfansharif @cockroach-teamcity