feat: update to newest ftw-tests-schema (#209)

* feat: add run_once option for tests

- add new `retry_once` option
- add test case for `retry_once`
- make test infrastructure more modular

* feat: update code and tests to new schema version
* feat: implement platform overrides

* chore: fix lint issues
* chore: use PR branch of schema until ready
* feat: add --fail-fast flag

- add flag to stop test run on first test failure
- fix statistics to record at test, not stage level

* feat: add --log-file flag

The log file was the last remaining setting that could not be configured
from the command line.

* fix: increase default read timeout from 1 to 10 seconds

The default read timeout is too short for some of the more expensive
tests.

* feat: improve console output

- always print test ID on failure; especially useful with
  --show-failures-only
- use the same indentation for all output messages

* chore: update schema, drop legacy koanf

check/base.go

@@ -6,6 +6,7 @@ package check
 import (
 	"bytes"
 
+	schema "github.com/coreruleset/ftw-tests-schema/types"
 	"github.com/coreruleset/go-ftw/config"
 	"github.com/coreruleset/go-ftw/test"
 	"github.com/coreruleset/go-ftw/waflog"
@@ -39,8 +40,8 @@ func (c *FTWCheck) SetExpectTestOutput(t *test.Output) {
 }
 
 // SetExpectStatus sets to expect the HTTP status from the test to be in the integer range passed
-func (c *FTWCheck) SetExpectStatus(s []int) {
-	c.expected.Status = s
+func (c *FTWCheck) SetExpectStatus(status int) {
+	c.expected.Status = status
 }
 
 // SetExpectResponse sets the response we expect in the text from the server
@@ -54,39 +55,43 @@ func (c *FTWCheck) SetExpectError(expect bool) {
 }
 
 // SetLogContains sets the string to look for in logs
-func (c *FTWCheck) SetLogContains(contains string) {
-	c.expected.LogContains = contains
+func (c *FTWCheck) SetLogContains(regex string) {
+	//nolint:staticcheck
+	c.expected.LogContains = regex
+	c.expected.Log.MatchRegex = regex
 }
 
 // SetNoLogContains sets the string to look that should not present in logs
-func (c *FTWCheck) SetNoLogContains(contains string) {
-	c.expected.NoLogContains = contains
+func (c *FTWCheck) SetNoLogContains(regex string) {
+	//nolint:staticcheck
+	c.expected.NoLogContains = regex
+	c.expected.Log.NoMatchRegex = regex
 }
 
-// ForcedIgnore check if this id need to be ignored from results
-func (c *FTWCheck) ForcedIgnore(id string) bool {
+// ForcedIgnore check if this ID need to be ignored from results
+func (c *FTWCheck) ForcedIgnore(testCase *schema.Test) bool {
 	for re := range c.cfg.TestOverride.Ignore {
-		if re.MatchString(id) {
+		if re.MatchString(testCase.IdString()) {
 			return true
 		}
 	}
 	return false
 }
 
-// ForcedPass check if this id need to be ignored from results
-func (c *FTWCheck) ForcedPass(id string) bool {
+// ForcedPass check if this ID need to be ignored from results
+func (c *FTWCheck) ForcedPass(testCase *schema.Test) bool {
 	for re := range c.cfg.TestOverride.ForcePass {
-		if re.MatchString(id) {
+		if re.MatchString(testCase.IdString()) {
 			return true
 		}
 	}
 	return false
 }
 
-// ForcedFail check if this id need to be ignored from results
-func (c *FTWCheck) ForcedFail(id string) bool {
+// ForcedFail check if this ID need to be ignored from results
+func (c *FTWCheck) ForcedFail(testCase *schema.Test) bool {
 	for re := range c.cfg.TestOverride.ForceFail {
-		if re.MatchString(id) {
+		if re.MatchString(testCase.IdString()) {
 			return true
 		}
 	}
@@ -98,20 +103,6 @@ func (c *FTWCheck) CloudMode() bool {
 	return c.cfg.RunMode == config.CloudRunMode
 }
 
-// SetCloudMode alters the values for expected logs and status code
-func (c *FTWCheck) SetCloudMode() {
-	var status = c.expected.Status
-
-	if c.expected.LogContains != "" {
-		status = append(status, 403)
-		c.expected.LogContains = ""
-	} else if c.expected.NoLogContains != "" {
-		status = append(status, 200, 404, 405)
-		c.expected.NoLogContains = ""
-	}
-	c.expected.Status = status
-}
-
 // SetStartMarker sets the log line that marks the start of the logs to analyze
 func (c *FTWCheck) SetStartMarker(marker []byte) {
 	c.log.StartMarker = bytes.ToLower(marker)

check/base_test.go

@@ -4,11 +4,11 @@
 package check
 
 import (
-	"sort"
 	"testing"
 
 	"github.com/stretchr/testify/suite"
 
+	schema "github.com/coreruleset/ftw-tests-schema/types"
 	"github.com/coreruleset/go-ftw/config"
 	"github.com/coreruleset/go-ftw/test"
 	"github.com/coreruleset/go-ftw/utils"
@@ -60,7 +60,7 @@ func (s *checkBaseTestSuite) TestNewCheck() {
 	}
 
 	to := test.Output{
-		Status:           []int{200},
+		Status:           200,
 		ResponseContains: "",
 		LogContains:      "nothing",
 		NoLogContains:    "",
@@ -72,59 +72,26 @@ func (s *checkBaseTestSuite) TestNewCheck() {
 
 	c.SetNoLogContains("nologcontains")
 
+	//nolint:staticcheck
 	s.Equal(c.expected.NoLogContains, "nologcontains", "Problem setting nologcontains")
 }
 
 func (s *checkBaseTestSuite) TestForced() {
 	c, err := NewCheck(s.cfg)
 	s.Require().NoError(err)
 
-	s.True(c.ForcedIgnore("942200-1"), "Can't find ignored value")
+	s.True(c.ForcedIgnore(&schema.Test{RuleId: 942200, TestId: 1}), "Can't find ignored value")
 
-	s.False(c.ForcedFail("1245"), "Value should not be found")
+	s.False(c.ForcedFail(&schema.Test{RuleId: 12345, TestId: 1}), "Value should not be found")
 
-	s.False(c.ForcedPass("1234"), "Value should not be found")
+	s.False(c.ForcedPass(&schema.Test{RuleId: 12345, TestId: 1}), "Value should not be found")
 
-	s.True(c.ForcedPass("1245"), "Value should be found")
+	s.True(c.ForcedPass(&schema.Test{RuleId: 1245, TestId: 1}), "Value should be found")
 
-	s.True(c.ForcedFail("6789"), "Value should be found")
+	s.True(c.ForcedFail(&schema.Test{RuleId: 6789, TestId: 1}), "Value should be found")
 
 	s.cfg.TestOverride.Ignore = make(map[*config.FTWRegexp]string)
-	s.Falsef(c.ForcedIgnore("anything"), "Should not find ignored value in empty map")
-
-}
-
-func (s *checkBaseTestSuite) TestCloudMode() {
-	c, err := NewCheck(s.cfg)
-	s.Require().NoError(err)
-
-	s.True(c.CloudMode(), "couldn't detect cloud mode")
-
-	status := []int{200, 301}
-	c.SetExpectStatus(status)
-	c.SetLogContains("this text")
-	// this should override logcontains
-	c.SetCloudMode()
-
-	cloudStatus := c.expected.Status
-	sort.Ints(cloudStatus)
-	res := sort.SearchInts(cloudStatus, 403)
-	s.Equalf(2, res, "couldn't find expected 403 status in %#v -> %d", cloudStatus, res)
-
-	c.SetLogContains("")
-	c.SetNoLogContains("no log contains")
-	// this should override logcontains
-	c.SetCloudMode()
-
-	cloudStatus = c.expected.Status
-	sort.Ints(cloudStatus)
-	found := false
-	for _, n := range cloudStatus {
-		if n == 200 {
-			found = true
-		}
-	}
-	s.True(found, "couldn't find expected 200 status")
+	s.Falsef(c.ForcedIgnore(&schema.Test{RuleId: 1234, TestId: 1}), "Should not find ignored value in empty map")
 
 }
 

check/error.go

@@ -6,14 +6,15 @@ package check
 import "github.com/rs/zerolog/log"
 
 // AssertExpectError helper to check if this error was expected or not
-func (c *FTWCheck) AssertExpectError(err error) bool {
-	if err != nil {
-		log.Debug().Msgf("ftw/check: expected error? -> %t, and error is %s", *c.expected.ExpectError, err.Error())
+func (c *FTWCheck) AssertExpectError(err error) (bool, bool) {
+	errorExpected := c.expected.ExpectError != nil && *c.expected.ExpectError
+	var errorString string
+	if err == nil {
+		errorString = "-"
 	} else {
-		log.Debug().Msgf("ftw/check: expected error? -> %t, and error is nil", *c.expected.ExpectError)
+		errorString = err.Error()
 	}
-	if *c.expected.ExpectError && err != nil {
-		return true
-	}
-	return false
+	log.Debug().Caller().Msgf("Error expected: %t. Found: %s", errorExpected, errorString)
+
+	return errorExpected, (errorExpected && err != nil) || (!errorExpected && err == nil)
 }

check/error_test.go

@@ -46,12 +46,15 @@ func (s *checkErrorTestSuite) SetupTest() {
 	s.Require().NoError(err)
 	s.cfg.WithLogfile(logName)
 }
+
 func (s *checkErrorTestSuite) TestAssertResponseErrorOK() {
 	c, err := NewCheck(s.cfg)
 	s.Require().NoError(err)
 	for _, e := range expectedOKTests {
 		c.SetExpectError(e.expected)
-		s.Equal(e.expected, c.AssertExpectError(e.err))
+		expected, succeeded := c.AssertExpectError(e.err)
+		s.Equal(e.expected, expected)
+		s.True(succeeded)
 	}
 }
 
@@ -61,6 +64,8 @@ func (s *checkErrorTestSuite) TestAssertResponseFail() {
 
 	for _, e := range expectedFailTests {
 		c.SetExpectError(e.expected)
-		s.False(c.AssertExpectError(e.err))
+		expected, succeeded := c.AssertExpectError(e.err)
+		s.Equal(e.expected, expected)
+		s.False(succeeded)
 	}
 }

check/logs.go

@@ -3,28 +3,76 @@
 
 package check
 
-// AssertNoLogContains returns true is the string is not found in the logs
-func (c *FTWCheck) AssertNoLogContains() bool {
-	if c.expected.NoLogContains != "" {
-		return !c.log.Contains(c.expected.NoLogContains)
+import (
+	"fmt"
+	"strings"
+
+	"github.com/rs/zerolog/log"
+)
+
+func (c *FTWCheck) AssertLogs() bool {
+	if c.CloudMode() {
+		// No logs to check in cloud mode
+		return true
 	}
-	return false
+
+	return c.assertLogContains() && c.assertNoLogContains()
 }
 
-// NoLogContainsRequired checks that the test requires no_log_contains
-func (c *FTWCheck) NoLogContainsRequired() bool {
-	return c.expected.NoLogContains != ""
+// AssertNoLogContains returns true is the string is not found in the logs
+func (c *FTWCheck) assertNoLogContains() bool {
+	logExpectations := c.expected.Log
+	result := true
+	if logExpectations.NoMatchRegex != "" {
+		result = !c.log.Contains(logExpectations.NoMatchRegex)
+		if !result {
+			log.Debug().Msgf("Unexpectedly found match for '%s'", logExpectations.NoMatchRegex)
+		}
+	}
+	if result && len(logExpectations.NoExpectIds) > 0 {
+		result = !c.log.Contains(generateIdRegex(logExpectations.NoExpectIds))
+		if !result {
+			log.Debug().Msg("Unexpectedly found IDs")
+		}
+	}
+	return result
 }
 
 // AssertLogContains returns true when the logs contain the string
-func (c *FTWCheck) AssertLogContains() bool {
-	if c.expected.LogContains != "" {
-		return c.log.Contains(c.expected.LogContains)
+func (c *FTWCheck) assertLogContains() bool {
+	logExpectations := c.expected.Log
+	result := true
+	if logExpectations.MatchRegex != "" {
+		result = c.log.Contains(logExpectations.MatchRegex)
+		if !result {
+			log.Debug().Msgf("Failed to find match for match_regex. Expected to find '%s'", logExpectations.MatchRegex)
+		}
+	}
+	if result && len(logExpectations.ExpectIds) > 0 {
+		result = c.log.Contains(generateIdRegex(logExpectations.ExpectIds))
+		if !result {
+			log.Debug().Msg("Failed to find expected IDs")
+		}
 	}
-	return false
+	return result
 }
 
-// LogContainsRequired checks that the test requires log_contains
-func (c *FTWCheck) LogContainsRequired() bool {
-	return c.expected.LogContains != ""
+// Search for both standard ModSecurity, and JSON output
+func generateIdRegex(ids []uint) string {
+	modSecLogSyntax := strings.Builder{}
+	jsonLogSyntax := strings.Builder{}
+	modSecLogSyntax.WriteString(`\[id "(?:`)
+	jsonLogSyntax.WriteString(`"id":\s*"?(?:`)
+	for index, id := range ids {
+		if index > 0 {
+			modSecLogSyntax.WriteRune('|')
+			jsonLogSyntax.WriteRune('|')
+		}
+		modSecLogSyntax.WriteString(fmt.Sprint(id))
+		jsonLogSyntax.WriteString(fmt.Sprint(id))
+	}
+	modSecLogSyntax.WriteString(`)"\]`)
+	jsonLogSyntax.WriteString(`)"?`)
+
+	return modSecLogSyntax.String() + "|" + jsonLogSyntax.String()
 }