From a3a20e0396c3eb927a0ea3940b5f014accd0a711 Mon Sep 17 00:00:00 2001 From: James Bardin Date: Sun, 18 Oct 2020 11:25:44 -0400 Subject: [PATCH] remove LevelFilter We want to always be using the hclogger to filter whenever possible --- helper/resource/testing.go | 51 +---------- internal/logging/level.go | 159 --------------------------------- internal/logging/level_test.go | 93 ------------------- internal/logging/logging.go | 2 +- 4 files changed, 3 insertions(+), 302 deletions(-) delete mode 100644 internal/logging/level.go delete mode 100644 internal/logging/level_test.go diff --git a/helper/resource/testing.go b/helper/resource/testing.go index 5b9ccee29..c36ff4b2e 100644 --- a/helper/resource/testing.go +++ b/helper/resource/testing.go @@ -4,7 +4,6 @@ import ( "bytes" "flag" "fmt" - "io" "io/ioutil" "log" "os" @@ -12,7 +11,6 @@ import ( "reflect" "regexp" "strings" - "syscall" "testing" "github.com/davecgh/go-spew/spew" @@ -25,11 +23,12 @@ import ( "github.com/hashicorp/terraform/configs" "github.com/hashicorp/terraform/configs/configload" "github.com/hashicorp/terraform/internal/initwd" - "github.com/hashicorp/terraform/internal/logging" "github.com/hashicorp/terraform/providers" "github.com/hashicorp/terraform/states" "github.com/hashicorp/terraform/terraform" "github.com/hashicorp/terraform/tfdiags" + + _ "github.com/hashicorp/terraform/internal/logging" ) // flagSweep is a flag available when running tests on the command line. It @@ -392,46 +391,6 @@ type TestStep struct { // Set to a file mask in sprintf format where %s is test name const EnvLogPathMask = "TF_LOG_PATH_MASK" -func LogOutput(t TestT) (logOutput io.Writer, err error) { - logOutput = ioutil.Discard - - logLevel := logging.CurrentLogLevel() - if logLevel == "" { - return - } - - logOutput = os.Stderr - - if logPath := os.Getenv(logging.EnvLogFile); logPath != "" { - var err error - logOutput, err = os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666) - if err != nil { - return nil, err - } - } - - if logPathMask := os.Getenv(EnvLogPathMask); logPathMask != "" { - // Escape special characters which may appear if we have subtests - testName := strings.Replace(t.Name(), "/", "__", -1) - - logPath := fmt.Sprintf(logPathMask, testName) - var err error - logOutput, err = os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666) - if err != nil { - return nil, err - } - } - - // This was the default since the beginning - logOutput = &logging.LevelFilter{ - Levels: logging.ValidLevels, - MinLevel: logging.LogLevel(logLevel), - Writer: logOutput, - } - - return -} - // ParallelTest performs an acceptance test on a resource, allowing concurrency // with other ParallelTest. // @@ -464,12 +423,6 @@ func Test(t TestT, c TestCase) { return } - logWriter, err := LogOutput(t) - if err != nil { - t.Error(fmt.Errorf("error setting up logging: %s", err)) - } - log.SetOutput(logWriter) - // We require verbose mode so that the user knows what is going on. if !testTesting && !testing.Verbose() && !c.IsUnitTest { t.Fatal("Acceptance tests must be run with the -v flag on tests") diff --git a/internal/logging/level.go b/internal/logging/level.go deleted file mode 100644 index 0dc4dfe8d..000000000 --- a/internal/logging/level.go +++ /dev/null @@ -1,159 +0,0 @@ -package logging - -import ( - "bytes" - "io" - "sync" -) - -// LogLevel is a special string, conventionally written all in uppercase, that -// can be used to mark a log line for filtering and to specify filtering -// levels in the LevelFilter type. -type LogLevel string - -// LevelFilter is an io.Writer that can be used with a logger that -// will attempt to filter out log messages that aren't at least a certain -// level. -// -// This filtering is HEURISTIC-BASED, and so will not be 100% reliable. The -// assumptions it makes are: -// -// - Individual log messages are never split across multiple calls to the -// Write method. -// -// - Messages that carry levels are marked by a sequence starting with "[", -// then the level name string, and then "]". Any message without a sequence -// like this is an un-levelled message, and is not subject to filtering. -// -// - Each \n-delimited line in a write is a separate log message, unless a -// line starts with at least one space in which case it is interpreted -// as a continuation of the previous line. -// -// - If a log line starts with a non-whitespace character that isn't a digit -// then it's recognized as a degenerate continuation, because "real" log -// lines should start with a date/time and thus always have a leading -// digit. (This also cleans up after some situations where the assumptuion -// that messages arrive atomically aren't met, which is sadly sometimes -// true for longer messages that trip over some buffering behavior in -// panicwrap.) -// -// Because logging is a cross-cutting concern and not fully under the control -// of Terraform itself, there will certainly be cases where the above -// heuristics will fail. For example, it is likely that LevelFilter will -// occasionally misinterpret a continuation line as a new message because the -// code generating it doesn't know about our indentation convention. -// -// Our goal here is just to make a best effort to reduce the log volume, -// accepting that the results will not be 100% correct. -// -// Logging calls within Terraform Core should follow the above conventions so -// that the log output is broadly correct, however. -// -// Once the filter is in use somewhere, it is not safe to modify -// the structure. -type LevelFilter struct { - // Levels is the list of log levels, in increasing order of - // severity. Example might be: {"DEBUG", "WARN", "ERROR"}. - Levels []LogLevel - - // MinLevel is the minimum level allowed through - MinLevel LogLevel - - // The underlying io.Writer where log messages that pass the filter - // will be set. - Writer io.Writer - - badLevels map[LogLevel]struct{} - show bool - once sync.Once -} - -// Check will check a given line if it would be included in the level -// filter. -func (f *LevelFilter) Check(line []byte) bool { - f.once.Do(f.init) - - // Check for a log level - var level LogLevel - x := bytes.IndexByte(line, '[') - if x >= 0 { - y := bytes.IndexByte(line[x:], ']') - if y >= 0 { - level = LogLevel(line[x+1 : x+y]) - } - } - - //return level == "" - - _, ok := f.badLevels[level] - return !ok -} - -// Write is a specialized implementation of io.Writer suitable for being -// the output of a logger from the "log" package. -// -// This Writer implementation assumes that it will only recieve byte slices -// containing one or more entire lines of log output, each one terminated by -// a newline. This is compatible with the behavior of the "log" package -// directly, and is also tolerant of intermediaries that might buffer multiple -// separate writes together, as long as no individual log line is ever -// split into multiple slices. -// -// Behavior is undefined if any log line is split across multiple writes or -// written without a trailing '\n' delimiter. -func (f *LevelFilter) Write(p []byte) (n int, err error) { - for len(p) > 0 { - // Split at the first \n, inclusive - idx := bytes.IndexByte(p, '\n') - if idx == -1 { - // Invalid, undelimited write. We'll tolerate it assuming that - // our assumptions are being violated, but the results may be - // non-ideal. - idx = len(p) - 1 - break - } - var l []byte - l, p = p[:idx+1], p[idx+1:] - // Lines starting with characters other than decimal digits (including - // whitespace) are assumed to be continuations lines. This is an - // imprecise heuristic, but experimentally it seems to generate - // "good enough" results from Terraform Core's own logging. Its mileage - // may vary with output from other systems. - if l[0] >= '0' && l[0] <= '9' { - f.show = f.Check(l) - } - if f.show { - _, err = f.Writer.Write(l) - if err != nil { - // Technically it's not correct to say we've written the whole - // buffer, but for our purposes here it's good enough as we're - // only implementing io.Writer enough to satisfy logging - // use-cases. - return len(p), err - } - } - } - - // We always behave as if we wrote the whole of the buffer, even if - // we actually skipped some lines. We're only implementiong io.Writer - // enough to satisfy logging use-cases. - return len(p), nil -} - -// SetMinLevel is used to update the minimum log level -func (f *LevelFilter) SetMinLevel(min LogLevel) { - f.MinLevel = min - f.init() -} - -func (f *LevelFilter) init() { - badLevels := make(map[LogLevel]struct{}) - for _, level := range f.Levels { - if level == f.MinLevel { - break - } - badLevels[level] = struct{}{} - } - f.badLevels = badLevels - f.show = true -} diff --git a/internal/logging/level_test.go b/internal/logging/level_test.go deleted file mode 100644 index baa94748e..000000000 --- a/internal/logging/level_test.go +++ /dev/null @@ -1,93 +0,0 @@ -package logging - -import ( - "bytes" - "io" - "log" - "testing" -) - -func TestLevelFilter_impl(t *testing.T) { - var _ io.Writer = new(LevelFilter) -} - -func TestLevelFilter(t *testing.T) { - buf := new(bytes.Buffer) - filter := &LevelFilter{ - Levels: []LogLevel{"DEBUG", "WARN", "ERROR"}, - MinLevel: "WARN", - Writer: buf, - } - - logger := log.New(filter, "", 0) - logger.Print("2019/01/01 00:00:00 [WARN] foo") - logger.Println("2019/01/01 00:00:00 [ERROR] bar\n2019/01/01 00:00:00 [DEBUG] buzz") - logger.Println("2019/01/01 00:00:00 [DEBUG] baz\n continuation\n2019/01/01 00:00:00 [WARN] buzz\n more\n2019/01/01 00:00:00 [DEBUG] fizz") - - result := buf.String() - expected := "2019/01/01 00:00:00 [WARN] foo\n2019/01/01 00:00:00 [ERROR] bar\n2019/01/01 00:00:00 [WARN] buzz\n more\n" - if result != expected { - t.Fatalf("wrong result\ngot:\n%s\nwant:\n%s", result, expected) - } -} - -func TestLevelFilterCheck(t *testing.T) { - filter := &LevelFilter{ - Levels: []LogLevel{"DEBUG", "WARN", "ERROR"}, - MinLevel: "WARN", - Writer: nil, - } - - testCases := []struct { - line string - check bool - }{ - {"[WARN] foo\n", true}, - {"[ERROR] bar\n", true}, - {"[DEBUG] baz\n", false}, - {"[WARN] buzz\n", true}, - } - - for _, testCase := range testCases { - result := filter.Check([]byte(testCase.line)) - if result != testCase.check { - t.Errorf("Fail: %s", testCase.line) - } - } -} - -func TestLevelFilter_SetMinLevel(t *testing.T) { - filter := &LevelFilter{ - Levels: []LogLevel{"DEBUG", "WARN", "ERROR"}, - MinLevel: "ERROR", - Writer: nil, - } - - testCases := []struct { - line string - checkBefore bool - checkAfter bool - }{ - {"[WARN] foo\n", false, true}, - {"[ERROR] bar\n", true, true}, - {"[DEBUG] baz\n", false, false}, - {"[WARN] buzz\n", false, true}, - } - - for _, testCase := range testCases { - result := filter.Check([]byte(testCase.line)) - if result != testCase.checkBefore { - t.Errorf("Fail: %s", testCase.line) - } - } - - // Update the minimum level to WARN - filter.SetMinLevel("WARN") - - for _, testCase := range testCases { - result := filter.Check([]byte(testCase.line)) - if result != testCase.checkAfter { - t.Errorf("Fail: %s", testCase.line) - } - } -} diff --git a/internal/logging/logging.go b/internal/logging/logging.go index 1ba199b92..52ac75b00 100644 --- a/internal/logging/logging.go +++ b/internal/logging/logging.go @@ -20,7 +20,7 @@ const ( ) // ValidLevels are the log level names that Terraform recognizes. -var ValidLevels = []LogLevel{"TRACE", "DEBUG", "INFO", "WARN", "ERROR"} +var ValidLevels = []string{"TRACE", "DEBUG", "INFO", "WARN", "ERROR"} // logger is the global hclog logger var logger hclog.Logger