Merge pull request #26 from fzipi/feature-override-test

feat(tests): add test result overrides

README.md

@@ -142,7 +142,7 @@ And the result should be similar to:
 ```
 Happy testing!
 
-## Additional features implemented already
+## Additional features
 
 You can add functions to your tests, to simplify bulk writing, or even read values from the environment while executing. This is because `data:` sections in tests will be parse for Go [text/template](https://golang.org/pkg/text/template/) additional syntax, and with the power of additional [Sprig functions](https://masterminds.github.io/sprig/).
 
@@ -172,5 +172,34 @@ data: 'username=fzipi
 
 Other interesting functions you can use are: `randBytes`, `htpasswd`, `encryptAES`, etc.
 
+## Overriding test results
+
+Sometimes you have tests that work well in some platform combination, e.g. Apache + modsecurity2, but fail in other, e.g. Nginx + modsecurity3. Taking that into account, you can override test results using the `testoverride` config param. The test will be run, but the _result_ would be overriden, and your comment will be printed out.
+
+Example:
+
+```yaml
+...
+testoverride:
+  ignore:
+    # text comes from our friends at https://github.com/digitalwave/ftwrunner
+    '941190-3': 'known MSC bug - PR #2023 (Cookie without value)'
+    '941330-1': 'know MSC bug - #2148 (double escape)'
+    '942480-2': 'known MSC bug - PR #2023 (Cookie without value)'
+    '944100-11': 'known MSC bug - PR #2045, ISSUE #2146'
+  forcefail:
+    '123456-01': 'I want this test to fail, even if passing'
+  forcepass:
+    '123456-02': 'This test will always pass'
+```
+
+You can combine any of `ignore`, `forcefail` and `forcepass` to make it work for you.
+
+## Truncating logs
+
+Log files can get really big. Searching patterns are performed using reverse text search in the file. Because the test tool is *really* fast, we sometimes see failures in nginx depending on how fast the tests are performed, mainly because log times in nginx are truncated to one second.
+
+To overcome this, you can use the new config value `logtruncate: True`. This will, as it says, call _truncate_ on the file, actively modifying it between each test. You will need permissions to write the logfile, implying you might need to call the go-ftw binary using sudo.
+
 ## License
 [![FOSSA Status](https://app.fossa.com/api/projects/git%2Bgithub.com%2Ffzipi%2Fgo-ftw.svg?type=large)](https://app.fossa.com/projects/git%2Bgithub.com%2Ffzipi%2Fgo-ftw?ref=badge_large)

check/base.go

@@ -9,10 +9,11 @@ import (
 	"github.com/rs/zerolog/log"
 )
 
-// FTWCheck is the base struct for checks
+// FTWCheck is the base struct for checking test results
 type FTWCheck struct {
-	log      *waflog.FTWLogLines
-	expected *test.Output
+	log       *waflog.FTWLogLines
+	expected  *test.Output
+	overrides *config.FTWTestOverride
 }
 
 // NewCheck creates a new FTWCheck, allowing to inject the configuration
@@ -25,11 +26,15 @@ func NewCheck(c *config.FTWConfiguration) *FTWCheck {
 			Since:        time.Now(),
 			Until:        time.Now(),
 			TimeTruncate: c.LogType.TimeTruncate,
+			LogTruncate:  c.LogTruncate,
 		},
-		expected: &test.Output{},
+		expected:  &test.Output{},
+		overrides: &c.TestOverride,
 	}
 
-	log.Trace().Msgf("check/base: truncate set to %s", check.log.TimeTruncate)
+	log.Trace().Msgf("check/base: time will be truncated to %s", check.log.TimeTruncate)
+	log.Trace().Msgf("check/base: logfile will be truncated? %t", check.log.LogTruncate)
+
 	return check
 }
 
@@ -68,3 +73,21 @@ func (c *FTWCheck) SetLogContains(contains string) {
 func (c *FTWCheck) SetNoLogContains(contains string) {
 	c.expected.NoLogContains = contains
 }
+
+// ForcedIgnore check if this id need to be ignored from results
+func (c *FTWCheck) ForcedIgnore(id string) bool {
+	_, ok := c.overrides.Ignore[id]
+	return ok
+}
+
+// ForcedPass check if this id need to be ignored from results
+func (c *FTWCheck) ForcedPass(id string) bool {
+	_, ok := c.overrides.ForcePass[id]
+	return ok
+}
+
+// ForcedFail check if this id need to be ignored from results
+func (c *FTWCheck) ForcedFail(id string) bool {
+	_, ok := c.overrides.ForceFail[id]
+	return ok
+}

check/base_test.go

@@ -24,6 +24,9 @@ logtype:
   timeregex:  '(\d{4}\/\d{2}\/\d{2} \d{2}:\d{2}:\d{2})'
   timeformat: 'YYYY/MM/DD HH:mm:ss'
   timetruncate: 1s
+testoverride:
+  ignore:
+    '942200-1': 'Ignore Me'
 `
 
 func TestNewCheck(t *testing.T) {
@@ -34,4 +37,28 @@ func TestNewCheck(t *testing.T) {
 	if c.log.TimeTruncate != time.Second {
 		t.Errorf("Failed")
 	}
+
+	for _, text := range c.overrides.Ignore {
+		if text != "Ignore Me" {
+			t.Errorf("Well, didn't match Ignore Me")
+		}
+	}
+}
+
+func TestForced(t *testing.T) {
+	config.ImportFromString(yamlNginxConfig)
+
+	c := NewCheck(config.FTWConfig)
+
+	if !c.ForcedIgnore("942200-1") {
+		t.Errorf("Can't find ignored value")
+	}
+
+	if c.ForcedFail("1245") {
+		t.Errorf("Valued should not be found")
+	}
+
+	if c.ForcedPass("1245") {
+		t.Errorf("Valued should not be found")
+	}
 }

cmd/root.go

@@ -40,6 +40,7 @@ func init() {
 
 func initConfig() {
 	config.Init(cfgFile)
+	zerolog.SetGlobalLevel(zerolog.InfoLevel)
 	if debug {
 		zerolog.SetGlobalLevel(zerolog.TraceLevel)
 	}

cmd/run.go

@@ -4,6 +4,7 @@ import (
 	"fmt"
 
 	"github.com/kyokomi/emoji"
+	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/log"
 	"github.com/spf13/cobra"
 
@@ -23,7 +24,9 @@ var runCmd = &cobra.Command{
 		showTime, _ := cmd.Flags().GetBool("time")
 		quiet, _ := cmd.Flags().GetBool("quiet")
 		if !quiet {
-			emoji.Println(":hammer_and_wrench: Starting tests!")
+			log.Info().Msgf(emoji.Sprintf(":hammer_and_wrench: Starting tests!\n"))
+		} else {
+			zerolog.SetGlobalLevel(zerolog.Disabled)
 		}
 		files := fmt.Sprintf("%s/**/*.yaml", dir)
 		tests, err := test.GetTestsFromFiles(files)
@@ -37,7 +40,7 @@ var runCmd = &cobra.Command{
 func init() {
 	rootCmd.AddCommand(runCmd)
 	runCmd.Flags().StringP("id", "", "", "set test id to run")
-	runCmd.Flags().StringP("exclude", "", "", "exclude tests matching this Go regexp (e.g. to exclude all tests beginning with \"91\", use \"91.*\")")
+	runCmd.Flags().StringP("exclude", "", "", "exclude tests matching this Go regexp (e.g. to exclude all tests beginning with \"91\", use \"91.*\"). If you want more permanent exclusion, check the 'testmodify' option in the config file.")
 	runCmd.Flags().StringP("dir", "d", ".", "recursively find yaml tests in this directory")
 	runCmd.Flags().BoolP("quiet", "q", false, "do not show test by test, only results")
 	runCmd.Flags().BoolP("time", "t", false, "show time spent per test")

config/config.go

@@ -9,8 +9,10 @@ var FTWConfig *FTWConfiguration
 
 // FTWConfiguration FTW global Configuration
 type FTWConfiguration struct {
-	LogFile string
-	LogType FTWLogType
+	LogFile      string
+	LogType      FTWLogType
+	LogTruncate  bool
+	TestOverride FTWTestOverride
 }
 
 // FTWLogType log readers must implement this one
@@ -22,3 +24,13 @@ type FTWLogType struct {
 	TimeFormat   string
 	TimeTruncate time.Duration
 }
+
+// FTWTestOverride holds three lists:
+//   Ignore is for tests you want to ignore. It will still execute the test, but ignore the results. You should add a comment on why you ignore the test
+//   ForcePass is for tests you want to pass unconditionally. Test will be executed, and pass even when the test fails. You should add a comment on why you force pass the test
+//   ForceFail is for tests you want to fail unconditionally. Test will be executed, and fail even when the test passes. You should add a comment on why you force fail the test
+type FTWTestOverride struct {
+	Ignore    map[string]string
+	ForcePass map[string]string
+	ForceFail map[string]string
+}

config/config_test.go

@@ -3,6 +3,7 @@ package config
 import (
 	"io/ioutil"
 	"os"
+	"strings"
 	"testing"
 	"time"
 
@@ -16,6 +17,9 @@ logtype:
   name: 'apache'
   timeregex:  '\[([A-Z][a-z]{2} [A-z][a-z]{2} \d{1,2} \d{1,2}\:\d{1,2}\:\d{1,2}\.\d+? \d{4})\]'
   timeformat: 'ddd MMM DD HH:mm:ss.S YYYY'
+testoverride:
+  ignore:
+    '920400-1': 'This test result must be ignored'
 `
 
 var yamlBadConfig = `
@@ -30,6 +34,7 @@ logtype:
 var yamlTruncateConfig = `
 ---
 logfile: 'tests/logs/modsec3-nginx/nginx/error.log'
+logtruncate: True
 logtype:
   name: nginx
   timetruncate:  1s
@@ -53,6 +58,19 @@ func TestInitConfig(t *testing.T) {
 	if FTWConfig.LogType.TimeFormat != "ddd MMM DD HH:mm:ss.S YYYY" {
 		t.Errorf("Failed !")
 	}
+
+	if len(FTWConfig.TestOverride.Ignore) == 0 {
+		t.Errorf("Failed! Len must be > 0")
+	}
+
+	for id, text := range FTWConfig.TestOverride.Ignore {
+		if !strings.Contains(id, "920400-1") {
+			t.Errorf("Looks like we could not find item to ignore")
+		}
+		if text != "This test result must be ignored" {
+			t.Errorf("Text doesn't match")
+		}
+	}
 }
 
 func TestInitBadFileConfig(t *testing.T) {
@@ -107,6 +125,9 @@ func TestTimeTruncateConfig(t *testing.T) {
 		t.Errorf("Failed !")
 	}
 
+	if FTWConfig.LogTruncate != true {
+		t.Errorf("Trucate file is wrong !")
+	}
 	if FTWConfig.LogType.TimeTruncate != time.Second {
 		t.Errorf("Failed !")
 	}

http/response_test.go

@@ -42,7 +42,6 @@ func TestResponse(t *testing.T) {
 
 	req := generateRequestForTesting()
 
-	fmt.Printf("%+v\n", d)
 	client, err := NewConnection(*d)
 
 	if err != nil {

runner/run.go

@@ -58,7 +58,7 @@ func Run(testid string, exclude string, showTime bool, output bool, ftwtests []t
 
 				// Check sanity first
 				if checkTestSanity(testRequest) {
-					log.Fatal().Msgf("bad test: choose between data, encoded_request, or raw_request")
+					log.Fatal().Msgf("ftw/run: bad test: choose between data, encoded_request, or raw_request")
 				}
 
 				var client *http.Connection
@@ -83,8 +83,9 @@ func Run(testid string, exclude string, showTime bool, output bool, ftwtests []t
 
 				log.Debug().Msgf("ftw/run: sending request")
 
-				startSendingRequest := time.Now()
+				startSendingRequest := time.Now().Local()
 
+				log.Trace().Msgf("ftw/run: started at %s", startSendingRequest.String())
 				client, err = client.Request(req)
 				if err != nil {
 					log.Error().Msgf("ftw/run: error sending request: %s\n", err.Error())
@@ -95,8 +96,8 @@ func Run(testid string, exclude string, showTime bool, output bool, ftwtests []t
 
 				// We wrap go stdlib http for the response
 				log.Debug().Msgf("ftw/check: getting response")
-				startReceivingResponse := time.Now()
-
+				startReceivingResponse := time.Now().Local()
+				log.Trace().Msgf("ftw/run: started receiving at %s", startReceivingResponse.String())
 				response, responseError := client.Response()
 				if responseError != nil {
 					log.Debug().Msgf("ftw/run: error receiving response: %s\n", responseError.Error())
@@ -118,7 +119,7 @@ func Run(testid string, exclude string, showTime bool, output bool, ftwtests []t
 				ftwcheck.SetExpectTestOutput(&expectedOutput)
 
 				// now get the test result based on output
-				testResult = checkResult(ftwcheck, responseCode, responseError, responseText)
+				testResult = checkResult(ftwcheck, t.TestTitle, responseCode, responseError, responseText)
 
 				duration = client.GetRoundTripTime().RoundTripDuration()
 
@@ -154,17 +155,20 @@ func displayResult(quiet bool, result TestResult, duration time.Duration) {
 		printUnlessQuietMode(quiet, ":check_mark:passed in %s\n", duration)
 	case Failed:
 		printUnlessQuietMode(quiet, ":collision:failed in %s\n", duration)
+	case Ignored:
+		printUnlessQuietMode(quiet, ":equal:test result ignored in %s\n", duration)
 	default:
 		// don't print anything if skipped test
 	}
 }
 
 // checkResult has the logic for verifying the result for the test sent
-func checkResult(c *check.FTWCheck, responseCode int, responseError error, responseText string) TestResult {
+func checkResult(c *check.FTWCheck, id string, responseCode int, responseError error, responseText string) TestResult {
 	var result TestResult
 
 	// Set to failed initially
 	result = Failed
+
 	// Request might return an error, but it could be expected, we check that first
 	if c.AssertExpectError(responseError) {
 		log.Debug().Msgf("ftw/check: found expected error")
@@ -191,6 +195,19 @@ func checkResult(c *check.FTWCheck, responseCode int, responseError error, respo
 		result = Success
 	}
 
+	// After all normal checks, see if the test result has been explicitly forced
+	if c.ForcedIgnore(id) {
+		result = Ignored
+	}
+
+	if c.ForcedFail(id) {
+		result = ForceFail
+	}
+
+	if c.ForcedPass(id) {
+		result = ForcePass
+	}
+
 	return result
 }