Skip to content

Commit

Permalink
test: Avoid spamming logs in monitor aggreg test
Browse files Browse the repository at this point in the history
The monitor aggregation tests are currently spamming the logs because
they dump useless matches from regular expressions. Let's remove that.

Most of the log spam comes from the use of %+v to dump the regexp
matches. That doesn't even work properly and ends up dumping a huge
matrix of integers. Given we retry this step until it eventually
succeeds, this can add up to several megabytes of logs.

In addition to removing this dump of the regexp matches, we also switch
the checkMonitorOutput function to return an error instead of a boolean.
The consequence of that change is that the Eventually block will display
the actual error message from checkMonitorOutput on failure. The test
logs won't contain one error message (GinkgoPrint) per failure, but only
the last error message we got before timing out. I believe that's what
we want because: 1) it surfaces the actual error in the ginkgo results
instead of telling us "expected true, got false" (duh!) and (2) in logs,
we only care about the last error message.

Signed-off-by: Paul Chaignon <paul@cilium.io>
  • Loading branch information
pchaigno committed Apr 27, 2023
1 parent 4b0f110 commit 2a57194
Showing 1 changed file with 14 additions and 15 deletions.
29 changes: 14 additions & 15 deletions test/k8s/datapath_configuration.go
Original file line number Diff line number Diff line change
Expand Up @@ -101,10 +101,10 @@ var _ = Describe("K8sDatapathConfig", func() {
// | ACK | -> | Y | monitorAggregation=medium
egressPktCount := 3
ingressPktCount := 2
Eventually(func() bool {
Eventually(func() error {
monitorOutput = monitorRes.CombineOutput().Bytes()
return checkMonitorOutput(monitorOutput, egressPktCount, ingressPktCount)
}, helpers.HelperTimeout, time.Second).Should(BeTrue(), "Monitor log did not contain %d ingress and %d egress TCP notifications\n%s",
}, helpers.HelperTimeout, time.Second).Should(BeNil(), "Monitor log did not contain %d ingress and %d egress TCP notifications\n%s",
ingressPktCount, egressPktCount, monitorOutput)

helpers.WriteToReportFile(monitorOutput, monitorLog)
Expand Down Expand Up @@ -134,10 +134,10 @@ var _ = Describe("K8sDatapathConfig", func() {
// | ACK | -> | Y | monitorAggregation=medium
egressPktCount := 4
ingressPktCount := 3
Eventually(func() bool {
Eventually(func() error {
monitorOutput = monitorRes.CombineOutput().Bytes()
return checkMonitorOutput(monitorOutput, egressPktCount, ingressPktCount)
}, helpers.HelperTimeout, time.Second).Should(BeTrue(), "monitor aggregation did not result in correct number of TCP notifications\n%s", monitorOutput)
}, helpers.HelperTimeout, time.Second).Should(BeNil(), "monitor aggregation did not result in correct number of TCP notifications\n%s", monitorOutput)
helpers.WriteToReportFile(monitorOutput, monitorLog)
})
})
Expand Down Expand Up @@ -790,17 +790,16 @@ func monitorConnectivityAcrossNodes(kubectl *helpers.Kubectl) (monitorRes *helpe
return monitorRes, monitorCancel, targetIP
}

func checkMonitorOutput(monitorOutput []byte, egressPktCount, ingressPktCount int) bool {
func checkMonitorOutput(monitorOutput []byte, egressPktCount, ingressPktCount int) error {
// Multiple connection attempts may be made, we need to
// narrow down to the last connection close, then match
// the ephemeral port + flags to ensure that the
// notifications match the table above.
egressTCPExpr := `TCP.*DstPort=80.*FIN=true`
egressTCPRegex := regexp.MustCompile(egressTCPExpr)
egressTCPMatches := egressTCPRegex.FindAll(monitorOutput, -1)
if len(egressTCPMatches) <= 0 {
GinkgoPrint("Could not locate final FIN notification in monitor log: egressTCPMatches %+v", egressTCPMatches)
return false
if len(egressTCPMatches) == 0 {
return fmt.Errorf("could not locate TCP FIN in monitor log")
}
finalMatch := egressTCPMatches[len(egressTCPMatches)-1]
portRegex := regexp.MustCompile(`SrcPort=([0-9]*)`)
Expand All @@ -810,25 +809,25 @@ func checkMonitorOutput(monitorOutput []byte, egressPktCount, ingressPktCount in
By("Looking for TCP notifications using the ephemeral port %q", portBytes)
port, err := strconv.Atoi(string(portBytes))
if err != nil {
GinkgoPrint("ephemeral port %q could not be converted to integer: %s", string(portBytes), err)
return false
return fmt.Errorf("ephemeral port %q could not be converted to integer: %s",
string(portBytes), err)
}

expEgress := fmt.Sprintf("SrcPort=%d", port)
expEgressRegex := regexp.MustCompile(expEgress)
egressMatches := expEgressRegex.FindAllIndex(monitorOutput, -1)
if len(egressMatches) != egressPktCount {
GinkgoPrint("Could not locate final FIN notification in monitor log: egressTCPMatches %+v", egressTCPMatches)
return false
return fmt.Errorf("monitor logs contained unexpected number (%d) of egress notifications matching %q",
len(egressMatches), expEgress)
}

expIngress := fmt.Sprintf("DstPort=%d", port)
expIngressRegex := regexp.MustCompile(expIngress)
ingressMatches := expIngressRegex.FindAllIndex(monitorOutput, -1)
if len(ingressMatches) != ingressPktCount {
GinkgoPrint("Monitor log contained unexpected number of ingress notifications matching %q", expIngress)
return false
return fmt.Errorf("monitor log contained unexpected number (%d) of ingress notifications matching %q",
len(ingressMatches), expIngress)
}

return true
return nil
}

0 comments on commit 2a57194

Please sign in to comment.