Is this a request for help?:
Yes
Is this an ISSUE or FEATURE REQUEST? (choose one):
Issue
Which release version?:
1.0.4
Which component (CNI/IPAM/CNM/CNS):
Which Operating System (Linux/Windows):
For Linux: Include Distro and kernel version using "uname -a"
For windows: provide output of "$(Get-ItemProperty -Path "C:\windows\system32\hal.dll").VersionInfo.FileVersion"
Which Orchestrator and version (e.g. Kubernetes, Docker)
Kubernetes
AKS customer's CNI Azure plugin fails to assign IP address for pods
this is where we fail :
// Call into IPAM plugin to allocate an address for the endpoint.
nwCfg.Ipam.Subnet = subnetPrefix
result, err = plugin.DelegateAdd(nwCfg.Ipam.Type, nwCfg)
if err != nil {
err = plugin.Errorf("Failed to allocate address: %v", err)
return err
}
KUBELET_CONFIG=--address=0.0.0.0 --allow-privileged=true --anonymous-auth=false --authorization-mode=Webhook --azure-container-registry-config=/etc/kubernetes/azure.json --cadvisor-port=0 --cgroups-per-qos=true --client-ca-file=/etc/kubernetes/certs/ca.crt --cloud-config=/etc/kubernetes/azure.json --cloud-provider=azure --cluster-dns=10.129.128.4 --cluster-domain=cluster.local --enforce-node-allocatable=pods --event-qps=0 --eviction-hard=memory.available<100Mi,nodefs.available<10%,nodefs.inodesFree<5% --feature-gates= --image-gc-high-threshold=85 --image-gc-low-threshold=80 --image-pull-progress-deadline=30m --keep-terminated-pod-volumes=false --kubeconfig=/var/lib/kubelet/kubeconfig --max-pods=30 --network-plugin=cni --node-status-update-frequency=10s --non-masquerade-cidr=10.128.16.0/20 --pod-infra-container-image=k8s-gcrio.azureedge.net/pause-amd64:3.1 --pod-manifest-path=/etc/kubernetes/manifests
KUBELET_IMAGE=k8s-gcrio.azureedge.net/hyperkube-amd64:v1.9.6
KUBELET_REGISTER_SCHEDULABLE=true
KUBELET_NODE_LABELS=kubernetes.io/role=agent,agentpool=agentpool,storageprofile=managed,storagetier=Premium_LRS,kubernetes.azure.com/cluster=MC_nexus-sandbox-dev-rg_nexus-sandbox-dev-cluster_westeurope
oot@aks-agentpool-66686873-8:/etc/cni/net.d# cat 10-azure.conflist
{
"cniVersion":"0.3.0",
"name":"azure",
"plugins":[
{
"type":"azure-vnet",
"mode":"bridge",
"bridge":"azure0",
"ipam":{
"type":"azure-vnet-ipam"
}
},
{
"type":"portmap",
"capabilities":{
"portMappings":true
},
"snat":true
}
]
AKS Customer cannot deploy pods becouse cni plugin is crashing :
rpc error: code = Unknown desc = NetworkPlugin cni failed to set up pod "nas-publish-1530001800-c4fsz_nexus-dev" network: netplugin failed but error parsing its diagnostic message "": unexpected end of JSON input
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: E0626 08:31:00.012250 16604 kuberuntime_manager.go:647] createPodSandbox for pod "nas-publish-1530001800-c4fsz_nexus-dev(1e2ff9eb-791b-11e8-8c9a-d6939f04c1f3)" failed: rpc error: code = Unknown desc = NetworkPlugin cni failed to set up pod "nas-publish-1530001800-c4fsz_nexus-dev" network: netplugin failed but error parsing its diagnostic message "": unexpected end of JSON input
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: E0626 08:31:00.012849 16604 pod_workers.go:186] Error syncing pod 1e2ff9eb-791b-11e8-8c9a-d6939f04c1f3 ("nas-publish-1530001800-c4fsz_nexus-dev(1e2ff9eb-791b-11e8-8c9a-d6939f04c1f3)"), skipping: failed to "CreatePodSandbox" for "nas-publish-1530001800-c4fsz_nexus-dev(1e2ff9eb-791b-11e8-8c9a-d6939f04c1f3)" with CreatePodSandboxError: "CreatePodSandbox for pod "nas-publish-1530001800-c4fsz_nexus-dev(1e2ff9eb-791b-11e8-8c9a-d6939f04c1f3)" failed: rpc error: code = Unknown desc = NetworkPlugin cni failed to set up pod "nas-publish-1530001800-c4fsz_nexus-dev" network: netplugin failed but error parsing its diagnostic message "": unexpected end of JSON input"
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: 2018/06/26 08:31:00 Going to send Telemetry report to hostnetagent http://169.254.169.254/machine/plugins?comp=netagent&type=cnireport
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: 2018/06/26 08:31:00 "Start Flag false CniSucceeded false Name CNI Version v1.0.4-1-gf0f090e ErrorMessage runtime error: invalid memory address or nil pointer dereference; goroutine 1 [running]:
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/Azure/azure-container-networking/cni.(*Plugin).Execute.func1(0xc420211ec0)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/Azure/azure-container-networking/cni/plugin.go:94 +0xbc
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: panic(0x69b3c0, 0x83ed90)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /usr/local/go/src/runtime/panic.go:489 +0x2cf
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/Azure/azure-container-networking/cni/network.(*netPlugin).Add.func1(0xc420211910, 0xc4201f2850, 0xc4202118d0, 0xc4202118f0, 0xc4200c09c0)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/Azure/azure-container-networking/cni/network/network.go:150 +0x9f
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/Azure/azure-container-networking/cni/network.(*netPlugin).Add(0xc4200c09c0, 0xc4201f2850, 0x818c20, 0xc4201007e0)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/Azure/azure-container-networking/cni/network/network.go:285 +0x13b7
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/Azure/azure-container-networking/cni.(PluginApi).Add-fm(0xc4201f2850, 0xc420187fd6, 0x5)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/Azure/azure-container-networking/cni/plugin.go:112 +0x39
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/containernetworking/cni/pkg/skel.(*dispatcher).checkVersionAndCall(0xc420177000, 0xc4201f2850, 0x81b220, 0xc4200ed680, 0xc420211e80, 0x0, 0xc420102040)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/containernetworking/cni/pkg/skel/skel.go:168 +0x19f
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/containernetworking/cni/pkg/skel.(*dispatcher).pluginMain(0xc420177000, 0xc420211e80, 0xc420211e68, 0x81b220, 0xc4200ed680, 0xc420211e38)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/containernetworking/cni/pkg/skel/skel.go:199 +0x384
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/containernetworking/cni/pkg/skel.PluginMainWithError(0xc420211e80, 0xc420211e68, 0x81b220, 0xc4200ed680, 0xc4200ed680)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/containernetworking/cni/pkg/skel/skel.go:236 +0xed
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/Azure/azure-container-networking/cni.(*Plugin).Execute(0xc42000e080, 0x81b0e0, 0xc4200c09c0, 0x0, 0x0)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/Azure/azure-container-networking/cni/plugin.go:112 +0x127
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: main.main()
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/Azure/azure-container-networking/cni/network/plugin/main.go:93 +0x4d4
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: vnet []
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: Context AzureCNI SubContext "
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: 2018/06/26 08:31:00 OrchestratorDetails &{Kubernetes v1.9.6
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: }
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: 2018/06/26 08:31:00 OSDetails &{linux 16.04.4 4.13.0-1018-azure Ubuntu }
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: 2018/06/26 08:31:00 SystemDetails &{32147 12944 0 29715 14942 4 }
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: 2018/06/26 08:31:00 InterfaceDetails &{ 0 0 xml decode failed due to expected element type but have }
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: 2018/06/26 08:31:00 BridgeDetails
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: E0626 08:31:00.217683 16604 cni.go:259] Error adding network: runtime error: invalid memory address or nil pointer dereference; goroutine 1 [running]:
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/Azure/azure-container-networking/cni.(*Plugin).Execute.func1(0xc420211ec0)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /go/src/github.com/Azure/azure-container-networking/cni/plugin.go:94 +0xbc
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: panic(0x69b3c0, 0x83ed90)
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: /usr/local/go/src/runtime/panic.go:489 +0x2cf
Jun 26 08:31:00 aks-agentpool-66686873-8 kubelet[16604]: github.com/Azure/azure-container-networking/cni/network.(*netPlugin).Add.func1(0xc420211910
vnet log :
2018/06/26 09:31:36 [cni-net] Processing ADD command with args {ContainerID:cb38e2330422821950138d84dc16ca355412b724fbfa492deabed9d81524f051 Netns:/proc/29051/ns/net IfName:eth0 Args:IgnoreUnknown=1;K8S_POD_NAMESPACE=nexus-dev;K8S_POD_NAME=nexus-ui-db5c9656d-9t2ps;K8S_POD_INFRA_CONTAINER_ID=cb38e2330422821950138d84dc16ca355412b724fbfa492deabed9d81524f051 Path:/opt/azure-vnet/bin:/opt/cni/bin}.
2018/06/26 09:31:36 [cni-net] Read network configuration &{CNIVersion:0.3.0 Name:azure Type:azure-vnet Mode:bridge Master: Bridge:azure0 LogLevel: LogTarget: Ipam:{Type:azure-vnet-ipam Environment: AddrSpace: Subnet: Address: QueryInterval:} DNS:{Nameservers:[] Domain: Search:[] Options:[]} AdditionalArgs:[]}.
2018/06/26 09:31:36 [cni-net] Found network azure with subnet 10.128.16.0/20.
2018/06/26 09:31:36 [cni] Calling plugin azure-vnet-ipam ADD nwCfg:&{CNIVersion:0.3.0 Name:azure Type:azure-vnet Mode:bridge Master: Bridge:azure0 LogLevel: LogTarget: Ipam:{Type:azure-vnet-ipam Environment: AddrSpace: Subnet:10.128.16.0/20 Address: QueryInterval:} DNS:{Nameservers:[] Domain: Search:[] Options:[]} AdditionalArgs:[]}.
2018/06/26 09:31:36 [cni] Plugin azure-vnet-ipam returned result:, err:Failed to allocate address: No available addresses.
2018/06/26 09:31:36 [azure-vnet] Failed to allocate address: Failed to delegate: Failed to allocate address: No available addresses.
2018/06/26 09:31:36 [cni] Recovered panic: runtime error: invalid memory address or nil pointer dereference goroutine 1 [running]:
github.com/Azure/azure-container-networking/cni.(*Plugin).Execute.func1(0xc420153ec0)
/go/src/github.com/Azure/azure-container-networking/cni/plugin.go:94 +0xbc
panic(0x69b3c0, 0x83ed90)
/usr/local/go/src/runtime/panic.go:489 +0x2cf
github.com/Azure/azure-container-networking/cni/network.(*netPlugin).Add.func1(0xc420153910, 0xc4201b0000, 0xc4201538d0, 0xc4201538f0, 0xc42015ca20)
/go/src/github.com/Azure/azure-container-networking/cni/network/network.go:150 +0x9f
github.com/Azure/azure-container-networking/cni/network.(*netPlugin).Add(0xc42015ca20, 0xc4201b0000, 0x818c20, 0xc4200eeff0)
/go/src/github.com/Azure/azure-container-networking/cni/network/network.go:285 +0x13b7
github.com/Azure/azure-container-networking/cni.(PluginApi).Add-fm(0xc4201b0000, 0xc420142290, 0x5)
/go/src/github.com/Azure/azure-container-networking/cni/plugin.go:112 +0x39
github.com/containernetworking/cni/pkg/skel.(*dispatcher).checkVersionAndCall(0xc42013c400, 0xc4201b0000, 0x81b220, 0xc4200ee270, 0xc420153e80, 0x0, 0xc42013c200)
/go/src/github.com/containernetworking/cni/pkg/skel/skel.go:168 +0x19f
github.com/containernetworking/cni/pkg/skel.(*dispatcher).pluginMain(0xc42013c400, 0xc420153e80, 0xc420153e68, 0x81b220, 0xc4200ee270, 0xc420153e38)
/go/src/github.com/containernetworking/cni/pkg/skel/skel.go:199 +0x384
github.com/containernetworking/cni/pkg/skel.PluginMainWithError(0xc420153e80, 0xc420153e68, 0x81b220, 0xc4200ee270, 0xc4200ee270)
/go/src/github.com/containernetworking/cni/pkg/skel/skel.go:236 +0xed
github.com/Azure/azure-container-networking/cni.(*Plugin).Execute(0xc42000e108, 0x81b0e0, 0xc42015ca20, 0x0, 0x0)
/go/src/github.com/Azure/azure-container-networking/cni/plugin.go:112 +0x127
main.main()
/go/src/github.com/Azure/azure-container-networking/cni/network/plugin/main.go:93 +0x4d4
ipam logs :
018/06/26 08:12:25 [ipam] Starting source azure.
2018/06/26 08:12:25 [ipam] Refreshing address source.
2018/06/26 08:12:25 [ipam] Save succeeded.
2018/06/26 08:12:25 [ipam] Requesting address with address: options:map[].
2018/06/26 08:12:25 [ipam] Address request completed with address: err:.
2018/06/26 08:12:25 [azure-vnet-ipam] Failed to allocate address: No available addresses.
2018/06/26 08:12:25 [cni-ipam] ADD command completed with result: err:Failed to allocate address: No available addresses.
2018/06/26 08:12:25 [cni-ipam] Plugin stopped.
2018/06/26 08:12:27 [cni-ipam] Plugin azure-vnet-ipam version v1.0.4-1-gf0f090e.
2018/06/26 08:12:27 [cni-ipam] Running on Linux version 4.13.0-1018-azure (buildd@lcy01-amd64-014) (gcc version 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.9)) #21-Ubuntu SMP Thu May 17 13:58:38 UTC 2018
2018/06/26 08:12:27 [ipam] Store timestamp is 2018-06-26 08:12:25.4999318 +0000 UTC.
2018/06/26 08:12:27 [ipam] Restored state, &{Version:v1.0.4-1-gf0f090e TimeStamp:2018-06-26 08:12:25.5050892 +0000 UTC AddrSpaces:map[local:0xc4200751d0] store:0xc420074db0 source: netApi: Mutex:{state:0 sema:0}}
2018/06/26 08:12:27 [cni-ipam] Plugin started.
2018/06/26 08:12:27 [cni-ipam] Processing ADD command with args {ContainerID:64d3d3a709384e177afd13ae65bd456294582b036896ad0e3e425f8b209be75c Netns:/proc/61869/ns/net IfName:eth0 Args:IgnoreUnknown=1;K8S_POD_NAMESPACE=nexus-dev;K8S_POD_NAME=esb-central-5c9bbbccb7-l2rnx;K8S_POD_INFRA_CONTAINER_ID=64d3d3a709384e177afd13ae65bd456294582b036896ad0e3e425f8b209be75c Path:/opt/azure-vnet/bin:/opt/cni/bin}.
2018/06/26 08:12:27 [cni-ipam] Read network configuration &{CNIVersion:0.3.0 Name:azure Type:azure-vnet Mode:bridge Master: Bridge:azure0 LogLevel: LogTarget: Ipam:{Type:azure-vnet-ipam Environment: AddrSpace: Subnet:10.128.16.0/20 Address: QueryInterval:} DNS:{Nameservers:[] Domain: Search:[] Options:[]} AdditionalArgs:[]}.
2018/06/26 08:12:27 [ipam] Starting source azure.
2018/06/26 08:12:27 [ipam] Refreshing address source.
2018/06/26 08:12:27 [ipam] Save succeeded.
2018/06/26 08:12:27 [ipam] Requesting address with address: options:map[].
2018/06/26 08:12:27 [ipam] Address request completed with address: err:.
2018/06/26 08:12:27 [azure-vnet-ipam] Failed to allocate address: No available addresses.
2018/06/26 08:12:27 [cni-ipam] ADD command completed with result: err:Failed to allocate address: No available addresses.
S
Createdby: Dinor Geler [ DIGELER ] Pod get stuck in ContainerCreating state:
outgoing-messages-service-7fc659fb84-rn2ht 0/1 ContainerCreating 0 6m aks-agentpool-66686873-5
On aks-agentpool-66686873-5 node there are 28 pods while the limit is 30 so there should not be any issues with assigning IP address, but in the azure-vnet-ipam.log there are entries that show lack of free IP addresses:
2018/06/22 13:22:25 [cni-ipam] Plugin started.
2018/06/22 13:22:25 [cni-ipam] Processing ADD command with args {ContainerID:d18c6829adb1015ef677f2319d33157637a37b80612fa7474a643b374432f72b Netns:/proc/81095/ns/net IfName:eth0 Args:IgnoreUnknown=1;K8S_POD_NAMESPACE=nexus-dev;K8S_POD_NAME=outgoing-messages-service-7fc659fb84-rn2ht;K8S_POD_INFRA_CONTAINER_ID=d18c6829adb1015ef677f2319d33157637a37b80612fa7474a643b374432f72b Path:/opt/azure-vnet/bin:/opt/cni/bin}.
2018/06/22 13:22:25 [cni-ipam] Read network configuration &{CNIVersion:0.3.0 Name:azure Type:azure-vnet Mode:bridge Master: Bridge:azure0 LogLevel: LogTarget: Ipam:{Type:azure-vnet-ipam Environment: AddrSpace: Subnet:10.128.16.0/20 Address: QueryInterval:} DNS:{Nameservers:[] Domain: Search:[] Options:[]} AdditionalArgs:[]}.
2018/06/22 13:22:25 [ipam] Starting source azure.
2018/06/22 13:22:25 [ipam] Refreshing address source.
2018/06/22 13:22:25 [ipam] Save succeeded.
2018/06/22 13:22:25 [ipam] Requesting address with address: options:map[].
2018/06/22 13:22:25 [ipam] Address request completed with address: err:.
2018/06/22 13:22:25 [azure-vnet-ipam] Failed to allocate address: No available addresses.
2018/06/22 13:22:25 [cni-ipam] ADD command completed with result: err:Failed to allocate address: No available addresses.
2018/06/22 13:22:25 [cni-ipam] Plugin stopped.
[Problem start date and time]
Thu, 21 Jun 2018 22:00:00 GMT
2018/06/26 09:31:36 [cni] Recovered panic: runtime error: invalid memory address or nil pointer dereference goroutine 1 [running]:
github.com/Azure/azure-container-networking/cni.(*Plugin).Execute.func1(0xc420153ec0)
/go/src/github.com/Azure/azure-container-networking/cni/plugin.go:94 +0xbc
panic(0x69b3c0, 0x83ed90)```