Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CNI fails healthchecks, errors when we run containers #1590

Closed
korotovsky opened this issue Aug 25, 2021 · 15 comments
Closed

CNI fails healthchecks, errors when we run containers #1590

korotovsky opened this issue Aug 25, 2021 · 15 comments
Assignees
Labels
bug stale Issue or PR is stale

Comments

@korotovsky
Copy link

korotovsky commented Aug 25, 2021

Hello, we are experiencing errors in aws cni, in particular from logs I can point out two possible major issues:

  1. Excessive amount of lines about "ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary". It's just does not look right for me, but I could not find an answer or figure out what could be an issue of it.
  2. Another is when in logs appeared lots of messages about DelNetwork related to cron container. These lines also do not look good for me, because exactly when they appear, aws-cni shows failed probe.
==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"debug","ts":"2021-08-25T15:58:52.082Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:58:57.082Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:03.744Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:08.764Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:13.765Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:18.765Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:23.765Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:28.766Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:34.454Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:39.508Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:44.601Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:49.602Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:52.518Z","caller":"ipamd/ipamd.go:557","msg":"Reconciling ENI/IP pool info because time since last 1m2.942069324s <= 1m0s"}
{"level":"debug","ts":"2021-08-25T15:59:53.840Z","caller":"ipamd/ipamd.go:1106","msg":"Total number of interfaces found: 1 "}
{"level":"debug","ts":"2021-08-25T15:59:53.840Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI MAC address: 02:72:23:ac:41:1b"}
{"level":"debug","ts":"2021-08-25T15:59:53.842Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI: eni-0488a0403d6fa7e41, MAC 02:72:23:ac:41:1b, device 0"}
{"level":"debug","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP pool"}
{"level":"info","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1239","msg":"Reconcile and skip primary IP 172.16.2.235 on ENI eni-0488a0403d6fa7e41"}
{"level":"debug","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP prefixes"}
{"level":"debug","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1172","msg":"Found prefix pool count 3 for eni eni-0488a0403d6fa7e41\n"}
{"level":"debug","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.160/28"}
{"level":"info","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.160/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.16/28"}
{"level":"info","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.16/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T15:59:53.844Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.176/28"}
{"level":"info","ts":"2021-08-25T15:59:53.845Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.176/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T15:59:53.845Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T15:59:53.845Z","caller":"ipamd/ipamd.go:557","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2021-08-25T15:59:53.845Z","caller":"ipamd/ipamd.go:557","msg":"IP/Prefix Address Pool stats: total: 48, assigned: 15, total prefixes: 3"}
{"level":"debug","ts":"2021-08-25T15:59:56.345Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T15:59:56.509Z","caller":"awsutils/awsutils.go:1480","msg":"Checking for leaked AWS CNI ENIs."}
{"level":"debug","ts":"2021-08-25T15:59:56.738Z","caller":"ec2/api.go:21868","msg":"EC2 DescribeNetworkInterfaces succeeded with 0 results on page 1"}
{"level":"debug","ts":"2021-08-25T15:59:56.738Z","caller":"awsutils/awsutils.go:1489","msg":"No AWS CNI leaked ENIs found."}
{"level":"debug","ts":"2021-08-25T16:00:01.350Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:06.350Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:11.351Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:16.351Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:21.351Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:26.352Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:31.352Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:36.353Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:41.353Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:46.353Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:51.354Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:00:53.854Z","caller":"ipamd/ipamd.go:557","msg":"Reconciling ENI/IP pool info because time since last 1m1.336181777s <= 1m0s"}
{"level":"debug","ts":"2021-08-25T16:00:53.855Z","caller":"ipamd/ipamd.go:1106","msg":"Total number of interfaces found: 1 "}
{"level":"debug","ts":"2021-08-25T16:00:53.855Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI MAC address: 02:72:23:ac:41:1b"}
{"level":"debug","ts":"2021-08-25T16:00:53.858Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI: eni-0488a0403d6fa7e41, MAC 02:72:23:ac:41:1b, device 0"}
{"level":"debug","ts":"2021-08-25T16:00:53.863Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP pool"}
{"level":"info","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1239","msg":"Reconcile and skip primary IP 172.16.2.235 on ENI eni-0488a0403d6fa7e41"}
{"level":"debug","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP prefixes"}
{"level":"debug","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1172","msg":"Found prefix pool count 3 for eni eni-0488a0403d6fa7e41\n"}
{"level":"debug","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.160/28"}
{"level":"info","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.160/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.16/28"}
{"level":"info","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.16/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.176/28"}
{"level":"info","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.176/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:557","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2021-08-25T16:00:53.864Z","caller":"ipamd/ipamd.go:557","msg":"IP/Prefix Address Pool stats: total: 48, assigned: 15, total prefixes: 3"}
{"level":"debug","ts":"2021-08-25T16:00:56.364Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:01.364Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:06.365Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:11.365Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:16.365Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:21.366Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:26.366Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:31.366Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:36.367Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:41.367Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:46.367Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:51.368Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:53.868Z","caller":"ipamd/ipamd.go:557","msg":"Reconciling ENI/IP pool info because time since last 1m0.014229104s <= 1m0s"}
{"level":"debug","ts":"2021-08-25T16:01:53.869Z","caller":"ipamd/ipamd.go:1106","msg":"Total number of interfaces found: 1 "}
{"level":"debug","ts":"2021-08-25T16:01:53.869Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI MAC address: 02:72:23:ac:41:1b"}
{"level":"debug","ts":"2021-08-25T16:01:53.872Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI: eni-0488a0403d6fa7e41, MAC 02:72:23:ac:41:1b, device 0"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP pool"}
{"level":"info","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1239","msg":"Reconcile and skip primary IP 172.16.2.235 on ENI eni-0488a0403d6fa7e41"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP prefixes"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1172","msg":"Found prefix pool count 3 for eni eni-0488a0403d6fa7e41\n"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.160/28"}
{"level":"info","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.160/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.16/28"}
{"level":"info","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.16/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.176/28"}
{"level":"info","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.176/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:557","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2021-08-25T16:01:53.874Z","caller":"ipamd/ipamd.go:557","msg":"IP/Prefix Address Pool stats: total: 48, assigned: 15, total prefixes: 3"}
{"level":"debug","ts":"2021-08-25T16:01:56.374Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:01.375Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:06.375Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:11.376Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:16.376Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:21.376Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:26.377Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:31.377Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:36.378Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:41.378Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:46.378Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:51.379Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:02:53.879Z","caller":"ipamd/ipamd.go:557","msg":"Reconciling ENI/IP pool info because time since last 1m0.010720268s <= 1m0s"}
{"level":"debug","ts":"2021-08-25T16:02:53.880Z","caller":"ipamd/ipamd.go:1106","msg":"Total number of interfaces found: 1 "}
{"level":"debug","ts":"2021-08-25T16:02:53.880Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI MAC address: 02:72:23:ac:41:1b"}
{"level":"debug","ts":"2021-08-25T16:02:53.882Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI: eni-0488a0403d6fa7e41, MAC 02:72:23:ac:41:1b, device 0"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP pool"}
{"level":"info","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1239","msg":"Reconcile and skip primary IP 172.16.2.235 on ENI eni-0488a0403d6fa7e41"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP prefixes"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1172","msg":"Found prefix pool count 3 for eni eni-0488a0403d6fa7e41\n"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.160/28"}
{"level":"info","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.160/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.16/28"}
{"level":"info","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.16/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.176/28"}
{"level":"info","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.176/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:557","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2021-08-25T16:02:53.884Z","caller":"ipamd/ipamd.go:557","msg":"IP/Prefix Address Pool stats: total: 48, assigned: 15, total prefixes: 3"}
{"level":"debug","ts":"2021-08-25T16:02:56.384Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:01.384Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:06.385Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:11.385Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:16.385Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:21.386Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:26.386Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:31.386Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:36.387Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:41.387Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:03:46.388Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:03:49.556Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a) Netns(/proc/30392/ns/net) IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-03-cron-27165117-mrcpg;K8S_POD_INFRA_CONTAINER_ID=881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"info","ts":"2021-08-25T16:03:49.565Z","caller":"rpc/rpc.pb.go:519","msg":"Received DelNetwork for Sandbox 881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a"}
{"level":"debug","ts":"2021-08-25T16:03:49.565Z","caller":"rpc/rpc.pb.go:519","msg":"DelNetworkRequest: ClientVersion:\"v1.9.0\" K8S_POD_NAME:\"md-conqueror-satellite-pl-03-cron-27165117-mrcpg\" K8S_POD_NAMESPACE:\"staging-md-conqueror-satellite-3674\" K8S_POD_INFRA_CONTAINER_ID:\"881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a\" Reason:\"PodDeleted\" ContainerID:\"881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a\" IfName:\"eth0\" NetworkName:\"aws-cni\" "}
{"level":"debug","ts":"2021-08-25T16:03:49.565Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: IP address pool stats: total:48, assigned 15, sandbox aws-cni/881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a/eth0"}
{"level":"info","ts":"2021-08-25T16:03:49.565Z","caller":"datastore/data_store.go:982","msg":"UnAssignPodIPv4Address: Unassign IP 172.16.2.160 from sandbox aws-cni/881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a/eth0"}
{"level":"info","ts":"2021-08-25T16:03:49.566Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: sandbox aws-cni/881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a/eth0's ipAddr 172.16.2.160, DeviceNumber 0"}
{"level":"info","ts":"2021-08-25T16:03:49.566Z","caller":"rpc/rpc.pb.go:519","msg":"Send DelNetworkReply: IPv4Addr 172.16.2.160, DeviceNumber: 0, err: <nil>"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:03:49.603Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received del network response for pod md-conqueror-satellite-pl-03-cron-27165117-mrcpg namespace staging-md-conqueror-satellite-3674 sandbox 881db247ff8912d789852925501854632162de4d144cf6534dc12a76ce0f0c8a: Success:true IPv4Addr:\"172.16.2.160\" "}
{"level":"debug","ts":"2021-08-25T16:03:49.606Z","caller":"routed-eni-cni-plugin/cni.go:316","msg":"TeardownNS: addr 172.16.2.160/32, deviceNumber 0"}
{"level":"info","ts":"2021-08-25T16:03:49.607Z","caller":"driver/driver.go:421","msg":"Delete toContainer rule for 172.16.2.160/32 "}
{"level":"debug","ts":"2021-08-25T16:03:49.607Z","caller":"driver/driver.go:421","msg":"Tear down of NS complete"}
{"level":"info","ts":"2021-08-25T16:03:49.631Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec) Netns(/proc/30345/ns/net) IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165117-9wsfv;K8S_POD_INFRA_CONTAINER_ID=64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"info","ts":"2021-08-25T16:03:49.633Z","caller":"rpc/rpc.pb.go:519","msg":"Received DelNetwork for Sandbox 64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec"}
{"level":"debug","ts":"2021-08-25T16:03:49.633Z","caller":"rpc/rpc.pb.go:519","msg":"DelNetworkRequest: ClientVersion:\"v1.9.0\" K8S_POD_NAME:\"md-conqueror-satellite-de-04-cron-27165117-9wsfv\" K8S_POD_NAMESPACE:\"staging-md-conqueror-satellite-3674\" K8S_POD_INFRA_CONTAINER_ID:\"64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec\" Reason:\"PodDeleted\" ContainerID:\"64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec\" IfName:\"eth0\" NetworkName:\"aws-cni\" "}
{"level":"debug","ts":"2021-08-25T16:03:49.633Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: IP address pool stats: total:48, assigned 14, sandbox aws-cni/64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec/eth0"}
{"level":"info","ts":"2021-08-25T16:03:49.633Z","caller":"datastore/data_store.go:982","msg":"UnAssignPodIPv4Address: Unassign IP 172.16.2.165 from sandbox aws-cni/64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec/eth0"}
{"level":"info","ts":"2021-08-25T16:03:49.634Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: sandbox aws-cni/64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec/eth0's ipAddr 172.16.2.165, DeviceNumber 0"}
{"level":"info","ts":"2021-08-25T16:03:49.634Z","caller":"rpc/rpc.pb.go:519","msg":"Send DelNetworkReply: IPv4Addr 172.16.2.165, DeviceNumber: 0, err: <nil>"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:03:49.635Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received del network response for pod md-conqueror-satellite-de-04-cron-27165117-9wsfv namespace staging-md-conqueror-satellite-3674 sandbox 64a8f3035030cfaefb3c8e92bbafca4b3532f60122972026b781968fca64ceec: Success:true IPv4Addr:\"172.16.2.165\" "}
{"level":"debug","ts":"2021-08-25T16:03:49.635Z","caller":"routed-eni-cni-plugin/cni.go:316","msg":"TeardownNS: addr 172.16.2.165/32, deviceNumber 0"}
{"level":"info","ts":"2021-08-25T16:03:49.635Z","caller":"driver/driver.go:421","msg":"Delete toContainer rule for 172.16.2.165/32 "}
{"level":"debug","ts":"2021-08-25T16:03:49.635Z","caller":"driver/driver.go:421","msg":"Tear down of NS complete"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"debug","ts":"2021-08-25T16:03:51.388Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:03:51.810Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0) Netns(/proc/30363/ns/net) IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165117-qhf47;K8S_POD_INFRA_CONTAINER_ID=0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"info","ts":"2021-08-25T16:03:51.813Z","caller":"rpc/rpc.pb.go:519","msg":"Received DelNetwork for Sandbox 0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0"}
{"level":"debug","ts":"2021-08-25T16:03:51.813Z","caller":"rpc/rpc.pb.go:519","msg":"DelNetworkRequest: ClientVersion:\"v1.9.0\" K8S_POD_NAME:\"md-conqueror-satellite-pl-01-cron-27165117-qhf47\" K8S_POD_NAMESPACE:\"staging-md-conqueror-satellite-3674\" K8S_POD_INFRA_CONTAINER_ID:\"0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0\" Reason:\"PodDeleted\" ContainerID:\"0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0\" IfName:\"eth0\" NetworkName:\"aws-cni\" "}
{"level":"debug","ts":"2021-08-25T16:03:51.813Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: IP address pool stats: total:48, assigned 13, sandbox aws-cni/0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0/eth0"}
{"level":"info","ts":"2021-08-25T16:03:51.813Z","caller":"datastore/data_store.go:982","msg":"UnAssignPodIPv4Address: Unassign IP 172.16.2.161 from sandbox aws-cni/0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0/eth0"}
{"level":"info","ts":"2021-08-25T16:03:51.813Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: sandbox aws-cni/0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0/eth0's ipAddr 172.16.2.161, DeviceNumber 0"}
{"level":"info","ts":"2021-08-25T16:03:51.813Z","caller":"rpc/rpc.pb.go:519","msg":"Send DelNetworkReply: IPv4Addr 172.16.2.161, DeviceNumber: 0, err: <nil>"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:03:51.814Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received del network response for pod md-conqueror-satellite-pl-01-cron-27165117-qhf47 namespace staging-md-conqueror-satellite-3674 sandbox 0f8601ce311e1c90e4417baaded96f7ef6c4b4ff933a947f73b74d71a8399fb0: Success:true IPv4Addr:\"172.16.2.161\" "}
{"level":"debug","ts":"2021-08-25T16:03:51.814Z","caller":"routed-eni-cni-plugin/cni.go:316","msg":"TeardownNS: addr 172.16.2.161/32, deviceNumber 0"}
{"level":"info","ts":"2021-08-25T16:03:51.814Z","caller":"driver/driver.go:421","msg":"Delete toContainer rule for 172.16.2.161/32 "}
{"level":"debug","ts":"2021-08-25T16:03:51.814Z","caller":"driver/driver.go:421","msg":"Tear down of NS complete"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"debug","ts":"2021-08-25T16:03:53.888Z","caller":"ipamd/ipamd.go:557","msg":"Reconciling ENI/IP pool info because time since last 1m0.009301766s <= 1m0s"}
{"level":"debug","ts":"2021-08-25T16:03:53.889Z","caller":"ipamd/ipamd.go:1106","msg":"Total number of interfaces found: 1 "}
{"level":"debug","ts":"2021-08-25T16:03:53.889Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI MAC address: 02:72:23:ac:41:1b"}
{"level":"debug","ts":"2021-08-25T16:03:53.891Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI: eni-0488a0403d6fa7e41, MAC 02:72:23:ac:41:1b, device 0"}
{"level":"debug","ts":"2021-08-25T16:03:53.893Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP pool"}
{"level":"info","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1239","msg":"Reconcile and skip primary IP 172.16.2.235 on ENI eni-0488a0403d6fa7e41"}
{"level":"debug","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP prefixes"}
{"level":"debug","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1172","msg":"Found prefix pool count 3 for eni eni-0488a0403d6fa7e41\n"}
{"level":"debug","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.160/28"}
{"level":"info","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.160/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.16/28"}
{"level":"info","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.16/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:03:53.894Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.176/28"}
{"level":"info","ts":"2021-08-25T16:03:53.895Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.176/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:03:53.895Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:03:53.895Z","caller":"ipamd/ipamd.go:557","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2021-08-25T16:03:53.895Z","caller":"ipamd/ipamd.go:557","msg":"IP/Prefix Address Pool stats: total: 48, assigned: 12, total prefixes: 3"}
{"level":"debug","ts":"2021-08-25T16:03:56.395Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:01.541Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:06.541Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:11.542Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:16.766Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
^[[1;2D{"level":"debug","ts":"2021-08-25T16:04:21.766Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:26.855Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:31.861Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:36.861Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:42.019Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:47.019Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:52.020Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:04:54.520Z","caller":"ipamd/ipamd.go:557","msg":"Reconciling ENI/IP pool info because time since last 1m0.63172729s <= 1m0s"}
{"level":"debug","ts":"2021-08-25T16:04:54.539Z","caller":"ipamd/ipamd.go:1106","msg":"Total number of interfaces found: 1 "}
{"level":"debug","ts":"2021-08-25T16:04:54.539Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI MAC address: 02:72:23:ac:41:1b"}
{"level":"debug","ts":"2021-08-25T16:04:54.542Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI: eni-0488a0403d6fa7e41, MAC 02:72:23:ac:41:1b, device 0"}
{"level":"debug","ts":"2021-08-25T16:04:54.544Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP pool"}
{"level":"info","ts":"2021-08-25T16:04:54.544Z","caller":"ipamd/ipamd.go:1239","msg":"Reconcile and skip primary IP 172.16.2.235 on ENI eni-0488a0403d6fa7e41"}
{"level":"debug","ts":"2021-08-25T16:04:54.544Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP prefixes"}
{"level":"debug","ts":"2021-08-25T16:04:54.544Z","caller":"ipamd/ipamd.go:1172","msg":"Found prefix pool count 3 for eni eni-0488a0403d6fa7e41\n"}
{"level":"debug","ts":"2021-08-25T16:04:54.544Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.160/28"}
{"level":"info","ts":"2021-08-25T16:04:54.544Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.160/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:04:54.544Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.16/28"}
{"level":"info","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.16/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.176/28"}
{"level":"info","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.176/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:557","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2021-08-25T16:04:54.545Z","caller":"ipamd/ipamd.go:557","msg":"IP/Prefix Address Pool stats: total: 48, assigned: 12, total prefixes: 3"}
{"level":"debug","ts":"2021-08-25T16:04:57.045Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:02.239Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:07.239Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:12.239Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:17.240Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:22.692Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:27.739Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:32.740Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:37.740Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:42.740Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:47.741Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:53.319Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:05:55.819Z","caller":"ipamd/ipamd.go:557","msg":"Reconciling ENI/IP pool info because time since last 1m1.298845694s <= 1m0s"}
{"level":"debug","ts":"2021-08-25T16:05:55.820Z","caller":"ipamd/ipamd.go:1106","msg":"Total number of interfaces found: 1 "}
{"level":"debug","ts":"2021-08-25T16:05:55.820Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI MAC address: 02:72:23:ac:41:1b"}
{"level":"debug","ts":"2021-08-25T16:05:55.822Z","caller":"awsutils/awsutils.go:539","msg":"Found ENI: eni-0488a0403d6fa7e41, MAC 02:72:23:ac:41:1b, device 0"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP pool"}
{"level":"info","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1239","msg":"Reconcile and skip primary IP 172.16.2.235 on ENI eni-0488a0403d6fa7e41"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:557","msg":"Reconcile existing ENI eni-0488a0403d6fa7e41 IP prefixes"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1172","msg":"Found prefix pool count 3 for eni eni-0488a0403d6fa7e41\n"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.160/28"}
{"level":"info","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.160/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.16/28"}
{"level":"info","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.16/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1281","msg":"Check in coolddown Found prefix 172.16.2.176/28"}
{"level":"info","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1435","msg":"Adding 172.16.2.176/28 to DS for eni-0488a0403d6fa7e41"}
{"level":"info","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:1435","msg":"IP already in DS"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:557","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2021-08-25T16:05:55.826Z","caller":"ipamd/ipamd.go:557","msg":"IP/Prefix Address Pool stats: total: 48, assigned: 12, total prefixes: 3"}
{"level":"debug","ts":"2021-08-25T16:05:58.326Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:06:00.488Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165114-cj56n;K8S_POD_INFRA_CONTAINER_ID=ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"info","ts":"2021-08-25T16:06:00.490Z","caller":"rpc/rpc.pb.go:519","msg":"Received DelNetwork for Sandbox ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48"}
{"level":"debug","ts":"2021-08-25T16:06:00.490Z","caller":"rpc/rpc.pb.go:519","msg":"DelNetworkRequest: ClientVersion:\"v1.9.0\" K8S_POD_NAME:\"md-conqueror-satellite-de-04-cron-27165114-cj56n\" K8S_POD_NAMESPACE:\"staging-md-conqueror-satellite-3674\" K8S_POD_INFRA_CONTAINER_ID:\"ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48\" Reason:\"PodDeleted\" ContainerID:\"ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48\" IfName:\"eth0\" NetworkName:\"aws-cni\" "}
{"level":"debug","ts":"2021-08-25T16:06:00.490Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: IP address pool stats: total:48, assigned 12, sandbox aws-cni/ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48/eth0"}
{"level":"debug","ts":"2021-08-25T16:06:00.490Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: Failed to find IPAM entry under full key, trying CRI-migrated version"}
{"level":"warn","ts":"2021-08-25T16:06:00.490Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: Failed to find sandbox _migrated-from-cri/ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48/unknown"}
{"level":"info","ts":"2021-08-25T16:06:00.490Z","caller":"rpc/rpc.pb.go:519","msg":"Send DelNetworkReply: IPv4Addr , DeviceNumber: 0, err: datastore: unknown pod"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:06:00.490Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Container ac45ad5d2891cde20800cec3deffff73bb548dfabe12933f0d2e164505ca0a48 not found"}
{"level":"info","ts":"2021-08-25T16:06:02.036Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165114-ptrt4;K8S_POD_INFRA_CONTAINER_ID=26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"info","ts":"2021-08-25T16:06:02.040Z","caller":"rpc/rpc.pb.go:519","msg":"Received DelNetwork for Sandbox 26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86"}
{"level":"debug","ts":"2021-08-25T16:06:02.041Z","caller":"rpc/rpc.pb.go:519","msg":"DelNetworkRequest: ClientVersion:\"v1.9.0\" K8S_POD_NAME:\"md-conqueror-satellite-pl-01-cron-27165114-ptrt4\" K8S_POD_NAMESPACE:\"staging-md-conqueror-satellite-3674\" K8S_POD_INFRA_CONTAINER_ID:\"26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86\" Reason:\"PodDeleted\" ContainerID:\"26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86\" IfName:\"eth0\" NetworkName:\"aws-cni\" "}
{"level":"debug","ts":"2021-08-25T16:06:02.041Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: IP address pool stats: total:48, assigned 12, sandbox aws-cni/26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86/eth0"}
{"level":"debug","ts":"2021-08-25T16:06:02.041Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: Failed to find IPAM entry under full key, trying CRI-migrated version"}
{"level":"warn","ts":"2021-08-25T16:06:02.041Z","caller":"ipamd/rpc_handler.go:204","msg":"UnassignPodIPv4Address: Failed to find sandbox _migrated-from-cri/26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86/unknown"}
{"level":"info","ts":"2021-08-25T16:06:02.041Z","caller":"rpc/rpc.pb.go:519","msg":"Send DelNetworkReply: IPv4Addr , DeviceNumber: 0, err: datastore: unknown pod"}

==> /var/log/aws-routed-eni/plugin.log <==
{"level":"info","ts":"2021-08-25T16:06:02.041Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Container 26da684891b29d95b2e2094b602b8dbed0368528267ee48c072db5450c035c86 not found"}

==> /var/log/aws-routed-eni/ipamd.log <==
{"level":"debug","ts":"2021-08-25T16:06:03.327Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:06:08.327Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:06:13.327Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:06:18.328Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:06:23.328Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:06:28.329Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:06:33.329Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:06:38.329Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}

At some point it ended up with this:

{"level":"info","ts":"2021-08-25T16:57:31.011Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:31.012Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:31.027Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:31.027Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:31.055Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:31.056Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:51.239Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:51.240Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:51.504Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:51.508Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:51.524Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-03-cron-27165168-pbzkb;K8S_POD_INFRA_CONTAINER_ID=fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"info","ts":"2021-08-25T16:57:51.524Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:51.525Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"error","ts":"2021-08-25T16:57:51.527Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:51.578Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:51.581Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:52.628Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=redis-master-0;K8S_POD_INFRA_CONTAINER_ID=b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:52.632Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:52.634Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"info","ts":"2021-08-25T16:57:52.639Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:52.640Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"error","ts":"2021-08-25T16:57:52.641Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:52.655Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:52.657Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:52.675Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-03-cron-27165168-pbzkb;K8S_POD_INFRA_CONTAINER_ID=fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:52.676Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:52.700Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:52.701Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:53.700Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"info","ts":"2021-08-25T16:57:53.700Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=redis-master-0;K8S_POD_INFRA_CONTAINER_ID=b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:53.701Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"error","ts":"2021-08-25T16:57:53.702Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:57:53.737Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:57:53.739Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:06.041Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:06.046Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:06.086Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:06.087Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:07.025Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=redis-master-0;K8S_POD_INFRA_CONTAINER_ID=b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:07.025Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:07.040Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-03-cron-27165168-pbzkb;K8S_POD_INFRA_CONTAINER_ID=fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:07.040Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:08.038Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:08.039Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:09.022Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:09.028Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:17.023Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:17.024Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:17.042Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:17.043Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:18.032Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-03-cron-27165168-pbzkb;K8S_POD_INFRA_CONTAINER_ID=fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:18.033Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:20.035Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=redis-master-0;K8S_POD_INFRA_CONTAINER_ID=b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:20.036Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:21.022Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:21.023Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:24.063Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:24.064Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:30.025Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:30.027Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:30.047Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:30.048Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:31.021Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-03-cron-27165168-pbzkb;K8S_POD_INFRA_CONTAINER_ID=fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:31.022Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container fc57e7b3edc3ca8ea781a82d4fc8fb7dc6649375d40ad03f2afaea54644011b1: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:31.409Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:31.410Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:31.431Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:31.431Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:31.448Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:31.449Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:32.049Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=redis-master-0;K8S_POD_INFRA_CONTAINER_ID=b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:32.052Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container b85a01e25479f7c87024a621ed5d05c56780c37886fe47e841f58e6a7b0da527: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:35.023Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-06-cron-27165168-gsrhn;K8S_POD_INFRA_CONTAINER_ID=ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:35.024Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container ababd76e130b87035c175523e56450ae3c94041e4da404abe3235099e903b51d: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:36.032Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-pl-01-cron-27165168-2lz2v;K8S_POD_INFRA_CONTAINER_ID=9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:36.033Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 9c864709df2b73c732fc802ce25dc9ba842acd0d8a488419a0307524d8ce70af: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:41.021Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:41.022Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 4366d3c749d810b9019857b5447f8e70aed04a540caa61ac120824a771f07251: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}
{"level":"info","ts":"2021-08-25T16:58:41.037Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Received CNI del request: ContainerID(8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Netns() IfName(eth0) Args(IgnoreUnknown=1;K8S_POD_NAMESPACE=staging-md-conqueror-satellite-3674;K8S_POD_NAME=md-conqueror-satellite-de-04-cron-27165168-cpqr5;K8S_POD_INFRA_CONTAINER_ID=8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3) Path(/opt/cni/bin) argsStdinData({\"cniVersion\":\"0.3.1\",\"mtu\":\"9001\",\"name\":\"aws-cni\",\"pluginLogFile\":\"/var/log/aws-routed-eni/plugin.log\",\"pluginLogLevel\":\"DEBUG\",\"type\":\"aws-cni\",\"vethPrefix\":\"eni\"})"}
{"level":"error","ts":"2021-08-25T16:58:41.038Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Error received from DelNetwork gRPC call for container 8b50bfe22b52bbce96f409be1affe436828b7f31181274de3c143772912bf6c3: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused\""}

What you expected to happen:
Passing probes, normal operation.

How to reproduce it (as minimally and precisely as possible):
I'm afraid I could not provide any

Anything else we need to know?:
We are running CronJobs every minute and I had an idea that it could be an issue? Maybe we should adjust some settings of CNI for such utilization?

Environment:

  • Kubernetes version (use kubectl version):
Client Version: version.Info{Major:"1", Minor:"21", GitVersion:"v1.21.1", GitCommit:"5e58841cce77d4bc13713ad2b91fa0d961e69192", GitTreeState:"clean", BuildDate:"2021-05-12T14:18:45Z", GoVersion:"go1.16.4", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"21+", GitVersion:"v1.21.2-eks-0389ca3", GitCommit:"8a4e27b9d88142bbdd21b997b532eb6d493df6d2", GitTreeState:"clean", BuildDate:"2021-07-31T01:34:46Z", GoVersion:"go1.16.5", Compiler:"gc", Platform:"linux/amd64"}
  • CNI Version v1.9.0-eksbuild.1
  • OS (e.g: cat /etc/os-release):
- NAME="Amazon Linux"
VERSION="2"
ID="amzn"
ID_LIKE="centos rhel fedora"
VERSION_ID="2"
PRETTY_NAME="Amazon Linux 2"
ANSI_COLOR="0;33"
CPE_NAME="cpe:2.3:o:amazon:amazon_linux:2"
HOME_URL="https://amazonlinux.com/"
  • Kernel (e.g. uname -a):
Linux ip-172-16-2-235.eu-west-1.compute.internal 5.4.129-63.229.amzn2.x86_64 #1 SMP Tue Jul 20 21:22:08 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
@korotovsky korotovsky added the bug label Aug 25, 2021
@jayanthvn
Copy link
Contributor

Hi @korotovsky

Regarding [1], the primary ENI log you are seeing is because of reconciler which runs every 5 seconds -

func (c *IPAMContext) StartNodeIPPoolManager() {
. This is expected debug log.

{"level":"debug","ts":"2021-08-25T16:00:56.364Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:01.364Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:06.365Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot be deleted because it is primary"}
{"level":"debug","ts":"2021-08-25T16:01:11.365Z","caller":"ipamd/ipamd.go:1063","msg":"ENI eni-0488a0403d6fa7e41 cannot 

Reg [2], I see you are using k8s 1.21, can you please check if you are having this issue- #1425 (comment). This would need timeoutSeconds of the aws-node livenessProbe to be set to 5s.

@korotovsky
Copy link
Author

korotovsky commented Aug 25, 2021

@jacksontj Thanks for the hint, I'll try it, I also noticed in the logs the following:

{"level":"info","ts":"2021-08-25T17:06:33.921Z","caller":"routed-eni-cni-plugin/cni.go:240","msg":"Container 1818da407ab708f7e17ba3fef0e731088bd782f1e2acc5a5c849d35a36f3eeec not found"}

This goes in combination with these errors about net deletion/etc related to cron container. And I'm wondering, what if setting probes timeout will just "mask" the real issue? Maybe the container that CNI expects to see in cache/etc should not be deleted so early?

I mean, what if somehow keeping the cronjob that has been executed and its container a bit longer would help? I did not try just curious to fact check this and maybe if would be helpful for others too in similar scenarios

UPDATE: I'm pretty sure there are high chances to reproduce similar error if you create ~4-5 CronJobs with interval every minute that does its job fairly fast to be ready to next run.

@jayanthvn
Copy link
Contributor

Because of the timeout aws-node will restart, CNI is unable to process kubelet requests because CNI is not able to connect to IPAMD and errors out. Kubelet will retry until the operation is successful. Without aws-node restarting/timeout if the issue happens then it might be IPAMD issue but here it looks like it is expected. Is it possible to increase the timeout and verify or if possible to try on any older k8s cluster (1.16 or 1.17) with CNI 1.9 and try similar cronjobs?

transport: Error while dialing dial tcp 127.0.0.1:50051: connect: connection refused

Until CNI sends a del call to IPAMD, local cache of IPAMD won't be cleaned up.

@korotovsky
Copy link
Author

@jayanthvn I see, okay I increased the timeouts at the moment and will observe with enabled cronjobs. Unfortunately I'm now a bit limited in time because I spent so much time on the investigation of the issue already and I could not try it out with older versions, I'm sorry!

I'll keep this issue updated about the results after applying increased timeouts, thanks for your help.

@jayanthvn
Copy link
Contributor

@korotovsky no problem, I understand. Thanks so much for the deep dive :)

@korotovsky
Copy link
Author

korotovsky commented Aug 26, 2021

@jayanthvn Yesterday honestly I could not manage it and did rollback to eks 1.19 + cni 1.9 too but there were same errors, then I installed cni 1.8 and so far it works stable on eks 1.19.

Maybe later I'll try upgrade to eks 1.21 with cni 1.8, but it seems that in my workload cni 1.9 is buggy a bit even with increased timeouts.

@jayanthvn
Copy link
Contributor

@korotovsky Thanks for trying. I will also try repro - [~4-5 CronJobs with interval every minute].

Next time when you hit the issue, will you please be able to share me the logs from one of the nodes which has the issue. To collect the logs you can run this script on the node - sudo bash /opt/cni/bin/aws-cni-support.sh

@korotovsky
Copy link
Author

@jayanthvn I tried this script when I came to create this issue and checked what was gathered, then realized that there was a bit too much sensitive data collected, e.g. commands for sidecars and so on, container names from private ecr/etc, we don't really want to share it publicly. Is there any way to share these logs privately?

Meanwhile I also found slight confirmation of my theory about CronJobs:

Do you happen to run Kubernetes cron jobs with a frequent cadence (e.g. minutes) on such failing nodes?
https://serverfault.com/questions/943075/container-runtime-kubelet-failures-on-eks-cluster-nodes#comment1225869_943075

When I said yesterday that my workload worked "stable" it was one deployed app with one CronJob every minute. Today I made other things much stable and deployed rest 5 and overall got workload of 6 pretty similar apps each has one CronJob so I started to receive "context deadline exceeded" errors (However aws-cni did not report any health-check errors) on new deployments and some I even could not completely deploy.

My plan is the following:

  1. Deploy these 6 apps at the same time but without cronjobs enabled and observe a little;
  2. If 1. okay then upgrade eks to 1.21 and observe further;
  3. if 2. okay then upgrade aws-cni to 1.9 and observe further;

So far I'm pretty sure issues are coming from excessive cronjobs run with short interval.

Here is my "simplified" CronJob, feel free to try it out with your own container:

apiVersion: batch/v1beta1
kind: CronJob
metadata:
    name: cron-cni
spec:
    schedule: "* * * * *"
    failedJobsHistoryLimit: 0
    startingDeadlineSeconds: 120
    suspend: false
    concurrencyPolicy: Forbid
    jobTemplate:
        spec:
            template:
                spec:
                    containers:
                        - image: "ubuntu"
                          name: cron
                          command:
                              - "sh"
                              - "-c"
                              - >
                                  echo "OK"
                          imagePullPolicy: IfNotPresent
                    restartPolicy: Never

@jayanthvn
Copy link
Contributor

@korotovsky Sorry missed sharing my email id, you can send it to varavaj@amazon.com. This is great thanks for all the info. I will try this cron job locally.

@jayanthvn
Copy link
Contributor

@korotovsky - sorry for the delay. I haven't received the logs. Can you please run this script - sudo bash /opt/cni/bin/aws-cni-support.sh and email it to us?

@s7an-it
Copy link

s7an-it commented Feb 4, 2022

I am trying to reproduce a bug where pods end up in init state because aws-node gets into a loop due to "caller":"entrypoint.sh","msg":"Retrying waiting for IPAM-D"}.
My setup is eks 1.20.7 / 1.7.5 or 1.10.1, eventually on latest AMI/1.10.1 I just did force wrong image and waited for server side job to amend configuration, it looks like while aws-node was down for like 8 min I finally managed to bug few of the pods.
Now I write it here I did run on the node what @jayanthvn usually suggests, I got in logs:
{"level":"info","ts":"2022-02-04T17:02:32.089Z","caller":"ipamd/ipamd.go:1539","msg":"Adding 10.230.1.89/32 to DS for eni-0d2fa14c4bf7bc55b"}
{"level":"info","ts":"2022-02-04T17:02:32.089Z","caller":"ipamd/ipamd.go:1539","msg":"IP already in DS"}
{"level":"debug","ts":"2022-02-04T17:02:32.089Z","caller":"ipamd/ipamd.go:646","msg":"Reconcile existing ENI eni-0d2fa14c4bf7bc55b IP prefixes"}
{"level":"debug","ts":"2022-02-04T17:02:32.089Z","caller":"ipamd/ipamd.go:1347","msg":"Found prefix pool count 0 for eni eni-0d2fa14c4bf7bc55b\n"}
{"level":"debug","ts":"2022-02-04T17:02:32.089Z","caller":"ipamd/ipamd.go:646","msg":"Successfully Reconciled ENI/IP pool"}
{"level":"debug","ts":"2022-02-04T17:02:32.089Z","caller":"ipamd/ipamd.go:646","msg":"IP/Prefix Address Pool stats: total: 42, assigned: 26, cooldownIPs: 0, total prefixes: 0"}
From what I see it goes into reconciling eni loop.

@s7an-it
Copy link

s7an-it commented Feb 4, 2022

Update reboots and restart of kubelet didnt help.
When I checked eni on node I had 3 primary and 2 extra, I detached 2 extra and after they disapper node fixed.
I guess these are shared eni or I don't undertsand what happened here, but I saw another node got fixed by it however both don't have these 2 anymore only 1 I guess this is bad so I guess logically even if all schedules I will get less ips now so I need to terminate?

@s7an-it
Copy link

s7an-it commented Feb 4, 2022

Update 3: while terminate fixed the issue I got 1 primary + extra eni after terminate I did only terminte single node but fixed all 3 failing. Dos it means the were in somekind of shared group or something? Aside from that this looks like an issue to release ips or something related to eni release and reconsile, probaby if I release ips and let it refill them I might not even need to terminate? Ultimately the postive thing I can schedule extra node and then move all traffic pods that already work with no downtime and only terminate that one taht is already suffering init loop.

@github-actions
Copy link

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days

@github-actions github-actions bot added the stale Issue or PR is stale label Apr 16, 2022
@github-actions
Copy link

Issue closed due to inactivity.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug stale Issue or PR is stale
Projects
None yet
Development

No branches or pull requests

4 participants