From 4bc6f62f5194fa630ddfe3acfc74a26a9bea4787 Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Thu, 21 Apr 2022 15:49:57 -0500 Subject: [PATCH 1/8] Fix Tail.sendLine() to NOT drop log lines when the tailer is dying because of errStopAtEOF. --- plugins/inputs/logfile/logfile.go | 6 +- plugins/inputs/logfile/logfile_test.go | 154 +++++++++++++---------- plugins/inputs/logfile/tail/tail.go | 13 +- plugins/inputs/logfile/tail/tail_test.go | 47 +++++-- plugins/inputs/logfile/tailersrc.go | 14 ++- 5 files changed, 150 insertions(+), 84 deletions(-) diff --git a/plugins/inputs/logfile/logfile.go b/plugins/inputs/logfile/logfile.go index e1c7f48fbf..80932ce553 100644 --- a/plugins/inputs/logfile/logfile.go +++ b/plugins/inputs/logfile/logfile.go @@ -167,9 +167,11 @@ func (t *LogFile) FindLogSrc() []logs.LogSrc { if _, ok := dests[filename]; ok { continue - } else if fileconfig.AutoRemoval { // This logic means auto_removal does not work with publish_multi_logs + } else if fileconfig.AutoRemoval { + // This logic means auto_removal does not work with publish_multi_logs for _, dst := range dests { - dst.tailer.StopAtEOF() // Stop all other tailers in favor of the newly found file + // Stop all other tailers in favor of the newly found file + dst.tailer.StopAtEOF() } } diff --git a/plugins/inputs/logfile/logfile_test.go b/plugins/inputs/logfile/logfile_test.go index ebea61c5d4..eea5c52486 100644 --- a/plugins/inputs/logfile/logfile_test.go +++ b/plugins/inputs/logfile/logfile_test.go @@ -358,100 +358,128 @@ func TestLogsFileRemove(t *testing.T) { tt.Stop() } -//When another file is created for the same file config and the file config has auto_removal as true, the old files will stop at EOF and removed afterwards -func TestLogsFileAutoRemoval(t *testing.T) { - var wg sync.WaitGroup +// getLogSrc returns a LogSrc from the given LogFile, and the channel for output. +// Verifies 1 and only 1 LogSrc is discovered. +func getLogSrc(t *testing.T, logFile *LogFile) (*logs.LogSrc, chan logs.LogEvent) { + logSources := logFile.FindLogSrc() + require.Equal(t, 1, len(logSources)) + logSource := logSources[0] + evts := make(chan logs.LogEvent) + logSource.SetOutput(func(e logs.LogEvent) { + if e != nil { + evts <- e + } + }) + return &logSource, evts +} +func writeSomeLines(t *testing.T, file *os.File, numLines int, msg string) { + for i := 0; i < numLines; i++ { + //time.Sleep(1 * time.Millisecond) + //fmt.Printf("write i %v\n", i) + _, err := file.WriteString(msg + "\n") + require.NoError(t, err) + } +} + +// TestLogsFileAutoRemoval verifies when a new file matching the configured +// FilePath is discovered, the old file will be automatically deleted after +// being read to the end-of-file. +func TestLogsFileAutoRemoval(t *testing.T) { + // Override global in tailersrc.go. multilineWaitPeriod = 10 * time.Millisecond - logEntryString := "anything" + filePrefix := "file_auto_removal" tmpfile1, err := createTempFile("", filePrefix) + fmt.Printf("Created 1st temp file, %s\n", tmpfile1.Name()) require.NoError(t, err) - _, err = tmpfile1.WriteString(logEntryString + "\n") - require.NoError(t, err) - tmpfile1.Sync() - tmpfile1.Close() - - tt := NewLogFile() - tt.Log = TestLogger{t} - tt.FileConfig = []FileConfig{{ + logFile := NewLogFile() + defer logFile.Stop() + logFile.Log = TestLogger{t} + logFile.FileConfig = []FileConfig{{ FilePath: filepath.Join(filepath.Dir(tmpfile1.Name()), filePrefix+"*"), FromBeginning: true, AutoRemoval: true, }} - tt.FileConfig[0].init() - tt.started = true + logFile.FileConfig[0].init() + logFile.started = true - lsrcs := tt.FindLogSrc() - if len(lsrcs) != 1 { - t.Fatalf("%v log src was returned when 1 should be available", len(lsrcs)) - } + logSource, evts := getLogSrc(t, logFile) + defer (*logSource).Stop() - lsrc := lsrcs[0] - evts := make(chan logs.LogEvent) - lsrc.SetOutput(func(e logs.LogEvent) { - if e != nil { - evts <- e - } - }) + fmt.Println("Fill temp file with sufficient lines to be read.") + numLogLinesToWrite := 10000 + logEntryString := "this is the best log line ever written to a file" + writeSomeLines(t, tmpfile1, numLogLinesToWrite, logEntryString) + tmpfile1.Close() var tmpfile2 *os.File + var logSource2 *logs.LogSrc + var evts2 chan logs.LogEvent defer func() { + if logSource2 != nil { + (*logSource2).Stop() + } if tmpfile2 != nil { + tmpfile2.Close() os.Remove(tmpfile2.Name()) } }() - wg.Add(1) + fmt.Println("Verify every line written to the first temp file is received.") + // Do this in a goroutine in case there is a bug and it hangs. + readerDone := make(chan bool) + // Need to make sure tmpfile2 is created before accessing evts2 + fileCreatorDone := make(chan bool) go func() { - defer wg.Done() - - // create a new file matching configured pattern - tmpfile2, err = createTempFile("", filePrefix) - require.NoError(t, err) - - _, err = tmpfile2.WriteString(logEntryString + "\n") - require.NoError(t, err) - + defer close(readerDone) + for i := 0; i < numLogLinesToWrite; i++ { + logEvent := <- evts + require.Equal(t, logEntryString, logEvent.Message()) + if i != numLogLinesToWrite / 2 { + continue + } + // Halfway through receiving events create a new temp file. + // Still expect to recv all events from the first file. + // Need to do this in a goroutine since FindLogSrc() + // will block until tailer reaches EOF on first temp file. + go func() { + defer close(fileCreatorDone) + tmpfile2, err = createTempFile("", filePrefix) + fmt.Printf("Created 2nd temp file, %s\n", tmpfile2.Name()) + require.NoError(t, err) + _, err = tmpfile2.WriteString(logEntryString + "\n") + require.NoError(t, err) + logSource2, evts2 = getLogSrc(t, logFile) + }() + } }() - e := <-evts - if e.Message() != logEntryString { - t.Errorf("Wrong log found from first file: \n%v\nExpecting:\n%v\n", e.Message(), logEntryString) - } - defer lsrc.Stop() - - for { - lsrcs = tt.FindLogSrc() - if len(lsrcs) > 0 { - break - } - time.Sleep(1 * time.Second) + fmt.Println("Verify reader completed.") + select { + case <-readerDone: + fmt.Println("Completed before timeout (as expected)") + case <-time.After(time.Second * 10): + t.Fatalf("timeout waiting for reader") } - lsrc = lsrcs[0] - lsrc.SetOutput(func(e logs.LogEvent) { - if e != nil { - evts <- e - } - }) - - e = <-evts - if e.Message() != logEntryString { - t.Errorf("Wrong log found from 2nd file: \n% x\nExpecting:\n% x\n", e.Message(), logEntryString) + fmt.Println("Verify 2nd tmp file created and discovered.") + select { + case <-fileCreatorDone: + fmt.Println("Completed before timeout (as expected)") + case <-time.After(time.Second * 10): + t.Fatalf("timeout waiting for 2nd temp file.") } - //Use Wait Group to avoid race condition between opening tmpfile2 to delete tmpfile1 with auto_removal and opening tmpfile1 - //to check it exist - wg.Wait() + fmt.Println("Verify message in 2nd temp file.") + e2 := <- evts2 + assert.Equal(t, logEntryString, e2.Message()) + fmt.Println("Verify 1st temp file was auto deleted.") _, err = os.Open(tmpfile1.Name()) assert.True(t, os.IsNotExist(err)) - - lsrc.Stop() - tt.Stop() } func TestLogsTimestampAsMultilineStarter(t *testing.T) { diff --git a/plugins/inputs/logfile/tail/tail.go b/plugins/inputs/logfile/tail/tail.go index b270e197e4..bc4b333dc9 100644 --- a/plugins/inputs/logfile/tail/tail.go +++ b/plugins/inputs/logfile/tail/tail.go @@ -158,6 +158,7 @@ func (tail *Tail) Stop() error { } // StopAtEOF stops tailing as soon as the end of the file is reached. +// Blocks until tailer is dead and returns reason for death. func (tail *Tail) StopAtEOF() error { tail.Kill(errStopAtEOF) return tail.Wait() @@ -390,7 +391,7 @@ func (tail *Tail) tailFileSync() { if errReadLine == nil { tail.sendLine(line, tail.curOffset) } else { - break + return } } } else if err != ErrStop { @@ -465,7 +466,6 @@ func (tail *Tail) waitForChanges() error { case <-tail.Dying(): return ErrStop } - } func (tail *Tail) openReader() { @@ -510,8 +510,13 @@ func (tail *Tail) sendLine(line string, offset int64) bool { select { case tail.Lines <- &Line{line, now, nil, offset}: case <-tail.Dying(): - tail.dropCnt += len(lines) - i - return true + if tail.Err() == errStopAtEOF { + // Try sending, even if it blocks. + tail.Lines <- &Line{line, now, nil, offset} + } else { + tail.dropCnt += len(lines) - i + return true + } } } diff --git a/plugins/inputs/logfile/tail/tail_test.go b/plugins/inputs/logfile/tail/tail_test.go index 765dfa89a4..45d4382c67 100644 --- a/plugins/inputs/logfile/tail/tail_test.go +++ b/plugins/inputs/logfile/tail/tail_test.go @@ -8,8 +8,12 @@ import ( "strings" "testing" "time" + + "gotest.tools/assert" ) +var linesWrittenToFile int = 10 + type testLogger struct { debugs, infos, warns, errors []string } @@ -56,6 +60,7 @@ func (l *testLogger) Info(args ...interface{}) { func TestNotTailedCompeletlyLogging(t *testing.T) { tmpfile, tail, tlog := setup(t) + tmpfile.Close() defer tearDown(tmpfile) readThreelines(t, tail) @@ -71,22 +76,46 @@ func TestNotTailedCompeletlyLogging(t *testing.T) { verifyTailerExited(t, tail) } -func TestDroppedLinesWhenStopAtEOFLogging(t *testing.T) { - tmpfile, tail, tlog := setup(t) +func TestStopAtEOF(t *testing.T) { + tmpfile, tail, _ := setup(t) defer tearDown(tmpfile) readThreelines(t, tail) - // Ask the tailer to StopAtEOF - tail.StopAtEOF() + // Since StopAtEOF() will block until the EOF is reached, run it in a goroutine. + done := make(chan bool) + go func() { + tail.StopAtEOF() + close(done) + }() + + // Verify the goroutine is blocked indefinitely. + select { + case <-done: + t.Fatalf("StopAtEOF() completed unexpectedly") + case <-time.After(time.Second * 1): + fmt.Println("timeout waiting for StopAtEOF() (as expected)") + } + + assert.Equal(t, errStopAtEOF, tail.Err()) + + // Read to EOF + for i := 0; i < linesWrittenToFile - 3; i++ { + <-tail.Lines + } + + // Verify StopAtEOF() has completed. + select { + case <-done: + fmt.Println("StopAtEOF() completed (as expected)") + case <- time.After(time.Second * 1): + t.Fatalf("StopAtEOF() has not completed") + } + // Then remove the tmpfile if err := os.Remove(tmpfile.Name()); err != nil { t.Fatalf("failed to remove temporary log file %v: %v", tmpfile.Name(), err) } - // Wait until the tailer should have been terminated - time.Sleep(exitOnDeletionWaitDuration + exitOnDeletionCheckDuration + 1*time.Second) - - verifyTailerLogging(t, tlog, "Dropped 7 lines for stopped tail for file "+tmpfile.Name()) verifyTailerExited(t, tail) } @@ -97,7 +126,7 @@ func setup(t *testing.T) (*os.File, *Tail, *testLogger) { } // Write the file content - for i := 0; i < 10; i++ { + for i := 0; i < linesWrittenToFile; i++ { if _, err := fmt.Fprintf(tmpfile, "%v some log line\n", time.Now()); err != nil { log.Fatal(err) } diff --git a/plugins/inputs/logfile/tailersrc.go b/plugins/inputs/logfile/tailersrc.go index 858a869ad6..1bb07ca792 100644 --- a/plugins/inputs/logfile/tailersrc.go +++ b/plugins/inputs/logfile/tailersrc.go @@ -76,6 +76,8 @@ type tailerSrc struct { startTailerOnce sync.Once cleanUpFns []func() } +// Verify tailerSrc implements LogSrc +var _ logs.LogSrc = (*tailerSrc)(nil) func NewTailerSrc( group, stream, destination, stateFilePath string, @@ -119,26 +121,26 @@ func (ts *tailerSrc) SetOutput(fn func(logs.LogEvent)) { ts.startTailerOnce.Do(func() { go ts.runTail() }) } -func (ts tailerSrc) Group() string { +func (ts *tailerSrc) Group() string { return ts.group } -func (ts tailerSrc) Stream() string { +func (ts *tailerSrc) Stream() string { return ts.stream } -func (ts tailerSrc) Description() string { +func (ts *tailerSrc) Description() string { return ts.tailer.Filename } -func (ts tailerSrc) Destination() string { +func (ts *tailerSrc) Destination() string { return ts.destination } -func (ts tailerSrc) Retention() int { +func (ts *tailerSrc) Retention() int { return ts.retentionInDays } -func (ts tailerSrc) Done(offset fileOffset) { +func (ts *tailerSrc) Done(offset fileOffset) { // ts.offsetCh will only be blocked when the runSaveState func has exited, // which only happens when the original file has been removed, thus making // Keeping its offset useless From f501db3e9b3fa2527c57205b2071b0eb290c6d25 Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Fri, 22 Apr 2022 08:00:30 -0500 Subject: [PATCH 2/8] Change imported assert package. Use const instead of var. --- plugins/inputs/logfile/tail/tail_test.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/plugins/inputs/logfile/tail/tail_test.go b/plugins/inputs/logfile/tail/tail_test.go index 45d4382c67..670b4587e9 100644 --- a/plugins/inputs/logfile/tail/tail_test.go +++ b/plugins/inputs/logfile/tail/tail_test.go @@ -9,10 +9,10 @@ import ( "testing" "time" - "gotest.tools/assert" + "github.com/stretchr/testify/assert" ) -var linesWrittenToFile int = 10 +const linesWrittenToFile int = 10 type testLogger struct { debugs, infos, warns, errors []string From d6215e294506b74141d229634a3250666c64a31e Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Fri, 22 Apr 2022 09:35:53 -0500 Subject: [PATCH 3/8] Simplify TestLogsFileAutoRemoval(). --- plugins/inputs/logfile/logfile_test.go | 174 ++++++++++++------------- 1 file changed, 81 insertions(+), 93 deletions(-) diff --git a/plugins/inputs/logfile/logfile_test.go b/plugins/inputs/logfile/logfile_test.go index eea5c52486..7bce079814 100644 --- a/plugins/inputs/logfile/logfile_test.go +++ b/plugins/inputs/logfile/logfile_test.go @@ -358,6 +358,26 @@ func TestLogsFileRemove(t *testing.T) { tt.Stop() } +func setupLogFileForTest(t *testing.T, file *os.File, prefix string) *LogFile { + logFile := NewLogFile() + logFile.Log = TestLogger{t} + logFile.FileConfig = []FileConfig{{ + FilePath: filepath.Join(filepath.Dir(file.Name()), prefix+"*"), + FromBeginning: true, + AutoRemoval: true, + }} + logFile.FileConfig[0].init() + logFile.started = true + return logFile +} + +func makeTempFile(t *testing.T, prefix string) *os.File { + file, err := createTempFile("", prefix) + t.Logf("Created temp file, %s\n", file.Name()) + require.NoError(t, err) + return file +} + // getLogSrc returns a LogSrc from the given LogFile, and the channel for output. // Verifies 1 and only 1 LogSrc is discovered. func getLogSrc(t *testing.T, logFile *LogFile) (*logs.LogSrc, chan logs.LogEvent) { @@ -373,113 +393,81 @@ func getLogSrc(t *testing.T, logFile *LogFile) (*logs.LogSrc, chan logs.LogEvent return &logSource, evts } -func writeSomeLines(t *testing.T, file *os.File, numLines int, msg string) { +func writeLines(t *testing.T, file *os.File, numLines int, msg string) { + t.Log("Fill temp file with sufficient lines to be read.") for i := 0; i < numLines; i++ { - //time.Sleep(1 * time.Millisecond) - //fmt.Printf("write i %v\n", i) _, err := file.WriteString(msg + "\n") require.NoError(t, err) } } +// createWriteRead creates a temp file, writes to it, then verifies events +// are received. If isParent is true, then spawn a 2nd goroutine for createWriteRead. +// Close the given channel when complete to let caller know it was successful. +func createWriteRead(t *testing.T, prefix string, logFile *LogFile, done chan bool, isParent bool) { + // Let caller know when the goroutine is done. + defer close(done) + // done2 is only passed to child if this is the parent. + done2 := make(chan bool) + file := makeTempFile(t, prefix) + if isParent { + logFile = setupLogFileForTest(t, file, prefix) + defer logFile.Stop() + } + logSrc, evts := getLogSrc(t, logFile) + defer (*logSrc).Stop() + defer close(evts) + const numLines int = 1000 + const msg string = "this is the best log line ever written to a file" + writeLines(t, file, numLines, msg) + file.Close() + if !isParent { + // Child creates 2nd temp file which is NOT auto removed. + defer os.Remove(file.Name()) + } + t.Log("Verify every line written to the temp file is received.") + for i := 0; i < numLines; i++ { + logEvent := <- evts + require.Equal(t, msg, logEvent.Message()) + if i != numLines / 2 { + continue + } + // Halfway through start another goroutine to create another temp file. + if isParent { + go createWriteRead(t, prefix, logFile, done2, false) + } + } + // Only wait for child if it was spawned + if isParent { + t.Log("Verify child completed.") + select { + case <-done2: + t.Log("Completed before timeout (as expected)") + case <-time.After(time.Second * 5): + require.Fail(t, "timeout waiting for child") + } + t.Log("Verify 1st temp file was auto deleted.") + _, err := os.Open(file.Name()) + assert.True(t, os.IsNotExist(err)) + } +} + // TestLogsFileAutoRemoval verifies when a new file matching the configured // FilePath is discovered, the old file will be automatically deleted after // being read to the end-of-file. func TestLogsFileAutoRemoval(t *testing.T) { // Override global in tailersrc.go. multilineWaitPeriod = 10 * time.Millisecond - - filePrefix := "file_auto_removal" - tmpfile1, err := createTempFile("", filePrefix) - fmt.Printf("Created 1st temp file, %s\n", tmpfile1.Name()) - require.NoError(t, err) - - logFile := NewLogFile() - defer logFile.Stop() - logFile.Log = TestLogger{t} - logFile.FileConfig = []FileConfig{{ - FilePath: filepath.Join(filepath.Dir(tmpfile1.Name()), filePrefix+"*"), - FromBeginning: true, - AutoRemoval: true, - }} - logFile.FileConfig[0].init() - logFile.started = true - - logSource, evts := getLogSrc(t, logFile) - defer (*logSource).Stop() - - fmt.Println("Fill temp file with sufficient lines to be read.") - numLogLinesToWrite := 10000 - logEntryString := "this is the best log line ever written to a file" - writeSomeLines(t, tmpfile1, numLogLinesToWrite, logEntryString) - tmpfile1.Close() - - var tmpfile2 *os.File - var logSource2 *logs.LogSrc - var evts2 chan logs.LogEvent - defer func() { - if logSource2 != nil { - (*logSource2).Stop() - } - if tmpfile2 != nil { - tmpfile2.Close() - os.Remove(tmpfile2.Name()) - } - }() - - fmt.Println("Verify every line written to the first temp file is received.") - // Do this in a goroutine in case there is a bug and it hangs. - readerDone := make(chan bool) - // Need to make sure tmpfile2 is created before accessing evts2 - fileCreatorDone := make(chan bool) - - go func() { - defer close(readerDone) - for i := 0; i < numLogLinesToWrite; i++ { - logEvent := <- evts - require.Equal(t, logEntryString, logEvent.Message()) - if i != numLogLinesToWrite / 2 { - continue - } - // Halfway through receiving events create a new temp file. - // Still expect to recv all events from the first file. - // Need to do this in a goroutine since FindLogSrc() - // will block until tailer reaches EOF on first temp file. - go func() { - defer close(fileCreatorDone) - tmpfile2, err = createTempFile("", filePrefix) - fmt.Printf("Created 2nd temp file, %s\n", tmpfile2.Name()) - require.NoError(t, err) - _, err = tmpfile2.WriteString(logEntryString + "\n") - require.NoError(t, err) - logSource2, evts2 = getLogSrc(t, logFile) - }() - } - }() - - fmt.Println("Verify reader completed.") - select { - case <-readerDone: - fmt.Println("Completed before timeout (as expected)") - case <-time.After(time.Second * 10): - t.Fatalf("timeout waiting for reader") - } - - fmt.Println("Verify 2nd tmp file created and discovered.") + prefix := "file_auto_removal" + done := make(chan bool) + createWriteRead(t, prefix, nil, done, true) + t.Log("Verify 1st tmp file created and discovered.") select { - case <-fileCreatorDone: - fmt.Println("Completed before timeout (as expected)") - case <-time.After(time.Second * 10): - t.Fatalf("timeout waiting for 2nd temp file.") + case <-done: + t.Log("Completed before timeout (as expected)") + case <-time.After(time.Second * 5): + require.Fail(t, "timeout waiting for 2nd temp file.") } - - fmt.Println("Verify message in 2nd temp file.") - e2 := <- evts2 - assert.Equal(t, logEntryString, e2.Message()) - - fmt.Println("Verify 1st temp file was auto deleted.") - _, err = os.Open(tmpfile1.Name()) - assert.True(t, os.IsNotExist(err)) } func TestLogsTimestampAsMultilineStarter(t *testing.T) { From 89f75615cb13eae87cf65432331a7ae05ffeb46f Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Fri, 22 Apr 2022 12:45:37 -0500 Subject: [PATCH 4/8] Remove extra file.Close(). --- plugins/inputs/logfile/tail/tail_test.go | 1 - 1 file changed, 1 deletion(-) diff --git a/plugins/inputs/logfile/tail/tail_test.go b/plugins/inputs/logfile/tail/tail_test.go index 670b4587e9..5b72769ca9 100644 --- a/plugins/inputs/logfile/tail/tail_test.go +++ b/plugins/inputs/logfile/tail/tail_test.go @@ -60,7 +60,6 @@ func (l *testLogger) Info(args ...interface{}) { func TestNotTailedCompeletlyLogging(t *testing.T) { tmpfile, tail, tlog := setup(t) - tmpfile.Close() defer tearDown(tmpfile) readThreelines(t, tail) From 814331fa03f4b5c5558162557e843cb3a8b1177f Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Mon, 25 Apr 2022 09:23:51 -0500 Subject: [PATCH 5/8] Use t.Log() instead of fmt.Println(). --- plugins/inputs/logfile/tail/tail_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/plugins/inputs/logfile/tail/tail_test.go b/plugins/inputs/logfile/tail/tail_test.go index 5b72769ca9..de221b234a 100644 --- a/plugins/inputs/logfile/tail/tail_test.go +++ b/plugins/inputs/logfile/tail/tail_test.go @@ -93,7 +93,7 @@ func TestStopAtEOF(t *testing.T) { case <-done: t.Fatalf("StopAtEOF() completed unexpectedly") case <-time.After(time.Second * 1): - fmt.Println("timeout waiting for StopAtEOF() (as expected)") + t.Log("timeout waiting for StopAtEOF() (as expected)") } assert.Equal(t, errStopAtEOF, tail.Err()) From 4a84ecf29f2d39aae0cbc01e22563f0e399d2339 Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Mon, 25 Apr 2022 09:34:56 -0500 Subject: [PATCH 6/8] Use t.Log() instead of fmt.Println() in more places. --- cmd/config-translator/translator_test.go | 19 +++++++++---------- logger/lumberjack_logger_test.go | 3 +-- plugins/inputs/logfile/tail/tail_test.go | 2 +- .../windows_event_log_test.go | 8 ++++---- .../awscsm/metametrics/listener_test.go | 2 +- translator/toenvconfig/toEnvConfig_test.go | 5 ++--- 6 files changed, 18 insertions(+), 21 deletions(-) diff --git a/cmd/config-translator/translator_test.go b/cmd/config-translator/translator_test.go index 1048a3cf3a..661c1f88b0 100644 --- a/cmd/config-translator/translator_test.go +++ b/cmd/config-translator/translator_test.go @@ -4,7 +4,6 @@ package main import ( - "fmt" "io/ioutil" "regexp" "testing" @@ -34,13 +33,13 @@ func checkIfSchemaValidateAsExpected(t *testing.T, jsonInputPath string, shouldS } else { errorDetails := result.Errors() for _, errorDetail := range errorDetails { - fmt.Printf("String: %v \n", errorDetail.String()) - fmt.Printf("Context: %v \n", errorDetail.Context().String()) - fmt.Printf("Description: %v \n", errorDetail.Description()) - fmt.Printf("Details: %v \n", errorDetail.Details()) - fmt.Printf("Field: %v \n", errorDetail.Field()) - fmt.Printf("Type: %v \n", errorDetail.Type()) - fmt.Printf("Value: %v \n", errorDetail.Value()) + t.Logf("String: %v \n", errorDetail.String()) + t.Logf("Context: %v \n", errorDetail.Context().String()) + t.Logf("Description: %v \n", errorDetail.Description()) + t.Logf("Details: %v \n", errorDetail.Details()) + t.Logf("Field: %v \n", errorDetail.Field()) + t.Logf("Type: %v \n", errorDetail.Type()) + t.Logf("Value: %v \n", errorDetail.Value()) if _, ok := actualErrorMap[errorDetail.Type()]; ok { actualErrorMap[errorDetail.Type()] += 1 } else { @@ -185,9 +184,9 @@ func TestSampleConfigSchema(t *testing.T) { re := regexp.MustCompile(".json") for _, file := range files { if re.MatchString(file.Name()) { - fmt.Printf("Validating ../../translator/totomlconfig/sampleConfig/%s\n", file.Name()) + t.Logf("Validating ../../translator/totomlconfig/sampleConfig/%s\n", file.Name()) checkIfSchemaValidateAsExpected(t, "../../translator/totomlconfig/sampleConfig/"+file.Name(), true, map[string]int{}) - fmt.Printf("Validated ../../translator/totomlconfig/sampleConfig/%s\n", file.Name()) + t.Logf("Validated ../../translator/totomlconfig/sampleConfig/%s\n", file.Name()) } } } else { diff --git a/logger/lumberjack_logger_test.go b/logger/lumberjack_logger_test.go index 7be85f3a65..d8ef85b279 100644 --- a/logger/lumberjack_logger_test.go +++ b/logger/lumberjack_logger_test.go @@ -4,7 +4,6 @@ package logger import ( - "fmt" "io" "io/ioutil" "log" @@ -141,7 +140,7 @@ func TestWriteToFileInRotation(t *testing.T) { files, _ = ioutil.ReadDir(tempDir) for _, file := range files { - fmt.Printf("%v/%v, size:%v\n", tempDir, file.Name(), file.Size()) + t.Logf("%v/%v, size:%v\n", tempDir, file.Name(), file.Size()) } assert.Equal(t, 4, len(files)) diff --git a/plugins/inputs/logfile/tail/tail_test.go b/plugins/inputs/logfile/tail/tail_test.go index de221b234a..ddd74a46bc 100644 --- a/plugins/inputs/logfile/tail/tail_test.go +++ b/plugins/inputs/logfile/tail/tail_test.go @@ -106,7 +106,7 @@ func TestStopAtEOF(t *testing.T) { // Verify StopAtEOF() has completed. select { case <-done: - fmt.Println("StopAtEOF() completed (as expected)") + t.Log("StopAtEOF() completed (as expected)") case <- time.After(time.Second * 1): t.Fatalf("StopAtEOF() has not completed") } diff --git a/plugins/inputs/windows_event_log/windows_event_log_test.go b/plugins/inputs/windows_event_log/windows_event_log_test.go index 8f5e1178be..86b4975e8b 100644 --- a/plugins/inputs/windows_event_log/windows_event_log_test.go +++ b/plugins/inputs/windows_event_log/windows_event_log_test.go @@ -27,7 +27,7 @@ func TestGetStateFilePathGood(t *testing.T) { Name: "SystemEventLog", } pathname, err := getStateFilePath(&plugin, &ec) - fmt.Println(pathname) + t.Log(pathname) if err != nil { t.Errorf("expected nil, actual %v", err) } @@ -55,7 +55,7 @@ func TestGetStateFilePathEscape(t *testing.T) { Name: "System Event//Log::", } pathname, err := getStateFilePath(&plugin, &ec) - fmt.Println(pathname) + t.Log(pathname) if err != nil { t.Errorf("expected nil, actual %v", err) } @@ -78,7 +78,7 @@ func TestGetStateFilePathEmpty(t *testing.T) { Name: "SystemEventLog", } pathname, err := getStateFilePath(&plugin, &ec) - fmt.Println(pathname) + t.Log(pathname) if err == nil { t.Errorf("expected non-nil") } @@ -97,7 +97,7 @@ func TestGetStateFilePathSpecialChars(t *testing.T) { Name: "SystemEventLog", } pathname, err := getStateFilePath(&plugin, &ec) - fmt.Println(pathname) + t.Log(pathname) if err == nil { t.Errorf("expected non-nil") } diff --git a/plugins/outputs/awscsm/metametrics/listener_test.go b/plugins/outputs/awscsm/metametrics/listener_test.go index cc856fc27c..50320c898c 100644 --- a/plugins/outputs/awscsm/metametrics/listener_test.go +++ b/plugins/outputs/awscsm/metametrics/listener_test.go @@ -87,7 +87,7 @@ func TestMetricWriter(t *testing.T) { for i := 0; i < innerMetricCount; i++ { eventTime := now.Add(time.Duration(j) * time.Minute) bin := i % innerMetricBins - fmt.Printf("%d", bin) + t.Logf("%d", bin) listener.Count(fmt.Sprintf("%d", bin), float64(bin), eventTime, testEndpoints[k]) } } diff --git a/translator/toenvconfig/toEnvConfig_test.go b/translator/toenvconfig/toEnvConfig_test.go index b8329da137..69d49d79ab 100644 --- a/translator/toenvconfig/toEnvConfig_test.go +++ b/translator/toenvconfig/toEnvConfig_test.go @@ -6,7 +6,6 @@ package toenvconfig import ( "bytes" "encoding/json" - "fmt" "io/ioutil" "testing" @@ -37,13 +36,13 @@ func checkIfTranslateSucceed(t *testing.T, jsonStr string, targetOs string, expe err := json.Unmarshal([]byte(jsonStr), &input) if err == nil { envVarsBytes := ToEnvConfig(input) - fmt.Println(string(envVarsBytes)) + t.Log(string(envVarsBytes)) var actualEnvVars = make(map[string]string) err := json.Unmarshal(envVarsBytes, &actualEnvVars) assert.NoError(t, err) assert.Equal(t, expectedEnvVars, actualEnvVars, "Expect to be equal") } else { - fmt.Printf("Got error %v", err) + t.Logf("Got error %v", err) t.Fail() } } From 6e9b1c7ab1db2e4c00825cc400d3d4a4006e4873 Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Mon, 25 Apr 2022 10:35:26 -0500 Subject: [PATCH 7/8] Remove unused import. --- plugins/inputs/windows_event_log/windows_event_log_test.go | 1 - 1 file changed, 1 deletion(-) diff --git a/plugins/inputs/windows_event_log/windows_event_log_test.go b/plugins/inputs/windows_event_log/windows_event_log_test.go index 86b4975e8b..069137bab8 100644 --- a/plugins/inputs/windows_event_log/windows_event_log_test.go +++ b/plugins/inputs/windows_event_log/windows_event_log_test.go @@ -7,7 +7,6 @@ package windows_event_log import ( - "fmt" "os" "path/filepath" "testing" From 02d06613852621408d0a5f8d4d119df5790e2e82 Mon Sep 17 00:00:00 2001 From: Adam <90734270+adam-mateen@users.noreply.github.com> Date: Mon, 16 May 2022 08:30:33 -0500 Subject: [PATCH 8/8] Fix flaky TestLogsFileAutoRemoval() on high spec hosts. --- plugins/inputs/logfile/logfile_test.go | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/plugins/inputs/logfile/logfile_test.go b/plugins/inputs/logfile/logfile_test.go index 7bce079814..c81ffc466c 100644 --- a/plugins/inputs/logfile/logfile_test.go +++ b/plugins/inputs/logfile/logfile_test.go @@ -417,7 +417,9 @@ func createWriteRead(t *testing.T, prefix string, logFile *LogFile, done chan bo logSrc, evts := getLogSrc(t, logFile) defer (*logSrc).Stop() defer close(evts) - const numLines int = 1000 + // Choose a large enough number of lines so that even high-spec hosts will not + // complete receiving logEvents before the 2nd createWriteRead() goroutine begins. + const numLines int = 100000 const msg string = "this is the best log line ever written to a file" writeLines(t, file, numLines, msg) file.Close()