From 345dae142b677c2de34324453524a38570e275c6 Mon Sep 17 00:00:00 2001 From: Chris Telfer Date: Wed, 11 Apr 2018 11:46:18 -0400 Subject: [PATCH 1/2] Filter xtable wait messages when using firewalld This gets filtered for raw iptables calls, but not from calls made through firewalld. The patch just ensures consistency of operation. It also adds a warning when xtables contention detected and truncates the search string slightly as it appears that the suffix will be changing in the near future. Signed-off-by: Chris Telfer (cherry picked from commit 2fb05a336d713bf8a190d01c12f4f357ba02c76e) Signed-off-by: Chris Telfer --- iptables/iptables.go | 32 ++++++++++++++++++++++++-------- 1 file changed, 24 insertions(+), 8 deletions(-) diff --git a/iptables/iptables.go b/iptables/iptables.go index f0691e9235..dff5e61b90 100644 --- a/iptables/iptables.go +++ b/iptables/iptables.go @@ -9,6 +9,7 @@ import ( "strconv" "strings" "sync" + "time" "github.com/Sirupsen/logrus" ) @@ -45,7 +46,7 @@ var ( iptablesPath string supportsXlock = false supportsCOpt = false - xLockWaitMsg = "Another app is currently holding the xtables lock; waiting" + xLockWaitMsg = "Another app is currently holding the xtables lock" // used to lock iptables commands if xtables lock is not supported bestEffortLock sync.Mutex // ErrIptablesNotFound is returned when the rule is not found. @@ -399,12 +400,31 @@ func existsRaw(table Table, chain string, rule ...string) bool { return strings.Contains(string(existingRules), ruleString) } +// Maximum duration that an iptables operation can take +// before flagging a warning. +const opWarnTime = 2 * time.Second + +func filterOutput(start time.Time, output []byte, args ...string) []byte { + // Flag operations that have taken a long time to complete + if time.Since(start) > opWarnTime { + logrus.Warnf("xtables contention detected while running [%s]: %q", strings.Join(args, " "), string(output)) + } + // ignore iptables' message about xtables lock: + // it is a warning, not an error. + if strings.Contains(string(output), xLockWaitMsg) { + output = []byte("") + } + // Put further filters here if desired + return output +} + // Raw calls 'iptables' system command, passing supplied arguments. func Raw(args ...string) ([]byte, error) { if firewalldRunning { + startTime := time.Now() output, err := Passthrough(Iptables, args...) if err == nil || !strings.Contains(err.Error(), "was not provided by any .service files") { - return output, err + return filterOutput(startTime, output, args...), err } } return raw(args...) @@ -423,17 +443,13 @@ func raw(args ...string) ([]byte, error) { logrus.Debugf("%s, %v", iptablesPath, args) + startTime := time.Now() output, err := exec.Command(iptablesPath, args...).CombinedOutput() if err != nil { return nil, fmt.Errorf("iptables failed: iptables %v: %s (%s)", strings.Join(args, " "), output, err) } - // ignore iptables' message about xtables lock - if strings.Contains(string(output), xLockWaitMsg) { - output = []byte("") - } - - return output, err + return filterOutput(startTime, output, args...), err } // RawCombinedOutput inernally calls the Raw function and returns a non nil From 20f9b47dbd28f5386fad72eb99493a4e4461a3f2 Mon Sep 17 00:00:00 2001 From: Chris Telfer Date: Thu, 26 Apr 2018 10:19:26 -0400 Subject: [PATCH 2/2] Add wait time into xtables lock warning Signed-off-by: Chris Telfer (cherry picked from commit 36847dd923b71f56671eed23df4809786350445c) Signed-off-by: Chris Telfer --- iptables/iptables.go | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/iptables/iptables.go b/iptables/iptables.go index dff5e61b90..124c87223d 100644 --- a/iptables/iptables.go +++ b/iptables/iptables.go @@ -406,8 +406,9 @@ const opWarnTime = 2 * time.Second func filterOutput(start time.Time, output []byte, args ...string) []byte { // Flag operations that have taken a long time to complete - if time.Since(start) > opWarnTime { - logrus.Warnf("xtables contention detected while running [%s]: %q", strings.Join(args, " "), string(output)) + opTime := time.Since(start) + if opTime > opWarnTime { + logrus.Warnf("xtables contention detected while running [%s]: Waited for %.2f seconds and received %q", strings.Join(args, " "), float64(opTime)/float64(time.Second), string(output)) } // ignore iptables' message about xtables lock: // it is a warning, not an error.