Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Add debug log and unit test for fsnotify remove and rename #1208

Merged
merged 9 commits into from
Nov 15, 2024
+78 −23
Merged

Add debug log and unit test for fsnotify remove and rename #1208

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
9555da8
Add debug log for fsnotify remove and rename
matoval Nov 14, 2024
34016b7
Replace if-else with switch
matoval Nov 14, 2024
4f56783
Add unit test for remove and rename
matoval Nov 14, 2024
0eab20b
Fix lint
matoval Nov 14, 2024
5f8d3c5
change remove and rename to debug and update tests
matoval Nov 15, 2024
83c5bb9
Update test
matoval Nov 15, 2024
a4aa195
fix lint
matoval Nov 15, 2024
1ec72fc
lint
matoval Nov 15, 2024
066681b
refactor test
matoval Nov 15, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 13 additions & 2 deletions pkg/workceptor/workunitbase.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -432,13 +432,24 @@
case <-bwu.ctx.Done():
break loop
case event := <-watcherEvents:
if event.Has(fsnotify.Create) {
switch {
case event.Has(fsnotify.Create):

Check warning on line 436 in pkg/workceptor/workunitbase.go

View check run for this annotation

Codecov / codecov/patch

pkg/workceptor/workunitbase.go#L436 

Added line #L436 was not covered by tests
bwu.w.nc.GetLogger().Debug("Watcher Event create of %s", statusFile)
} else if event.Op&fsnotify.Write == fsnotify.Write {
case event.Op&fsnotify.Write == fsnotify.Write:
err = bwu.Load()
if err != nil {
bwu.w.nc.GetLogger().Error("Watcher Events Error reading %s: %s", statusFile, err)
}
case event.Op&fsnotify.Remove == fsnotify.Remove:
err = bwu.Load()
if err != nil {
bwu.w.nc.GetLogger().Debug("Watcher Events Remove reading %s: %s", statusFile, err)
}
case event.Op&fsnotify.Rename == fsnotify.Rename:
err = bwu.Load()
if err != nil {
bwu.w.nc.GetLogger().Debug("Watcher Events Rename reading %s: %s", statusFile, err)
}
}
case <-time.After(time.Second):
newFi, err := bwu.fs.Stat(statusFile)
Expand Down
86 changes: 65 additions & 21 deletions pkg/workceptor/workunitbase_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,15 +1,18 @@
package workceptor_test

import (
"bytes"
"context"
"errors"
"fmt"
"os"
"path"
"strings"
"testing"
"time"

"github.com/ansible/receptor/pkg/logger"
"github.com/ansible/receptor/pkg/randstr"
"github.com/ansible/receptor/pkg/workceptor"
"github.com/ansible/receptor/pkg/workceptor/mock_workceptor"
"github.com/fsnotify/fsnotify"
Expand Down Expand Up @@ -81,12 +84,13 @@ func TestIsPending(t *testing.T) {
}
}

func setUp(t *testing.T) (*gomock.Controller, workceptor.BaseWorkUnit, *workceptor.Workceptor, *mock_workceptor.MockNetceptorForWorkceptor) {
func setUp(t *testing.T) (*gomock.Controller, workceptor.BaseWorkUnit, *workceptor.Workceptor, *mock_workceptor.MockNetceptorForWorkceptor, *logger.ReceptorLogger) {
ctrl := gomock.NewController(t)

mockNetceptor := mock_workceptor.NewMockNetceptorForWorkceptor(ctrl)

// attach logger to the mock netceptor and return any number of times
logger.SetGlobalLogLevel(4)
logger := logger.NewReceptorLogger("")
mockNetceptor.EXPECT().GetLogger().AnyTimes().Return(logger)
mockNetceptor.EXPECT().NodeID().Return("NodeID")
Expand All @@ -98,45 +102,45 @@ func setUp(t *testing.T) (*gomock.Controller, workceptor.BaseWorkUnit, *workcept

bwu := workceptor.BaseWorkUnit{}

return ctrl, bwu, w, mockNetceptor
return ctrl, bwu, w, mockNetceptor, logger
}

func TestInit(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, nil)
ctrl.Finish()
}

func TestErrorLog(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, &workceptor.RealWatcher{})
bwu.Error("test error")
ctrl.Finish()
}

func TestWarningLog(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, &workceptor.RealWatcher{})
bwu.Warning("test warning")
ctrl.Finish()
}

func TestInfoLog(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, &workceptor.RealWatcher{})
bwu.Info("test info")
ctrl.Finish()
}

func TestDebugLog(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, &workceptor.RealWatcher{})
bwu.Error("test debug")
ctrl.Finish()
}

func TestSetFromParams(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, &workceptor.RealWatcher{})
err := bwu.SetFromParams(nil)
if err != nil {
Expand All @@ -152,7 +156,7 @@ const (
)

func TestUnitDir(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, &workceptor.RealWatcher{})
expectedUnitDir := path.Join(rootDir, testDir)
if unitDir := bwu.UnitDir(); unitDir != expectedUnitDir {
Expand All @@ -162,7 +166,7 @@ func TestUnitDir(t *testing.T) {
}

func TestID(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "test", workceptor.FileSystem{}, &workceptor.RealWatcher{})
if id := bwu.ID(); id != "test" {
t.Errorf("ID returned wrong value: got %s, want %s", id, "test")
Expand All @@ -171,7 +175,7 @@ func TestID(t *testing.T) {
}

func TestStatusFileName(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "", workceptor.FileSystem{}, &workceptor.RealWatcher{})
expectedUnitDir := path.Join(rootDir, testDir)
expectedStatusFileName := path.Join(expectedUnitDir, "status")
Expand All @@ -182,7 +186,7 @@ func TestStatusFileName(t *testing.T) {
}

func TestStdoutFileName(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "", workceptor.FileSystem{}, &workceptor.RealWatcher{})
expectedUnitDir := path.Join(rootDir, testDir)
expectedStdoutFileName := path.Join(expectedUnitDir, "stdout")
Expand All @@ -193,7 +197,7 @@ func TestStdoutFileName(t *testing.T) {
}

func TestBaseSave(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "", workceptor.FileSystem{}, &workceptor.RealWatcher{})
err := bwu.Save()
if !strings.Contains(err.Error(), dirError) {
Expand All @@ -203,7 +207,7 @@ func TestBaseSave(t *testing.T) {
}

func TestBaseLoad(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "", workceptor.FileSystem{}, &workceptor.RealWatcher{})
err := bwu.Load()
if !strings.Contains(err.Error(), dirError) {
Expand All @@ -213,7 +217,7 @@ func TestBaseLoad(t *testing.T) {
}

func TestBaseUpdateFullStatus(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "", workceptor.FileSystem{}, &workceptor.RealWatcher{})
sf := func(sfd *workceptor.StatusFileData) {
// Do nothing
Expand All @@ -227,7 +231,7 @@ func TestBaseUpdateFullStatus(t *testing.T) {
}

func TestBaseUpdateBasicStatus(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "", workceptor.FileSystem{}, &workceptor.RealWatcher{})
bwu.UpdateBasicStatus(1, "Details", 0)
err := bwu.LastUpdateError()
Expand All @@ -238,7 +242,7 @@ func TestBaseUpdateBasicStatus(t *testing.T) {
}

func TestBaseStatus(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
bwu.Init(w, "test", "", workceptor.FileSystem{}, &workceptor.RealWatcher{})
status := bwu.Status()
if status.State != workceptor.WorkStatePending {
Expand All @@ -248,7 +252,7 @@ func TestBaseStatus(t *testing.T) {
}

func TestBaseRelease(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, _ := setUp(t)
mockFileSystem := mock_workceptor.NewMockFileSystemer(ctrl)
bwu.Init(w, "test", "", mockFileSystem, &workceptor.RealWatcher{})

Expand Down Expand Up @@ -300,6 +304,7 @@ func TestMonitorLocalStatus(t *testing.T) {
addWatcherErr error
statErr error
fsNotifyEvent *fsnotify.Event // using pointer to allow nil
logOutput string
sleepDuration time.Duration
}{
{
Expand All @@ -308,6 +313,7 @@ func TestMonitorLocalStatus(t *testing.T) {
addWatcherErr: nil,
statErr: nil,
fsNotifyEvent: &fsnotify.Event{Op: fsnotify.Write},
logOutput: "Watcher Events Error reading",
sleepDuration: 100 * time.Millisecond,
},
{
Expand All @@ -316,6 +322,7 @@ func TestMonitorLocalStatus(t *testing.T) {
addWatcherErr: fmt.Errorf("error adding watcher"),
statErr: nil,
fsNotifyEvent: nil,
logOutput: "",
sleepDuration: 100 * time.Millisecond,
},
{
Expand All @@ -324,6 +331,7 @@ func TestMonitorLocalStatus(t *testing.T) {
addWatcherErr: fmt.Errorf("error adding watcher"),
statErr: fmt.Errorf("stat error"),
fsNotifyEvent: nil,
logOutput: "",
sleepDuration: 100 * time.Millisecond,
},
{
Expand All @@ -332,6 +340,7 @@ func TestMonitorLocalStatus(t *testing.T) {
addWatcherErr: nil,
statErr: nil,
fsNotifyEvent: &fsnotify.Event{Op: fsnotify.Write},
logOutput: "Watcher Events Error reading",
sleepDuration: 100 * time.Millisecond,
},
{
Expand All @@ -341,14 +350,35 @@ func TestMonitorLocalStatus(t *testing.T) {
addWatcherErr: nil,
statErr: nil,
fsNotifyEvent: &fsnotify.Event{Op: fsnotify.Write},
logOutput: "Watcher Events Error reading",
sleepDuration: 500 * time.Millisecond,
},
{
name: "Handle Remove Event",
statObj: NewInfo("test", 1, 0, time.Now()),
addWatcherErr: nil,
statErr: nil,
fsNotifyEvent: &fsnotify.Event{Op: fsnotify.Remove},
logOutput: "Watcher Events Remove reading",
sleepDuration: 100 * time.Millisecond,
},
{
name: "Handle Rename Event",
statObj: NewInfo("test", 1, 0, time.Now()),
addWatcherErr: nil,
statErr: nil,
fsNotifyEvent: &fsnotify.Event{Op: fsnotify.Rename},
logOutput: "Watcher Events Rename reading",
sleepDuration: 100 * time.Millisecond,
},
}

for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
ctrl, bwu, w, _ := setUp(t)
ctrl, bwu, w, _, l := setUp(t)
defer ctrl.Finish()
randstring := randstr.RandomString(4)
logFilePath := fmt.Sprintf("/tmp/monitorLocalStatusLog%s", randstring)

mockWatcher := mock_workceptor.NewMockWatcherWrapper(ctrl)
mockFileSystem := mock_workceptor.NewMockFileSystemer(ctrl)
Expand All @@ -362,18 +392,32 @@ func TestMonitorLocalStatus(t *testing.T) {
mockWatcher.EXPECT().Close().AnyTimes()

if tc.fsNotifyEvent != nil {
logFile, err := os.OpenFile(logFilePath, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0o600)
if err != nil {
t.Error("error creating monitorLocalStatusLog file")
}
l.SetOutput(logFile)
eventCh := make(chan fsnotify.Event, 1)
mockWatcher.EXPECT().EventChannel().Return(eventCh).AnyTimes()
go func() { eventCh <- *tc.fsNotifyEvent }()

errorCh := make(chan error, 1)
mockWatcher.EXPECT().ErrorChannel().Return(errorCh).AnyTimes()
// go func() { errorCh <- nil }()
}

go bwu.MonitorLocalStatus()

time.Sleep(tc.sleepDuration)

if tc.fsNotifyEvent != nil {
logOutput, err := os.ReadFile(logFilePath)
if err != nil && len(logOutput) == 0 {
t.Errorf("error reading %s file", logFilePath)
}
if !bytes.Contains(logOutput, []byte(tc.logOutput)) {
t.Errorf("expected log to be: %s, got %s", tc.logOutput, string(logOutput))
}
}

bwu.CancelContext()
})
}
Expand Down