fix(logging): Handle closing correctly and fix tests (#16539)

This commit is contained in:
Sven Rebhan 2025-02-24 17:05:29 +01:00 committed by GitHub
parent c505caf6e9
commit 26fc051441
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
8 changed files with 152 additions and 61 deletions

View File

@ -24,7 +24,14 @@ type eventLogger struct {
}
func (l *eventLogger) Close() error {
return l.eventlog.Close()
if l.eventlog == nil {
return nil
}
if err := l.eventlog.Close(); err != nil {
return err
}
l.eventlog = nil
return nil
}
func (l *eventLogger) Print(level telegraf.LogLevel, _ time.Time, prefix string, _ map[string]interface{}, args ...interface{}) {
@ -33,7 +40,7 @@ func (l *eventLogger) Print(level telegraf.LogLevel, _ time.Time, prefix string,
return
}
msg := level.Indicator() + " " + prefix + fmt.Sprint(args...)
msg := prefix + fmt.Sprint(args...)
var err error
switch level {

View File

@ -58,6 +58,7 @@ func TestEventLogIntegration(t *testing.T) {
Logfile: "",
}
require.NoError(t, SetupLogging(config))
defer func() { require.NoError(t, CloseLogging()) }()
now := time.Now()
log.Println("I! Info message")
@ -80,6 +81,7 @@ func TestRestrictedEventLogIntegration(t *testing.T) {
Quiet: true,
}
require.NoError(t, SetupLogging(config))
defer func() { require.NoError(t, CloseLogging()) }()
// separate previous log messages by small delay
time.Sleep(time.Second)

View File

@ -5,6 +5,7 @@ import (
"fmt"
"io"
"log"
"os"
"strings"
"sync"
"time"
@ -289,7 +290,15 @@ func RedirectLogging(w io.Writer) {
}
func CloseLogging() error {
return instance.close()
if instance == nil {
return nil
}
if err := instance.close(); err != nil && !errors.Is(err, os.ErrClosed) {
return err
}
return nil
}
func init() {

View File

@ -14,6 +14,8 @@ func TestTextLogTargetDefault(t *testing.T) {
Quiet: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
logger, ok := instance.impl.(*textLogger)
require.Truef(t, ok, "logging instance is not a default-logger but %T", instance.impl)
require.Equal(t, logger.logger.Writer(), os.Stderr)

View File

@ -21,6 +21,11 @@ type structuredLogger struct {
}
func (l *structuredLogger) Close() error {
// Close the writer if possible and avoid closing stderr
if l.output == os.Stderr {
return nil
}
if closer, ok := l.output.(io.Closer); ok {
return closer.Close()
}

View File

@ -21,27 +21,33 @@ func TestStructuredStderr(t *testing.T) {
Quiet: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
logger, ok := instance.impl.(*structuredLogger)
require.Truef(t, ok, "logging instance is not a structured-logger but %T", instance.impl)
require.Equal(t, logger.output, os.Stderr)
}
func TestStructuredFile(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("I! TEST")
log.Printf("D! TEST") // <- should be ignored
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
expected := map[string]interface{}{
@ -59,21 +65,25 @@ func TestStructuredFile(t *testing.T) {
}
func TestStructuredFileDebug(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("D! TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
expected := map[string]interface{}{
@ -91,22 +101,26 @@ func TestStructuredFileDebug(t *testing.T) {
}
func TestStructuredFileError(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
Quiet: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("E! TEST")
log.Printf("I! TEST") // <- should be ignored
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
@ -125,21 +139,25 @@ func TestStructuredFileError(t *testing.T) {
}
func TestStructuredAddDefaultLogLevel(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
expected := map[string]interface{}{
@ -159,22 +177,26 @@ func TestStructuredAddDefaultLogLevel(t *testing.T) {
func TestStructuredDerivedLogger(t *testing.T) {
instance = defaultHandler()
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
l := New("testing", "test", "")
l.Info("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
expected := map[string]interface{}{
@ -196,17 +218,21 @@ func TestStructuredDerivedLogger(t *testing.T) {
func TestStructuredDerivedLoggerWithAttributes(t *testing.T) {
instance = defaultHandler()
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
l := New("testing", "test", "myalias")
l.AddAttribute("alias", "foo") // Should be ignored
@ -214,7 +240,7 @@ func TestStructuredDerivedLoggerWithAttributes(t *testing.T) {
l.Info("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
expected := map[string]interface{}{
@ -236,21 +262,25 @@ func TestStructuredDerivedLoggerWithAttributes(t *testing.T) {
}
func TestStructuredWriteToTruncatedFile(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
expected := map[string]interface{}{
@ -266,11 +296,11 @@ func TestStructuredWriteToTruncatedFile(t *testing.T) {
delete(actual, "time")
require.Equal(t, expected, actual)
require.NoError(t, os.Truncate(tmpfile.Name(), 0))
require.NoError(t, os.Truncate(filename, 0))
log.Printf("SHOULD BE FIRST")
buf, err = os.ReadFile(tmpfile.Name())
buf, err = os.ReadFile(filename)
require.NoError(t, err)
expected = map[string]interface{}{
@ -292,15 +322,13 @@ func TestStructuredWriteToFileInRotation(t *testing.T) {
Logfile: filepath.Join(tempDir, "test.log"),
LogFormat: "structured",
RotationMaxArchives: -1,
RotationMaxSize: 30,
RotationMaxSize: 70,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
// Close the writer here, otherwise the temp folder cannot be deleted because the current log file is in use.
defer CloseLogging() //nolint:errcheck // We cannot do anything if this fails
log.Printf("I! TEST 1") // Writes 31 bytes, will rotate
log.Printf("I! TEST") // Writes 29 byes, no rotation expected
log.Printf("I! TEST 1") // Writes 70 bytes in structured format, will rotate
log.Printf("I! TEST") // Writes 68 bytes in structured format, no rotation expected
files, err := os.ReadDir(tempDir)
require.NoError(t, err)
@ -310,23 +338,27 @@ func TestStructuredWriteToFileInRotation(t *testing.T) {
func TestStructuredLogMessageKey(t *testing.T) {
instance = defaultHandler()
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "structured",
RotationMaxArchives: -1,
Debug: true,
StructuredLogMessageKey: "message",
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
l := New("testing", "test", "")
l.Info("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
expected := map[string]interface{}{

View File

@ -11,6 +11,12 @@ import (
"github.com/influxdata/telegraf/internal/rotate"
)
// Keep those constants for backward compatibility even though they are not
// used anywhere. See https://github.com/influxdata/telegraf/pull/15514 for
// more details.
//
// Deprecated: Those constants are unused and deprecated. The removal is
// scheduled for v1.45.0, if you use them please adapt your code!
const (
LogTargetFile = "file"
LogTargetStderr = "stderr"

View File

@ -19,121 +19,143 @@ func TestTextStderr(t *testing.T) {
Quiet: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
logger, ok := instance.impl.(*textLogger)
require.Truef(t, ok, "logging instance is not a text-logger but %T", instance.impl)
require.Equal(t, logger.logger.Writer(), os.Stderr)
}
func TestTextFile(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "text",
RotationMaxArchives: -1,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("I! TEST")
log.Printf("D! TEST") // <- should be ignored
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
require.Equal(t, "Z I! TEST\n", string(buf[19:]))
}
func TestTextFileDebug(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "text",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("D! TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
require.Equal(t, "Z D! TEST\n", string(buf[19:]))
}
func TestTextFileError(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "text",
RotationMaxArchives: -1,
Quiet: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("E! TEST")
log.Printf("I! TEST") // <- should be ignored
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
require.Equal(t, "Z E! TEST\n", string(buf[19:]))
}
func TestTextAddDefaultLogLevel(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "text",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
require.Equal(t, "Z I! TEST\n", string(buf[19:]))
}
func TestTextWriteToTruncatedFile(t *testing.T) {
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "text",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
require.Equal(t, "Z I! TEST\n", string(buf[19:]))
require.NoError(t, os.Truncate(tmpfile.Name(), 0))
require.NoError(t, os.Truncate(filename, 0))
log.Printf("SHOULD BE FIRST")
buf, err = os.ReadFile(tmpfile.Name())
buf, err = os.ReadFile(filename)
require.NoError(t, err)
require.Equal(t, "Z I! SHOULD BE FIRST\n", string(buf[19:]))
}
@ -147,9 +169,7 @@ func TestTextWriteToFileInRotation(t *testing.T) {
RotationMaxSize: 30,
}
require.NoError(t, SetupLogging(cfg))
// Close the writer here, otherwise the temp folder cannot be deleted because the current log file is in use.
defer CloseLogging() //nolint:errcheck // We cannot do anything if this fails
defer func() { require.NoError(t, CloseLogging()) }()
log.Printf("I! TEST 1") // Writes 31 bytes, will rotate
log.Printf("I! TEST") // Writes 29 byes, no rotation expected
@ -162,22 +182,26 @@ func TestTextWriteToFileInRotation(t *testing.T) {
func TestTextWriteDerivedLogger(t *testing.T) {
instance = defaultHandler()
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "text",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
l := New("testing", "test", "")
l.Info("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
require.Equal(t, "Z I! [testing.test] TEST\n", string(buf[19:]))
@ -186,17 +210,21 @@ func TestTextWriteDerivedLogger(t *testing.T) {
func TestTextWriteDerivedLoggerWithAttributes(t *testing.T) {
instance = defaultHandler()
tmpfile, err := os.CreateTemp("", "")
tmpfile, err := os.CreateTemp(t.TempDir(), "")
require.NoError(t, err)
defer os.Remove(tmpfile.Name())
filename := tmpfile.Name()
require.NoError(t, tmpfile.Close())
cfg := &Config{
Logfile: tmpfile.Name(),
Logfile: filename,
LogFormat: "text",
RotationMaxArchives: -1,
Debug: true,
}
require.NoError(t, SetupLogging(cfg))
defer func() { require.NoError(t, CloseLogging()) }()
l := New("testing", "test", "myalias")
@ -206,7 +234,7 @@ func TestTextWriteDerivedLoggerWithAttributes(t *testing.T) {
l.Info("TEST")
buf, err := os.ReadFile(tmpfile.Name())
buf, err := os.ReadFile(filename)
require.NoError(t, err)
require.Greater(t, len(buf), 19)
require.Equal(t, "Z I! [testing.test::myalias] TEST\n", string(buf[19:]))