From 6b28e38cea0dec3e3f045ab8ec833608b91a946f Mon Sep 17 00:00:00 2001 From: Owen Waller Date: Sun, 16 Nov 2014 17:50:26 +0000 Subject: [PATCH] Expansion of unit tests for utils/utils.go This commit expands the test coverage for the utils/utils.go module. The utils module uses the 'github.com/spf13/jwalterweatherman' (aka jww) package for logging. The tests take the approach of examining the log file that is produced by this module to verify correct behaviour. This avoids refactoring the utils module. The log file messages written by the jww module are of the form: : yyyy/mm/dd The checkLogFile function checks each of these parts in turn except for the date string, which is currently ignored. The final part of the log file format can either be a single error message, or a series of strings followed by an error message. Both the error message and the series of strings can be empty strings. The log file is checked using a combination of the regex package, along with the bufio scanner type. Each test logs to its own temporary log file. This is achieved with standard test setup and teardown functions. One consequence of these tests is that StopOnErr has been refactored into call a new unexported function doStopOnErr which contains the bulk of the original logic. This allows the same testing approach to be used with StopOnErr as with CheckErr and cutUsageMessage, rather than look at the exit status code of the test itself. An unfortunate side effect of this is that the author of the tests must now know if a log file is expected or not. If doStopOnErr determines that an empty error message would be written to the log file then nothing is written. In the context of the tests this means that the log file created by the test would have no contents. Consequently there would be nothing for the test to examine. This situation is indicated by the boolean flag logFileExoected in the testData struct, and processed by the logFileIsExpectedAndValid function. Although not ideal this was deemed a reasonable compromise. --- utils/utils.go | 37 +++++----- utils/utils_test.go | 167 +++++++++++++++++++++++++++++++++++++++++--- 2 files changed, 179 insertions(+), 25 deletions(-) diff --git a/utils/utils.go b/utils/utils.go index eaa6c09a9..381ebc53e 100644 --- a/utils/utils.go +++ b/utils/utils.go @@ -22,36 +22,39 @@ func CheckErr(err error, s ...string) { func StopOnErr(err error, s ...string) { if err != nil { - if len(s) == 0 { - newMessage := cutUsageMessage(err.Error()) + doStopOnErr(err, s...) + os.Exit(-1) + } +} - // Printing an empty string results in a error with - // no message, no bueno. - if newMessage != "" { - jww.CRITICAL.Println(newMessage) - } - } else { - for _, message := range s { - message := cutUsageMessage(message) +func doStopOnErr(err error, s ...string) { + if len(s) == 0 { + newMessage := cutUsageMessage(err.Error()) + // Printing an empty string results in a error with + // no message, no bueno. + if newMessage != "" { + jww.CRITICAL.Println(newMessage) + } + } else { + for _, message := range s { + message := cutUsageMessage(message) - if message != "" { - jww.CRITICAL.Println(message) - } + if message != "" { + jww.CRITICAL.Println(message) } } - os.Exit(-1) } } // cutUsageMessage splits the incoming string on the beginning of the usage // message text. Anything in the first element of the returned slice, trimmed -// of its Unicode defined spaces, should be returned. The 2nd element of the +// of its Unicode defined spaces, should be returned. The 2nd element of the // slice will have the usage message that we wish to elide. // // This is done because Cobra already prints Hugo's usage message; not eliding -// would result in the usage output being printed twice, which leads to bug +// would result in the usage output being printed twice, which leads to bug // reports, more specifically: https://github.com/spf13/hugo/issues/374 func cutUsageMessage(s string) string { - pieces := strings.Split(s, "Usage of") + pieces := strings.Split(s, "Usage of") return strings.TrimSpace(pieces[0]) } diff --git a/utils/utils_test.go b/utils/utils_test.go index 0bb92dea8..69acf7248 100644 --- a/utils/utils_test.go +++ b/utils/utils_test.go @@ -1,22 +1,35 @@ package utils import ( + "bufio" + "bytes" + "errors" + "io/ioutil" + "os" + "regexp" "testing" - ) + jww "github.com/spf13/jwalterweatherman" +) +type testData struct { + logLevel string + logError string + logStr []string + logFileExpected bool +} func TestCutUsageMessage(t *testing.T) { - tests := []struct{ - message string + tests := []struct { + message string cutMessage string }{ {"", ""}, - {" Usage of hugo: \n -b, --baseUrl=...", ""}, - {"Some error Usage of hugo: \n", "Some error"}, - {"Usage of hugo: \n -b --baseU", ""}, - {"CRITICAL error for usage of hugo ", "CRITICAL error for usage of hugo"}, - {"Invalid short flag a in -abcde", "Invalid short flag a in -abcde"}, + {" Usage of hugo: \n -b, --baseUrl=...", ""}, + {"Some error Usage of hugo: \n", "Some error"}, + {"Usage of hugo: \n -b --baseU", ""}, + {"CRITICAL error for usage of hugo ", "CRITICAL error for usage of hugo"}, + {"Invalid short flag a in -abcde", "Invalid short flag a in -abcde"}, } for _, test := range tests { @@ -26,3 +39,141 @@ func TestCutUsageMessage(t *testing.T) { } } } + +func TestCheckErr(t *testing.T) { + tests := []testData{ + {"ERROR", "first test case", []string{""}, true}, + {"ERROR", "second test case", []string{"banana", "man"}, true}, + {"ERROR", "third test case", []string{"multi-word string"}, true}, + {"ERROR", "fourth test case", []string{"multiple", "multi-word strings"}, true}, + {"CRITICAL", "Oops no array of strings", []string{}, true}, + } + for _, test := range tests { + filename := setup(t) + defer teardown(t, filename) + CheckErr(errors.New(test.logError), test.logStr...) // converts the array of strings in test.logStr to a varadic - cool! + checkLogFile(t, filename, &test) + } +} + +func TestDoStopOnErr(t *testing.T) { + tests := []struct { + message string + cutMessage string + t testData + }{ + {"", "", testData{"", "", []string{}, false}}, + {" Usage of hugo: \n -b, --baseUrl=...", "", testData{"", "", []string{}, false}}, + {"Some error Usage of hugo: \n", "Some error", testData{"CRITICAL", "Some error", []string{}, true}}, + // sould get the same output if we pass any array of strings and not via the error + {"Some error Usage of hugo: \n", "Some error", testData{"CRITICAL", "", []string{"Some error"}, true}}, + {"Usage of hugo: \n -b --baseU", "", testData{"", "", []string{""}, false}}, + {"CRITICAL error for usage of hugo ", "CRITICAL error for usage of hugo", testData{"CRITICAL", "CRITICAL error for usage of hugo", []string{""}, false}}, + {"CRITICAL error for usage of hugo ", "CRITICAL error for usage of hugo", testData{"CRITICAL", "", []string{"CRITICAL error for usage of hugo"}, true}}, + {"Invalid short flag a in -abcde", "Invalid short flag a in -abcde", testData{"CRITICAL", "Invalid short flag a in -abcde", []string{""}, false}}, + {"Invalid short flag a in -abcde", "Invalid short flag a in -abcde", testData{"CRITICAL", "", []string{"Invalid short flag a in -abcde"}, true}}, + } + + for _, test := range tests { + filename := setup(t) + defer teardown(t, filename) + doStopOnErr(errors.New(test.t.logError), test.t.logStr...) // converts the array of strings in test.logStr to a varadic - cool! + checkLogFile(t, filename, &test.t) + } + +} + +func checkLogFile(t *testing.T, filename string, test *testData) { + contents, err := ioutil.ReadFile(filename) + if err != nil { + t.Fatalf("Could not open the log file \"%s\". Failed with %v\n", filename, err) + } + // does the test expect to have a log file. If so, it must also have contents. + if !logFileIsExpectedAndValid(t, filename, test, &contents) { + return + } + r := bytes.NewReader(contents) + scanner := bufio.NewScanner(r) + errorMessageMatches := false + for scanner.Scan() { + line := scanner.Text() + // lines in the log file are of the form: + // : yyyy/mm/dd + // we pase this format left to right in three sections + checkForExpectedLogLevelOrFail(t, line, test) + errorMessageMatches = checkForExpectedErrorMsg(t, line, test) + // There was no match against the error message. So see if it matchs one of the error strings + if !errorMessageMatches { + checkForExpectedStingOrFail(t, line, test) + } + } + if err = scanner.Err(); err != nil { + t.Fatalf("Could not scan the next token in the log file. Failed with: %v\n", err) + } +} + +func logFileIsExpectedAndValid(t *testing.T, filename string, test *testData, contents *[]byte) bool { + if test.logFileExpected { + // yup, so then the file cannot be empty. + if len(*contents) == 0 { + t.Fatalf("Unexpected empty log file! Filename:\"%s\"\n", filename) + } + return true + } + // we don't expect a log file for this test so bail here. + return false +} + +func checkForExpectedLogLevelOrFail(t *testing.T, line string, test *testData) { + regexpErrorLabel := "^" + test.logLevel + validErrorLevel := regexp.MustCompile(regexpErrorLabel) + if !validErrorLevel.MatchString(line) { + // can't find the expected start of line string. So fail + t.Fatalf("Did not find the expected log level \"%s\" at the start of the line \"%s\"\n", test.logLevel, line) + } +} + +func checkForExpectedErrorMsg(t *testing.T, line string, test *testData) bool { + regexpValidErrorMsg := test.logError + "$" + validErrorMsg := regexp.MustCompile(regexpValidErrorMsg) + return validErrorMsg.MatchString(line) +} + +func checkForExpectedStingOrFail(t *testing.T, line string, test *testData) { + for _, s := range test.logStr { + regexpstr := s + "$" + validLineEnd := regexp.MustCompile(regexpstr) + if validLineEnd.MatchString(line) { + return + } + } + // if we reach here there was no match. + // Note: It's not possibe for this to be called with test.logStr as an empty array. + // The proceeding call to checkForExpectedErrorMsg + // in checkLogFile guarentees this. i.e. checkForExpecedErrorMsg will return true in this case. + t.Fatalf("Did not find any of the strings \"%v\" in \"%s\"\n", test.logStr, line) +} + +func setup(t *testing.T) string { + // first set the logger + // we can't use jww.UseLogTempFile for this, becase we need the file name + // so we can delete the file in teardown function. + // We should really fix jww.UseLogTempFile so we can access the temp file, or + // better yet provide a "DeleteTempLogFile" function + const logfilename = "utils_test_" + f, err := ioutil.TempFile(os.TempDir(), logfilename) + if err != nil { + t.Errorf("Error: Could not create temporary file for the logger. Error: %#v\n", err) + } + jww.SetStdoutThreshold(jww.LevelFatal) + // jww.SetLogFile generates the "Logging to .... " line on stdout. + // Maybe we should update jww to remove the fmt.PrintF calls? + jww.SetLogFile(f.Name()) + return f.Name() +} + +func teardown(t *testing.T, f string) { + if err := os.Remove(f); err != nil { + t.Errorf("Error: Could not remove file \"f\". Error: %v\n", err) + } +}