Issue #, if available:
CNI -> NP agent rpc calls are multi threaded and concurrent go routines are running at same time. When multiple pods in the same pod identifier come up at the same time, NP agent is trying to attach progFDs to these pods in multiple go routines. Due to the race condition each pod has different progfds being attached.
Ideally all pods in same pod identifier share progFDs and should have same progFDs attached to them. When we get reconcile request we update only one set of progFD(one for ingress, one for egress) for one pod identifier. If two pods in same pod identifier have different progFDs attached, pods will be in some inconsistent state and network policies will not be applied
Description of changes:
We have this recent change https://github.com/aws/aws-network-policy-agent/pull/322 where we are adding locks to avoid race condition of attaching probes to same pod from two different code paths. Updating that lock from per pod to per pod identifier in current change. This way we will prevent race condition for both the cases - between pods in same pod identifier and for same pod from two different code paths
Testing:
Simulated race condition by adding sleep in the code.
Logs before the fix
{"level":"info","ts":"2024-11-11T18:27:53.632Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:55","msg":"Received Enforce Network Policy Request for Pod","Name":"tester2-55c7c875f-fvc8j","Namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:53.632Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:784","msg":"No map instance found"}
{"level":"info","ts":"2024-11-11T18:27:53.632Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:455","msg":"Got the attachProbesLock for","pod":"tester2-55c7c875f-fvc8j"," in namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:53.632Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:467","msg":"AttacheBPFProbes for","pod":"tester2-55c7c875f-fvc8j"," in namespace":"test3"," with hostVethName":"enib229d24714a"}
{"level":"info","ts":"2024-11-11T18:27:53.632Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:583","msg":"First pod sleeping for 1 sec for second pod to come and repro the race condition"}
{"level":"info","ts":"2024-11-11T18:27:53.716Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:55","msg":"Received Enforce Network Policy Request for Pod","Name":"tester2-55c7c875f-c6b7v","Namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:53.716Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:784","msg":"No map instance found"}
{"level":"info","ts":"2024-11-11T18:27:53.716Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:455","msg":"Got the attachProbesLock for","pod":"tester2-55c7c875f-c6b7v"," in namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:53.716Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:467","msg":"AttacheBPFProbes for","pod":"tester2-55c7c875f-c6b7v"," in namespace":"test3"," with hostVethName":"eni4c74010093c"}
{"level":"info","ts":"2024-11-11T18:27:53.716Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:700","msg":"Load the eBPF program"}
{"level":"info","ts":"2024-11-11T18:27:53.743Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:712","msg":"Prog Info: ","Pin Path: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test3_handle_ingress"}
{"level":"info","ts":"2024-11-11T18:27:53.743Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:716","msg":"PinPath for this pod: ","PinPath: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test3_handle_ingress"}
{"level":"info","ts":"2024-11-11T18:27:53.743Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:719","msg":"Prog Load Succeeded","for ":"ingress","progFD: ":20}
{"level":"info","ts":"2024-11-11T18:27:53.743Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:592","msg":"Attempting to do an Ingress Attach ","with progFD: ":20}
{"level":"info","ts":"2024-11-11T18:27:53.745Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:478","msg":"Successfully attached Ingress TC probe for","pod: ":"tester2-55c7c875f-c6b7v"," in namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:53.745Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:700","msg":"Load the eBPF program"}
{"level":"info","ts":"2024-11-11T18:27:53.770Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:712","msg":"Prog Info: ","Pin Path: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test3_handle_egress"}
{"level":"info","ts":"2024-11-11T18:27:53.770Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:716","msg":"PinPath for this pod: ","PinPath: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test3_handle_egress"}
{"level":"info","ts":"2024-11-11T18:27:53.770Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:719","msg":"Prog Load Succeeded","for ":"egress","progFD: ":26}
{"level":"info","ts":"2024-11-11T18:27:53.770Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:626","msg":"Attempting to do an Egress Attach ","with progFD: ":26}
{"level":"info","ts":"2024-11-11T18:27:53.771Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:493","msg":"Successfully attached Egress TC probe for","pod: ":"tester2-55c7c875f-c6b7v"," in namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:53.771Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:89","msg":"Pod either has no active policies or shares the eBPF firewall maps with otherlocal pods. No Map update required.."}
{"level":"info","ts":"2024-11-11T18:27:54.633Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:700","msg":"Load the eBPF program"}
{"level":"info","ts":"2024-11-11T18:27:54.666Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:712","msg":"Prog Info: ","Pin Path: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test3_handle_ingress"}
{"level":"info","ts":"2024-11-11T18:27:54.666Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:716","msg":"PinPath for this pod: ","PinPath: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test3_handle_ingress"}
{"level":"info","ts":"2024-11-11T18:27:54.666Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:719","msg":"Prog Load Succeeded","for ":"ingress","progFD: ":31}
{"level":"info","ts":"2024-11-11T18:27:54.666Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:592","msg":"Attempting to do an Ingress Attach ","with progFD: ":31}
{"level":"info","ts":"2024-11-11T18:27:54.668Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:478","msg":"Successfully attached Ingress TC probe for","pod: ":"tester2-55c7c875f-fvc8j"," in namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:54.668Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:700","msg":"Load the eBPF program"}
{"level":"info","ts":"2024-11-11T18:27:54.688Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:712","msg":"Prog Info: ","Pin Path: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test3_handle_egress"}
{"level":"info","ts":"2024-11-11T18:27:54.688Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:719","msg":"Prog Load Succeeded","for ":"egress","progFD: ":33}
{"level":"info","ts":"2024-11-11T18:27:54.688Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:626","msg":"Attempting to do an Egress Attach ","with progFD: ":33}
{"level":"info","ts":"2024-11-11T18:27:54.688Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:493","msg":"Successfully attached Egress TC probe for","pod: ":"tester2-55c7c875f-fvc8j"," in namespace":"test3"}
{"level":"info","ts":"2024-11-11T18:27:54.688Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:89","msg":"Pod either has no active policies or shares the eBPF firewall maps with otherlocal pods. No Map update required.."}
Pod1 has progFDs - 20 and 26 attached
Pod2 has progFDs - 31 and 33 attached
Logs after change
{"level":"info","ts":"2024-11-11T19:24:05.938Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:55","msg":"Received Enforce Network Policy Request for Pod","Name":"tester2-55c7c875f-9jtqq","Namespace":"test4"}
{"level":"info","ts":"2024-11-11T19:24:05.938Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:785","msg":"No map instance found"}
{"level":"info","ts":"2024-11-11T19:24:05.938Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:454","msg":"Got the attachProbesLock for","Pod: ":"tester2-55c7c875f-9jtqq"," Namespace:":"test4"," PodIdentifier: ":"tester2-55c7c875f-test4"}
{"level":"info","ts":"2024-11-11T19:24:05.938Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:466","msg":"AttacheBPFProbes for","pod":"tester2-55c7c875f-9jtqq"," in namespace":"test4"," with hostVethName":"eni08caf171186"}
{"level":"info","ts":"2024-11-11T19:24:05.938Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:584","msg":"First pod sleeping for 1 sec for second pod to come and repro the race condition"}
{"level":"info","ts":"2024-11-11T19:24:06.020Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:55","msg":"Received Enforce Network Policy Request for Pod","Name":"tester2-55c7c875f-ngr78","Namespace":"test4"}
{"level":"info","ts":"2024-11-11T19:24:06.020Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:785","msg":"No map instance found"}
{"level":"info","ts":"2024-11-11T19:24:06.939Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:701","msg":"Load the eBPF program"}
{"level":"info","ts":"2024-11-11T19:24:06.956Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:713","msg":"Prog Info: ","Pin Path: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test4_handle_ingress"}
{"level":"info","ts":"2024-11-11T19:24:06.956Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:717","msg":"PinPath for this pod: ","PinPath: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test4_handle_ingress"}
{"level":"info","ts":"2024-11-11T19:24:06.956Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:720","msg":"Prog Load Succeeded","for ":"ingress","progFD: ":20}
{"level":"info","ts":"2024-11-11T19:24:06.956Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:593","msg":"Attempting to do an Ingress Attach ","with progFD: ":20}
{"level":"info","ts":"2024-11-11T19:24:06.958Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:477","msg":"Successfully attached Ingress TC probe for","pod: ":"tester2-55c7c875f-9jtqq"," in namespace":"test4"}
{"level":"info","ts":"2024-11-11T19:24:06.958Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:701","msg":"Load the eBPF program"}
{"level":"info","ts":"2024-11-11T19:24:06.974Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:713","msg":"Prog Info: ","Pin Path: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test4_handle_egress"}
{"level":"info","ts":"2024-11-11T19:24:06.974Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:717","msg":"PinPath for this pod: ","PinPath: ":"/sys/fs/bpf/globals/aws/programs/tester2-55c7c875f-test4_handle_egress"}
{"level":"info","ts":"2024-11-11T19:24:06.974Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:720","msg":"Prog Load Succeeded","for ":"egress","progFD: ":22}
{"level":"info","ts":"2024-11-11T19:24:06.974Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:627","msg":"Attempting to do an Egress Attach ","with progFD: ":22}
{"level":"info","ts":"2024-11-11T19:24:06.975Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:492","msg":"Successfully attached Egress TC probe for","pod: ":"tester2-55c7c875f-9jtqq"," in namespace":"test4"}
{"level":"info","ts":"2024-11-11T19:24:06.975Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:89","msg":"Pod either has no active policies or shares the eBPF firewall maps with otherlocal pods. No Map update required.."}
{"level":"info","ts":"2024-11-11T19:24:06.975Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:454","msg":"Got the attachProbesLock for","Pod: ":"tester2-55c7c875f-ngr78"," Namespace:":"test4"," PodIdentifier: ":"tester2-55c7c875f-test4"}
{"level":"info","ts":"2024-11-11T19:24:06.975Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:466","msg":"AttacheBPFProbes for","pod":"tester2-55c7c875f-ngr78"," in namespace":"test4"," with hostVethName":"enif1d9b4c41a3"}
{"level":"info","ts":"2024-11-11T19:24:06.975Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:578","msg":"Found an existing instance, let's derive the ingress context.."}
{"level":"info","ts":"2024-11-11T19:24:06.975Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:593","msg":"Attempting to do an Ingress Attach ","with progFD: ":20}
{"level":"info","ts":"2024-11-11T19:24:06.977Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:477","msg":"Successfully attached Ingress TC probe for","pod: ":"tester2-55c7c875f-ngr78"," in namespace":"test4"}
{"level":"info","ts":"2024-11-11T19:24:06.977Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:617","msg":"Found an existing instance, let's derive the egress context.."}
{"level":"info","ts":"2024-11-11T19:24:06.977Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:627","msg":"Attempting to do an Egress Attach ","with progFD: ":22}
{"level":"info","ts":"2024-11-11T19:24:06.978Z","logger":"ebpf-client","caller":"ebpf/bpf_client.go:492","msg":"Successfully attached Egress TC probe for","pod: ":"tester2-55c7c875f-ngr78"," in namespace":"test4"}
{"level":"info","ts":"2024-11-11T19:24:06.978Z","logger":"rpc-handler","caller":"rpc/rpc_handler.go:89","msg":"Pod either has no active policies or shares the eBPF firewall maps with otherlocal pods. No Map update required.."}
Both pods have 20 and 22 progFDs attached. We can see the lock acquisition which is making sure that first pod probes are attached and all internal caches are updated before second pod probe attach starts
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.
Issue #, if available: CNI -> NP agent rpc calls are multi threaded and concurrent go routines are running at same time. When multiple pods in the same pod identifier come up at the same time, NP agent is trying to attach progFDs to these pods in multiple go routines. Due to the race condition each pod has different progfds being attached.
Ideally all pods in same pod identifier share progFDs and should have same progFDs attached to them. When we get reconcile request we update only one set of progFD(one for ingress, one for egress) for one pod identifier. If two pods in same pod identifier have different progFDs attached, pods will be in some inconsistent state and network policies will not be applied
Description of changes: We have this recent change https://github.com/aws/aws-network-policy-agent/pull/322 where we are adding locks to avoid race condition of attaching probes to same pod from two different code paths. Updating that lock from per pod to per pod identifier in current change. This way we will prevent race condition for both the cases - between pods in same pod identifier and for same pod from two different code paths
Testing: Simulated race condition by adding sleep in the code. Logs before the fix
Pod1 has progFDs - 20 and 26 attached Pod2 has progFDs - 31 and 33 attached
Logs after change
Both pods have 20 and 22 progFDs attached. We can see the lock acquisition which is making sure that first pod probes are attached and all internal caches are updated before second pod probe attach starts
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.