From 7f55a0bae084eada532227f56b0481420595c045 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Fri, 10 Jun 2022 14:22:40 +0200 Subject: [PATCH] kubelet: avoid manipulating global logger during unit test The code as it stands now works, but it is still complicated and previous versions had race conditions (https://github.com/kubernetes/kubernetes/issues/108040). Now the test works without modifying global state. The individual test cases could run in parallel, this just isn't done because they complete quickly already (2 seconds). --- .../nodeshutdown_manager_linux_test.go | 55 +++++++------------ 1 file changed, 19 insertions(+), 36 deletions(-) diff --git a/pkg/kubelet/nodeshutdown/nodeshutdown_manager_linux_test.go b/pkg/kubelet/nodeshutdown/nodeshutdown_manager_linux_test.go index c8b12b64d4b..652b4a32d8e 100644 --- a/pkg/kubelet/nodeshutdown/nodeshutdown_manager_linux_test.go +++ b/pkg/kubelet/nodeshutdown/nodeshutdown_manager_linux_test.go @@ -20,7 +20,6 @@ limitations under the License. package nodeshutdown import ( - "bytes" "fmt" "os" "strings" @@ -35,7 +34,6 @@ import ( utilfeature "k8s.io/apiserver/pkg/util/feature" "k8s.io/client-go/tools/record" featuregatetesting "k8s.io/component-base/featuregate/testing" - "k8s.io/klog/v2" "k8s.io/klog/v2/ktesting" _ "k8s.io/klog/v2/ktesting/init" // activate ktesting command line flags "k8s.io/kubernetes/pkg/apis/scheduling" @@ -626,23 +624,6 @@ func Test_groupByPriority(t *testing.T) { } } -type buffer struct { - b bytes.Buffer - rw sync.RWMutex -} - -func (b *buffer) String() string { - b.rw.RLock() - defer b.rw.RUnlock() - return b.b.String() -} - -func (b *buffer) Write(p []byte) (n int, err error) { - b.rw.Lock() - defer b.rw.Unlock() - return b.b.Write(p) -} - func Test_managerImpl_processShutdownEvent(t *testing.T) { var ( probeManager = probetest.FakeManager{} @@ -666,10 +647,10 @@ func Test_managerImpl_processShutdownEvent(t *testing.T) { clock clock.Clock } tests := []struct { - name string - fields fields - wantErr bool - exceptOutputContains string + name string + fields fields + wantErr bool + expectedOutputContains string }{ { name: "kill pod func take too long", @@ -701,21 +682,17 @@ func Test_managerImpl_processShutdownEvent(t *testing.T) { clock: fakeclock, dbusCon: &fakeDbus{}, }, - wantErr: false, - exceptOutputContains: "Shutdown manager pod killing time out", + wantErr: false, + expectedOutputContains: "Shutdown manager pod killing time out", }, } + for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - l := klog.Level(1) - l.Set("1") - // hijack the klog output - tmpWriteBuffer := new(buffer) - klog.SetOutput(tmpWriteBuffer) - klog.LogToStderr(false) + logger, _ := ktesting.NewTestContext(t) m := &managerImpl{ - logger: klog.TODO(), // This test will be updated in a separate commit. + logger: logger, recorder: tt.fields.recorder, nodeRef: tt.fields.nodeRef, probeManager: tt.fields.probeManager, @@ -732,11 +709,17 @@ func Test_managerImpl_processShutdownEvent(t *testing.T) { if err := m.processShutdownEvent(); (err != nil) != tt.wantErr { t.Errorf("managerImpl.processShutdownEvent() error = %v, wantErr %v", err, tt.wantErr) } - klog.Flush() - log := tmpWriteBuffer.String() - if !strings.Contains(log, tt.exceptOutputContains) { - t.Errorf("managerImpl.processShutdownEvent() should log %s, got %s", tt.exceptOutputContains, log) + underlier, ok := logger.GetSink().(ktesting.Underlier) + if !ok { + t.Fatalf("Should have had a ktesting LogSink, got %T", logger.GetSink()) + } + + log := underlier.GetBuffer().String() + if !strings.Contains(log, tt.expectedOutputContains) { + // Log will be shown on failure. To see it + // during a successful run use "go test -v". + t.Errorf("managerImpl.processShutdownEvent() should have logged %s, see actual output above.", tt.expectedOutputContains) } }) }