TestFlowAggregator failed when AntreaIPAM is used

[tnqn]

Describe the bug

The test failed very frequently in "jenkins-flexible-ipam-e2e", on which cluster AntreaIPAM is enabled:

=== RUN   TestFlowAggregator/IPv4/InterNodeFlows
I1104 11:31:48.223994   27153 k8s_util.go:655] Creating/updating Antrea NetworkPolicy antrea-test/test-flow-aggregator-antrea-networkpolicy-ingress
I1104 11:31:48.237402   27153 k8s_util.go:655] Creating/updating Antrea NetworkPolicy antrea-test/test-flow-aggregator-antrea-networkpolicy-egress
    flowaggregator_test.go:874: Antrea Network Policies are realized.
    flowaggregator_test.go:601: Check the average bandwidth using octetTotalCountFromSourceNode 7731439957 in data record.
    flowaggregator_test.go:714: Iperf throughput: 6993.92 Mbits/s, IPFIX record throughput calculated through octetTotalCountFromSourceNode: 5154.29 Mbits/s
    flowaggregator_test.go:715: 
        	Error Trace:	flowaggregator_test.go:715
        	            				flowaggregator_test.go:602
        	            				flowaggregator_test.go:340
        	Error:      	Max difference between 5154.293304666667 and 6993.92 allowed is 1049.088, but difference was -1839.6266953333334
        	Test:       	TestFlowAggregator/IPv4/InterNodeFlows
        	Messages:   	Difference between Iperf bandwidth and IPFIX record bandwidth calculated through octetTotalCountFromSourceNode should be lower than 15%
    assertion_compare.go:323: 
        	Error Trace:	flowaggregator_test.go:606
        	            				flowaggregator_test.go:340
        	Error:      	"2" is not greater than or equal to "3"
        	Test:       	TestFlowAggregator/IPv4/InterNodeFlows
        	Messages:   	[IPFIX collector should receive expected number of flow records. Considered records: %s 
        	            	 Collector output: %s [I1104 11:30:30.044932       1 collector.go:149] Starting IPFIX collector
        	            	I1104 11:30:30.046424       1 tcp.go:38] Start TCP collecting process on [::]:4739
        	            	I1104 11:30:53.374638       1 collector.go:172] Processing IPFIX message
        	            	I1104 11:30:53.374655       1 collector.go:172] Processing IPFIX message
...

Versions:

• Antrea version (Docker image tag). main-a48f4db0608b30cb420032f5e8e42eb79fa499cc, v1.4.0

[tnqn]

@srikartati could you please take a look or assign it to proper developer?

[srikartati]

Hi @dreamtalen, As this issue is very similar to the one you root caused before #2283 (comment)
Could you take a look at what is different in the new testbed that the flexible IPAM feature is using? The test is passing on other CI test beds but failing frequently on the "jenkins-flexible-ipam-e2e" test bed.

[dreamtalen]

Hi @dreamtalen, As this issue is very similar to the one you root caused before #2283 (comment) Could you take a look at what is different in the new testbed that the flexible IPAM feature is using? The test is passing on other CI test beds but failing frequently on the "jenkins-flexible-ipam-e2e" test bed.

Sure, I will take a look.

[dreamtalen]

Update: looks like this failure may cause by a time difference between k8s pod and testbed host.
An example of logs from a failed test running on ipam testbed: http://10.176.27.169:8080/job/antrea-flexible-ipam-e2e-for-pull-request/139/consoleFull

flowaggregator_test.go:788: Flow passed condition with flowStartSeconds 1636070251, flowEndSeconds 1636070259, timeStart 1636070245, srcPort 52804
flowaggregator_test.go:591: 1st Data record with flowStartSeconds 1636070251, flowEndSeconds 1636070255, timeStart 1636070245, totalCount 11998432821
flowaggregator_test.go:591: 2nd Data record with flowStartSeconds 1636070251, flowEndSeconds 1636070259, timeStart 1636070245, totalCount 26157627473
flowaggregator_test.go:591: 3rd Data record with flowStartSeconds 1636070251, flowEndSeconds 1636070263, timeStart 1636070245, totalCount 38674431709

We could see there is a 6 seconds difference between flowStartSeconds and timeStart. However in other testbed, this difference is less than 1 second, like https://jenkins.antrea-ci.rocks/job/antrea-e2e-for-pull-request/3506/consoleFull.
Since our current condition is

antrea/test/e2e/flowaggregator_test.go

Line 779 in 5db792d

if exportTime >= timeStart.Unix()+iperfTimeSec {

In this case, 2nd data record could pass the condition which caused e2e test didn't wait for the 3rd data record.
To solve this issue, we could check the time sync between host and k8s Pod on this testbed, or we could change our condition to use flowStartSeconds instead of timeStart.

[antoninbas]

@dreamtalen it's probably better to write the test in such a way that it doesn't assume time sync between 1) the host running the Go tests and 2) K8s Nodes / Pods.

[srikartati]

Thanks @dreamtalen

we could change our condition to use flowStartSeconds instead of timeStart

I think comparing flowStartSeconds and flowEndSeconds seems like a decent solution for the issue.

[dreamtalen]

Have a fix at #2983 by removing the comparing with host time, triggered test-flexible-ipam-e2e multiple times and no FlowAggregator test failure happened again.