fix(log testing): re-use logger library testing functionality

docs/contributing/dev-guide.md

@@ -48,6 +48,36 @@ make generate-metrics-documentation
 We require all changes to be covered by acceptance tests and/or unit tests, depending on the situation.
 In the context of the `external-dns`, acceptance tests are tests of interactions with providers, such as creating, reading information about, and destroying DNS resources. In contrast, unit tests test functionality wholly within the codebase itself, such as function tests.
 
+### Log Unit Testing
+
+Testing log messages within codebase provides significant advantages, especially when it comes to debugging, monitoring, and gaining a deeper understanding of system behavior. Log library [build-in testing functionality](https://github.com/sirupsen/logrus?tab=readme-ov-file#testing)
+
+This practice enables:
+
+- Early detection of logging issues
+- Verification of Important Information
+- Ensuring Correct Severity Levels
+- Improving Observability and Monitoring
+- Driving Better Logging Practices
+
+To illustrate how to unit test log output within functions, consider the following example:
+
+```go
+import (
+	"testing"
+
+	"sigs.k8s.io/external-dns/internal/testutils"
+)
+
+func TestMe(t *testing.T) {
+  hook := testutils.LogsUnderTestWithLogLeve(log.WarnLevel, t)
+  ... function under tests ...
+  testutils.TestHelperLogContains("example warning message", hook, t)
+  // provide negative assertion
+  testuitls.TestHelperLogNotContains("this message should not be shown", hook, t)
+}
+```
+
 ### Continuous Integration
 
 When submitting a pull request, you'll notice that we run several automated processes on your proposed change. Some of these processes are tests to ensure your contribution aligns with our standards. While we strive for accuracy, some users may find these tests confusing.

internal/testutils/log.go

@@ -17,24 +17,100 @@ limitations under the License.
 package testutils
 
 import (
-	"bytes"
+	"strings"
 	"testing"
 
 	log "github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+
+	"github.com/sirupsen/logrus/hooks/test"
 )
 
-// LogsToBuffer redirects log(s) output to a buffer for testing purposes
+// LogsUnderTestWithLogLevel redirects log(s) output to a buffer for testing purposes
 //
-// Usage: LogsToBuffer(t)
+// Usage: LogsUnderTestWithLogLevel(t)
 // Example:
 //
-//	buf := LogsToBuffer(log.DebugLevel, t)
+//	hook := testutils.LogsUnderTestWithLogLevel(log.DebugLevel, t)
 //	... do something that logs ...
-//	assert.Contains(t, buf.String(), "expected debug log message")
-func LogsToBuffer(level log.Level, t *testing.T) *bytes.Buffer {
+//
+// testutils.TestHelperLogContains("expected debug log message", hook, t)
+func LogsUnderTestWithLogLevel(level log.Level, t *testing.T) *test.Hook {
 	t.Helper()
-	buf := new(bytes.Buffer)
-	log.SetOutput(buf)
+	logger, hook := test.NewNullLogger()
+
+	log.AddHook(hook)
+	log.SetOutput(logger.Out)
 	log.SetLevel(level)
-	return buf
+	return hook
+}
+
+// TestHelperLogContains verifies that a specific log message is present
+// in the captured log entries. It asserts that the provided message `msg`
+// appears in at least one of the log entries recorded by the `hook`.
+//
+// Parameters:
+// - msg: The log message that should be found.
+// - hook: The test hook capturing log entries.
+// - t: The testing object used for assertions.
+//
+// Usage:
+// This helper is used in tests to ensure that certain log messages are
+// logged during the execution of the code under test.
+func TestHelperLogContains(msg string, hook *test.Hook, t *testing.T) {
+	t.Helper()
+	isContains := false
+	for _, entry := range hook.AllEntries() {
+		if strings.Contains(entry.Message, msg) {
+			isContains = true
+		}
+	}
+	assert.True(t, isContains, "Expected log message not found: %s", msg)
+}
+
+// TestHelperLogNotContains verifies that a specific log message is not present
+// in the captured log entries. It asserts that the provided message `msg`
+// does not appear in any of the log entries recorded by the `hook`.
+//
+// Parameters:
+// - msg: The log message that should not be found.
+// - hook: The test hook capturing log entries.
+// - t: The testing object used for assertions.
+//
+// Usage:
+// This helper is used in tests to ensure that certain log messages are not
+// logged during the execution of the code under test.
+func TestHelperLogNotContains(msg string, hook *test.Hook, t *testing.T) {
+	t.Helper()
+	isContains := false
+	for _, entry := range hook.AllEntries() {
+		if strings.Contains(entry.Message, msg) {
+			isContains = true
+		}
+	}
+	assert.False(t, isContains, "Expected log message found when should not: %s", msg)
+}
+
+// TestHelperLogContainsWithLogLevel verifies that a specific log message with a given log level
+// is present in the captured log entries. It asserts that the provided message `msg`
+// appears in at least one of the log entries recorded by the `hook` with the specified log level.
+//
+// Parameters:
+// - msg: The log message that should be found.
+// - level: The log level that the message should have.
+// - hook: The test hook capturing log entries.
+// - t: The testing object used for assertions.
+//
+// Usage:
+// This helper is used in tests to ensure that certain log messages with a specific log level
+// are logged during the execution of the code under test.
+func TestHelperLogContainsWithLogLevel(msg string, level log.Level, hook *test.Hook, t *testing.T) {
+	t.Helper()
+	isContains := false
+	for _, entry := range hook.AllEntries() {
+		if strings.Contains(entry.Message, msg) && entry.Level == level {
+			isContains = true
+		}
+	}
+	assert.True(t, isContains, "Expected log message not found: %s with level %s", msg, level)
 }

pkg/metrics/metrics_test.go

@@ -84,13 +84,13 @@ func TestMustRegister(t *testing.T) {
 }
 
 func TestUnsupportedMetricWarning(t *testing.T) {
-	buf := testutils.LogsToBuffer(log.WarnLevel, t)
+	hook := testutils.LogsUnderTestWithLogLevel(log.WarnLevel, t)
 	registry := NewMetricsRegister()
 	mockUnsupported := &MockMetric{FQDN: "unsupported_metric"}
 	registry.MustRegister(mockUnsupported)
 	assert.NotContains(t, registry.mName, "unsupported_metric")
 
-	assert.Contains(t, buf.String(), "Unsupported metric type: *metrics.MockMetric")
+	testutils.TestHelperLogContains("Unsupported metric type: *metrics.MockMetric", hook, t)
 }
 
 func TestNewMetricsRegister(t *testing.T) {

provider/aws/aws_fixtures_test.go

@@ -101,7 +101,8 @@ func TestAWSZonesSecondRequestHitsTheCache(t *testing.T) {
 	ctx := context.Background()
 	_, err := provider.Zones(ctx)
 	assert.NoError(t, err)
-	b := testutils.LogsToBuffer(log.DebugLevel, t)
+	hook := testutils.LogsUnderTestWithLogLevel(log.DebugLevel, t)
 	_, _ = provider.Zones(ctx)
-	assert.Contains(t, b.String(), "level=debug msg=\"Using cached zones list\"")
+
+	testutils.TestHelperLogContainsWithLogLevel("Using cached zones list", log.DebugLevel, hook, t)
 }

provider/aws/aws_utils_test.go

@@ -24,7 +24,7 @@ import (
 
 	"github.com/aws/aws-sdk-go-v2/service/route53"
 	route53types "github.com/aws/aws-sdk-go-v2/service/route53/types"
-	yaml "github.com/goccy/go-yaml"
+	"github.com/goccy/go-yaml"
 	"github.com/stretchr/testify/assert"
 	"sigs.k8s.io/external-dns/endpoint"
 	"sigs.k8s.io/external-dns/provider"

provider/cloudflare/cloudflare_test.go

@@ -1960,7 +1960,7 @@ func TestCloudflareLongRecordsErrorLog(t *testing.T) {
 			},
 		},
 	})
-	b := testutils.LogsToBuffer(log.InfoLevel, t)
+	hook := testutils.LogsUnderTestWithLogLevel(log.InfoLevel, t)
 	p := &CloudFlareProvider{
 		Client:                client,
 		CustomHostnamesConfig: CustomHostnamesConfig{Enabled: true},
@@ -1970,7 +1970,7 @@ func TestCloudflareLongRecordsErrorLog(t *testing.T) {
 	if err != nil {
 		t.Errorf("should not fail - too long record, %s", err)
 	}
-	assert.Contains(t, b.String(), "is longer than 63 characters. Cannot create endpoint")
+	testutils.TestHelperLogContains("s longer than 63 characters. Cannot create endpoint", hook, t)
 }
 
 // check if the error is expected
@@ -2720,7 +2720,7 @@ func TestCloudflareCustomHostnameNotFoundOnRecordDeletion(t *testing.T) {
 			Name:         "remove DNS record with unexpectedly missing custom hostname",
 			Endpoints:    []*endpoint.Endpoint{},
 			preApplyHook: "corrupt",
-			logOutput:    "level=warning msg=\"failed to delete custom hostname \\\"newerror-getCustomHostnameOrigin.foo.fancybar.com\\\": failed to get custom hostname: \\\"newerror-getCustomHostnameOrigin.foo.fancybar.com\\\" not found\" action=DELETE record=create.foo.bar.com",
+			logOutput:    "failed to delete custom hostname \"newerror-getCustomHostnameOrigin.foo.fancybar.com\": failed to get custom hostname: \"newerror-getCustomHostnameOrigin.foo.fancybar.com\" not found",
 		},
 		{
 			Name:         "duplicate custom hostname",
@@ -2746,12 +2746,12 @@ func TestCloudflareCustomHostnameNotFoundOnRecordDeletion(t *testing.T) {
 				},
 			},
 			preApplyHook: "",
-			logOutput:    "custom hostname \\\"a.foo.fancybar.com\\\" already exists with the same origin \\\"a.foo.bar.com\\\", continue",
+			logOutput:    "custom hostname \"a.foo.fancybar.com\" already exists with the same origin \"a.foo.bar.com\", continue",
 		},
 	}
 
 	for _, tc := range testCases {
-		b := testutils.LogsToBuffer(log.InfoLevel, t)
+		hook := testutils.LogsUnderTestWithLogLevel(log.InfoLevel, t)
 
 		records, err := provider.Records(ctx)
 		if err != nil {
@@ -2801,7 +2801,8 @@ func TestCloudflareCustomHostnameNotFoundOnRecordDeletion(t *testing.T) {
 		if e := checkFailed(tc.Name, err, false); !errors.Is(e, nil) {
 			t.Error(e)
 		}
-		assert.Contains(t, b.String(), tc.logOutput)
+
+		testutils.TestHelperLogContains(tc.logOutput, hook, t)
 	}
 }
 

provider/zonefinder_test.go

@@ -76,7 +76,8 @@ func TestZoneIDName(t *testing.T) {
 	assert.Equal(t, "エイミー.みんな", zoneName)
 	assert.Equal(t, "987654", zoneID)
 
-	b := testutils.LogsToBuffer(log.WarnLevel, t)
+	hook := testutils.LogsUnderTestWithLogLevel(log.WarnLevel, t)
 	_, _ = z.FindZone("???")
-	assert.Contains(t, b.String(), "level=warning msg=\"Failed to convert label '???' of hostname '???' to its Unicode form: idna: disallowed rune U+003F\"")
+
+	testutils.TestHelperLogContains("Failed to convert label '???' of hostname '???' to its Unicode form: idna: disallowed rune U+003F", hook, t)
 }

registry/txt_test.go

@@ -1821,7 +1821,7 @@ func TestTXTRegistryRecordsWithEmptyTargets(t *testing.T) {
 	})
 
 	r, _ := NewTXTRegistry(p, "", "", "owner", time.Hour, "", []string{}, []string{}, false, nil, false)
-	b := testutils.LogsToBuffer(log.ErrorLevel, t)
+	hook := testutils.LogsUnderTestWithLogLevel(log.ErrorLevel, t)
 	records, err := r.Records(ctx)
 	require.NoError(t, err)
 
@@ -1835,5 +1835,6 @@ func TestTXTRegistryRecordsWithEmptyTargets(t *testing.T) {
 	}
 
 	assert.True(t, testutils.SameEndpoints(records, expectedRecords))
-	assert.Contains(t, b.String(), "TXT record has no targets empty-targets.test-zone.example.org")
+
+	testutils.TestHelperLogContains("TXT record has no targets empty-targets.test-zone.example.org", hook, t)
 }

source/gateway_httproute_test.go

@@ -219,7 +219,7 @@ func TestGatewayHTTPRouteSourceEndpoints(t *testing.T) {
 				newTestEndpoint("test.example.internal", "A", "1.2.3.4"),
 			},
 			logExpectations: []string{
-				"level=debug msg=\"Gateway gateway-namespace/not-gateway-name does not match gateway-name route-namespace/test\"",
+				"Gateway gateway-namespace/not-gateway-name does not match gateway-name route-namespace/test",
 			},
 		},
 		{
@@ -259,7 +259,7 @@ func TestGatewayHTTPRouteSourceEndpoints(t *testing.T) {
 				newTestEndpoint("test.example.internal", "A", "1.2.3.4"),
 			},
 			logExpectations: []string{
-				"level=debug msg=\"Gateway gateway-namespace/gateway-name has not accepted the current generation HTTPRoute route-namespace/old-test\"",
+				"Gateway gateway-namespace/gateway-name has not accepted the current generation HTTPRoute route-namespace/old-test",
 			},
 		},
 		{
@@ -294,7 +294,7 @@ func TestGatewayHTTPRouteSourceEndpoints(t *testing.T) {
 			}},
 			endpoints: []*endpoint.Endpoint{},
 			logExpectations: []string{
-				"level=debug msg=\"Gateway gateway-namespace/gateway-name has not accepted the current generation HTTPRoute route-namespace/old-test\"",
+				"Gateway gateway-namespace/gateway-name has not accepted the current generation HTTPRoute route-namespace/old-test",
 			},
 		},
 		{
@@ -1509,8 +1509,8 @@ func TestGatewayHTTPRouteSourceEndpoints(t *testing.T) {
 				newTestEndpoint("test.two.internal", "A", "2.3.4.5"),
 			},
 			logExpectations: []string{
-				"level=debug msg=\"Endpoints generated from HTTPRoute default/one: [test.one.internal 0 IN A  1.2.3.4 []]\"",
-				"level=debug msg=\"Endpoints generated from HTTPRoute default/two: [test.two.internal 0 IN A  2.3.4.5 []]\"",
+				"Endpoints generated from HTTPRoute default/one: [test.one.internal 0 IN A  1.2.3.4 []]",
+				"Endpoints generated from HTTPRoute default/two: [test.two.internal 0 IN A  2.3.4.5 []]",
 			},
 		},
 		{
@@ -1540,7 +1540,7 @@ func TestGatewayHTTPRouteSourceEndpoints(t *testing.T) {
 			}},
 			endpoints: []*endpoint.Endpoint{},
 			logExpectations: []string{
-				"level=debug msg=\"No parent references found for HTTPRoute route-namespace/test\"",
+				"No parent references found for HTTPRoute route-namespace/test",
 			},
 		},
 		{
@@ -1575,7 +1575,7 @@ func TestGatewayHTTPRouteSourceEndpoints(t *testing.T) {
 			}},
 			endpoints: []*endpoint.Endpoint{},
 			logExpectations: []string{
-				"level=debug msg=\"Parent reference gateway-namespace/other-gateway not found in routeParentRefs for HTTPRoute route-namespace/test\"",
+				"Parent reference gateway-namespace/other-gateway not found in routeParentRefs for HTTPRoute route-namespace/test",
 			},
 		},
 	}
@@ -1610,14 +1610,14 @@ func TestGatewayHTTPRouteSourceEndpoints(t *testing.T) {
 			src, err := NewGatewayHTTPRouteSource(clients, &tt.config)
 			require.NoError(t, err, "failed to create Gateway HTTPRoute Source")
 
-			b := testutils.LogsToBuffer(log.DebugLevel, t)
+			hook := testutils.LogsUnderTestWithLogLevel(log.DebugLevel, t)
 
 			endpoints, err := src.Endpoints(ctx)
 			require.NoError(t, err, "failed to get Endpoints")
 			validateEndpoints(t, endpoints, tt.endpoints)
 
 			for _, msg := range tt.logExpectations {
-				require.Contains(t, b.String(), msg)
+				testutils.TestHelperLogContains(msg, hook, t)
 			}
 		})
 	}

source/node_test.go

@@ -17,11 +17,11 @@ limitations under the License.
 package source
 
 import (
-	"bytes"
 	"context"
 	"testing"
 
 	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus/hooks/test"
 	"sigs.k8s.io/external-dns/internal/testutils"
 
 	"github.com/stretchr/testify/assert"
@@ -391,7 +391,7 @@ func testNodeSourceEndpoints(t *testing.T) {
 		},
 	} {
 		t.Run(tc.title, func(t *testing.T) {
-			buf := testutils.LogsToBuffer(log.DebugLevel, t)
+			hook := testutils.LogsUnderTestWithLogLevel(log.DebugLevel, t)
 
 			labelSelector := labels.Everything()
 			if tc.labelSelector != "" {
@@ -443,11 +443,10 @@ func testNodeSourceEndpoints(t *testing.T) {
 			validateEndpoints(t, endpoints, tc.expected)
 
 			for _, entry := range tc.expectedLogs {
-				assert.Contains(t, buf.String(), entry)
+				testutils.TestHelperLogContains(entry, hook, t)
 			}
-
 			for _, entry := range tc.expectedAbsentLogs {
-				assert.NotContains(t, buf.String(), entry)
+				testutils.TestHelperLogNotContains(entry, hook, t)
 			}
 		})
 	}
@@ -533,9 +532,9 @@ func testNodeEndpointsWithIPv6(t *testing.T) {
 		_, err := kubernetes.CoreV1().Nodes().Create(context.Background(), node, metav1.CreateOptions{})
 		require.NoError(t, err)
 
-		var buf *bytes.Buffer
+		var hook *test.Hook
 		if tc.exposeInternalIPv6 {
-			buf = testutils.LogsToBuffer(log.WarnLevel, t)
+			hook = testutils.LogsUnderTestWithLogLevel(log.WarnLevel, t)
 		}
 
 		// Create our object under test and get the endpoints.
@@ -556,8 +555,8 @@ func testNodeEndpointsWithIPv6(t *testing.T) {
 		} else {
 			require.NoError(t, err)
 
-			if tc.exposeInternalIPv6 && buf != nil {
-				assert.Contains(t, buf.String(), warningMsg)
+			if tc.exposeInternalIPv6 && hook != nil {
+				testutils.TestHelperLogContainsWithLogLevel(warningMsg, log.WarnLevel, hook, t)
 			}
 		}