feat: [NPM] ipset save before restoring and fixing grep UTs

common/ioshim_linux.go

@@ -1,8 +1,11 @@
 package common
 
 import (
+	"testing"
+
 	testutils "github.com/Azure/azure-container-networking/test/utils"
 	utilexec "k8s.io/utils/exec"
+	testingexec "k8s.io/utils/exec/testing"
 )
 
 type IOShim struct {
@@ -20,3 +23,11 @@ func NewMockIOShim(calls []testutils.TestCmd) *IOShim {
 		Exec: testutils.GetFakeExecWithScripts(calls),
 	}
 }
+
+// VerifyCalls is used for Unit Testing with a mock ioshim. It asserts that the number of calls made is equal to the number given to the mock ioshim.
+func (ioshim *IOShim) VerifyCalls(t *testing.T, calls []testutils.TestCmd) {
+	fexec, couldCast := ioshim.Exec.(*testingexec.FakeExec)
+	if couldCast {
+		testutils.VerifyCalls(t, fexec, calls)
+	}
+}

npm/pkg/dataplane/ioutil/grep.go

@@ -0,0 +1,35 @@
+package ioutil
+
+import utilexec "k8s.io/utils/exec"
+
+// Grep is the grep command string
+const Grep = "grep"
+
+func PipeCommandToGrep(command, grepCommand utilexec.Cmd) (searchResults []byte, gotMatches bool, commandError error) {
+	pipe, commandError := command.StdoutPipe()
+	if commandError != nil {
+		return
+	}
+	closePipe := func() { _ = pipe.Close() } // appease go lint
+	defer closePipe()
+
+	grepCommand.SetStdin(pipe)
+	commandError = command.Start()
+	if commandError != nil {
+		return
+	}
+
+	// Without this wait, defunct iptable child process are created
+	wait := func() { _ = command.Wait() } // appease go lint
+	defer wait()
+
+	output, err := grepCommand.CombinedOutput()
+	if err != nil {
+		// grep returns err status 1 if nothing is found
+		// but the other command's exit status gets propagated through this CombinedOutput, so we might have errors undetected
+		return
+	}
+	searchResults = output
+	gotMatches = true
+	return
+}

npm/pkg/dataplane/ioutil/grep_test.go

@@ -0,0 +1,92 @@
+package ioutil
+
+import (
+	"testing"
+
+	testutils "github.com/Azure/azure-container-networking/test/utils"
+	"github.com/stretchr/testify/require"
+)
+
+func TestGrepMatch(t *testing.T) {
+	calls := []testutils.TestCmd{
+		{
+			Cmd:            []string{"some", "command"},
+			PipedToCommand: true,
+		},
+		{
+			Cmd:    []string{"grep", "pattern"},
+			Stdout: "1: here's the pattern we're looking for",
+		},
+		{
+			Cmd:            []string{"some", "command"},
+			PipedToCommand: true,
+		},
+		{
+			Cmd:    []string{"grep", "pattern"},
+			Stdout: "2: here's the pattern we're looking for",
+		},
+	}
+	fexec := testutils.GetFakeExecWithScripts(calls)
+	defer testutils.VerifyCalls(t, fexec, calls)
+
+	someCommand := fexec.Command("some", "command")
+	grepCommand := fexec.Command(Grep, "pattern")
+	output, gotMatches, err := PipeCommandToGrep(someCommand, grepCommand)
+	require.NoError(t, err)
+	require.True(t, gotMatches)
+	require.Equal(t, "1: here's the pattern we're looking for", string(output))
+
+	someCommand = fexec.Command("some", "command")
+	grepCommand = fexec.Command(Grep, "pattern")
+	output, gotMatches, err = PipeCommandToGrep(someCommand, grepCommand)
+	require.NoError(t, err)
+	require.True(t, gotMatches)
+	require.Equal(t, "2: here's the pattern we're looking for", string(output))
+}
+
+func TestGrepNoMatch(t *testing.T) {
+	calls := []testutils.TestCmd{
+		{
+			Cmd:            []string{"some", "command"},
+			PipedToCommand: true,
+			ExitCode:       0,
+		},
+		{
+			Cmd:      []string{"grep", "pattern"},
+			ExitCode: 1,
+		},
+	}
+	fexec := testutils.GetFakeExecWithScripts(calls)
+	defer testutils.VerifyCalls(t, fexec, calls)
+
+	someCommand := fexec.Command("some", "command")
+	grepCommand := fexec.Command(Grep, "pattern")
+	output, gotMatches, err := PipeCommandToGrep(someCommand, grepCommand)
+	require.NoError(t, err)
+	require.False(t, gotMatches)
+	require.Nil(t, output)
+}
+
+func TestCommandStartError(t *testing.T) {
+	calls := []testutils.TestCmd{
+		{
+			Cmd:            []string{"some", "command"},
+			HasStartError:  true,
+			PipedToCommand: true,
+			ExitCode:       5,
+		},
+		{
+			Cmd:      []string{"grep", "pattern"},
+			ExitCode: 0,
+		},
+	}
+	fexec := testutils.GetFakeExecWithScripts(calls)
+	defer testutils.VerifyCalls(t, fexec, calls)
+
+	someCommand := fexec.Command("some", "command")
+	grepCommand := fexec.Command(Grep, "pattern")
+	output, gotMatches, err := PipeCommandToGrep(someCommand, grepCommand)
+	require.Error(t, err)
+	require.False(t, gotMatches)
+	require.Nil(t, output)
+}

npm/pkg/dataplane/ioutil/file-creator.go → npm/pkg/dataplane/ioutil/restore_linux.go

@@ -8,12 +8,10 @@ import (
 	"strings"
 
 	"github.com/Azure/azure-container-networking/common"
-	"github.com/Azure/azure-container-networking/log"
 	npmerrors "github.com/Azure/azure-container-networking/npm/util/errors"
+	"k8s.io/klog"
 )
 
-// TODO add file creator log prefix
-
 // FileCreator is a tool for:
 // - building a buffer file
 // - running a command with the file
@@ -56,19 +54,24 @@ type ErrorDefinition struct {
 type LineErrorHandler struct {
 	Definition *ErrorDefinition
 	Method     LineErrorHandlerMethod
-	Reason     string
 	Callback   func()
 }
 
 // LineErrorHandlerMethod defines behavior when an error occurs
 type LineErrorHandlerMethod string
 
-// possible LineErrorHandlerMethod
 const (
-	SkipLine     LineErrorHandlerMethod = "skip"
-	AbortSection LineErrorHandlerMethod = "abort"
+	// Continue specifies skipping this line and all previous lines
+	Continue LineErrorHandlerMethod = "continue"
+	// ContinueAndAbortSection specifies skipping this line, all previous lines, and all lines tied to this line's section
+	ContinueAndAbortSection LineErrorHandlerMethod = "continue-and-abort"
+
+	anyMatchPattern = ".*"
 )
 
+// AlwaysMatchDefinition will match any error
+var AlwaysMatchDefinition = NewErrorDefinition(anyMatchPattern)
+
 func NewFileCreator(ioShim *common.IOShim, maxTryCount int, lineFailurePatterns ...string) *FileCreator {
 	creator := &FileCreator{
 		lines:                  make([]*Line, 0),
@@ -125,27 +128,26 @@ func (creator *FileCreator) RunCommandWithFile(cmd string, args ...string) error
 	fileString := creator.ToString()
 	wasFileAltered, err := creator.runCommandOnceWithFile(fileString, cmd, args...)
 	if err == nil {
-		// success
 		return nil
 	}
-	for {
-		commandString := cmd + " " + strings.Join(args, " ")
-		if creator.hasNoMoreRetries() {
-			// TODO conditionally specify as retriable?
-			return npmerrors.Errorf(npmerrors.RunFileCreator, false, fmt.Sprintf("failed to run command [%s] with error: %v", commandString, err))
-		}
+	commandString := cmd + " " + strings.Join(args, " ")
+	for !creator.hasNoMoreRetries() {
 		if wasFileAltered {
 			fileString = creator.ToString()
-			log.Logf("rerunning command [%s] with new file:\n%s", commandString, fileString)
+			klog.Infof("rerunning command [%s] with new file:\n%s", commandString, fileString)
 		} else {
-			log.Logf("rerunning command [%s] with the same file", commandString)
+			klog.Infof("rerunning command [%s] with the same file", commandString)
 		}
 		wasFileAltered, err = creator.runCommandOnceWithFile(fileString, cmd, args...)
 		if err == nil {
-			// success
+			klog.Infof("successfully ran command [%s] on try number %d", commandString, creator.tryCount)
 			return nil
 		}
 	}
+	errString := fmt.Sprintf("failed to run command [%s] with error: %v", commandString, err)
+	klog.Error(errString)
+	// TODO conditionally specify as retriable?
+	return npmerrors.Errorf(npmerrors.RunFileCreator, false, errString)
 }
 
 // RunCommandOnceWithFile runs the command with the file once and increments the try count.
@@ -160,8 +162,15 @@ func (creator *FileCreator) RunCommandOnceWithFile(cmd string, args ...string) (
 	return creator.runCommandOnceWithFile(fileString, cmd, args...)
 }
 
+// returns whether the file was altered and any error
 // TODO return another bool that specifies if there was a file-level retriable error?
 func (creator *FileCreator) runCommandOnceWithFile(fileString, cmd string, args ...string) (bool, error) {
+	commandString := cmd + " " + strings.Join(args, " ")
+	if fileString == "" { // NOTE this wouldn't prevent us from running an iptables restore file with just "COMMIT\n"
+		klog.Infof("returning as a success without running command [%s] since the fileString is empty", commandString)
+		return false, nil
+	}
+
 	command := creator.ioShim.Exec.Command(cmd, args...)
 	command.SetStdin(bytes.NewBufferString(fileString))
 
@@ -173,27 +182,30 @@ func (creator *FileCreator) runCommandOnceWithFile(fileString, cmd string, args
 	}
 	creator.tryCount++
 
-	commandString := cmd + " " + strings.Join(args, " ")
 	stdErr := string(stdErrBytes)
-	log.Errorf("on try number %d, failed to run command [%s] with error [%v] and stdErr [%s]. Used file:\n%s", creator.tryCount, commandString, err, stdErr, fileString)
+	klog.Errorf("on try number %d, failed to run command [%s] with error [%v] and stdErr [%s]. Used file:\n%s", creator.tryCount, commandString, err, stdErr, fileString)
 	if creator.hasNoMoreRetries() {
 		return false, fmt.Errorf("after %d tries, failed with final error [%w] and stdErr [%s]", creator.tryCount, err, stdErr)
 	}
 
 	// begin the retry logic
 	if creator.hasFileLevelError(stdErr) {
-		log.Logf("detected a file-level error after running command [%s]", commandString)
+		klog.Infof("detected a file-level error after running command [%s]", commandString)
 		return false, fmt.Errorf("file-level error: %w", err)
 	}
 
 	// no file-level error, so handle line-level error if there is one
-	lineNum := creator.getErrorLineNumber(commandString, stdErr)
-	if lineNum == -1 {
-		// can't detect a line number error
-		return false, fmt.Errorf("can't discern error: %w", err)
+	numLines := creator.numLines()
+	for _, lineFailureDefinition := range creator.lineFailureDefinitions {
+		lineNum := lineFailureDefinition.getErrorLineNumber(stdErr, commandString, numLines)
+		if lineNum != -1 {
+			klog.Infof("detected a line number error on line %d", lineNum)
+			wasFileAltered := creator.handleLineError(stdErr, commandString, lineNum)
+			return wasFileAltered, fmt.Errorf("tried to handle line number error: %w", err)
+		}
 	}
-	wasFileAltered := creator.handleLineError(lineNum, commandString, stdErr)
-	return wasFileAltered, fmt.Errorf("tried to handle line number error: %w", err)
+	klog.Infof("couldn't detect a line number error")
+	return false, fmt.Errorf("can't discern error: %w", err)
 }
 
 func (creator *FileCreator) hasNoMoreRetries() bool {
@@ -210,61 +222,63 @@ func (creator *FileCreator) hasFileLevelError(stdErr string) bool {
 }
 
 func (definition *ErrorDefinition) isMatch(stdErr string) bool {
-	return definition.re.MatchString(stdErr)
+	return definition.matchPattern == anyMatchPattern || definition.re.MatchString(stdErr)
+}
+
+func (creator *FileCreator) numLines() int {
+	return len(creator.lines) - len(creator.lineNumbersToOmit)
 }
 
 // return -1 if there's a failure
-func (creator *FileCreator) getErrorLineNumber(commandString, stdErr string) int {
-	for _, definition := range creator.lineFailureDefinitions {
-		result := definition.re.FindStringSubmatch(stdErr)
-		if result == nil || len(result) < 2 {
-			log.Logf("expected error with line number, but couldn't detect one with error regex pattern [%s] for command [%s] with stdErr [%s]", definition.matchPattern, commandString, stdErr)
-			continue
-		}
-		lineNumString := result[1]
-		lineNum, err := strconv.Atoi(lineNumString)
-		if err != nil {
-			log.Logf("expected error with line number, but error regex pattern %s didn't produce a number for command [%s] with stdErr [%s]", definition.matchPattern, commandString, stdErr)
-			continue
-		}
-		if lineNum < 1 || lineNum > len(creator.lines) {
-			log.Logf("expected error with line number, but error regex pattern %s produced an invalid line number %d for command [%s] with stdErr [%s]", definition.matchPattern, lineNum, commandString, stdErr)
-			continue
-		}
-		return lineNum
+func (definition *ErrorDefinition) getErrorLineNumber(stdErr, commandString string, numLines int) int {
+	result := definition.re.FindStringSubmatch(stdErr)
+	if result == nil || len(result) < 2 {
+		klog.Infof("expected error with line number, but couldn't detect one with error regex pattern [%s] for command [%s] with stdErr [%s]", definition.matchPattern, commandString, stdErr)
+		return -1
+	}
+	lineNumString := result[1]
+	lineNum, err := strconv.Atoi(lineNumString)
+	if err != nil {
+		klog.Infof("expected error with line number, but error regex pattern %s didn't produce a number for command [%s] with stdErr [%s]", definition.matchPattern, commandString, stdErr)
+		return -1
+	}
+	if lineNum < 1 || lineNum > numLines {
+		klog.Infof(
+			"expected error with line number, but error regex pattern %s produced an invalid line number %d for command [%s] with stdErr [%s]",
+			definition.matchPattern, lineNum, commandString, stdErr,
+		)
+		return -1
 	}
-	return -1
+	return lineNum
 }
 
 // return whether the file was altered
-func (creator *FileCreator) handleLineError(lineNum int, commandString, stdErr string) bool {
+func (creator *FileCreator) handleLineError(stdErr, commandString string, lineNum int) bool {
 	lineNumIndex := lineNum - 1
 	line := creator.lines[lineNumIndex]
 	for _, errorHandler := range line.errorHandlers {
 		if !errorHandler.Definition.isMatch(stdErr) {
 			continue
 		}
 		switch errorHandler.Method {
-		case SkipLine:
-			log.Errorf("skipping line %d for command [%s]", lineNumIndex, commandString)
-			creator.lineNumbersToOmit[lineNumIndex] = struct{}{}
-			errorHandler.Callback()
-			return true
-		case AbortSection:
-			log.Errorf("aborting section associated with line %d for command [%s]", lineNumIndex, commandString)
-			section, exists := creator.sections[line.sectionID]
-			if !exists {
-				log.Errorf("can't abort section because line references section %d which doesn't exist, so skipping the line instead", line.sectionID)
-				creator.lineNumbersToOmit[lineNumIndex] = struct{}{}
-			} else {
-				for _, lineNum := range section.lineNums {
-					creator.lineNumbersToOmit[lineNum] = struct{}{}
-				}
+		case Continue:
+			klog.Errorf("continuing after line %d for command [%s]", lineNum, commandString)
+			for i := 0; i <= lineNumIndex; i++ {
+				creator.lineNumbersToOmit[i] = struct{}{}
+			}
+		case ContinueAndAbortSection:
+			klog.Errorf("continuing after line %d and aborting section associated with the line for command [%s]", lineNum, commandString)
+			for i := 0; i <= lineNumIndex; i++ {
+				creator.lineNumbersToOmit[i] = struct{}{}
+			}
+			section := creator.sections[line.sectionID]
+			for _, lineNum := range section.lineNums {
+				creator.lineNumbersToOmit[lineNum] = struct{}{}
 			}
 		}
 		errorHandler.Callback()
 		return true
 	}
-	log.Logf("no error handler for line %d for command [%s] with stdErr [%s]", lineNum, commandString, stdErr)
+	klog.Infof("no error handler for line %d for command [%s] with stdErr [%s]", lineNum, commandString, stdErr)
 	return false
 }