diff --git a/npm/iptm/iptm.go b/npm/iptm/iptm.go index 9b5c288cbd..45421ede86 100644 --- a/npm/iptm/iptm.go +++ b/npm/iptm/iptm.go @@ -19,10 +19,9 @@ import ( ) const ( - defaultlockWaitTimeInSeconds string = "60" - iptablesErrDoesNotExist int = 1 - reconcileChainTimeInMinutes = 5 - minLineNumberStringLength int = 3 + iptablesErrDoesNotExist int = 1 + reconcileChainTimeInMinutes = 5 + minLineNumberStringLength int = 3 ) var ( @@ -139,7 +138,7 @@ func (iptMgr *IptablesManager) UninitNpmChains() error { util.IptablesAzureTargetSetsChain, util.IptablesAzureIngressWrongDropsChain, ) - currentAzureChains, err := ioutil.AllCurrentAzureChains(iptMgr.exec, defaultlockWaitTimeInSeconds) + currentAzureChains, err := ioutil.AllCurrentAzureChains(iptMgr.exec, util.IptablesDefaultWaitTime) if err != nil { metrics.SendErrorLogAndMetric(util.IptmID, "Warning: failed to get all current AZURE-NPM chains, so stale v2 chains may exist") } else { @@ -490,7 +489,7 @@ func (iptMgr *IptablesManager) run(entry *IptEntry) (int, error) { } if entry.LockWaitTimeInSeconds == "" { - entry.LockWaitTimeInSeconds = defaultlockWaitTimeInSeconds + entry.LockWaitTimeInSeconds = util.IptablesDefaultWaitTime } cmdArgs := append([]string{util.IptablesWaitFlag, entry.LockWaitTimeInSeconds, iptMgr.OperationFlag, entry.Chain}, entry.Specs...) diff --git a/npm/pkg/dataplane/ipsets/ipsetmanager_linux.go b/npm/pkg/dataplane/ipsets/ipsetmanager_linux.go index 5d732ac59a..286c1aaca5 100644 --- a/npm/pkg/dataplane/ipsets/ipsetmanager_linux.go +++ b/npm/pkg/dataplane/ipsets/ipsetmanager_linux.go @@ -1,18 +1,27 @@ package ipsets import ( + "errors" "fmt" "strings" + "github.com/Azure/azure-container-networking/npm/metrics" "github.com/Azure/azure-container-networking/npm/pkg/dataplane/parse" "github.com/Azure/azure-container-networking/npm/util" npmerrors "github.com/Azure/azure-container-networking/npm/util/errors" "github.com/Azure/azure-container-networking/npm/util/ioutil" "k8s.io/klog" + utilexec "k8s.io/utils/exec" ) const ( - azureNPMPrefix = "azure-npm-" + ipsetFlushAndDestroyString = "ipset flush && ipset destroy" + + azureNPMPrefix = "azure-npm-" + azureNPMRegex = "azure-npm-\\d+" + positiveRefsRegex = "References: [1-9]" + referenceGrepLookBack = "5" + maxLinesToPrint = 10 ipsetCommand = "ipset" ipsetListFlag = "list" @@ -58,6 +67,9 @@ var ( /* based on ipset list output with azure-npm- prefix, create an ipset restore file where we flush all sets first, then destroy all sets + NOTE: the behavior has changed to run two separate restore files. The first to flush all, the second to destroy all. In between restores, + we determine if there are any sets with leaked ipset reference counts. We ignore destroys for those sets in-line with v1. + overall error handling: - if flush fails because the set doesn't exist (should never happen because we're listing sets right before), then ignore it and the destroy - if flush fails otherwise, then add to destroyFailureCount and continue (aborting the destroy too) @@ -85,54 +97,113 @@ var ( If a flush fails, we could update the num entries for that set, but that would be a lot of overhead. */ func (iMgr *IPSetManager) resetIPSets() error { - listCommand := iMgr.ioShim.Exec.Command(ipsetCommand, ipsetListFlag, ipsetNameFlag) + if success := iMgr.resetWithoutRestore(); success { + return nil + } + + // get current NPM ipsets + listNamesCommand := iMgr.ioShim.Exec.Command(ipsetCommand, ipsetListFlag, ipsetNameFlag) grepCommand := iMgr.ioShim.Exec.Command(ioutil.Grep, azureNPMPrefix) - azureIPSets, haveAzureIPSets, commandError := ioutil.PipeCommandToGrep(listCommand, grepCommand) + klog.Infof("running this command while resetting ipsets: [%s %s %s | %s %s]", ipsetCommand, ipsetListFlag, ipsetNameFlag, ioutil.Grep, azureNPMRegex) + azureIPSets, haveAzureNPMIPSets, commandError := ioutil.PipeCommandToGrep(listNamesCommand, grepCommand) if commandError != nil { return npmerrors.SimpleErrorWrapper("failed to run ipset list for resetting IPSets (prometheus metrics may be off now)", commandError) } - if !haveAzureIPSets { + if !haveAzureNPMIPSets { return nil } - creator, originalNumAzureSets, destroyFailureCount := iMgr.fileCreatorForReset(azureIPSets) + + // flush all NPM sets + creator, names, failedNames := iMgr.fileCreatorForFlushAll(azureIPSets) restoreError := creator.RunCommandWithFile(ipsetCommand, ipsetRestoreFlag) if restoreError != nil { klog.Errorf( - "failed to restore ipsets (prometheus metrics may be off now). Had originalNumAzureSets %d and destroyFailureCount %d with err: %v", - originalNumAzureSets, destroyFailureCount, restoreError, + "failed to flush all ipsets (prometheus metrics may be off now). originalNumAzureSets: %d. failed flushes: %+v. err: %v", + len(names), failedNames, restoreError, ) - return npmerrors.SimpleErrorWrapper("failed to run ipset restore for resetting IPSets", restoreError) + return npmerrors.SimpleErrorWrapper("failed to run ipset restore while flushing all for resetting IPSets", restoreError) + } + + // destroy all NPM sets + creator, destroyFailureCount := iMgr.fileCreatorForDestroyAll(names, failedNames, iMgr.setsWithReferences()) + destroyError := creator.RunCommandWithFile(ipsetCommand, ipsetRestoreFlag) + if destroyError != nil { + klog.Errorf( + "failed to destroy all ipsets (prometheus metrics may be off now). destroyFailureCount %d. err: %v", + destroyFailureCount, destroyError, + ) + return npmerrors.SimpleErrorWrapper("failed to run ipset restore while destroying all for resetting IPSets", destroyError) } return nil } +// resetWithoutRestore will return true (success) if able to reset without restore +func (iMgr *IPSetManager) resetWithoutRestore() bool { + listNamesCommand := iMgr.ioShim.Exec.Command(ipsetCommand, ipsetListFlag, ipsetNameFlag) + grepCommand := iMgr.ioShim.Exec.Command(ioutil.Grep, ioutil.GrepQuietFlag, ioutil.GrepAntiMatchFlag, azureNPMPrefix) + commandString := fmt.Sprintf(" [%s %s %s | %s %s %s %s]", ipsetCommand, ipsetListFlag, ipsetNameFlag, ioutil.Grep, ioutil.GrepQuietFlag, ioutil.GrepAntiMatchFlag, azureNPMPrefix) + klog.Infof("running this command while resetting ipsets: [%s]", commandString) + _, haveNonAzureNPMIPSets, commandError := ioutil.PipeCommandToGrep(listNamesCommand, grepCommand) + if commandError != nil { + metrics.SendErrorLogAndMetric(util.IpsmID, "failed to determine if there were non-azure sets while resetting. err: %v", commandError) + return false + } + if haveNonAzureNPMIPSets { + return false + } + + flushAndDestroy := iMgr.ioShim.Exec.Command(util.BashCommand, util.BashCommandFlag, ipsetFlushAndDestroyString) + klog.Infof("running this command while resetting ipsets: [%s %s '%s']", util.BashCommand, util.BashCommandFlag, ipsetFlushAndDestroyString) + output, err := flushAndDestroy.CombinedOutput() + if err != nil { + exitCode := -1 + stdErr := "no stdErr detected" + var exitError utilexec.ExitError + if ok := errors.As(err, &exitError); ok { + exitCode = exitError.ExitStatus() + stdErr = strings.TrimSuffix(string(output), "\n") + } + metrics.SendErrorLogAndMetric(util.IpsmID, "failed to flush and destroy ipsets at once. exitCode: %d. stdErr: [%v]", exitCode, stdErr) + return false + } + return true +} + // this needs to be a separate function because we need to check creator contents in UTs -func (iMgr *IPSetManager) fileCreatorForReset(ipsetListOutput []byte) (*ioutil.FileCreator, int, *int) { +// named returns to appease lint +func (iMgr *IPSetManager) fileCreatorForFlushAll(ipsetListOutput []byte) (creator *ioutil.FileCreator, names []string, failedNames map[string]struct{}) { destroyFailureCount := 0 - creator := ioutil.NewFileCreator(iMgr.ioShim, maxTryCount, ipsetRestoreLineFailurePattern) - names := make([]string, 0) + creator = ioutil.NewFileCreator(iMgr.ioShim, maxTryCount, ipsetRestoreLineFailurePattern) + names = make([]string, 0) + failedNames = make(map[string]struct{}, 0) readIndex := 0 var line []byte // flush all the sets and create a list of the sets so we can destroy them for readIndex < len(ipsetListOutput) { line, readIndex = parse.Line(readIndex, ipsetListOutput) hashedSetName := string(line) + if readIndex >= len(ipsetListOutput) { + // parse.Line() will include the newline character for the end of the byte array + hashedSetName = strings.Trim(hashedSetName, "\n") + } names = append(names, hashedSetName) // error handlers specific to resetting ipsets errorHandlers := []*ioutil.LineErrorHandler{ { Definition: setDoesntExistDefinition, - Method: ioutil.ContinueAndAbortSection, + Method: ioutil.Continue, Callback: func() { klog.Infof("[RESET-IPSETS] skipping flush and upcoming destroy for set %s since the set doesn't exist", hashedSetName) + failedNames[hashedSetName] = struct{}{} }, }, { Definition: ioutil.AlwaysMatchDefinition, - Method: ioutil.ContinueAndAbortSection, + Method: ioutil.Continue, Callback: func() { klog.Errorf("[RESET-IPSETS] marking flush and upcoming destroy for set %s as a failure due to unknown error", hashedSetName) destroyFailureCount++ + failedNames[hashedSetName] = struct{}{} // TODO mark as a failure }, }, @@ -141,8 +212,46 @@ func (iMgr *IPSetManager) fileCreatorForReset(ipsetListOutput []byte) (*ioutil.F creator.AddLine(sectionID, errorHandlers, ipsetFlushFlag, hashedSetName) // flush set } + return creator, names, failedNames +} + +func (iMgr *IPSetManager) setsWithReferences() map[string]struct{} { + listAllCommand := iMgr.ioShim.Exec.Command(ipsetCommand, ipsetListFlag) + grep1 := iMgr.ioShim.Exec.Command(ioutil.Grep, ioutil.GrepBeforeFlag, referenceGrepLookBack, ioutil.GrepRegexFlag, positiveRefsRegex) + grep2 := iMgr.ioShim.Exec.Command(ioutil.Grep, ioutil.GrepOnlyMatchingFlag, ioutil.GrepRegexFlag, azureNPMRegex) + klog.Infof("running this command while resetting ipsets: [%s %s | %s %s %s %s %s | %s %s %s %s]", ipsetCommand, ipsetListFlag, + ioutil.Grep, ioutil.GrepBeforeFlag, referenceGrepLookBack, ioutil.GrepRegexFlag, positiveRefsRegex, + ioutil.Grep, ioutil.GrepOnlyMatchingFlag, ioutil.GrepRegexFlag, azureNPMRegex) + setsWithReferencesBytes, haveRefsStill, err := ioutil.DoublePipeToGrep(listAllCommand, grep1, grep2) + + var setsWithReferences map[string]struct{} + if haveRefsStill { + setsWithReferences = readByteLinesToMap(setsWithReferencesBytes) + metrics.SendErrorLogAndMetric(util.IpsmID, "error: found leaked reference counts in kernel. ipsets (max %d): %+v. err: %v", + maxLinesToPrint, setsWithReferences, err) + } + + return setsWithReferences +} + +// named returns to appease lint +func (iMgr *IPSetManager) fileCreatorForDestroyAll(names []string, failedNames, setsWithReferences map[string]struct{}) (creator *ioutil.FileCreator, failureCount *int) { + failureCountVal := 0 + failureCount = &failureCountVal + creator = ioutil.NewFileCreator(iMgr.ioShim, maxTryCount, ipsetRestoreLineFailurePattern) + // destroy all the sets for _, hashedSetName := range names { + if _, ok := failedNames[hashedSetName]; ok { + klog.Infof("skipping destroy for set %s since it failed to flush", hashedSetName) + continue + } + + if _, ok := setsWithReferences[hashedSetName]; ok { + klog.Infof("skipping destroy for set %s since it has leaked reference counts", hashedSetName) + continue + } + hashedSetName := hashedSetName // to appease go lint errorHandlers := []*ioutil.LineErrorHandler{ // error handlers specific to resetting ipsets @@ -151,7 +260,7 @@ func (iMgr *IPSetManager) fileCreatorForReset(ipsetListOutput []byte) (*ioutil.F Method: ioutil.Continue, Callback: func() { klog.Errorf("[RESET-IPSETS] marking destroy for set %s as a failure since the set is in use by a kernel component", hashedSetName) - destroyFailureCount++ + failureCountVal++ // TODO mark the set as a failure and reconcile what iptables rule or ipset is referring to it }, }, @@ -167,7 +276,7 @@ func (iMgr *IPSetManager) fileCreatorForReset(ipsetListOutput []byte) (*ioutil.F Method: ioutil.Continue, Callback: func() { klog.Errorf("[RESET-IPSETS] marking destroy for set %s as a failure due to unknown error", hashedSetName) - destroyFailureCount++ + failureCountVal++ // TODO mark the set as a failure and reconcile what iptables rule or ipset is referring to it }, }, @@ -175,8 +284,8 @@ func (iMgr *IPSetManager) fileCreatorForReset(ipsetListOutput []byte) (*ioutil.F sectionID := sectionID(destroySectionPrefix, hashedSetName) creator.AddLine(sectionID, errorHandlers, ipsetDestroyFlag, hashedSetName) // destroy set } - originalNumAzureSets := len(names) - return creator, originalNumAzureSets, &destroyFailureCount + + return creator, failureCount } /* @@ -705,3 +814,18 @@ func (iMgr *IPSetManager) addMemberForApply(creator *ioutil.FileCreator, set *IP func sectionID(prefix, prefixedName string) string { return fmt.Sprintf("%s-%s", prefix, prefixedName) } + +func readByteLinesToMap(output []byte) map[string]struct{} { + readIndex := 0 + var line []byte + lines := make(map[string]struct{}) + for readIndex < len(output) { + line, readIndex = parse.Line(readIndex, output) + hashedSetName := strings.Trim(string(line), "\n") + lines[hashedSetName] = struct{}{} + if len(lines) > maxLinesToPrint { + break + } + } + return lines +} diff --git a/npm/pkg/dataplane/ipsets/ipsetmanager_linux_test.go b/npm/pkg/dataplane/ipsets/ipsetmanager_linux_test.go index 0871bab74c..c9db0194b7 100644 --- a/npm/pkg/dataplane/ipsets/ipsetmanager_linux_test.go +++ b/npm/pkg/dataplane/ipsets/ipsetmanager_linux_test.go @@ -20,17 +20,18 @@ import ( const ( saveResult = "create test-list1 list:set size 8\nadd test-list1 test-list2" - resetIPSetsListOutputString = `azure-npm-123456 -azure-npm-987654 -azure-npm-777777` - resetIPSetsNumGreppedSets = 3 - createNethashFormat = "create %s hash:net family inet hashsize 1024 maxelem 65536" createPorthashFormat = "create %s hash:ip,port family inet hashsize 1024 maxelem 65536" createListFormat = "create %s list:set size 8" ) -var resetIPSetsListOutput = []byte(resetIPSetsListOutputString) +var ( + // need to be sorted + resetIPSetsNames = []string{"azure-npm-123456", "azure-npm-777777", "azure-npm-987654"} + resetIPSetsListOutputString = strings.Join(resetIPSetsNames, "\n") + "\n" + resetIPSetsListOutput = []byte(resetIPSetsListOutputString) + otherIPSetsListOutput = "azure-npm-123456\n" +) // TODO test that a reconcile list is updated for all the TestFailure UTs // TODO same exact TestFailure UTs for unknown errors @@ -157,7 +158,7 @@ func TestNextCreateLine(t *testing.T) { expectedReadIndex int expectedLine []byte }{ - // parse.Line will omit the newline at the end of the line unless it's the last line + // parse.Line() will omit the newline at the end of the line unless it's the last line { name: "empty save file", lines: []string{}, @@ -192,112 +193,227 @@ func TestNextCreateLine(t *testing.T) { require.Equal(t, tt.expectedLine, line) }) } - // fmt.Println(string([]byte(addLine + addLine, createLineWithNewline})[:78])) } func TestDestroyNPMIPSetsCreatorSuccess(t *testing.T) { - calls := []testutils.TestCmd{fakeRestoreSuccessCommand} + calls := []testutils.TestCmd{fakeRestoreSuccessCommand, fakeRestoreSuccessCommand} ioshim := common.NewMockIOShim(calls) defer ioshim.VerifyCalls(t, calls) iMgr := NewIPSetManager(applyAlwaysCfg, ioshim) - creator, numSets, destroyFailureCount := iMgr.fileCreatorForReset(resetIPSetsListOutput) + creator, names, failedNames := iMgr.fileCreatorForFlushAll(resetIPSetsListOutput) actualLines := strings.Split(creator.ToString(), "\n") expectedLines := []string{ "-F azure-npm-123456", - "-F azure-npm-987654", "-F azure-npm-777777", + "-F azure-npm-987654", + "", + } + dptestutils.AssertEqualLines(t, expectedLines, actualLines) + sort.Strings(names) + require.Equal(t, resetIPSetsNames, names, "got unexpected ipset names") + wasModified, err := creator.RunCommandOnceWithFile("ipset", "restore") + require.False(t, wasModified, "got unexpected flush modify flag") + require.NoError(t, err, "got unexpected flush error") + require.Len(t, failedNames, 0, "got unexpected flush failure count") + + creator, destroyFailureCount := iMgr.fileCreatorForDestroyAll(names, failedNames, nil) + actualLines = strings.Split(creator.ToString(), "\n") + expectedLines = []string{ "-X azure-npm-123456", - "-X azure-npm-987654", "-X azure-npm-777777", + "-X azure-npm-987654", "", } dptestutils.AssertEqualLines(t, expectedLines, actualLines) - require.Equal(t, resetIPSetsNumGreppedSets, numSets, "got unexpected num sets") - wasModified, err := creator.RunCommandOnceWithFile("ipset", "restore") - require.False(t, wasModified) - require.NoError(t, err) - require.Equal(t, 0, *destroyFailureCount, "got unexpected failure count") + wasModified, err = creator.RunCommandOnceWithFile("ipset", "restore") + require.False(t, wasModified, "got unexpected destroy modified flag") + require.NoError(t, err, "got unexpected destroy error") + require.Equal(t, 0, *destroyFailureCount, "got unexpected destroy failure count") } func TestDestroyNPMIPSetsCreatorErrorHandling(t *testing.T) { + /* + original lines: + + "-F azure-npm-123456", + "-F azure-npm-777777", + "-F azure-npm-987654", + */ tests := []struct { - name string - call testutils.TestCmd - expectedLines []string - expectedFailureCount int + name string + calls []testutils.TestCmd + expectedFlushFailure bool + expectedFlushLines []string + expectedFailedNames map[string]struct{} + expectedDestroyFailure bool + expectedDestroyLines []string + expectedFailureCount int + setsWithReferences map[string]struct{} }{ { name: "set doesn't exist on flush", - call: testutils.TestCmd{ - Cmd: ipsetRestoreStringSlice, - Stdout: "Error in line 2: The set with the given name does not exist", - ExitCode: 1, + calls: []testutils.TestCmd{ + { + Cmd: ipsetRestoreStringSlice, + Stdout: "Error in line 2: The set with the given name does not exist", + ExitCode: 1, + }, + fakeRestoreSuccessCommand, }, - expectedLines: []string{ - "-F azure-npm-777777", + expectedFlushFailure: true, + expectedFlushLines: []string{ + "-F azure-npm-987654", + "", + }, + expectedFailedNames: map[string]struct{}{ + "azure-npm-777777": {}, + }, + expectedDestroyFailure: false, + expectedDestroyLines: []string{ "-X azure-npm-123456", - "-X azure-npm-777777", + "-X azure-npm-987654", "", }, expectedFailureCount: 0, }, { name: "some other error on flush", - call: testutils.TestCmd{ - Cmd: ipsetRestoreStringSlice, - Stdout: "Error in line 2: for some other error", - ExitCode: 1, + calls: []testutils.TestCmd{ + { + Cmd: ipsetRestoreStringSlice, + Stdout: "Error in line 2: for some other error", + ExitCode: 1, + }, + fakeRestoreSuccessCommand, }, - expectedLines: []string{ - "-F azure-npm-777777", + expectedFlushFailure: true, + expectedFlushLines: []string{ + "-F azure-npm-987654", + "", + }, + expectedFailedNames: map[string]struct{}{ + "azure-npm-777777": {}, + }, + expectedDestroyFailure: false, + expectedDestroyLines: []string{ "-X azure-npm-123456", - "-X azure-npm-777777", + "-X azure-npm-987654", "", }, - expectedFailureCount: 1, + expectedFailureCount: 0, }, { name: "set doesn't exist on destroy", - call: testutils.TestCmd{ - Cmd: ipsetRestoreStringSlice, - Stdout: "Error in line 5: The set with the given name does not exist", - ExitCode: 1, + calls: []testutils.TestCmd{ + fakeRestoreSuccessCommand, + { + Cmd: ipsetRestoreStringSlice, + Stdout: "Error in line 2: The set with the given name does not exist", + ExitCode: 1, + }, }, - expectedLines: []string{ - "-X azure-npm-777777", + expectedFlushFailure: false, + expectedDestroyFailure: true, + expectedDestroyLines: []string{ + "-X azure-npm-987654", "", }, expectedFailureCount: 0, }, { name: "some other error on destroy", - call: testutils.TestCmd{ - Cmd: ipsetRestoreStringSlice, - Stdout: "Error in line 5: some other error", - ExitCode: 1, + calls: []testutils.TestCmd{ + fakeRestoreSuccessCommand, + { + Cmd: ipsetRestoreStringSlice, + Stdout: "Error in line 2: some other error", + ExitCode: 1, + }, }, - expectedLines: []string{ - "-X azure-npm-777777", + expectedFlushFailure: false, + expectedDestroyFailure: true, + expectedDestroyLines: []string{ + "-X azure-npm-987654", "", }, expectedFailureCount: 1, }, + { + name: "set with references", + calls: []testutils.TestCmd{ + fakeRestoreSuccessCommand, + fakeRestoreSuccessCommand, + }, + expectedFlushFailure: false, + expectedDestroyFailure: false, + expectedDestroyLines: []string{ + "-X azure-npm-123456", + "-X azure-npm-987654", + "", + }, + expectedFailureCount: 0, + setsWithReferences: map[string]struct{}{ + "azure-npm-777777": {}, + }, + }, + { + name: "all sets with references", + calls: []testutils.TestCmd{ + fakeRestoreSuccessCommand, + }, + expectedFlushFailure: false, + expectedDestroyFailure: false, + expectedDestroyLines: []string{ + "", + }, + expectedFailureCount: 0, + setsWithReferences: map[string]struct{}{ + "azure-npm-123456": {}, + "azure-npm-777777": {}, + "azure-npm-987654": {}, + }, + }, } for _, tt := range tests { tt := tt t.Run(tt.name, func(t *testing.T) { - calls := []testutils.TestCmd{tt.call} - ioshim := common.NewMockIOShim(calls) - defer ioshim.VerifyCalls(t, calls) + ioshim := common.NewMockIOShim(tt.calls) + defer ioshim.VerifyCalls(t, tt.calls) iMgr := NewIPSetManager(applyAlwaysCfg, ioshim) - creator, numSets, destroyFailureCount := iMgr.fileCreatorForReset(resetIPSetsListOutput) - require.Equal(t, resetIPSetsNumGreppedSets, numSets, "got unexpected num sets") + creator, names, failedNames := iMgr.fileCreatorForFlushAll(resetIPSetsListOutput) + + sort.Strings(names) + require.Equal(t, resetIPSetsNames, names, "got unexpected ipset names") wasModified, err := creator.RunCommandOnceWithFile("ipset", "restore") - require.True(t, wasModified) - require.Error(t, err) - actualLines := strings.Split(creator.ToString(), "\n") - dptestutils.AssertEqualLines(t, tt.expectedLines, actualLines) - require.Equal(t, tt.expectedFailureCount, *destroyFailureCount, "got unexpected failure count") + if tt.expectedFlushFailure { + require.True(t, wasModified, "got unexpected flush modify flag") + require.Error(t, err, "got unexpected flush success") + fmt.Println("err:", err.Error()) + require.Equal(t, failedNames, tt.expectedFailedNames) + actualLines := strings.Split(creator.ToString(), "\n") + dptestutils.AssertEqualLines(t, tt.expectedFlushLines, actualLines) + } else { + require.False(t, wasModified, "got unexpected flush modify flag") + require.NoError(t, err, "got unexpected flush error") + require.Len(t, failedNames, 0) + } + + creator, destroyFailureCount := iMgr.fileCreatorForDestroyAll(names, failedNames, tt.setsWithReferences) + wasModified, err = creator.RunCommandOnceWithFile("ipset", "restore") + if tt.expectedDestroyFailure { + require.True(t, wasModified, "got unexpected destroy modify flag") + require.Error(t, err, "got unexpected destroy success") + fmt.Println("err:", err.Error()) + require.Equal(t, tt.expectedFailureCount, *destroyFailureCount, "got unexpected failure count") + actualLines := strings.Split(creator.ToString(), "\n") + dptestutils.AssertEqualLines(t, tt.expectedDestroyLines, actualLines) + } else { + require.False(t, wasModified, "got unexpected destroy modify flag") + require.NoError(t, err, "got unexpected destroy error") + require.Equal(t, 0, *destroyFailureCount, "got unexpected failure count") + actualLines := strings.Split(creator.ToString(), "\n") + dptestutils.AssertEqualLines(t, tt.expectedDestroyLines, actualLines) + } }) } } @@ -308,9 +424,31 @@ func TestDestroyNPMIPSets(t *testing.T) { calls []testutils.TestCmd wantErr bool }{ + { + name: "non-azure sets don't exist", + calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 1}, // grep didn't find anything + {Cmd: []string{"bash", "-c", "ipset flush && ipset destroy"}}, + }, + wantErr: false, + }, + { + name: "ignore failure when looking for non-azure sets", + calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 1}, // grep didn't find anything + {Cmd: []string{"bash", "-c", "ipset flush && ipset destroy"}, ExitCode: 1, Stdout: "some error here"}, + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "azure-npm-"}, ExitCode: 1}, + }, + wantErr: false, + }, { name: "success with no results from grep", calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, {Cmd: []string{"grep", "azure-npm-"}, ExitCode: 1}, }, @@ -319,23 +457,33 @@ func TestDestroyNPMIPSets(t *testing.T) { { name: "successfully delete sets", calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, ExitCode: 1}, + fakeRestoreSuccessCommand, }, wantErr: false, }, { name: "grep error", calls: []testutils.TestCmd{ - {Cmd: []string{"ipset", "list", "--name"}, HasStartError: true, PipedToCommand: true, ExitCode: 1}, + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true, HasStartError: true, ExitCode: 1}, {Cmd: []string{"grep", "azure-npm-"}}, }, wantErr: true, }, { - name: "restore error from max tries", + name: "restore error from max flush tries", calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, {Cmd: ipsetRestoreStringSlice, ExitCode: 1}, @@ -344,9 +492,57 @@ func TestDestroyNPMIPSets(t *testing.T) { }, wantErr: true, }, + { + name: "restore error from max destroy tries", + calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, + fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, ExitCode: 1}, + {Cmd: ipsetRestoreStringSlice, ExitCode: 1}, + {Cmd: ipsetRestoreStringSlice, ExitCode: 1}, + {Cmd: ipsetRestoreStringSlice, ExitCode: 1}, + }, + wantErr: true, + }, + { + name: "success despite all sets having references", + calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, + fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, Stdout: resetIPSetsListOutputString}, + }, + wantErr: false, + }, + { + name: "success despite one set having references", + calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, + fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, Stdout: otherIPSetsListOutput}, + fakeRestoreSuccessCommand, + }, + wantErr: false, + }, { name: "successfully restore, but fail to flush/destroy 1 set since the set doesn't exist when flushing", calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, { @@ -355,12 +551,18 @@ func TestDestroyNPMIPSets(t *testing.T) { ExitCode: 1, }, fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, ExitCode: 1}, + fakeRestoreSuccessCommand, }, wantErr: false, }, { name: "successfully restore, but fail to flush/destroy 1 set due to other flush error", calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, { @@ -369,17 +571,27 @@ func TestDestroyNPMIPSets(t *testing.T) { ExitCode: 1, }, fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, ExitCode: 1}, + fakeRestoreSuccessCommand, }, wantErr: false, }, { name: "successfully restore, but fail to destroy 1 set since the set doesn't exist when destroying", calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, + fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, ExitCode: 1}, { Cmd: ipsetRestoreStringSlice, - Stdout: "Error in line 5: The set with the given name does not exist", + Stdout: "Error in line 2: The set with the given name does not exist", ExitCode: 1, }, fakeRestoreSuccessCommand, @@ -389,11 +601,17 @@ func TestDestroyNPMIPSets(t *testing.T) { { name: "successfully restore, but fail to destroy 1 set due to other destroy error", calls: []testutils.TestCmd{ + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, {Cmd: []string{"grep", "azure-npm-"}, Stdout: resetIPSetsListOutputString}, + fakeRestoreSuccessCommand, + {Cmd: []string{"ipset", "list"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-B", "5", "-P", "References: [1-9]"}, PipedToCommand: true}, + {Cmd: []string{"grep", "-o", "-P", "azure-npm-\\d+"}, ExitCode: 1}, { Cmd: ipsetRestoreStringSlice, - Stdout: "Error in line 5: for some other error", + Stdout: "Error in line 2: for some other error", ExitCode: 1, }, fakeRestoreSuccessCommand, @@ -411,6 +629,7 @@ func TestDestroyNPMIPSets(t *testing.T) { err := iMgr.resetIPSets() if tt.wantErr { require.Error(t, err) + fmt.Println("got correct error:", err.Error()) } else { require.NoError(t, err) } @@ -423,7 +642,9 @@ func TestDestroyNPMIPSets(t *testing.T) { func TestResetIPSetsOnFailure(t *testing.T) { metrics.ReinitializeAll() calls := []testutils.TestCmd{ - {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true, HasStartError: true}, + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true, HasStartError: true, ExitCode: 1}, + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 0}, // non-azure sets exist + {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true, HasStartError: true, ExitCode: 1}, {Cmd: []string{"grep", "azure-npm-"}}, } ioShim := common.NewMockIOShim(calls) @@ -438,7 +659,7 @@ func TestResetIPSetsOnFailure(t *testing.T) { metrics.AddEntryToIPSet("test1") metrics.AddEntryToIPSet("test2") - require.NoError(t, iMgr.ResetIPSets()) + require.Error(t, iMgr.ResetIPSets()) assertExpectedInfo(t, iMgr, &expectedInfo{ mainCache: nil, @@ -490,7 +711,7 @@ func TestApplyIPSetsSuccessWithSave(t *testing.T) { func TestApplyIPSetsFailureOnSave(t *testing.T) { calls := []testutils.TestCmd{ - {Cmd: ipsetSaveStringSlice, HasStartError: true, PipedToCommand: true, ExitCode: 1}, + {Cmd: ipsetSaveStringSlice, PipedToCommand: true, HasStartError: true, ExitCode: 1}, {Cmd: []string{"grep", "azure-npm-"}}, } ioshim := common.NewMockIOShim(calls) diff --git a/npm/pkg/dataplane/ipsets/testutils_linux.go b/npm/pkg/dataplane/ipsets/testutils_linux.go index 344bff312b..94a59f4f45 100644 --- a/npm/pkg/dataplane/ipsets/testutils_linux.go +++ b/npm/pkg/dataplane/ipsets/testutils_linux.go @@ -23,6 +23,7 @@ func GetApplyIPSetsTestCalls(toAddOrUpdateIPSets, toDeleteIPSets []*IPSetMetadat func GetResetTestCalls() []testutils.TestCmd { return []testutils.TestCmd{ {Cmd: []string{"ipset", "list", "--name"}, PipedToCommand: true}, - {Cmd: []string{"grep", "azure-npm-"}, ExitCode: 1}, // grep didn't find anything + {Cmd: []string{"grep", "-q", "-v", "azure-npm-"}, ExitCode: 1}, // grep didn't find anything + {Cmd: []string{"bash", "-c", "ipset flush && ipset destroy"}}, } } diff --git a/npm/pkg/dataplane/policies/chain-management_linux.go b/npm/pkg/dataplane/policies/chain-management_linux.go index eab713c7c0..21524f0757 100644 --- a/npm/pkg/dataplane/policies/chain-management_linux.go +++ b/npm/pkg/dataplane/policies/chain-management_linux.go @@ -18,9 +18,6 @@ import ( ) const ( - // TODO replace all util constants with local constants - defaultlockWaitTimeInSeconds string = "60" - doesNotExistErrorCode int = 1 // stderr possibility: Bad rule (does a matching rule exist in that chain?) couldntLoadTargetErrorCode int = 2 // Couldn't load target `AZURE-NPM-EGRESS':No such file or directory @@ -66,7 +63,7 @@ var ( } listForwardEntriesArgs = []string{ - util.IptablesWaitFlag, defaultlockWaitTimeInSeconds, util.IptablesTableFlag, util.IptablesFilterTable, + util.IptablesWaitFlag, util.IptablesDefaultWaitTime, util.IptablesTableFlag, util.IptablesFilterTable, util.IptablesNumericFlag, util.IptablesListFlag, util.IptablesForwardChain, util.IptablesLineNumbersFlag, } spaceByte = []byte(" ") @@ -184,7 +181,7 @@ func (pMgr *PolicyManager) bootup(_ []string) error { klog.Errorf("failed to delete deprecated jump rule from FORWARD chain to AZURE-NPM chain for unexpected reason with exit code %d and error: %s", deprecatedErrCode, deprecatedErr.Error()) } - currentChains, err := ioutil.AllCurrentAzureChains(pMgr.ioShim.Exec, defaultlockWaitTimeInSeconds) + currentChains, err := ioutil.AllCurrentAzureChains(pMgr.ioShim.Exec, util.IptablesDefaultWaitTime) if err != nil { return npmerrors.SimpleErrorWrapper("failed to get current chains for bootup", err) } @@ -270,7 +267,7 @@ func (pMgr *PolicyManager) runIPTablesCommand(operationFlag string, args ...stri } func (pMgr *PolicyManager) ignoreErrorsAndRunIPTablesCommand(ignored []*exitErrorInfo, operationFlag string, args ...string) (int, error) { - allArgs := []string{util.IptablesWaitFlag, defaultlockWaitTimeInSeconds, operationFlag} + allArgs := []string{util.IptablesWaitFlag, util.IptablesDefaultWaitTime, operationFlag} allArgs = append(allArgs, args...) klog.Infof("Executing iptables command with args %v", allArgs) diff --git a/npm/pkg/dataplane/policies/chain-management_linux_test.go b/npm/pkg/dataplane/policies/chain-management_linux_test.go index 7a3d3f6589..8e7addcc82 100644 --- a/npm/pkg/dataplane/policies/chain-management_linux_test.go +++ b/npm/pkg/dataplane/policies/chain-management_linux_test.go @@ -45,7 +45,7 @@ func TestBootupFailure(t *testing.T) { metrics.ReinitializeAll() calls := []testutils.TestCmd{ {Cmd: []string{"iptables", "-w", "60", "-D", "FORWARD", "-j", "AZURE-NPM"}, ExitCode: 2}, //nolint // AZURE-NPM chain didn't exist - {Cmd: listAllCommandStrings, PipedToCommand: true, HasStartError: true}, + {Cmd: listAllCommandStrings, PipedToCommand: true, HasStartError: true, ExitCode: 1}, {Cmd: []string{"grep", "Chain AZURE-NPM"}}, } ioshim := common.NewMockIOShim(calls) @@ -702,6 +702,7 @@ func TestPositionAzureChainJumpRule(t *testing.T) { calls: []testutils.TestCmd{ {Cmd: listLineNumbersCommandStrings, PipedToCommand: true}, {Cmd: []string{"grep", "AZURE-NPM"}, ExitCode: 1}, + // should add ExitCode: 1 to below, but this causes an error for the previous commands actually... {Cmd: listLineNumbersCommandStrings, PipedToCommand: true, HasStartError: true}, {Cmd: []string{"grep", "KUBE-SERVICES"}}, }, diff --git a/npm/pkg/dataplane/policies/policymanager_linux.go b/npm/pkg/dataplane/policies/policymanager_linux.go index f7560b97cb..d88c23cd0c 100644 --- a/npm/pkg/dataplane/policies/policymanager_linux.go +++ b/npm/pkg/dataplane/policies/policymanager_linux.go @@ -91,7 +91,7 @@ func (pMgr *PolicyManager) removePolicy(networkPolicy *NPMNetworkPolicy, _ map[s } func restore(creator *ioutil.FileCreator) error { - err := creator.RunCommandWithFile(util.IptablesRestore, util.IptablesWaitFlag, defaultlockWaitTimeInSeconds, util.IptablesRestoreTableFlag, util.IptablesFilterTable, util.IptablesRestoreNoFlushFlag) + err := creator.RunCommandWithFile(util.IptablesRestore, util.IptablesWaitFlag, util.IptablesDefaultWaitTime, util.IptablesRestoreTableFlag, util.IptablesFilterTable, util.IptablesRestoreNoFlushFlag) if err != nil { return npmerrors.SimpleErrorWrapper("failed to restore iptables file", err) } diff --git a/npm/util/const.go b/npm/util/const.go index 3e204cea7a..f94ecf4935 100644 --- a/npm/util/const.go +++ b/npm/util/const.go @@ -43,6 +43,7 @@ const ( IptablesDestroyFlag string = "-X" IptablesJumpFlag string = "-j" IptablesWaitFlag string = "-w" + IptablesDefaultWaitTime string = "60" IptablesAccept string = "ACCEPT" IptablesReject string = "REJECT" IptablesDrop string = "DROP" @@ -190,6 +191,11 @@ const ( SetPolicyDelimiter string = "," ) +const ( + BashCommand string = "bash" + BashCommandFlag string = "-c" +) + // NPM telemetry constants. const ( AddNamespaceEvent string = "Add Namespace" diff --git a/npm/util/ioutil/current-azure-chains.go b/npm/util/ioutil/current-azure-chains.go index 44731bd11c..70b95ba3ba 100644 --- a/npm/util/ioutil/current-azure-chains.go +++ b/npm/util/ioutil/current-azure-chains.go @@ -22,9 +22,9 @@ var ( errInvalidGrepResult = errors.New("unexpectedly got no lines while grepping for current Azure chains") ) -func AllCurrentAzureChains(exec utilexec.Interface, defaultlockWaitTimeInSeconds string) (map[string]struct{}, error) { +func AllCurrentAzureChains(exec utilexec.Interface, lockWaitTimeSeconds string) (map[string]struct{}, error) { iptablesListCommand := exec.Command(util.Iptables, - util.IptablesWaitFlag, defaultlockWaitTimeInSeconds, util.IptablesTableFlag, util.IptablesFilterTable, + util.IptablesWaitFlag, lockWaitTimeSeconds, util.IptablesTableFlag, util.IptablesFilterTable, util.IptablesNumericFlag, util.IptablesListFlag, ) grepCommand := exec.Command(Grep, azureChainGrepPattern) diff --git a/npm/util/ioutil/grep.go b/npm/util/ioutil/grep.go index 92ce1e0e6e..dab18a19da 100644 --- a/npm/util/ioutil/grep.go +++ b/npm/util/ioutil/grep.go @@ -2,10 +2,71 @@ package ioutil -import utilexec "k8s.io/utils/exec" +import ( + "fmt" + + utilexec "k8s.io/utils/exec" +) // Grep is the grep command string -const Grep = "grep" +const ( + Grep = "grep" + GrepRegexFlag = "-P" + GrepOnlyMatchingFlag = "-o" + GrepAntiMatchFlag = "-v" + GrepQuietFlag = "-q" + GrepBeforeFlag = "-B" +) + +func DoublePipeToGrep(command, grepCommand1, grepCommand2 utilexec.Cmd) (searchResults []byte, gotMatches bool, commandError error) { + pipe, commandError := command.StdoutPipe() + if commandError != nil { + return + } + grepCommand1.SetStdin(pipe) + + grepPipe, commandError := grepCommand1.StdoutPipe() + if commandError != nil { + _ = pipe.Close() + commandError = fmt.Errorf("error getting pipe for grep command: %w", commandError) + return + } + grepCommand2.SetStdin(grepPipe) + + closePipes := func() { + _ = grepPipe.Close() + _ = pipe.Close() + } + defer closePipes() + + commandError = grepCommand1.Start() + if commandError != nil { + commandError = fmt.Errorf("error while starting first grep command: %w", commandError) + return + } + + commandError = command.Start() + if commandError != nil { + commandError = fmt.Errorf("error while starting command: %w", commandError) + _ = grepCommand1.Wait() + return + } + + waitForAll := func() { + _ = command.Wait() + _ = grepCommand1.Wait() + } + defer waitForAll() + + output, err := grepCommand2.CombinedOutput() + if err != nil { + // grep returns err status 1 if nothing is found + return + } + searchResults = output + gotMatches = true + return searchResults, gotMatches, commandError // include named results to appease lint +} func PipeCommandToGrep(command, grepCommand utilexec.Cmd) (searchResults []byte, gotMatches bool, commandError error) { pipe, commandError := command.StdoutPipe() diff --git a/npm/util/ioutil/restore.go b/npm/util/ioutil/restore.go index 4bfaebebe3..9bd462b01d 100644 --- a/npm/util/ioutil/restore.go +++ b/npm/util/ioutil/restore.go @@ -141,7 +141,7 @@ func (creator *FileCreator) RunCommandWithFile(cmd string, args ...string) error if wasFileAltered { sameNew = "updated" } - msg := fmt.Sprintf("on try number %d, failed to run command [%s]. Rerunning with %s file. Had error [%s].Used file:%s", creator.tryCount, commandString, sameNew, err.Error(), fileString) + msg := fmt.Sprintf("on try number %d, failed to run command [%s]. Rerunning with %s file. err: [%s]", creator.tryCount, commandString, sameNew, err.Error()) klog.Error(msg) metrics.SendErrorLogAndMetric(util.UtilID, "error: %s", msg) @@ -181,6 +181,8 @@ func (creator *FileCreator) runCommandOnceWithFile(fileString, cmd string, args return false, nil } + klog.Infof("running this restore command: [%s]", commandString) + command := creator.ioShim.Exec.Command(cmd, args...) command.SetStdin(bytes.NewBufferString(fileString)) @@ -208,8 +210,8 @@ func (creator *FileCreator) runCommandOnceWithFile(fileString, cmd string, args for _, lineFailureDefinition := range creator.lineFailureDefinitions { lineNum := lineFailureDefinition.getErrorLineNumber(stdErr, commandString, numLines) if lineNum != -1 { - wasFileAltered := creator.handleLineError(stdErr, commandString, lineNum) - return wasFileAltered, npmerrors.SimpleErrorWrapper("line-number error", err) + wasFileAltered, line := creator.handleLineError(stdErr, commandString, lineNum) + return wasFileAltered, npmerrors.SimpleErrorWrapper(fmt.Sprintf("line-number error for line [%s]", line.content), err) } } return false, npmerrors.SimpleErrorWrapper("unknown error", err) @@ -260,9 +262,20 @@ func (definition *ErrorDefinition) getErrorLineNumber(stdErr, commandString stri } // return whether the file was altered -func (creator *FileCreator) handleLineError(stdErr, commandString string, lineNum int) bool { - lineNumIndex := lineNum - 1 - line := creator.lines[lineNumIndex] +func (creator *FileCreator) handleLineError(stdErr, commandString string, lineNum int) (bool, *Line) { + lineIndex := 0 + currentLineIndex := 0 + for i := range creator.lines { + if _, isOmitted := creator.lineNumbersToOmit[i]; isOmitted { + continue + } + if currentLineIndex == lineNum-1 { + lineIndex = currentLineIndex + } + currentLineIndex++ + } + + line := creator.lines[lineIndex] for _, errorHandler := range line.errorHandlers { if !errorHandler.Definition.isMatch(stdErr) { continue @@ -270,12 +283,12 @@ func (creator *FileCreator) handleLineError(stdErr, commandString string, lineNu switch errorHandler.Method { case Continue: klog.Infof("continuing after line %d for command [%s]", lineNum, commandString) - for i := 0; i <= lineNumIndex; i++ { + for i := 0; i <= lineIndex; i++ { creator.lineNumbersToOmit[i] = struct{}{} } case ContinueAndAbortSection: klog.Infof("continuing after line %d and aborting section associated with the line for command [%s]", lineNum, commandString) - for i := 0; i <= lineNumIndex; i++ { + for i := 0; i <= lineIndex; i++ { creator.lineNumbersToOmit[i] = struct{}{} } section := creator.sections[line.sectionID] @@ -284,7 +297,7 @@ func (creator *FileCreator) handleLineError(stdErr, commandString string, lineNu } } errorHandler.Callback() - return true + return true, creator.lines[lineIndex] } - return false + return false, creator.lines[lineIndex] }