Skip to content

Commit

Permalink
Merge #64490
Browse files Browse the repository at this point in the history
64490: issues: improve random syntax test crash reports r=mgartner a=mgartner

Crashes during random syntax tests now report more useful information to
the issue including the error message, the SQL that produced the error,
and the database schema.

The report will be formatted as:

> Random syntax error:
>
> ```
>     rsg_test.go:755: Crash detected: server panic: pq: internal error: something bad
> ```
> Query:
>
> ```
> 		SELECT
> 			foo
> 		FROM
> 			bar
> 		LIMIT
> 			33:::INT8;
> ```
> Schema:
>
> ```
>     rsg_test.go:575: To reproduce, use schema:
>     rsg_test.go:577:
>         	CREATE TABLE table1 (col1_0 BOOL);
>         ;
>     rsg_test.go:577:
>
>         CREATE TYPE greeting AS ENUM ('hello', 'howdy', 'hi', 'good day', 'morning');
>         ;
>     rsg_test.go:579:
>     rsg_test.go:580: -- test log scope end --
> test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestRandomSyntaxSQLSmith460792454
> --- FAIL: TestRandomSyntaxSQLSmith (300.69s)
> ```

Release note: None

Co-authored-by: Marcus Gartner <[email protected]>
  • Loading branch information
craig[bot] and mgartner committed May 5, 2021
2 parents 4ee093c + dd708c7 commit 43a079d
Show file tree
Hide file tree
Showing 9 changed files with 400 additions and 9 deletions.
62 changes: 55 additions & 7 deletions pkg/cmd/internal/issues/condense.go
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,18 @@ import (
"strings"
)

func firstNlines(input string, n int) string {
if input == "" {
return ""
}
pos := 0
for pos < len(input) && n > 0 {
n--
pos += strings.Index(input[pos:], "\n") + 1
}
return input[:pos]
}

func lastNlines(input string, n int) string {
if input == "" {
return ""
Expand All @@ -34,30 +46,61 @@ type FatalOrPanic struct {
FirstStack string // the first stack, i.e. the goroutine relevant to error
}

// RSGCrash contains information about a crash during random syntax tests
// obtained from a test log.
type RSGCrash struct {
Error, // the error message from the crash
Query, // the query that induced the crash
Schema string // the schema that the crash was induced with
}

// A CondensedMessage is a test log output garnished with useful helper methods
// that extract concise information for seamless debugging.
type CondensedMessage string

var panicRE = regexp.MustCompile(`(?ms)^(panic:.*?\n)(goroutine \d+.*?\n)\n`)
var fatalRE = regexp.MustCompile(`(?ms)(^F\d{6}.*?\n)(goroutine \d+.*?\n)\n`)

// Note: These must be kept in-sync with the crash output of
// tests_test.testRandomSyntax.
var crasherRE = regexp.MustCompile(`(?s)( *rsg_test.go:\d{3}: Crash detected:.*?\n)(.*?;\n)`)
var reproRE = regexp.MustCompile(`(?s)( *rsg_test.go:\d{3}: To reproduce, use schema:)`)

// FatalOrPanic constructs a FatalOrPanic. If no fatal or panic occurred in the
// test, the zero value is returned.
func (s CondensedMessage) FatalOrPanic(numPrecedingLines int) FatalOrPanic {
// test, ok=false is returned.
func (s CondensedMessage) FatalOrPanic(numPrecedingLines int) (fop FatalOrPanic, ok bool) {
ss := string(s)
var fop FatalOrPanic
add := func(matches []int) {
fop.LastLines = lastNlines(ss[:matches[2]], numPrecedingLines)
fop.Error += ss[matches[2]:matches[3]]
fop.FirstStack += ss[matches[4]:matches[5]]
ok = true
}
if sl := panicRE.FindStringSubmatchIndex(ss); sl != nil {
add(sl)
}
if sl := fatalRE.FindStringSubmatchIndex(ss); sl != nil {
add(sl)
}
return fop
return fop, ok
}

// RSGCrash constructs an RSGCrash. The query and reproduction SQL are limited
// to the first lineLimit lines. If no random syntax test crash occurred in the
// test, ok=false is returned.
func (s CondensedMessage) RSGCrash(lineLimit int) (c RSGCrash, ok bool) {
ss := string(s)
if cm := crasherRE.FindStringSubmatchIndex(ss); cm != nil {
c.Error = ss[cm[2]:cm[3]]
c.Query = firstNlines(ss[cm[4]:cm[5]], lineLimit)
if rm := reproRE.FindStringSubmatchIndex(ss); rm != nil {
// The "To reproduce" log is always near the end of the log file, so
// collect all lines after the first match position.
c.Schema = firstNlines(ss[rm[2]:], lineLimit)
}
return c, true
}
return RSGCrash{}, false
}

// String calls .Digest(30).
Expand All @@ -66,12 +109,17 @@ func (s CondensedMessage) String() string {
}

// Digest returns the last n lines of the test log. If a panic or fatal error
// occurred, it instead returns the last n lines preceding that event, the
// event itself, and the first stack trace.
// occurred, it instead returns the last n lines preceding that event, the event
// itself, and the first stack trace. If a crash occurred during a random syntax
// test, it returns the error and up to n lines of both the query that caused
// the crash and the database schema.
func (s CondensedMessage) Digest(n int) string {
if fop := s.FatalOrPanic(n); fop.Error != "" {
if fop, ok := s.FatalOrPanic(n); ok {
return fop.LastLines + fop.Error + fop.FirstStack
}
if c, ok := s.RSGCrash(n); ok {
return c.Error + c.Query + c.Schema
}
// TODO(tbg): consider adding some smarts around the FAIL line here to handle
// it similarly to FatalOrPanic (but without a stack trace).
return lastNlines(string(s), n)
Expand Down
30 changes: 30 additions & 0 deletions pkg/cmd/internal/issues/condense_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -77,8 +77,28 @@ created by main.main
exit status 2
`

const rsgCrash = ` rsg_test.go:755: Crash detected: server panic: pq: internal error: something bad
SELECT
foo
FROM
bar
LIMIT
33:::INT8;
`

const rsgRepro = ` rsg_test.go:575: To reproduce, use schema:
rsg_test.go:577:
CREATE TABLE table1 (col1_0 BOOL);
;
rsg_test.go:577:
CREATE TYPE greeting AS ENUM ('hello', 'hi');
;
rsg_test.go:579:
`

const panic5Lines = fiveLines + messagePanic + firstStack + restStack
const fatal5Lines = fiveLines + messageFatal + firstStack + restStack
const crashAndRepro = fiveLines + rsgCrash + fiveLines + rsgRepro

var errorCases = []condenseTestCase{
{
Expand Down Expand Up @@ -109,6 +129,16 @@ var errorCases = []condenseTestCase{
messageFatal + firstStack,
0,
},
{
crashAndRepro,
rsgCrash + rsgRepro,
100,
},
{
crashAndRepro,
" rsg_test.go:755: Crash detected: server panic: pq: internal error: something bad\n",
0,
},
}

var lineCases = []condenseTestCase{
Expand Down
11 changes: 10 additions & 1 deletion pkg/cmd/internal/issues/formatter_unit.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ var UnitTestFormatter = IssueFormatter{
r.Escaped(`:
`)
if fop := data.CondensedMessage.FatalOrPanic(50); fop != (FatalOrPanic{}) {
if fop, ok := data.CondensedMessage.FatalOrPanic(50); ok {
if fop.Error != "" {
r.Escaped("Fatal error:")
r.CodeBlock("", fop.Error)
Expand All @@ -54,6 +54,15 @@ var UnitTestFormatter = IssueFormatter{
r.Collapsed("Log preceding fatal error", func() {
r.CodeBlock("", fop.LastLines)
})
} else if rsgCrash, ok := data.CondensedMessage.RSGCrash(100); ok {
r.Escaped("Random syntax error:")
r.CodeBlock("", rsgCrash.Error)
r.Escaped("Query:")
r.CodeBlock("", rsgCrash.Query)
if rsgCrash.Schema != "" {
r.Escaped("Schema:")
r.CodeBlock("", rsgCrash.Schema)
}
} else {
r.CodeBlock("", data.CondensedMessage.Digest(50))
}
Expand Down
31 changes: 31 additions & 0 deletions pkg/cmd/internal/issues/issues_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -111,6 +111,37 @@ goroutine 13:
author: "bran",
reproCmd: "",
},
{
name: "rsg-crash",
packageName: "github.com/cockroachdb/cockroach/pkg/sql/tests",
testName: "TestRandomSyntaxSQLSmith",
message: `logging something
rsg_test.go:755: Crash detected: server panic: pq: internal error: something bad
SELECT
foo
FROM
bar
LIMIT
33:::INT8;
Stack trace:
rsg_test.go:764: 266003 executions, 235459 successful
rsg_test.go:575: To reproduce, use schema:
rsg_test.go:577:
CREATE TABLE table1 (col1_0 BOOL);
;
rsg_test.go:577:
CREATE TYPE greeting AS ENUM ('hello', 'howdy', 'hi', 'good day', 'morning');
;
rsg_test.go:579:
rsg_test.go:580: -- test log scope end --
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestRandomSyntaxSQLSmith460792454
--- FAIL: TestRandomSyntaxSQLSmith (300.69s)
`,
author: "bran",
reproCmd: "make test TESTS=TestRandomSyntaxSQLSmith PKG=./pkg/sql/tests 2>&1",
},
}

const (
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,68 @@
listCommits owner=cockroachdb repo=cockroach github.CommitsListOptions{SHA:"", Path:"", Author:"bran", Since:time.Time{wall:, ext:}, Until:time.Time{wall:, ext:}, ListOptions:github.ListOptions{Page:0, PerPage:1}}
searchIssue repo:"cockroach" user:"cockroachdb" is:issue is:open in:title label:"C-test-failure" sort:created-desc "sql/tests: TestRandomSyntaxSQLSmith failed" label:branch-release-0.1: [github.Issue{Number:30, Title:"boom", Labels:[github.Label{URL:"fake", Name:"C-test-failure"} github.Label{URL:"fake", Name:"O-robot"} github.Label{URL:"fake", Name:"release-0.1"}]}]
searchIssue repo:"cockroach" user:"cockroachdb" is:issue is:open in:title label:"C-test-failure" sort:created-desc "sql/tests: TestRandomSyntaxSQLSmith failed" -label:branch-release-0.1: [github.Issue{Number:31, Title:"boom related", Labels:[github.Label{URL:"fake", Name:"C-test-failure"} github.Label{URL:"fake", Name:"O-robot"} github.Label{URL:"fake", Name:"release-0.2"}]}]
createComment owner=cockroachdb repo=cockroach issue=30:

sql/tests.TestRandomSyntaxSQLSmith [failed](https://teamcity.example.com/viewLog.html?buildId=8008135&tab=buildLog) on release-0.1 @ [abcd123](https://github.com/cockroachdb/cockroach/commits/abcd123):

Random syntax error:

```
rsg_test.go:755: Crash detected: server panic: pq: internal error: something bad
```
Query:

```
SELECT
foo
FROM
bar
LIMIT
33:::INT8;
```
Schema:

```
rsg_test.go:575: To reproduce, use schema:
rsg_test.go:577:
CREATE TABLE table1 (col1_0 BOOL);
;
rsg_test.go:577:

CREATE TYPE greeting AS ENUM ('hello', 'howdy', 'hi', 'good day', 'morning');
;
rsg_test.go:579:
rsg_test.go:580: -- test log scope end --
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestRandomSyntaxSQLSmith460792454
--- FAIL: TestRandomSyntaxSQLSmith (300.69s)
```
<details><summary>Reproduce</summary>
<p>
<p>To reproduce, try:

```bash
make test TESTS=TestRandomSyntaxSQLSmith PKG=./pkg/sql/tests 2>&1
```
</p>
<p>Parameters in this failure:

- TAGS=deadlock

- GOFLAGS=race
</p>
</p>
</details>
<details><summary>Same failure on other branches</summary>
<p>

- #31 boom related [C-test-failure O-robot release-0.2]
</p>
</details>
/cc @hodor
<sub>

[This test on roachdash](https://roachdash.crdb.dev/?filter=status:open%20t:.*TestRandomSyntaxSQLSmith.*&sort=title+created&display=lastcommented+project) | [Improve this report!](https://github.com/cockroachdb/cockroach/tree/master/pkg/cmd/internal/issues)
</sub>


Rendered: https://github.com/cockroachdb/cockroach/issues/new?body=sql%2Ftests.TestRandomSyntaxSQLSmith+%5Bfailed%5D%28https%3A%2F%2Fteamcity.example.com%2FviewLog.html%3FbuildId%3D8008135%26tab%3DbuildLog%29+on+release-0.1+%40+%5Babcd123%5D%28https%3A%2F%2Fgithub.com%2Fcockroachdb%2Fcockroach%2Fcommits%2Fabcd123%29%3A%0A%0ARandom+syntax+error%3A%0A%0A%60%60%60%0A++++rsg_test.go%3A755%3A+Crash+detected%3A+server+panic%3A+pq%3A+internal+error%3A+something+bad%0A%60%60%60%0AQuery%3A%0A%0A%60%60%60%0A%09%09SELECT%0A%09%09%09foo%0A%09%09FROM%0A%09%09%09bar%0A%09%09LIMIT%0A%09%09%0933%3A%3A%3AINT8%3B%0A%60%60%60%0ASchema%3A%0A%0A%60%60%60%0A++++rsg_test.go%3A575%3A+To+reproduce%2C+use+schema%3A%0A++++rsg_test.go%3A577%3A+%0A++++++++%09CREATE+TABLE+table1+%28col1_0+BOOL%29%3B%0A++++++++%3B%0A++++rsg_test.go%3A577%3A+%0A++++++++%0A++++++++CREATE+TYPE+greeting+AS+ENUM+%28%27hello%27%2C+%27howdy%27%2C+%27hi%27%2C+%27good+day%27%2C+%27morning%27%29%3B%0A++++++++%3B%0A++++rsg_test.go%3A579%3A+%0A++++rsg_test.go%3A580%3A+--+test+log+scope+end+--%0Atest+logs+left+over+in%3A+%2Fgo%2Fsrc%2Fgithub.com%2Fcockroachdb%2Fcockroach%2Fartifacts%2FlogTestRandomSyntaxSQLSmith460792454%0A---+FAIL%3A+TestRandomSyntaxSQLSmith+%28300.69s%29%0A%60%60%60%0A%3Cdetails%3E%3Csummary%3EReproduce%3C%2Fsummary%3E%0A%3Cp%3E%0A%3Cp%3ETo+reproduce%2C+try%3A%0A%0A%60%60%60bash%0Amake+test+TESTS%3DTestRandomSyntaxSQLSmith+PKG%3D.%2Fpkg%2Fsql%2Ftests+2%3E%261%0A%60%60%60%0A%3C%2Fp%3E%0A%3Cp%3EParameters+in+this+failure%3A%0A%0A-+TAGS%3Ddeadlock%0A%0A-+GOFLAGS%3Drace%0A%3C%2Fp%3E%0A%3C%2Fp%3E%0A%3C%2Fdetails%3E%0A%3Cdetails%3E%3Csummary%3ESame+failure+on+other+branches%3C%2Fsummary%3E%0A%3Cp%3E%0A%0A-+%2331+boom+related+%5BC-test-failure+O-robot+release-0.2%5D%0A%3C%2Fp%3E%0A%3C%2Fdetails%3E%0A%2Fcc+%40hodor%0A%3Csub%3E%0A%0A%5BThis+test+on+roachdash%5D%28https%3A%2F%2Froachdash.crdb.dev%2F%3Ffilter%3Dstatus%3Aopen%2520t%3A.%2ATestRandomSyntaxSQLSmith.%2A%26sort%3Dtitle%2Bcreated%26display%3Dlastcommented%2Bproject%29+%7C+%5BImprove+this+report%21%5D%28https%3A%2F%2Fgithub.com%2Fcockroachdb%2Fcockroach%2Ftree%2Fmaster%2Fpkg%2Fcmd%2Finternal%2Fissues%29%0A%3C%2Fsub%3E%0A&title=%3Ccomment%3E
62 changes: 62 additions & 0 deletions pkg/cmd/internal/issues/testdata/post/rsg-crash-matching-issue.txt
Original file line number Diff line number Diff line change
@@ -0,0 +1,62 @@
listCommits owner=cockroachdb repo=cockroach github.CommitsListOptions{SHA:"", Path:"", Author:"bran", Since:time.Time{wall:, ext:}, Until:time.Time{wall:, ext:}, ListOptions:github.ListOptions{Page:0, PerPage:1}}
searchIssue repo:"cockroach" user:"cockroachdb" is:issue is:open in:title label:"C-test-failure" sort:created-desc "sql/tests: TestRandomSyntaxSQLSmith failed" label:branch-release-0.1: [github.Issue{Number:30, Title:"boom", Labels:[github.Label{URL:"fake", Name:"C-test-failure"} github.Label{URL:"fake", Name:"O-robot"} github.Label{URL:"fake", Name:"release-0.1"}]}]
searchIssue repo:"cockroach" user:"cockroachdb" is:issue is:open in:title label:"C-test-failure" sort:created-desc "sql/tests: TestRandomSyntaxSQLSmith failed" -label:branch-release-0.1: []
createComment owner=cockroachdb repo=cockroach issue=30:

sql/tests.TestRandomSyntaxSQLSmith [failed](https://teamcity.example.com/viewLog.html?buildId=8008135&tab=buildLog) on release-0.1 @ [abcd123](https://github.com/cockroachdb/cockroach/commits/abcd123):

Random syntax error:

```
rsg_test.go:755: Crash detected: server panic: pq: internal error: something bad
```
Query:

```
SELECT
foo
FROM
bar
LIMIT
33:::INT8;
```
Schema:

```
rsg_test.go:575: To reproduce, use schema:
rsg_test.go:577:
CREATE TABLE table1 (col1_0 BOOL);
;
rsg_test.go:577:

CREATE TYPE greeting AS ENUM ('hello', 'howdy', 'hi', 'good day', 'morning');
;
rsg_test.go:579:
rsg_test.go:580: -- test log scope end --
test logs left over in: /go/src/github.com/cockroachdb/cockroach/artifacts/logTestRandomSyntaxSQLSmith460792454
--- FAIL: TestRandomSyntaxSQLSmith (300.69s)
```
<details><summary>Reproduce</summary>
<p>
<p>To reproduce, try:

```bash
make test TESTS=TestRandomSyntaxSQLSmith PKG=./pkg/sql/tests 2>&1
```
</p>
<p>Parameters in this failure:

- TAGS=deadlock

- GOFLAGS=race
</p>
</p>
</details>
/cc @hodor
<sub>

[This test on roachdash](https://roachdash.crdb.dev/?filter=status:open%20t:.*TestRandomSyntaxSQLSmith.*&sort=title+created&display=lastcommented+project) | [Improve this report!](https://github.com/cockroachdb/cockroach/tree/master/pkg/cmd/internal/issues)
</sub>


Rendered: https://github.com/cockroachdb/cockroach/issues/new?body=sql%2Ftests.TestRandomSyntaxSQLSmith+%5Bfailed%5D%28https%3A%2F%2Fteamcity.example.com%2FviewLog.html%3FbuildId%3D8008135%26tab%3DbuildLog%29+on+release-0.1+%40+%5Babcd123%5D%28https%3A%2F%2Fgithub.com%2Fcockroachdb%2Fcockroach%2Fcommits%2Fabcd123%29%3A%0A%0ARandom+syntax+error%3A%0A%0A%60%60%60%0A++++rsg_test.go%3A755%3A+Crash+detected%3A+server+panic%3A+pq%3A+internal+error%3A+something+bad%0A%60%60%60%0AQuery%3A%0A%0A%60%60%60%0A%09%09SELECT%0A%09%09%09foo%0A%09%09FROM%0A%09%09%09bar%0A%09%09LIMIT%0A%09%09%0933%3A%3A%3AINT8%3B%0A%60%60%60%0ASchema%3A%0A%0A%60%60%60%0A++++rsg_test.go%3A575%3A+To+reproduce%2C+use+schema%3A%0A++++rsg_test.go%3A577%3A+%0A++++++++%09CREATE+TABLE+table1+%28col1_0+BOOL%29%3B%0A++++++++%3B%0A++++rsg_test.go%3A577%3A+%0A++++++++%0A++++++++CREATE+TYPE+greeting+AS+ENUM+%28%27hello%27%2C+%27howdy%27%2C+%27hi%27%2C+%27good+day%27%2C+%27morning%27%29%3B%0A++++++++%3B%0A++++rsg_test.go%3A579%3A+%0A++++rsg_test.go%3A580%3A+--+test+log+scope+end+--%0Atest+logs+left+over+in%3A+%2Fgo%2Fsrc%2Fgithub.com%2Fcockroachdb%2Fcockroach%2Fartifacts%2FlogTestRandomSyntaxSQLSmith460792454%0A---+FAIL%3A+TestRandomSyntaxSQLSmith+%28300.69s%29%0A%60%60%60%0A%3Cdetails%3E%3Csummary%3EReproduce%3C%2Fsummary%3E%0A%3Cp%3E%0A%3Cp%3ETo+reproduce%2C+try%3A%0A%0A%60%60%60bash%0Amake+test+TESTS%3DTestRandomSyntaxSQLSmith+PKG%3D.%2Fpkg%2Fsql%2Ftests+2%3E%261%0A%60%60%60%0A%3C%2Fp%3E%0A%3Cp%3EParameters+in+this+failure%3A%0A%0A-+TAGS%3Ddeadlock%0A%0A-+GOFLAGS%3Drace%0A%3C%2Fp%3E%0A%3C%2Fp%3E%0A%3C%2Fdetails%3E%0A%2Fcc+%40hodor%0A%3Csub%3E%0A%0A%5BThis+test+on+roachdash%5D%28https%3A%2F%2Froachdash.crdb.dev%2F%3Ffilter%3Dstatus%3Aopen%2520t%3A.%2ATestRandomSyntaxSQLSmith.%2A%26sort%3Dtitle%2Bcreated%26display%3Dlastcommented%2Bproject%29+%7C+%5BImprove+this+report%21%5D%28https%3A%2F%2Fgithub.com%2Fcockroachdb%2Fcockroach%2Ftree%2Fmaster%2Fpkg%2Fcmd%2Finternal%2Fissues%29%0A%3C%2Fsub%3E%0A&title=%3Ccomment%3E
Loading

0 comments on commit 43a079d

Please sign in to comment.