Add the data path filtering for policy verdict logs.

[lzang]

Generate policy verdict logs only if the endpoint does have a network policy
enforced on the direction of the traffic.

Signed-off-by: Zang Li zangli@google.com

---

This change is 

[maintainer-s-little-helper]

Release note label not set, please set the appropriate release note.

[coveralls]

Coverage decreased (-0.02%) to 45.523% when pulling 300236c on lzang:master into 0b5e263 on cilium:master.

[pchaigno]

test-me-please

[lzang]

test-me-please

[lzang]

test-me-please

[lzang]

test-me-please previous failure https://jenkins.cilium.io/job/Cilium-PR-Ginkgo-Tests-Validated/17796/

[aanm]

test-me-please

[joestringer]

From here:
https://jenkins.cilium.io/job/Cilium-PR-Ginkgo-Tests-Validated/17796
Through here:
https://jenkins.cilium.io/job/Cilium-PR-Ginkgo-Tests-Validated/17796/testReport/junit/Suite-k8s-1/11/K8sDatapathConfig_DirectRouting_Check_direct_connectivity_with_per_endpoint_routes/

Into the zip, into the cilium logs for pod cilium-cllgt, filtering out all level=debug / level=info, I found repeats of this set of complaints:

2020-03-09T02:54:00.2459225Z level=error msg="Command execution failed" cmd="[tc filter replace dev lxc5ea689f5bbdb ingress prio 1 handle 1 bpf da obj 564_next/bpf_lxc.o sec from-container]" error="exit status 1" subsys=datapath-loader
2020-03-09T02:54:00.245943042Z level=warning msg="Log buffer too small to dump verifier log 16777215 bytes (10 tries)!" subsys=datapath-loader
2020-03-09T02:54:00.24595512Z level=warning msg="Error fetching program/map!" subsys=datapath-loader
2020-03-09T02:54:00.245958089Z level=warning msg="Unable to load program" subsys=datapath-loader
2020-03-09T02:54:00.263696359Z level=warning msg="JoinEP: Failed to load program" containerID=70678a65fa datapathPolicyRevision=0 desiredPolicyRevision=1 endpointID=564 error="Failed to load tc filter: exit status 1" file-path=564_next/bpf_lxc.o identity=58084 ipv4=10.10.1.179 ipv6= k8sPodName=default/test-k8s2-8d47f6c76-mpxvg subsys=datapath-loader veth=lxc5ea689f5bbdb
2020-03-09T02:54:00.263715579Z level=error msg="Error while rewriting endpoint BPF program" containerID=70678a65fa datapathPolicyRevision=0 desiredPolicyRevision=1 endpointID=564 error="Failed to load tc filter: exit status 1" identity=58084 ipv4=10.10.1.179 ipv6= k8sPodName=default/test-k8s2-8d47f6c76-mpxvg subsys=endpoint
2020-03-09T02:54:00.264195958Z level=warning msg="generating BPF for endpoint failed, keeping stale directory." containerID=70678a65fa datapathPolicyRevision=0 desiredPolicyRevision=1 endpointID=564 file-path=564_next_fail identity=58084 ipv4=10.10.1.179 ipv6= k8sPodName=default/test-k8s2-8d47f6c76-mpxvg subsys=endpoint
2020-03-09T02:54:00.264422446Z level=warning msg="Regeneration of endpoint failed" bpfCompilation=1.389299726s bpfLoadProg=13.921122438s bpfWaitForELF=1.389554451s bpfWriteELF="211.137µs" buildDuration=15.316466496s containerID=70678a65fa datapathPolicyRevision=0 desiredPolicyRevision=1 endpointID=564 error="Failed to load tc filter: exit status 1" identity=58084 ipv4=10.10.1.179 ipv6= k8sPodName=default/test-k8s2-8d47f6c76-mpxvg mapSync="21.086µs" policyCalculation="162.228µs" prepareBuild="332.159µs" proxyConfiguration="4.986µs" proxyPolicyCalculation="132.499µs" proxyWaitForAck=0s reason="updated security labels" subsys=endpoint waitingForCTClean=2.773349ms waitingForLock=883ns
2020-03-09T02:54:00.264678764Z level=error msg="endpoint regeneration failed" containerID=70678a65fa datapathPolicyRevision=0 desiredPolicyRevision=1 endpointID=564 error="Failed to load tc filter: exit status 1" identity=58084 ipv4=10.10.1.179 ipv6= k8sPodName=default/test-k8s2-8d47f6c76-mpxvg subsys=endpoint

I'm not sure why the Jenkins CI didn't identify any errors/warnings in the logs, but I saw them there.

This particular case I think we've seen before on the net-next kernel image, do you recall the workaround there?

I've filed issue #10517 to track root-cause and upstream fixes for the underlying issue here.

For the other two failures from that link, they look like policy-related CI flakes. Given the timing they may have been resolved by #10493.

At a glance from the latest failures, I see endpoints in not-ready state, and I was able to find evidence of the above "log buffer too small" issue again.

[lzang]

We bypassed the issue earlier by removing all the if else statements in the datapath patch. For this one, we cannot bypass the single check for the filtering operation.

[lzang]

test-me-please

[joestringer]

I filed #10615 for the Travis flake.

[lzang]

test-me-please

[lzang]

Thanks @joestringer ! For the "log buffer too small" issue, it is possible to put in the mitigation with iproute2 to the CI?

[pchaigno]

Thanks @joestringer ! For the "log buffer too small" issue, it is possible to put in the mitigation with iproute2 to the CI?

That wouldn't solve the underlying issue, which is a complexity error in the BPF verifier (we're hitting the limit). As a short term solution, we're hoping #10542 will give us some slack there and allow the currently-blocked PRs to pass.

[lzang]

That wouldn't solve the underlying issue, which is a complexity error in the BPF verifier (we're hitting the limit). As a short term solution, we're hoping #10542 will give us some slack there and allow the currently-blocked PRs to pass.

Yes, I know it doesn't solve the underlying issue, but I think it shouldn't block CI as it will take longer time for the real fix to get in. We can always remove the workaround later. It's great if #10542 can help and unblock CI.

[pchaigno]

Hi @lzang 👋 Could you rebase your pull request against master? #10542 was merged yesterday. It updates the LLVM/Clang version we use and should fix the CI issues you're currently hitting.

[lzang]

test-me-please

[pchaigno]

Neat! The tests are passing 😃

I have a couple small comments below, but we should be okay to merge after that 🎉

[tklauser]

test-me-please