Skip to content

Commit

Permalink
Fix bug in terratest-log-parser that mixes result lines (#899)
Browse files Browse the repository at this point in the history
  • Loading branch information
yorinasub17 authored May 14, 2021
1 parent 3af8e92 commit d1ce8be
Show file tree
Hide file tree
Showing 23 changed files with 83 additions and 52 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -4,14 +4,6 @@
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:03:33-07:00 Spawned log writer for test TestGetOrCreateChannelCreatesNewChannel
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:03:33-07:00 Storing logs for test TestGetOrCreateChannelCreatesNewChannel to /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory272503116/TestGetOrCreateChannelCreatesNewChannel.log
--- PASS: TestGetOrCreateChannelCreatesNewChannel (0.00s)
--- PASS: TestGetOrCreateChannelCreatesNewChannel (0.00s)
--- PASS: TestEnsureDirectoryExistsHandlesExistingDirectory (0.00s)
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:03:33-07:00 Creating directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory272503116
--- PASS: TestIsPanicLine (0.00s)
--- PASS: TestStackPop (0.00s)
--- PASS: TestStackPopEmpty (0.00s)
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:03:33-07:00 Channel closed for log writer of test TestGetOrCreateChannelCreatesNewChannel
--- PASS: TestEnsureDirectoryExistsCreatesDirectory (0.00s)
--- PASS: TestGetOrCreateChannelSpawnsLogCollectorOnCreate (1.01s)
--- PASS: TestLogCollectorCreatesAndWritesToFile (1.01s)
PASS
Original file line number Diff line number Diff line change
Expand Up @@ -3,13 +3,6 @@
=== CONT TestGetOrCreateChannelSpawnsLogCollectorOnCreate
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:33-07:00 Spawned log writer for test TestGetOrCreateChannelSpawnsLogCollectorOnCreate
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:33-07:00 Storing logs for test TestGetOrCreateChannelSpawnsLogCollectorOnCreate to /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory894837527/TestGetOrCreateChannelSpawnsLogCollectorOnCreate.log
--- PASS: TestCloseChannelsClosesAll (0.00s)
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:33-07:00 Directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory894837527 already exists
--- PASS: TestIsStatusLine (0.00s)
--- PASS: TestGetIndent (0.00s)
--- PASS: TestIsEmpty (0.00s)
--- PASS: TestPeekEmpty (0.00s)
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:33-07:00 Channel closed for log writer of test TestGetOrCreateChannelSpawnsLogCollectorOnCreate
--- PASS: TestGetTestNameFromResultLine (0.00s)
--- PASS: TestIsResultLine (0.00s)
--- PASS: TestGetOrCreateChannelSpawnsLogCollectorOnCreate (1.01s)
Original file line number Diff line number Diff line change
Expand Up @@ -2,10 +2,7 @@
=== PAUSE TestLogCollectorCreatesAndWritesToFile
=== CONT TestLogCollectorCreatesAndWritesToFile
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:03:33-07:00 Spawned log writer for test TestLogCollectorCreatesAndWritesToFile
--- PASS: TestGetOrCreateChannelReturnsExistingChannel (0.00s)
--- PASS: TestPeek (0.00s)
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:03:33-07:00 Storing logs for test TestLogCollectorCreatesAndWritesToFile to /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestLogCollectorCreatesAndWritesToFile509683594/TestLogCollectorCreatesAndWritesToFile.log
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:03:33-07:00 Directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestLogCollectorCreatesAndWritesToFile509683594 already exists
--- PASS: TestGetTestNameFromStatusLine (0.00s)
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:03:33-07:00 Channel closed for log writer of test TestLogCollectorCreatesAndWritesToFile
--- PASS: TestLogCollectorCreatesAndWritesToFile (1.01s)
6 changes: 3 additions & 3 deletions modules/logger/parser/fixtures/failing_example.log
Original file line number Diff line number Diff line change
Expand Up @@ -18,19 +18,19 @@
--- PASS: TestRemoveDedentedTestResultMarkersAll (0.00s)
=== RUN TestBasicExample
--- FAIL: TestBasicExample (0.00s)
integration_test.go:10:
integration_test.go:10:
Error Trace: integration_test.go:10
Error: Expected value not to be nil.
Test: TestBasicExample
=== RUN TestPanicExample
--- FAIL: TestPanicExample (0.00s)
integration_test.go:14:
integration_test.go:14:
Error Trace: integration_test.go:14
Error: Expected value not to be nil.
Test: TestPanicExample
=== RUN TestRealWorldExample
--- FAIL: TestRealWorldExample (0.00s)
integration_test.go:18:
integration_test.go:18:
Error Trace: integration_test.go:18
Error: Expected value not to be nil.
Test: TestRealWorldExample
Expand Down
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
=== RUN TestBasicExample
--- FAIL: TestBasicExample (0.00s)
integration_test.go:10:
integration_test.go:10:
Error Trace: integration_test.go:10
Error: Expected value not to be nil.
Test: TestBasicExample
Original file line number Diff line number Diff line change
Expand Up @@ -2,5 +2,4 @@
=== PAUSE TestCloseChannelsClosesAll
=== CONT TestCloseChannelsClosesAll
TestCloseChannelsClosesAll INFO 2018-10-20T13:15:09-07:00 Closing all the channels in log writer
--- PASS: TestStackPop (0.00s)
--- PASS: TestCloseChannelsClosesAll (0.00s)
Original file line number Diff line number Diff line change
Expand Up @@ -4,12 +4,6 @@
--- PASS: TestGetOrCreateChannelCreatesNewChannel (0.00s)
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:15:09-07:00 Spawned log writer for test TestGetOrCreateChannelCreatesNewChannel
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:15:09-07:00 Storing logs for test TestGetOrCreateChannelCreatesNewChannel to /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory867148002/TestGetOrCreateChannelCreatesNewChannel.log
--- PASS: TestEnsureDirectoryExistsHandlesExistingDirectory (0.00s)
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:15:09-07:00 Creating directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory867148002
--- PASS: TestIsPanicLine (0.00s)
TestGetOrCreateChannelCreatesNewChannel INFO 2018-10-20T13:15:09-07:00 Channel closed for log writer of test TestGetOrCreateChannelCreatesNewChannel
--- PASS: TestEnsureDirectoryExistsCreatesDirectory (0.00s)
--- PASS: TestLogCollectorCreatesAndWritesToFile (1.01s)
--- PASS: TestGetOrCreateChannelSpawnsLogCollectorOnCreate (1.01s)
FAIL
exit status 1
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,4 @@ TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:15:09-07:00
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:15:09-07:00 Storing logs for test TestGetOrCreateChannelSpawnsLogCollectorOnCreate to /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory945346773/TestGetOrCreateChannelSpawnsLogCollectorOnCreate.log
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:15:09-07:00 Directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory945346773 already exists
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:15:09-07:00 Channel closed for log writer of test TestGetOrCreateChannelSpawnsLogCollectorOnCreate
--- PASS: TestGetOrCreateChannelCreatesNewChannel (0.00s)
--- PASS: TestIsResultLine (0.00s)
--- PASS: TestGetOrCreateChannelSpawnsLogCollectorOnCreate (1.01s)
Original file line number Diff line number Diff line change
Expand Up @@ -3,8 +3,6 @@
=== CONT TestLogCollectorCreatesAndWritesToFile
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:15:09-07:00 Spawned log writer for test TestLogCollectorCreatesAndWritesToFile
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:15:09-07:00 Storing logs for test TestLogCollectorCreatesAndWritesToFile to /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestLogCollectorCreatesAndWritesToFile262063152/TestLogCollectorCreatesAndWritesToFile.log
--- PASS: TestCloseChannelsClosesAll (0.00s)
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:15:09-07:00 Directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestLogCollectorCreatesAndWritesToFile262063152 already exists
--- PASS: TestIsSummaryLine (0.00s)
TestLogCollectorCreatesAndWritesToFile INFO 2018-10-20T13:15:09-07:00 Channel closed for log writer of test TestLogCollectorCreatesAndWritesToFile
--- PASS: TestLogCollectorCreatesAndWritesToFile (1.01s)
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
=== RUN TestPanicExample
--- FAIL: TestPanicExample (0.00s)
integration_test.go:14:
integration_test.go:14:
Error Trace: integration_test.go:14
Error: Expected value not to be nil.
Test: TestPanicExample
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
=== RUN TestRealWorldExample
--- FAIL: TestRealWorldExample (0.00s)
integration_test.go:18:
integration_test.go:18:
Error Trace: integration_test.go:18
Error: Expected value not to be nil.
Test: TestRealWorldExample
Original file line number Diff line number Diff line change
Expand Up @@ -14,13 +14,13 @@
<testcase classname="parser" name="TestRemoveDedentedTestResultMarkersEmpty" time="0.000"></testcase>
<testcase classname="parser" name="TestRemoveDedentedTestResultMarkersAll" time="0.000"></testcase>
<testcase classname="parser" name="TestBasicExample" time="0.000">
<failure message="Failed" type="">integration_test.go:10: &#xA;Error Trace:&#x9;integration_test.go:10&#xA;Error: &#x9;Expected value not to be nil.&#xA;Test: &#x9;TestBasicExample</failure>
<failure message="Failed" type="">integration_test.go:10:&#xA;Error Trace:&#x9;integration_test.go:10&#xA;Error: &#x9;Expected value not to be nil.&#xA;Test: &#x9;TestBasicExample</failure>
</testcase>
<testcase classname="parser" name="TestPanicExample" time="0.000">
<failure message="Failed" type="">integration_test.go:14: &#xA;Error Trace:&#x9;integration_test.go:14&#xA;Error: &#x9;Expected value not to be nil.&#xA;Test: &#x9;TestPanicExample</failure>
<failure message="Failed" type="">integration_test.go:14:&#xA;Error Trace:&#x9;integration_test.go:14&#xA;Error: &#x9;Expected value not to be nil.&#xA;Test: &#x9;TestPanicExample</failure>
</testcase>
<testcase classname="parser" name="TestRealWorldExample" time="0.000">
<failure message="Failed" type="">integration_test.go:18: &#xA;Error Trace:&#x9;integration_test.go:18&#xA;Error: &#x9;Expected value not to be nil.&#xA;Test: &#x9;TestRealWorldExample</failure>
<failure message="Failed" type="">integration_test.go:18:&#xA;Error Trace:&#x9;integration_test.go:18&#xA;Error: &#x9;Expected value not to be nil.&#xA;Test: &#x9;TestRealWorldExample</failure>
</testcase>
<testcase classname="parser" name="TestGetIndent" time="0.000"></testcase>
<testcase classname="parser" name="TestGetTestNameFromResultLine" time="0.000"></testcase>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -53,4 +53,5 @@
--- PASS: TestEnsureDirectoryExistsCreatesDirectory (0.00s)
--- PASS: TestLogCollectorCreatesAndWritesToFile (1.01s)
--- PASS: TestGetOrCreateChannelSpawnsLogCollectorOnCreate (1.01s)
FAIL
FAIL github.com/gruntwork-io/terratest/modules/logger/parser 1.020s
20 changes: 20 additions & 0 deletions modules/logger/parser/fixtures/new_go_failing_example.log
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
=== RUN TestIntegrationBasicExample
=== PAUSE TestIntegrationBasicExample
=== RUN TestIntegrationFailingExample
=== PAUSE TestIntegrationFailingExample
=== RUN TestIntegrationPanicExample
=== PAUSE TestIntegrationPanicExample
=== CONT TestIntegrationBasicExample
=== CONT TestIntegrationPanicExample
=== CONT TestIntegrationFailingExample
=== CONT TestIntegrationBasicExample
integration_test.go:57:
Error Trace: integration_test.go:57
Error: Should be true
Test: TestIntegrationBasicExample
--- PASS: TestIntegrationPanicExample (0.00s)
--- PASS: TestIntegrationFailingExample (0.00s)
--- FAIL: TestIntegrationBasicExample (0.00s)
FAIL
FAIL github.com/gruntwork-io/terratest/modules/logger/parser 1.589s
FAIL
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
=== RUN TestIntegrationBasicExample
=== PAUSE TestIntegrationBasicExample
=== CONT TestIntegrationBasicExample
=== CONT TestIntegrationBasicExample
integration_test.go:57:
Error Trace: integration_test.go:57
Error: Should be true
Test: TestIntegrationBasicExample
--- FAIL: TestIntegrationBasicExample (0.00s)
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
=== RUN TestIntegrationFailingExample
=== PAUSE TestIntegrationFailingExample
=== CONT TestIntegrationFailingExample
--- PASS: TestIntegrationFailingExample (0.00s)
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
=== RUN TestIntegrationPanicExample
=== PAUSE TestIntegrationPanicExample
=== CONT TestIntegrationPanicExample
--- PASS: TestIntegrationPanicExample (0.00s)
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
<?xml version="1.0" encoding="UTF-8"?>
<testsuites>
<testsuite tests="3" failures="1" time="1.589" name="github.com/gruntwork-io/terratest/modules/logger/parser">
<properties>
<property name="go.version" value="go1.16.3"></property>
</properties>
<testcase classname="parser" name="TestIntegrationBasicExample" time="0.000">
<failure message="Failed" type=""> integration_test.go:57: </failure>
</testcase>
<testcase classname="parser" name="TestIntegrationFailingExample" time="0.000"></testcase>
<testcase classname="parser" name="TestIntegrationPanicExample" time="0.000"></testcase>
</testsuite>
</testsuites>
Original file line number Diff line number Diff line change
@@ -0,0 +1,6 @@
--- PASS: TestIntegrationPanicExample (0.00s)
--- PASS: TestIntegrationFailingExample (0.00s)
--- FAIL: TestIntegrationBasicExample (0.00s)
FAIL
FAIL github.com/gruntwork-io/terratest/modules/logger/parser 1.589s
FAIL
Original file line number Diff line number Diff line change
Expand Up @@ -2,5 +2,3 @@
=== PAUSE TestEnsureDirectoryExistsCreatesDirectory
=== CONT TestEnsureDirectoryExistsCreatesDirectory
TestEnsureDirectoryExistsCreatesDirectory INFO 2018-10-20T13:03:19-07:00 Creating directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory601920052/tmpdir
--- PASS: TestGetOrCreateChannelCreatesNewChannel (0.00s)
--- FAIL: TestIsPanicLine (0.00s)
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,4 @@
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:19-07:00 Spawned log writer for test TestGetOrCreateChannelSpawnsLogCollectorOnCreate
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:19-07:00 Storing logs for test TestGetOrCreateChannelSpawnsLogCollectorOnCreate to /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory724282597/TestGetOrCreateChannelSpawnsLogCollectorOnCreate.log
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:19-07:00 Directory /var/folders/n2/pljz6dq52bd1ksmw23qyr3sr0000gn/T/TestEnsureDirectoryCreatesDirectory724282597 already exists
--- PASS: TestCloseChannelsClosesAll (0.00s)
--- PASS: TestEnsureDirectoryExistsHandlesExistingDirectory (0.00s)
TestGetOrCreateChannelSpawnsLogCollectorOnCreate INFO 2018-10-20T13:03:19-07:00 Channel closed for log writer of test TestGetOrCreateChannelSpawnsLogCollectorOnCreate
11 changes: 8 additions & 3 deletions modules/logger/parser/integration_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -52,17 +52,22 @@ func testExample(t *testing.T, example string) {
assert.True(t, DirectoryEqual(t, dir, expectedOutputDirName))
}

func TestBasicExample(t *testing.T) {
func TestIntegrationBasicExample(t *testing.T) {
t.Parallel()
testExample(t, "basic")
}

func TestFailingExample(t *testing.T) {
func TestIntegrationFailingExample(t *testing.T) {
t.Parallel()
testExample(t, "failing")
}

func TestPanicExample(t *testing.T) {
func TestIntegrationPanicExample(t *testing.T) {
t.Parallel()
testExample(t, "panic")
}

func TestIntegrationNewGoExample(t *testing.T) {
t.Parallel()
testExample(t, "new_go_failing")
}
16 changes: 9 additions & 7 deletions modules/logger/parser/parser.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ func SpawnParsers(logger *logrus.Logger, reader io.Reader, outputDir string) {
var (
regexResult = regexp.MustCompile(`--- (PASS|FAIL|SKIP): (.+) \((\d+\.\d+)(?: ?seconds|s)\)`)
regexStatus = regexp.MustCompile(`=== (RUN|PAUSE|CONT)\s+(.+)`)
regexSummary = regexp.MustCompile(`^(ok|FAIL)\s+([^ ]+)\s+(?:(\d+\.\d+)s|\(cached\)|(\[\w+ failed]))(?:\s+coverage:\s+(\d+\.\d+)%\sof\sstatements(?:\sin\s.+)?)?$`)
regexSummary = regexp.MustCompile(`(^FAIL$)|(^(ok|FAIL)\s+([^ ]+)\s+(?:(\d+\.\d+)s|\(cached\)|(\[\w+ failed]))(?:\s+coverage:\s+(\d+\.\d+)%\sof\sstatements(?:\sin\s.+)?)?$)`)
regexPanic = regexp.MustCompile(`^panic:`)
)

Expand Down Expand Up @@ -140,6 +140,7 @@ func parseAndStoreTestOutput(

case isStatusLine(data):
testName := getTestNameFromStatusLine(data)
previousTestName = testName
logWriter.writeLog(logger, testName, data)

case strings.HasPrefix(data, "Test"):
Expand All @@ -149,12 +150,11 @@ func parseAndStoreTestOutput(
// This must be modified when `logger.DoLog` changes.
vals := strings.Split(data, " ")
testName := vals[0]
logWriter.writeLog(logger, testName, data)
previousTestName = testName
logWriter.writeLog(logger, testName, data)

case isIndented && previousTestName != "summary":
// In a test result block, so collect the line into all the test results we have seen so far.
// Note that previousTestName would only be set to summary if we saw a panic line.
case isIndented && isResultLine(data):
// In a nested test result block, so collect the line into all the test results we have seen so far.
for _, marker := range testResultMarkers {
logWriter.writeLog(logger, marker.TestName, data)
}
Expand All @@ -164,13 +164,15 @@ func parseAndStoreTestOutput(
previousTestName = "summary"
logWriter.writeLog(logger, "summary", data)

case isResultLine(data):
// We ignore result lines, because that is handled specially below.

case previousTestName != "":
// Base case: roll up to the previous test line, if it exists.
// Handles case where terratest log has entries with newlines in them.
logWriter.writeLog(logger, previousTestName, data)

case !isResultLine(data):
// Result Lines are handled below
default:
logger.Warnf("Found test line that does not match known cases: %s", data)
}

Expand Down

0 comments on commit d1ce8be

Please sign in to comment.