create VETH pair fails when source inft of device1 and dst intf of device2 are same

[networkservicemesh]

create VETH pair fails when source inft of device1 and dst intf of device2 are same

[vparames86]

@rdimitrov @networkop - Thanks for all your help. This PR fixes the issue and I validated it in my AKS cluster. Had to tweak the helm templates to just pull the kernel-forwarder image from my own docker repo.

[nickolaev]

Can you post the steps and configurations you use to hit this issue for reference?

[vparames86]

I have created a topology having 2 devices and one link between them. The device pods are deployed with "kind:Deployment". I use a config-map to store env vars and have deployed reloader to restart the pods when the config-maps change. I have uploaded the topology to CRD. All my resources and nsm is deployed in "default" namespace. I am using a /28 for the IPAM. Attached my full set of configs below.

kubectl get deployments deviceceos50 -o yaml
apiVersion: extensions/v1beta1
kind: Deployment
metadata:
annotations:
configmap.reloader.stakater.com/reload: deviceceos50-nsm
deployment.kubernetes.io/revision: "1"
creationTimestamp: "2020-03-15T04:19:21Z"
generation: 1
name: deviceceos50
namespace: default
resourceVersion: "31615700"
selfLink: /apis/extensions/v1beta1/namespaces/default/deployments/deviceceos50
uid: 2501f4d3-6674-11ea-81ea-000d3afe349d
spec:
progressDeadlineSeconds: 600
replicas: 1
revisionHistoryLimit: 10
selector:
matchLabels:
device: deviceceos50
strategy:
rollingUpdate:
maxSurge: 25%
maxUnavailable: 25%
type: RollingUpdate
template:
metadata:
creationTimestamp: null
labels:
app: newtopoceos50
device: deviceceos50
name: deviceceos50
spec:
affinity:
podAntiAffinity:
preferredDuringSchedulingIgnoredDuringExecution:
- podAffinityTerm:
labelSelector:
matchLabels:
app: newtopoceos50
topologyKey: kubernetes.io/hostname
weight: 100
containers:
- command:
- /sbin/init
env:
- name: CEOS
value: "1"
- name: EOS_PLATFORM
value: ceoslab
- name: container
value: docker
- name: ETBA
value: "1"
- name: SKIP_ZEROTOUCH_BARRIER_IN_SYSDBINIT
value: "1"
- name: INTFTYPE
value: eth
image: ccevirtnetpperegistry.azurecr.io/ceosimage:4.22.1F
imagePullPolicy: Always
name: router
resources:
limits:
cpu: "1"
requests:
cpu: 500m
memory: 1Gi
securityContext:
capabilities:
add:
- NET_ADMIN
procMount: Default
terminationMessagePath: /dev/termination-log
terminationMessagePolicy: File
volumeMounts:
- mountPath: /mnt/flash/startup-config
name: startup-config-volume
subPath: startup-config
- env:
- name: ENDPOINT_NETWORK_SERVICE
valueFrom:
configMapKeyRef:
key: ENDPOINT_NETWORK_SERVICE
name: deviceceos50-nsm
- name: ENDPOINT_LABELS
valueFrom:
configMapKeyRef:
key: ENDPOINT_LABELS
name: deviceceos50-nsm
- name: IP_ADDRESS
valueFrom:
configMapKeyRef:
key: IP_ADDRESS
name: deviceceos50-nsm
image: networkservicemesh/topology-sidecar-nse:master
imagePullPolicy: Always
name: nse-sidecar
resources:
limits:
networkservicemesh.io/socket: "1"
terminationMessagePath: /dev/termination-log
terminationMessagePolicy: File
- env:
- name: NS_NETWORKSERVICEMESH_IO
valueFrom:
configMapKeyRef:
key: NS_NETWORKSERVICEMESH_IO
name: deviceceos50-nsm
image: networkservicemesh/topology-sidecar-nsc:master
imagePullPolicy: Always
name: nsc-sidecar
resources:
limits:
networkservicemesh.io/socket: "1"
terminationMessagePath: /dev/termination-log
terminationMessagePolicy: File
dnsPolicy: ClusterFirst
imagePullSecrets:
- name: ipevirtnetppereg
restartPolicy: Always
schedulerName: default-scheduler
securityContext: {}
terminationGracePeriodSeconds: 0
volumes:
- configMap:
defaultMode: 420
name: deviceceos50-config
name: startup-config-volume
status:
conditions:

• lastTransitionTime: "2020-03-15T04:19:21Z"
  lastUpdateTime: "2020-03-15T04:19:30Z"
  message: ReplicaSet "deviceceos50-67cffd5f9" has successfully progressed.
  reason: NewReplicaSetAvailable
  status: "True"
  type: Progressing
• lastTransitionTime: "2020-03-16T15:57:06Z"
  lastUpdateTime: "2020-03-16T15:57:06Z"
  message: Deployment does not have minimum availability.
  reason: MinimumReplicasUnavailable
  status: "False"
  type: Available
  observedGeneration: 1
  replicas: 1
  unavailableReplicas: 1
  updatedReplicas: 1

kubectl get deployments deviceceos51 -o yaml
apiVersion: extensions/v1beta1
kind: Deployment
metadata:
annotations:
configmap.reloader.stakater.com/reload: deviceceos51-nsm
deployment.kubernetes.io/revision: "1"
creationTimestamp: "2020-03-15T04:19:21Z"
generation: 1
name: deviceceos51
namespace: default
resourceVersion: "31348542"
selfLink: /apis/extensions/v1beta1/namespaces/default/deployments/deviceceos51
uid: 253f4785-6674-11ea-81ea-000d3afe349d
spec:
progressDeadlineSeconds: 600
replicas: 1
revisionHistoryLimit: 10
selector:
matchLabels:
device: deviceceos51
strategy:
rollingUpdate:
maxSurge: 25%
maxUnavailable: 25%
type: RollingUpdate
template:
metadata:
creationTimestamp: null
labels:
app: newtopoceos50
device: deviceceos51
name: deviceceos51
spec:
affinity:
podAntiAffinity:
preferredDuringSchedulingIgnoredDuringExecution:
- podAffinityTerm:
labelSelector:
matchLabels:
app: newtopoceos50
topologyKey: kubernetes.io/hostname
weight: 100
containers:
- command:
- /sbin/init
env:
- name: CEOS
value: "1"
- name: EOS_PLATFORM
value: ceoslab
- name: container
value: docker
- name: ETBA
value: "1"
- name: SKIP_ZEROTOUCH_BARRIER_IN_SYSDBINIT
value: "1"
- name: INTFTYPE
value: eth
image: ccevirtnetpperegistry.azurecr.io/ceosimage:4.22.1F
imagePullPolicy: Always
name: router
resources:
limits:
cpu: "1"
requests:
cpu: 500m
memory: 1Gi
securityContext:
capabilities:
add:
- NET_ADMIN
procMount: Default
terminationMessagePath: /dev/termination-log
terminationMessagePolicy: File
volumeMounts:
- mountPath: /mnt/flash/startup-config
name: startup-config-volume
subPath: startup-config
- env:
- name: ENDPOINT_NETWORK_SERVICE
valueFrom:
configMapKeyRef:
key: ENDPOINT_NETWORK_SERVICE
name: deviceceos51-nsm
- name: ENDPOINT_LABELS
valueFrom:
configMapKeyRef:
key: ENDPOINT_LABELS
name: deviceceos51-nsm
- name: IP_ADDRESS
valueFrom:
configMapKeyRef:
key: IP_ADDRESS
name: deviceceos51-nsm
image: networkservicemesh/topology-sidecar-nse:master
imagePullPolicy: Always
name: nse-sidecar
resources:
limits:
networkservicemesh.io/socket: "1"
terminationMessagePath: /dev/termination-log
terminationMessagePolicy: File
dnsPolicy: ClusterFirst
imagePullSecrets:
- name: ipevirtnetppereg
restartPolicy: Always
schedulerName: default-scheduler
securityContext: {}
terminationGracePeriodSeconds: 0
volumes:
- configMap:
defaultMode: 420
name: deviceceos51-config
name: startup-config-volume
status:
availableReplicas: 1
conditions:

• lastTransitionTime: "2020-03-15T04:19:28Z"
  lastUpdateTime: "2020-03-15T04:19:28Z"
  message: Deployment has minimum availability.
  reason: MinimumReplicasAvailable
  status: "True"
  type: Available

• lastTransitionTime: "2020-03-15T04:19:21Z"
  lastUpdateTime: "2020-03-15T04:19:28Z"
  message: ReplicaSet "deviceceos51-684685f876" has successfully progressed.
  reason: NewReplicaSetAvailable
  status: "True"
  type: Progressing
  observedGeneration: 1
  readyReplicas: 1
  replicas: 1
  updatedReplicas: 1

• apiVersion: networkservicemesh.io/v1alpha1
  kind: NetworkService
  metadata:
  creationTimestamp: "2020-03-15T04:19:20Z"
  generation: 1
  name: newtopoceos50
  namespace: default
  resourceVersion: "31348460"
  selfLink: /apis/networkservicemesh.io/v1alpha1/namespaces/default/networkservices/newtopoceos50
  uid: 24c50418-6674-11ea-8961-000d3afe39b9
  spec:
  matches:

  • match: null
    route:
    • destination: null
      destinationSelector:
      device: deviceceos51
      sourceSelector:
      link: net-48
      payload: IP

kubectl get configmap deviceceos50-nsm -o yaml
apiVersion: v1
data:
ENDPOINT_LABELS: device=deviceceos50
ENDPOINT_NETWORK_SERVICE: newtopoceos50
IP_ADDRESS: 10.60.11.64/28
NS_NETWORKSERVICEMESH_IO: newtopoceos50/eth2?link=net-48&peerif=eth2
kind: ConfigMap
metadata:
creationTimestamp: "2020-03-15T04:19:20Z"
name: deviceceos50-nsm
namespace: default
resourceVersion: "31348461"
selfLink: /api/v1/namespaces/default/configmaps/deviceceos50-nsm
uid: 24e6aadf-6674-11ea-8961-000d3afe39b9

kubectl get configmap deviceceos51-nsm -o yaml
apiVersion: v1
data:
ENDPOINT_LABELS: device=deviceceos51
ENDPOINT_NETWORK_SERVICE: newtopoceos50
IP_ADDRESS: 10.60.11.80/28
NS_NETWORKSERVICEMESH_IO: ""
kind: ConfigMap
metadata:
creationTimestamp: "2020-03-15T04:19:21Z"
name: deviceceos51-nsm
namespace: default
resourceVersion: "31348481"
selfLink: /api/v1/namespaces/default/configmaps/deviceceos51-nsm
uid: 25291fe4-6674-11ea-8853-000d3afe3b95

kubectl get pods | grep nsm
nsm-admission-webhook-76f4b59cbb-ltk5c 1/1 Running 0 6d16h
nsm-kernel-forwarder-k7qnt 1/1 Running 0 6d16h
nsm-kernel-forwarder-m24s2 1/1 Running 0 6d16h
nsm-kernel-forwarder-tvgxr 1/1 Running 0 6d16h
nsm-kernel-forwarder-v94hk 1/1 Running 0 6d16h
nsmgr-4twzc 3/3 Running 0 6d16h
nsmgr-5kmqt 3/3 Running 0 6d16h
nsmgr-8q4xn 3/3 Running 0 6d16h
nsmgr-vt7zc 3/3 Running 0 6d16h

[vparames86]

@nickolaev @networkop - Please someone help me here. I am kind of stuck with this issue. I re-installed nsm and just ran the plain example given for "topology". Out of 5 connections, 4 went fine and I notice the same issue in connection from r4-r1.

router1-7cdf5b855c-brwk8 3/3 Running 0 14h
router2-5f556466c9-gc8zg 3/3 Running 0 14h
router3-5955db7f69-zhvhx 3/3 Running 0 14h
router4-7f8bdc5448-kd52t 2/3 CrashLoopBackOff 146 14h
router5-55d6f85df8-p8z8c 3/3 Running 0 14h

The nse-sidecar keeps getting multiple GRPC requests and the IPAM pool gets depleted.

time="2020-03-18T17:06:30Z" level=info msg="EndpointConnection-New event: &{{UPDATE map[21e9:0xc000222080] 0xc000284b10}}"
time="2020-03-18T17:06:30Z" level=info msg="==----> EndpointConnection-send-update() span:70cc3142a23297df:77bd056e8e94f432:3bb40e3dd0f674f1:1"
time="2020-03-18T17:06:30Z" level=info msg=">><<---- eventType="UPDATE" span=70cc3142a23297df:77bd056e8e94f432:3bb40e3dd0f674f1:1"
time="2020-03-18T17:06:30Z" level=info msg=">><<---- msg={"type":1,"connections":{"21e9":{"id":"21e9","network_service":"topo","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth14","netnsInode":"4026533191","socketfile":"nsm9pjIBJkMI/memif.sock"}},"context":{"ip_context":{"src_ip_addr":"10.60.1.81/30","dst_ip_addr":"10.60.1.82/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router1-7cdf5b855c-brwk8"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}}}} span=70cc3142a23297df:77bd056e8e94f432:3bb40e3dd0f674f1:1"
2020/03/18 17:06:30 Reporting span 70cc3142a23297df:77bd056e8e94f432:3bb40e3dd0f674f1:1
time="2020-03-18T17:06:30Z" level=info msg="EndpointConnection-New event: &{{UPDATE map[21e9:0xc000222080] 0xc000284840}}"
time="2020-03-18T17:06:30Z" level=info msg="==--> EndpointConnection-send-update() span:70cc3142a23297df:81afa6aef8eae94:70cc3142a23297df:1"
time="2020-03-18T17:06:30Z" level=info msg="Responding to NetworkService.Request(connection:<id:"21e9" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth14" > parameters:<key:"netnsInode" value:"4026533191" > parameters:<key:"socketfile" value:"nsm9pjIBJkMI/memif.sock" > > context:<ip_context:<src_ip_addr:"10.60.1.81/30" dst_ip_addr:"10.60.1.82/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.244.0.0/21" excluded_prefixes:"10.0.0.0/16" excluded_prefixes:"10.244.0.0/21" excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router1-7cdf5b855c-brwk8" > path:<path_segments:<name:"k8s-agentpool1-40367033-vmss000002" > > > mechanism_preferences:<type:"KERNEL_INTERFACE" > ): id:"21e9" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth14" > parameters:<key:"netnsInode" value:"4026533191" > parameters:<key:"socketfile" value:"nsm9pjIBJkMI/memif.sock" > > context:<ip_context:<src_ip_addr:"10.60.1.81/30" dst_ip_addr:"10.60.1.82/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.244.0.0/21" excluded_prefixes:"10.0.0.0/16" excluded_prefixes:"10.244.0.0/21" excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router1-7cdf5b855c-brwk8" > path:<path_segments:<name:"k8s-agentpool1-40367033-vmss000002" > > " operation=Endpoint.Request span="70cc3142a23297df:3078546f8eb3b0cb:70cc3142a23297df:1"
time="2020-03-18T17:06:30Z" level=info msg=">><<-- response={"id":"21e9","network_service":"topo","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth14","netnsInode":"4026533191","socketfile":"nsm9pjIBJkMI/memif.sock"}},"context":{"ip_context":{"src_ip_addr":"10.60.1.81/30","dst_ip_addr":"10.60.1.82/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router1-7cdf5b855c-brwk8"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}} span=70cc3142a23297df:3078546f8eb3b0cb:70cc3142a23297df:1"
2020/03/18 17:06:30 Reporting span 70cc3142a23297df:3078546f8eb3b0cb:70cc3142a23297df:1
time="2020-03-18T17:06:30Z" level=info msg=">><<-- response={"id":"21e9","network_service":"topo","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth14","netnsInode":"4026533191","socketfile":"nsm9pjIBJkMI/memif.sock"}},"context":{"ip_context":{"src_ip_addr":"10.60.1.81/30","dst_ip_addr":"10.60.1.82/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router1-7cdf5b855c-brwk8"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}} span=70cc3142a23297df:70cc3142a23297df:0:1"
2020/03/18 17:06:30 Reporting span 70cc3142a23297df:70cc3142a23297df:0:1
time="2020-03-18T17:06:30Z" level=info msg=">><<-- eventType="UPDATE" span=70cc3142a23297df:81afa6aef8eae94:70cc3142a23297df:1"
time="2020-03-18T17:06:30Z" level=info msg=">><<-- msg={"type":1,"connections":{"21e9":{"id":"21e9","network_service":"topo","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth14","netnsInode":"4026533191","socketfile":"nsm9pjIBJkMI/memif.sock"}},"context":{"ip_context":{"src_ip_addr":"10.60.1.81/30","dst_ip_addr":"10.60.1.82/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router1-7cdf5b855c-brwk8"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}}}} span=70cc3142a23297df:81afa6aef8eae94:70cc3142a23297df:1"
2020/03/18 17:06:30 Reporting span 70cc3142a23297df:81afa6aef8eae94:70cc3142a23297df:1
2020/03/18 17:06:30 ERROR: error when flushing the buffer: write udp 127.0.0.1:42841->127.0.0.1:6831: write: connection refused
time="2020-03-18T17:06:39Z" level=info msg=">><<-- GRPC->/networkservice.NetworkService/Request()="" span=1ccff894a37007b8:1ccff894a37007b8:0:1"
time="2020-03-18T17:06:39Z" level=info msg=">><<-- request={"connection":{"id":"21eb","network_service":"topo","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=1ccff894a37007b8:1ccff894a37007b8:0:1"
time="2020-03-18T17:06:39Z" level=info msg="==--> Endpoint.Request() span:1ccff894a37007b8:10f0f4c5c59cf4ad:1ccff894a37007b8:1"
time="2020-03-18T17:06:39Z" level=info msg=">><<-- request={"connection":{"id":"21eb","network_service":"topo","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=1ccff894a37007b8:10f0f4c5c59cf4ad:1ccff894a37007b8:1"
time="2020-03-18T17:06:39Z" level=info msg="Request for Network Service received connection:<id:"21eb" network_service:"topo" context:<ip_context:<src_ip_required:true dst_ip_required:true excluded_prefixes:"10.244.0.0/21" excluded_prefixes:"10.0.0.0/16" excluded_prefixes:"10.244.0.0/21" excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router4-7f8bdc5448-kd52t" > path:<path_segments:<name:"k8s-agentpool1-40367033-vmss000002" > > > mechanism_preferences:<type:"KERNEL_INTERFACE" > " operation=Endpoint.Request span="1ccff894a37007b8:10f0f4c5c59cf4ad:1ccff894a37007b8:1"
time="2020-03-18T17:06:39Z" level=info msg="==--> *MonitorEndpoint.Request() span:1ccff894a37007b8:1ab82e4e19a424a7:1ccff894a37007b8:1"
time="2020-03-18T17:06:39Z" level=info msg=">><<-- request={"connection":{"id":"21eb","network_service":"topo","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=1ccff894a37007b8:1ab82e4e19a424a7:1ccff894a37007b8:1"
time="2020-03-18T17:06:39Z" level=info msg="==----> *ConnectionEndpoint.Request() span:1ccff894a37007b8:6c21d7fc3fc7388f:1ab82e4e19a424a7:1"
time="2020-03-18T17:06:39Z" level=info msg=">><<---- request={"connection":{"id":"21eb","network_service":"topo","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=1ccff894a37007b8:6c21d7fc3fc7388f:1ab82e4e19a424a7:1"
time="2020-03-18T17:06:39Z" level=info msg="==------> *IfnameEndpoint.Request() span:1ccff894a37007b8:761e44cd5c7aa4f6:6c21d7fc3fc7388f:1"
time="2020-03-18T17:06:39Z" level=info msg=">><<------ request={"connection":{"id":"21eb","network_service":"topo","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"nsm61gI8JlMI","netnsInode":"4026533191","socketfile":"nsm61gI8JlMI/memif.sock"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=1ccff894a37007b8:761e44cd5c7aa4f6:6c21d7fc3fc7388f:1"

time="2020-03-18T17:54:35Z" level=info msg="==----> *ConnectionEndpoint.Request() span:339c4265d24a3aff:21ba6131fb8d7551:77f511c856d66704:1"
time="2020-03-18T17:54:35Z" level=info msg=">><<---- request={"connection":{"id":"242b","network_service":"topo","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=339c4265d24a3aff:21ba6131fb8d7551:77f511c856d66704:1"
time="2020-03-18T17:54:35Z" level=info msg="==------> *IfnameEndpoint.Request() span:339c4265d24a3aff:56e6a4df61409640:21ba6131fb8d7551:1"
time="2020-03-18T17:54:35Z" level=info msg=">><<------ request={"connection":{"id":"242b","network_service":"topo","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"nsmYtBdUJlTy","netnsInode":"4026533191","socketfile":"nsmYtBdUJlTy/memif.sock"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=339c4265d24a3aff:56e6a4df61409640:21ba6131fb8d7551:1"
time="2020-03-18T17:54:35Z" level=info msg="==--------> *IpamEndpoint.Request() span:339c4265d24a3aff:723bd5939312171a:56e6a4df61409640:1"
time="2020-03-18T17:54:35Z" level=info msg=">><<-------- request={"connection":{"id":"242b","network_service":"topo","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"nsmYtBdUJlTy","netnsInode":"4026533191","socketfile":"nsmYtBdUJlTy/memif.sock"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.244.0.0/21","10.0.0.0/16","10.244.0.0/21","10.0.0.0/16"]}},"labels":{"link":"r4-r1","namespace":"default","peerif":"eth14","podName":"router4-7f8bdc5448-kd52t"},"path":{"path_segments":[{"name":"k8s-agentpool1-40367033-vmss000002"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span=339c4265d24a3aff:723bd5939312171a:56e6a4df61409640:1"
time="2020-03-18T17:54:35Z" level=error msg="IPAM: The available address pool is empty, probably intersected by excludedPrefix"
time="2020-03-18T17:54:35Z" level=error msg=">><<-------- error=IPAM: The available address pool is empty, probably intersected by excludedPrefix\ngithub.com/networkservicemesh/networkservicemesh/sdk/prefix_pool.(*prefixPool).ExcludePrefixes\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/prefix_pool/prefixpool.go:137\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*IpamEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/ipam.go:42\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\nmain.(*IfnameEndpoint).Request\n\t/root/networkservicemesh/examples/topology/sidecar-nse/cmd/ifname.go:49\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*ConnectionEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/connection.go:62\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*MonitorEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/monitor.go:53\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*MonitorEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/monitor.go:53\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*CompositeEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/composite.go:62\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nsmEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/endpoint.go:162\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/controlplane/[email protected]/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/controlplane/[email protected]/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1373 span=339c4265d24a3aff:723bd5939312171a:56e6a4df61409640:1"
2020/03/18 17:54:35 Reporting span 339c4265d24a3aff:723bd5939312171a:56e6a4df61409640:1
time="2020-03-18T17:54:35Z" level=error msg="Next request failed: IPAM: The available address pool is empty, probably intersected by excludedPrefix" operation="*IfnameEndpoint.Request" span="339c4265d24a3aff:56e6a4df61409640:21ba6131fb8d7551:1"
time="2020-03-18T17:54:35Z" level=error msg=">><<------ error=IPAM: The available address pool is empty, probably intersected by excludedPrefix\ngithub.com/networkservicemesh/networkservicemesh/sdk/prefix_pool.(*prefixPool).ExcludePrefixes\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/prefix_pool/prefixpool.go:137\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*IpamEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/ipam.go:42\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\nmain.(*IfnameEndpoint).Request\n\t/root/networkservicemesh/examples/topology/sidecar-nse/cmd/ifname.go:49\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*ConnectionEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/connection.go:62\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*MonitorEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/monitor.go:53\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nextEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/next.go:39\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*MonitorEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/monitor.go:53\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*CompositeEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/composite.go:62\ngithub.com/networkservicemesh/networkservicemesh/sdk/endpoint.(*nsmEndpoint).Request\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/endpoint/endpoint.go:162\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/controlplane/[email protected]/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/[email protected]/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/go/pkg/mod/github.com/networkservicemesh/networkservicemesh/controlplane/[email protected]/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/[email protected]/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1373 span=339c4265d24a3aff:56e6a4df61409640:21ba6131fb8d7551:1"
2020/03/18 17:54:35 Reporting span 339c4265d24a3aff:56e6a4df61409640:21ba6131fb8d7551:1

[networkop]

@vparames86 can you confirm the steps to reproduce?

1. Build a kind kubernetes cluster
2. Install NSM helm
3. Apply topology example
   Is that enough to hit that error or am I missing something?

[vparames86]

1. I have a k8s cluster built in azure vmss (virtual machine scale set) cluster built using aks-engine. 3 master & 4 worker nodes in the cluster.
2. Cloned the latest nsm repo. Installed nsm in default namespace.
   SPIRE_ENABLED=false INSECURE=true FORWARDING_PLANE=kernel NSM_NAMESPACE=default make helm-install-nsm
3. Applied the topo.yaml & routers.yaml files via kubectl. I start seeing this error in r4-r1 connection.

router1-7cdf5b855c-brwk8 3/3 Running 0 24h 10.244.4.28 k8s-agentpool1-40367033-vmss000002
router2-5f556466c9-gc8zg 3/3 Running 0 24h 10.244.3.185 k8s-agentpool1-40367033-vmss000000
router3-5955db7f69-zhvhx 3/3 Running 0 24h 10.244.3.186 k8s-agentpool1-40367033-vmss000000
router4-7f8bdc5448-kd52t 2/3 CrashLoopBackOff 246 24h 10.244.6.23 k8s-agentpool1-40367033-vmss000001
router5-55d6f85df8-p8z8c 3/3 Running 0 24h 10.244.4.29 k8s-agentpool1-40367033-vmss000002

[networkop]

what version of k8s are you running?

[vparames86]

kubectl version
Client Version: version.Info{Major:"1", Minor:"16", GitVersion:"v1.16.0", GitCommit:"2bd9643cee5b3b3a5ecbd3af49d09018f0773c77", GitTreeState:"clean", BuildDate:"2019-09-18T14:36:53Z", GoVersion:"go1.12.9", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"13+", GitVersion:"v1.13.0-alpha.2", GitCommit:"3b5d2e865ea996d83951e8194da4395003640805", GitTreeState:"clean", BuildDate:"2018-10-24T11:35:19Z", GoVersion:"go1.11.1", Compiler:"gc", Platform:"linux/amd64"}

[vparames86]

@networkop - I upgraded my cluster to k8s 1.18 and the example topology that you have works fine now, but I still see the error in a sample topology I tried to create myself. I have pasted the sample yaml files below.

topo.yaml

apiVersion: networkservicemesh.io/v1alpha1
kind: NetworkService
metadata:
name: topology
namespace: default
spec:
matches:

• match:
  route:
  • destination:
    destinationSelector:
    device: k8sqrtr04
    sourceSelector:
    link: r1-r2
    payload: IP

k8sqrtr03.yaml
apiVersion: apps/v1
kind: Deployment
metadata:
name: k8sqrtr03
namespace: default
spec:
replicas: 1
selector:
matchLabels:
device: k8sqrtr03
template:
metadata:
labels:
app: topology
device: k8sqrtr03
spec:
containers:
- image: networkservicemesh/topology-qrtr:master
imagePullPolicy: Always
name: router
securityContext:
capabilities:
add:
- NET_ADMIN
volumeMounts:
- mountPath: /etc/quagga/zebra.conf
name: startup-config
subPath: zebra.conf
- env:
- name: ENDPOINT_NETWORK_SERVICE
value: topology
- name: ENDPOINT_LABELS
value: device=k8sqrtr03
- name: IP_ADDRESS
value: 10.60.14.0/24
image: networkservicemesh/topology-sidecar-nse:master
imagePullPolicy: Always
name: nse-sidecar
resources:
limits:
networkservicemesh.io/socket: "1"
- env:
- name: NS_NETWORKSERVICEMESH_IO
value: "topology/eth1?link=r1-r2&peerif=eth1"
image: networkservicemesh/topology-sidecar-nsc:master
imagePullPolicy: Always
name: nsc-sidecar
resources:
limits:
networkservicemesh.io/socket: "1"
#imagePullSecrets:
#- name: ipevirtnetppereg
volumes:
- configMap:
name: k8sqrtr03-config
name: startup-config

apiVersion: v1
metadata:
name: k8sqrtr03-config
data:
zebra.conf: |
!
hostname qrtr-2
!
interface lo
ip address 192.0.2.2/32
exit
!
kind: ConfigMap

k8sqrtr04.yaml
apiVersion: apps/v1
kind: Deployment
metadata:
name: k8sqrtr04
namespace: default
spec:
replicas: 1
selector:
matchLabels:
device: k8sqrtr04
template:
metadata:
labels:
app: topology
device: k8sqrtr04
spec:
containers:
- image: networkservicemesh/topology-qrtr:master
imagePullPolicy: Always
name: router
securityContext:
capabilities:
add:
- NET_ADMIN
volumeMounts:
- mountPath: /etc/quagga/zebra.conf
name: startup-config
subPath: zebra.conf
- env:
- name: ENDPOINT_NETWORK_SERVICE
value: topology
- name: ENDPOINT_LABELS
value: device=k8sqrtr04
- name: IP_ADDRESS
value: 10.60.15.160/28
image: networkservicemesh/topology-sidecar-nse:master
imagePullPolicy: Always
name: nse-sidecar
resources:
limits:
networkservicemesh.io/socket: "1"
volumes:
- configMap:
name: k8sqrtr04-config
name: startup-config

apiVersion: v1
metadata:
name: k8sqrtr04-config
data:
zebra.conf: |
!
hostname qrtr-1
!
interface lo
ip address 192.0.2.1/32
exit
!
kind: ConfigMap

I tried multiple combinations but still couldn't figure out why sample topology results in this error. Please help me to troubleshoot the error.

[vparames86]

@networkop @nickolaev - Finally found the issue. The issue occurs when the source and destination interfaces have same name. e.g. eth1 - eth1. If the source and destination interfaces are different then the issue doesn't occur.

"topology/eth12?link=r1-r2&peerif=eth21" - no issue
"topology/eth1?link=r1-r2&peerif=eth1" - issue noticed

[networkop]

interesting. let me try that in my lab.

[networkop]

just tried it in the lab and still can't reproduce. i've created a kind cluster and modified topology from examples so that r1 and r2 are both connected on the same interface "topo/eth1?link=r1-r2&peerif=eth1". Both pods came up fine and I was able to ping across the link.

[networkop]

@vparames86 have you tried reproducing the issue on kind or were you only testing on AKS?

[vparames86]

@networkop - I was testing it in AKS cluster only (Which I upgraded to k8s 1.18) and I amable to reproduce the issue. Will try the same in kind cluster and let you know.

[vparames86]

@networkop - This issue is not reproducible in a kind cluster but occurs every time in a AKS cluster. Do you know any possible reasons for this to happen? Please provide some suggestions for troubleshooting this issue further.

[networkop]

silly suggestion but are you sure you don't have eth1 in the pod already? i.e. AKS's default CNI plugin does not interfere with NSM? Try doing the same interface, but call it eth123 instead.

Also are you running anything else in AKS cluster? I can suggest collecting ALL logs from ALL pods using stern --all-namespaces . , but that may have a lot of bg noise if there are a lot of other services running.

[vparames86]

I tried eth123 to eth123 and still get the issue. I don't think it is interfering with default CNI since eth1 to eth2 works perfectly. I am not running any other service other than nsm. Will check the nsm mgr logs to see if i can find something.

[vparames86]

@networkop - Have a question. In the nse-sidecar's ifnameendpoint, you replace the "InterfaceNameKey" to the peerif, but not the SocketFileName. In the sdk I see that the SocketFileName is derived from InterfaceNameKey. Does this have anything to do with the issue I am seeing?

// NewMechanism creates a new mechanism with passed type and description.
func NewMechanism(cls string, t string, name, description string) (*connection.Mechanism, error) {
inodeNum, err := tools.GetCurrentNS()
if err != nil {
return nil, err
}
rv := &connection.Mechanism{
Cls: cls,
Type: t,
Parameters: map[string]string{
common.InterfaceNameKey: name,
common.InterfaceDescriptionKey: description,
kernel.SocketFilename: path.Join(name, memif.MemifSocket),
common.NetNsInodeKey: inodeNum,
},
}
err = rv.IsValid()
if err != nil {
return nil, err
}
return rv, nil
}

[vparames86]

@nickolaev @networkop - After digging through nsmd logs, found that the VETH pair is not getting created and fails with file exists if the "peerif" and local if are same. Also I feel if one call fails, nsmd shouldn't deplete the IPAM pool. I know the nsc will initiate new requests to connect to endpoint because of retry, but there should be a way to prevent this from happening. I have attached a detail log of the call flows from nsc-nsmd-nse. VETH pair shouldn't fail when I try to connect eth1 of device1 to eth1 of device2.

time="2020-03-27T17:54:15Z" level=info msg=">><<-- GRPC->/networkservice.NetworkService/Request()="" span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-- request={"connection":{"network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==--> Local.*requestValidator.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-- request={"connection":{"network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==----> Local.*monitorService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---- request={"connection":{"network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==------> Local.*workspaceProviderService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<------ request={"connection":{"network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="Received request from client to connect to NetworkService: connection:<network_service:"topology" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth123" > labels:<key:"podName" value:"k8sqrtr03-55746fd498-dk5dm" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth123" > parameters:<key:"netnsInode" value:"4026532849" > parameters:<key:"socketfile" value:"eth123/memif.sock" > > "
time="2020-03-27T17:54:15Z" level=info msg="==--------> Local.*connectionService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------- request={"connection":{"network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="Received request from client to connect to NetworkService: connection:<network_service:"topology" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth123" > labels:<key:"podName" value:"k8sqrtr03-55746fd498-dk5dm" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth123" > parameters:<key:"netnsInode" value:"4026532849" > parameters:<key:"socketfile" value:"eth123/memif.sock" > parameters:<key:"workspace" value:"nsm-58" > > " span="{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------- connection-id= span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------- workspace=nsm-58 span={}"
time="2020-03-27T17:54:15Z" level=info msg="resourceAdded started: &{5eca 1 0 0xc004672ba0}"
time="2020-03-27T17:54:15Z" level=info msg="resourceAdded finished: &{5eca 1 0 0xc004672ba0}"
time="2020-03-27T17:54:15Z" level=info msg="==----------> Local.*forwarderService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------- request={"connection":{"id":"5eca","network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==------------> wait-forwarder() span:{}"
time="2020-03-27T17:54:15Z" level=info msg="==----------> ClientConnectionAdded() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------- clientConnection={"ConnectionID":"5eca","Request":null,"Xcon":null,"RemoteNsm":null,"Endpoint":null,"ForwarderRegisteredName":"","ConnectionState":1,"ForwarderState":0,"Span":null,"Monitor":{"Server":{}}} span={}"
time="2020-03-27T17:54:15Z" level=info msg="Waiting for forwarder available..." operation=wait-forwarder span="{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<------------ dataplane={"RegisteredName":"kernel-forwarder","SocketLocation":"/var/lib/networkservicemesh/nsm-vppagent.forwarder.sock","LocalMechanisms":[{"type":"KERNEL_INTERFACE"}],"RemoteMechanisms":[{"type":"VXLAN","parameters":{"src_ip":"10.240.0.4"}},{"type":"WIREGUARD","parameters":{"src_ip":"10.240.0.4"}}],"MechanismsConfigured":true} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==------------> Local.*endpointSelectorService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<------------ request={"connection":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------------- requestNSEOnUpdate=false span={}"
time="2020-03-27T17:54:15Z" level=info msg="==--------------> select-nse-1() span:{}"
time="2020-03-27T17:54:15Z" level=info msg="==----------------> GetEndpoint() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- request={"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- ignores={} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- targetEndpoint="" span={}"
time="2020-03-27T17:54:15Z" level=info msg="Requesting NetworkServiceDiscoveryClient..."
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- nseRequest={"network_service_name":"topology"} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- /registry.NetworkServiceDiscovery/FindNetworkService()="" span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- request={"network_service_name":"topology"} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- response={"payload":"IP","network_service":{"name":"topology","payload":"IP","matches":[{"source_selector":{"link":"r1-r2"},"routes":[{"destination_selector":{"device":"k8sqrtr04"}}]}]},"network_service_managers":{"k8s-agentpool-24376997-vmss000000":{"name":"k8s-agentpool-24376997-vmss000000","url":"10.240.0.16:5001","state":"RUNNING"}},"network_service_endpoints":[{"name":"topology2j6dp","payload":"IP","network_service_name":"topology","network_service_manager_name":"k8s-agentpool-24376997-vmss000000","labels":{"device":"k8sqrtr03","networkservicename":"topology"},"state":"RUNNING"},{"name":"topologyprffr","payload":"IP","network_service_name":"topology","network_service_manager_name":"k8s-agentpool-24376997-vmss000000","labels":{"device":"k8sqrtr04","networkservicename":"topology"},"state":"RUNNING"}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- nseResponse={"payload":"IP","network_service":{"name":"topology","payload":"IP","matches":[{"source_selector":{"link":"r1-r2"},"routes":[{"destination_selector":{"device":"k8sqrtr04"}}]}]},"network_service_managers":{"k8s-agentpool-24376997-vmss000000":{"name":"k8s-agentpool-24376997-vmss000000","url":"10.240.0.16:5001","state":"RUNNING"}},"network_service_endpoints":[{"name":"topology2j6dp","payload":"IP","network_service_name":"topology","network_service_manager_name":"k8s-agentpool-24376997-vmss000000","labels":{"device":"k8sqrtr03","networkservicename":"topology"},"state":"RUNNING"},{"name":"topologyprffr","payload":"IP","network_service_name":"topology","network_service_manager_name":"k8s-agentpool-24376997-vmss000000","labels":{"device":"k8sqrtr04","networkservicename":"topology"},"state":"RUNNING"}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="Selecting endpoint for topology with 1 matches."
time="2020-03-27T17:54:15Z" level=info msg="Matching endpoint for labels map[link:r1-r2 namespace:default peerif:eth123 podName:k8sqrtr03-55746fd498-dk5dm]"
time="2020-03-27T17:54:15Z" level=info msg="RoundRobin selected name:"topologyprffr" payload:"IP" network_service_name:"topology" network_service_manager_name:"k8s-agentpool-24376997-vmss000000" labels:<key:"device" value:"k8sqrtr04" > labels:<key:"networkservicename" value:"topology" > state:"RUNNING" "
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- selected endpoint={"network_service":{"name":"topology","payload":"IP","matches":[{"source_selector":{"link":"r1-r2"},"routes":[{"destination_selector":{"device":"k8sqrtr04"}}]}]},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000000","url":"10.240.0.16:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topologyprffr","payload":"IP","network_service_name":"topology","network_service_manager_name":"k8s-agentpool-24376997-vmss000000","labels":{"device":"k8sqrtr04","networkservicename":"topology"},"state":"RUNNING"}} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==----------------> Local.*excludedPrefixesService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- request={"connection":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="ExcludedPrefixesService: adding excluded prefixes to connection: [10.0.0.0/16]" operation="Local.*excludedPrefixesService.Request" span="{}"
time="2020-03-27T17:54:15Z" level=info msg="==------------------> Local.*endpointService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<------------------ request={"connection":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==--------------------> createNSEClient() span:{}"
time="2020-03-27T17:54:15Z" level=info msg="Create local NSE connection to endpoint: &{network_service:<name:"topology" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000000" url:"10.240.0.16:5001" state:"RUNNING" > network_service_endpoint:<name:"topologyprffr" payload:"IP" network_service_name:"topology" network_service_manager_name:"k8s-agentpool-24376997-vmss000000" labels:<key:"device" value:"k8sqrtr04" > labels:<key:"networkservicename" value:"topology" > state:"RUNNING" > /var/lib/networkservicemesh/nsm-97/nsm.client.io.sock nsm-97}" operation=createNSEClient span="{}"
time="2020-03-27T17:54:15Z" level=info msg="NSM:(7.2.6.2) Requesting NSE with request connection:<id:"5ecb" network_service:"topology" context:<ip_context:<src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth123" > labels:<key:"podName" value:"k8sqrtr03-55746fd498-dk5dm" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > mechanism_preferences:<type:"KERNEL_INTERFACE" > " operation="Local.*endpointService.Request" span="{}"
time="2020-03-27T17:54:15Z" level=info msg="==--------------------> nse.request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------------------- nse.request={"connection":{"id":"5ecb","network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------------- /networkservice.NetworkService/Request()="" span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------------- request={"connection":{"id":"5ecb","network_service":"topology","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}},"mechanism_preferences":[{"type":"KERNEL_INTERFACE"}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg="NSM-EndpointMonitor(topologyprffr): Received event: &{{UPDATE map[5ecb:0xc002d84e00] 0xc000038048}}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------------- response={"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------------------- nse.response={"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}} span={}"
time="2020-03-27T17:54:15Z" level=info msg="NSM:(7.2.6.2.4) Update Local NSE connection parameters: cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth123" > parameters:<key:"netnsInode" value:"4026533295" > parameters:<key:"socketfile" value:"nsml4dGGrUJK/memif.sock" > parameters:<key:"workspace" value:"nsm-97" > parameters:<key:"workspaceNseName" value:"topologyprffr" > "
time="2020-03-27T17:54:15Z" level=info msg="==----------------------> Local.*сrossConnectService.Request() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------------- request={"connection":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}}]} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------------- response={"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<------------------ response={"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- response={"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<------------ response={"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}} span={}"
time="2020-03-27T17:54:15Z" level=info msg="==------------> programForwarder() span:{}"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6bf" payload:"IP" source:<id:"6bf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth34" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"eth34/memif.sock" > parameters:<key:"workspace" value:"nsm-71" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > > destination:<id:"6c0" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth43" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"nsmTS1SeZ8Kq/memif.sock" > parameters:<key:"workspace" value:"nsm-44" > parameters:<key:"workspaceNseName" value:"topokgtb5" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c1" payload:"IP" source:<id:"6c1" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth51" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"eth51/memif.sock" > parameters:<key:"workspace" value:"nsm-37" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > > destination:<id:"6c2" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth15" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsmRXNCFPKmO/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ca" payload:"IP" source:<id:"6ca" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth23" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"eth23/memif.sock" > parameters:<key:"workspace" value:"nsm-27" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > > destination:<id:"6cb" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth32" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"nsmvo8KtZaxI/memif.sock" > parameters:<key:"workspace" value:"nsm-33" > parameters:<key:"workspaceNseName" value:"topoqc95k" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ce" payload:"IP" source:<id:"6ce" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth12" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"eth12/memif.sock" > parameters:<key:"workspace" value:"nsm-10" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > > destination:<id:"6cf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth21" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"nsm4g6k6cECf/memif.sock" > parameters:<key:"workspace" value:"nsm-78" > parameters:<key:"workspaceNseName" value:"toponb2t9" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"2422" payload:"IP" source:<id:"2422" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533703" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-52" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr05-5646b667cb-vd49m" > > destination:<id:"2423" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533507" > parameters:<key:"socketfile" value:"nsm1p2D643Gd/memif.sock" > parameters:<key:"workspace" value:"nsm-1" > parameters:<key:"workspaceNseName" value:"k8stopo05n9fgj" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr06-db45d8f74-4ksp2" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"3ae7" payload:"IP" source:<id:"3ae7" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533427" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-12" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk01-6ff94cff8d-vwz52" > > destination:<id:"3ae8" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533687" > parameters:<key:"socketfile" value:"nsmQ12KMWFNy/memif.sock" > parameters:<key:"workspace" value:"nsm-66" > parameters:<key:"workspaceNseName" value:"ceostopovenk01vmcgr" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk02-75c79b99b9-s66ns" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c4" payload:"IP" source:<id:"6c4" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth41" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth41/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c5" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth14" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsm9pq0EKm5/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c6" payload:"IP" source:<id:"6c6" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth45" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth45/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c7" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth54" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"nsmJwsA7KWb1/memif.sock" > parameters:<key:"workspace" value:"nsm-59" > parameters:<key:"workspaceNseName" value:"topon9wmh" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c6" payload:"IP" source:<id:"6c6" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth45" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth45/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c7" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth54" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"nsmJwsA7KWb1/memif.sock" > parameters:<key:"workspace" value:"nsm-59" > parameters:<key:"workspaceNseName" value:"topon9wmh" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c4" payload:"IP" source:<id:"6c4" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth41" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth41/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c5" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth14" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsm9pq0EKm5/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"3ae7" payload:"IP" source:<id:"3ae7" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533427" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-12" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk01-6ff94cff8d-vwz52" > > destination:<id:"3ae8" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533687" > parameters:<key:"socketfile" value:"nsmQ12KMWFNy/memif.sock" > parameters:<key:"workspace" value:"nsm-66" > parameters:<key:"workspaceNseName" value:"ceostopovenk01vmcgr" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk02-75c79b99b9-s66ns" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"2422" payload:"IP" source:<id:"2422" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533703" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-52" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr05-5646b667cb-vd49m" > > destination:<id:"2423" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533507" > parameters:<key:"socketfile" value:"nsm1p2D643Gd/memif.sock" > parameters:<key:"workspace" value:"nsm-1" > parameters:<key:"workspaceNseName" value:"k8stopo05n9fgj" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr06-db45d8f74-4ksp2" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ce" payload:"IP" source:<id:"6ce" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth12" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"eth12/memif.sock" > parameters:<key:"workspace" value:"nsm-10" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > > destination:<id:"6cf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth21" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"nsm4g6k6cECf/memif.sock" > parameters:<key:"workspace" value:"nsm-78" > parameters:<key:"workspaceNseName" value:"toponb2t9" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c1" payload:"IP" source:<id:"6c1" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth51" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"eth51/memif.sock" > parameters:<key:"workspace" value:"nsm-37" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > > destination:<id:"6c2" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth15" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsmRXNCFPKmO/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ca" payload:"IP" source:<id:"6ca" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth23" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"eth23/memif.sock" > parameters:<key:"workspace" value:"nsm-27" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > > destination:<id:"6cb" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth32" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"nsmvo8KtZaxI/memif.sock" > parameters:<key:"workspace" value:"nsm-33" > parameters:<key:"workspaceNseName" value:"topoqc95k" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6bf" payload:"IP" source:<id:"6bf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth34" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"eth34/memif.sock" > parameters:<key:"workspace" value:"nsm-71" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > > destination:<id:"6c0" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth43" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"nsmTS1SeZ8Kq/memif.sock" > parameters:<key:"workspace" value:"nsm-44" > parameters:<key:"workspaceNseName" value:"topokgtb5" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="NSM-EndpointMonitor(topologyprffr): Handler is nil, event: %v not handled: &{{UPDATE map[5ecb:0xc002d84e00] 0xc000038048}}"
time="2020-03-27T17:54:15Z" level=info msg="NSM-EndpointMonitor(topologyprffr): Received event: &{{UPDATE map[5ecb:0xc002d84f00] 0xc000038048}}"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ca" payload:"IP" source:<id:"6ca" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth23" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"eth23/memif.sock" > parameters:<key:"workspace" value:"nsm-27" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > > destination:<id:"6cb" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth32" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"nsmvo8KtZaxI/memif.sock" > parameters:<key:"workspace" value:"nsm-33" > parameters:<key:"workspaceNseName" value:"topoqc95k" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6bf" payload:"IP" source:<id:"6bf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth34" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"eth34/memif.sock" > parameters:<key:"workspace" value:"nsm-71" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > > destination:<id:"6c0" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth43" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"nsmTS1SeZ8Kq/memif.sock" > parameters:<key:"workspace" value:"nsm-44" > parameters:<key:"workspaceNseName" value:"topokgtb5" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c1" payload:"IP" source:<id:"6c1" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth51" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"eth51/memif.sock" > parameters:<key:"workspace" value:"nsm-37" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > > destination:<id:"6c2" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth15" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsmRXNCFPKmO/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c4" payload:"IP" source:<id:"6c4" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth41" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth41/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c5" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth14" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsm9pq0EKm5/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c6" payload:"IP" source:<id:"6c6" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth45" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth45/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c7" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth54" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"nsmJwsA7KWb1/memif.sock" > parameters:<key:"workspace" value:"nsm-59" > parameters:<key:"workspaceNseName" value:"topon9wmh" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ce" payload:"IP" source:<id:"6ce" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth12" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"eth12/memif.sock" > parameters:<key:"workspace" value:"nsm-10" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > > destination:<id:"6cf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth21" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"nsm4g6k6cECf/memif.sock" > parameters:<key:"workspace" value:"nsm-78" > parameters:<key:"workspaceNseName" value:"toponb2t9" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"2422" payload:"IP" source:<id:"2422" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533703" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-52" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr05-5646b667cb-vd49m" > > destination:<id:"2423" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533507" > parameters:<key:"socketfile" value:"nsm1p2D643Gd/memif.sock" > parameters:<key:"workspace" value:"nsm-1" > parameters:<key:"workspaceNseName" value:"k8stopo05n9fgj" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr06-db45d8f74-4ksp2" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"3ae7" payload:"IP" source:<id:"3ae7" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533427" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-12" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk01-6ff94cff8d-vwz52" > > destination:<id:"3ae8" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533687" > parameters:<key:"socketfile" value:"nsmQ12KMWFNy/memif.sock" > parameters:<key:"workspace" value:"nsm-66" > parameters:<key:"workspaceNseName" value:"ceostopovenk01vmcgr" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk02-75c79b99b9-s66ns" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c6" payload:"IP" source:<id:"6c6" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth45" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth45/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c7" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth54" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"nsmJwsA7KWb1/memif.sock" > parameters:<key:"workspace" value:"nsm-59" > parameters:<key:"workspaceNseName" value:"topon9wmh" > > context:<ip_context:<src_ip_addr:"10.60.5.1/30" dst_ip_addr:"10.60.5.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r5" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth54" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c4" payload:"IP" source:<id:"6c4" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth41" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"eth41/memif.sock" > parameters:<key:"workspace" value:"nsm-67" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > > destination:<id:"6c5" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth14" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsm9pq0EKm5/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.5/30" dst_ip_addr:"10.60.1.6/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r4-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth14" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"2422" payload:"IP" source:<id:"2422" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533703" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-52" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr05-5646b667cb-vd49m" > > destination:<id:"2423" network_service:"k8stopo05" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533507" > parameters:<key:"socketfile" value:"nsm1p2D643Gd/memif.sock" > parameters:<key:"workspace" value:"nsm-1" > parameters:<key:"workspaceNseName" value:"k8stopo05n9fgj" > > context:<ip_context:<src_ip_addr:"10.60.14.53/30" dst_ip_addr:"10.60.14.54/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-65" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"k8sqrtr06-db45d8f74-4ksp2" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"3ae7" payload:"IP" source:<id:"3ae7" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth2" > parameters:<key:"netnsInode" value:"4026533427" > parameters:<key:"socketfile" value:"eth2/memif.sock" > parameters:<key:"workspace" value:"nsm-12" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk01-6ff94cff8d-vwz52" > > destination:<id:"3ae8" network_service:"ceostopovenk01" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth3" > parameters:<key:"netnsInode" value:"4026533687" > parameters:<key:"socketfile" value:"nsmQ12KMWFNy/memif.sock" > parameters:<key:"workspace" value:"nsm-66" > parameters:<key:"workspaceNseName" value:"ceostopovenk01vmcgr" > > context:<ip_context:<src_ip_addr:"10.60.14.97/30" dst_ip_addr:"10.60.14.98/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"net-66" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth3" > labels:<key:"podName" value:"ceosdevvenk02-75c79b99b9-s66ns" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ce" payload:"IP" source:<id:"6ce" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth12" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"eth12/memif.sock" > parameters:<key:"workspace" value:"nsm-10" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > > destination:<id:"6cf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth21" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"nsm4g6k6cECf/memif.sock" > parameters:<key:"workspace" value:"nsm-78" > parameters:<key:"workspaceNseName" value:"toponb2t9" > > context:<ip_context:<src_ip_addr:"10.60.2.1/30" dst_ip_addr:"10.60.2.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r1-r2" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth21" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6c1" payload:"IP" source:<id:"6c1" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth51" > parameters:<key:"netnsInode" value:"4026532694" > parameters:<key:"socketfile" value:"eth51/memif.sock" > parameters:<key:"workspace" value:"nsm-37" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router5-5d645874-6q5l6" > > destination:<id:"6c2" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth15" > parameters:<key:"netnsInode" value:"4026532980" > parameters:<key:"socketfile" value:"nsmRXNCFPKmO/memif.sock" > parameters:<key:"workspace" value:"nsm-28" > parameters:<key:"workspaceNseName" value:"topo4sb96" > > context:<ip_context:<src_ip_addr:"10.60.1.1/30" dst_ip_addr:"10.60.1.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r5-r1" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth15" > labels:<key:"podName" value:"router1-7445bcc8d9-2b6dr" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6bf" payload:"IP" source:<id:"6bf" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth34" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"eth34/memif.sock" > parameters:<key:"workspace" value:"nsm-71" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > > destination:<id:"6c0" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth43" > parameters:<key:"netnsInode" value:"4026532290" > parameters:<key:"socketfile" value:"nsmTS1SeZ8Kq/memif.sock" > parameters:<key:"workspace" value:"nsm-44" > parameters:<key:"workspaceNseName" value:"topokgtb5" > > context:<ip_context:<src_ip_addr:"10.60.4.1/30" dst_ip_addr:"10.60.4.2/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r3-r4" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth43" > labels:<key:"podName" value:"router4-9b4b8f77b-drc6m" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="checking existing connection: id:"6ca" payload:"IP" source:<id:"6ca" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth23" > parameters:<key:"netnsInode" value:"4026533199" > parameters:<key:"socketfile" value:"eth23/memif.sock" > parameters:<key:"workspace" value:"nsm-27" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router2-6bf6468bc9-vfzqf" > > destination:<id:"6cb" network_service:"topo" mechanism:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"NSM Endpoint" > parameters:<key:"name" value:"eth32" > parameters:<key:"netnsInode" value:"4026532420" > parameters:<key:"socketfile" value:"nsmvo8KtZaxI/memif.sock" > parameters:<key:"workspace" value:"nsm-33" > parameters:<key:"workspaceNseName" value:"topoqc95k" > > context:<ip_context:<src_ip_addr:"10.60.3.13/30" dst_ip_addr:"10.60.3.14/30" src_ip_required:true dst_ip_required:true excluded_prefixes:"10.0.0.0/16" > > labels:<key:"link" value:"r2-r3" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth32" > labels:<key:"podName" value:"router3-5775c4d577-bb442" > path:<path_segments:<name:"k8s-agentpool-24376997-vmss000000" > > > to match 5ecb"
time="2020-03-27T17:54:15Z" level=info msg="NSM-EndpointMonitor(topologyprffr): Handler is nil, event: %v not handled: &{{UPDATE map[5ecb:0xc002d84f00] 0xc000038048}}"
time="2020-03-27T17:54:15Z" level=info msg="==--------------> ProgramAttempt-0() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------------- attempt=0 span={}"
time="2020-03-27T17:54:15Z" level=info msg="NSM:(9.1) Sending request to forwarder" operation=programForwarder span="{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------------- request={"id":"5eca","payload":"IP","source":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"destination":{"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock","workspace":"nsm-97","workspaceNseName":"topologyprffr"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- /forwarder.Forwarder/Request()="" span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- request={"id":"5eca","payload":"IP","source":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"destination":{"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock","workspace":"nsm-97","workspaceNseName":"topologyprffr"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- response={} span={}"
time="2020-03-27T17:54:15Z" level=error msg="NSM:(9.1.1) Forwarder request failed: rpc error: code = Unknown desc = failed to create VETH pair - file exists retry: 0" operation=ProgramAttempt-0 span="{}"
time="2020-03-27T17:54:15Z" level=info msg="monitor client(/var/lib/networkservicemesh/nsm-44/nsm.client.io.sock) connection status: READY"
time="2020-03-27T17:54:15Z" level=info msg="monitor client(/var/lib/networkservicemesh/nsm-88/nsm.client.io.sock) connection status: READY"
time="2020-03-27T17:54:15Z" level=info msg="==--------------> ProgramAttempt-1() span:{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------------- attempt=1 span={}"
time="2020-03-27T17:54:15Z" level=info msg="NSM:(9.1) Sending request to forwarder" operation=programForwarder span="{}"
time="2020-03-27T17:54:15Z" level=info msg=">><<-------------- request={"id":"5eca","payload":"IP","source":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"destination":{"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock","workspace":"nsm-97","workspaceNseName":"topologyprffr"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- /forwarder.Forwarder/Request()="" span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- request={"id":"5eca","payload":"IP","source":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"destination":{"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock","workspace":"nsm-97","workspaceNseName":"topologyprffr"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}}} span={}"
time="2020-03-27T17:54:15Z" level=info msg=">><<---------------- response={} span={}"
time="2020-03-27T17:54:15Z" level=error msg="NSM:(9.1.1) Forwarder request failed: rpc error: code = Unknown desc = failed to create VETH pair - file exists retry: 1" operation=ProgramAttempt-1 span="{}"
time="2020-03-27T17:54:16Z" level=info msg="==--------------> ProgramAttempt-2() span:{}"
time="2020-03-27T17:54:16Z" level=info msg=">><<-------------- attempt=2 span={}"
time="2020-03-27T17:54:16Z" level=info msg="NSM:(9.1) Sending request to forwarder" operation=programForwarder span="{}"
time="2020-03-27T17:54:16Z" level=info msg=">><<-------------- request={"id":"5eca","payload":"IP","source":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"destination":{"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock","workspace":"nsm-97","workspaceNseName":"topologyprffr"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}}} span={}"
time="2020-03-27T17:54:16Z" level=info msg=">><<---------------- /forwarder.Forwarder/Request()="" span={}"
time="2020-03-27T17:54:16Z" level=info msg=">><<---------------- request={"id":"5eca","payload":"IP","source":{"id":"5eca","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth123","netnsInode":"4026532849","socketfile":"eth123/memif.sock","workspace":"nsm-58"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr03-55746fd498-dk5dm"}},"destination":{"id":"5ecb","network_service":"topology","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"NSM Endpoint","name":"eth123","netnsInode":"4026533295","socketfile":"nsml4dGGrUJK/memif.sock","workspace":"nsm-97","workspaceNseName":"topologyprffr"}},"context":{"ip_context":{"src_ip_addr":"10.60.15.169/30","dst_ip_addr":"10.60.15.170/30","src_ip_required":true,"dst_ip_required":true,"excluded_prefixes":["10.0.0.0/16"]}},"labels":{"link":"r1-r2","namespace":"default","peerif":"eth123","podName":"k8sqrtr04-54bff65d9b-pszxg"},"path":{"path_segments":[{"name":"k8s-agentpool-24376997-vmss000000"}]}}} span={}"
time="2020-03-27T17:54:16Z" level=info msg=">><<---------------- response={} span={}"
time="2020-03-27T17:54:16Z" level=error msg="NSM:(9.1.1) Forwarder request failed: rpc error: code = Unknown desc = failed to create VETH pair - file exists retry: 2" operation=ProgramAttempt-2 span="{}"

[networkop]

it's a good catch, I've seen this error before but I couldn't track it down to reproduce it. From memory, this happened during a race condition when two pods both had to have a new interface created with the same name. Due to the fact that the interface is first created in host OS namespace and then moved to pod's namespace, the first step will fail if there's already an interface in host namespace with the same name. Does that sound like it could be the case for you @vparames86? can you check if there's an eth123 in the main network namespace of the k8s node that has the failing pod?

@vparames86 can you also see if you can catch this bug when tracing the logs of nsm-kernel -forwader as this is where this error is originating from. you can do this with stern -n nsm-system .command.

[vparames86]

@networkop - I will try to catch these logs. I have one more question. I have deployed the nsm in "default" namespace and not in "nsm-system" namespace and I am deploying these pods in the "default" namespace as well. Will that be an issue?

[networkop]

the pods are in a default namespace, the nsm-mgmr and kernel-forwarder are in nsm-system namespace.

[vparames86]

When I helm install nsm, I chose default namespace

SPIRE_ENABLED=false INSECURE=true FORWARDING_PLANE=kernel NSM_NAMESPACE=default make helm-install-nsm

Is this a problem?

[networkop]

yep, try omitting this variable, just do SPIRE_ENABLED=false INSECURE=true FORWARDING_PLANE=kernel make helm-install-nsm

[rdimitrov]

@vparames86 - Nice one! 👍 As @networkop said, this was hard to reproduce, so I'm also interested to see what would be the cause for it at the end.

[vparames86]

VETH_error.zip
@networkop - Uploaded a zip file of the stern logs.

// CreateInterfaces - creates local interfaces pair
func (c Connect) CreateInterfaces(srcName, dstName string) error {
/ Create the VETH pair - host namespace */
if err := netlink.LinkAdd(newVETH(srcName, dstName)); err != nil {
return errors.Errorf("failed to create VETH pair - %v", err)
}
return nil
}
This is the function which errors out. The srcName and dstName comes from "InterfaceNameKey" which is same in my case. Please let me know if you need further logs to debug this issue. I am also checking at my end to see if I can find anything.

[vparames86]

@networkop - I checked the logs for NS_NETWORKSERVICEMESH_IO = "topology/eth123?link=r1-r2&peerif=eth12". In this case the VETH pair is created successfully. I can send you the full logs for working scenario if you need.

nsm-kernel-forwarder-m6r4t kernel-forwarder time="2020-03-29T23:28:33Z" level=info msg="local: connection type - local source/local destination"
nsm-kernel-forwarder-m6r4t kernel-forwarder time="2020-03-29T23:28:33Z" level=info msg="local: creating connection..."
nsm-kernel-forwarder-m6r4t kernel-forwarder time="2020-03-29T23:28:33Z" level=info msg="local: creation completed for devices - source: eth123, destination: eth12"
nsm-kernel-forwarder-m6r4t kernel-forwarder time="2020-03-29T23:28:33Z" level=info msg="kernel-forwarder: created devices: map[4026532714:{eth123 SRC-175c} 4026532796:{eth12 DST-175c}]"
nsm-kernel-forwarder-m6r4t kernel-forwarder time="2020-03-29T23:28:33Z" level=info msg="metrics: device list - map[4026532714:[{eth123 SRC-175c}] 4026532796:[{eth12 DST-175c}]]"
nsm-kernel-forwarder-m6r4t kernel-forwarder time="2020-03-29T23:28:33Z" level=info msg="CrossConnect-New event: &{{UPDATE map[175c:0xc0002d4640] 0xc0001c0f00} map[] 0xc0001c0f00}"

[vparames86]

@networkop - I think the issue is that the "netns" is not provided when the veth pair is created in the create function. In the LinkAttr since the netns is not provided, the src and dst are created in the same netns and fails since their names are same .i.e. eth123-eth123. I see a link attribute called "netnsid" but don't know how to get that from the "netnsInode" value we have. Also I see a "Namespace" field - Namespace interface{} // nil | NsPid | NsFd in Link Attributes, not sure providing this might solve this issue.

func newVETH(srcName, dstName string) netlink.Veth {
/ Populate the VETH interface configuration */
return &netlink.Veth{
LinkAttrs: netlink.LinkAttrs{
Name: srcName,
MTU: cVETHMTU,
},
PeerName: dstName,
}
}

[networkop]

one possible solution to this is randomizing interface names and then changing them after the move to netNs, e.g. https://github.com/redhat-nfvpe/koko/blob/bd156c82bf25837545fb109c69c7b91c3457b318/api/koko_api.go#L604

[vparames86]

Sorry to ask again, any update on this issue?
I had one more question. I want to inject BGP routes into the virtual network and planning to use a quagga BGP daemon to setup an EBGP connection. Do you guys have any pointers on how can I achieve this?

[networkop]

I won't have time to do this fix any time soon, but maybe @rdimitrov will?

As for the BGP, it should work just as good as OSPF. All links are p2p so there will be no problem running eBGP over them;.

[vparames86]

@networkop - Thanks for your help. Probably I didn't phrase my question correctly. If I want to inject BGP routes from actual physical network into the virtual network, how can I achieve this?

[networkop]

you can do it with meshnet-cni - you can attach to a macvlan interface of the underlying host. But I'm haven't researched if NSM can do the same. The basic idea is you need to connect your pod to the underlying host's physical interface and have some physical device peer with it on the other end.
alternatively, if you can install some bgp daemon on each host (as daemonset), then you should be able to peer with your pods over an eth0 interface.

[rdimitrov]

@vparames86 hey, I'll have an update for you these days, I'm giving it a look now 👍

[vparames86]

Thanks @rdimitrov !

[rdimitrov]

@vparames86 I've implemented a fix for the name conflict you found - networkservicemesh/networkservicemesh#2145. I've tested it locally using kind, but let me know if it's also okay for your use case 👍

I decided to use the approach suggested by @networkop (thanks!) as I think specifying a NetNsID is not that suitable for our use case where both ends of the VETH pair are intended to end up in separate namespaces (not in a single one as NetNsID implies), thus causing to move one of the pairs to a different namespace again. Nevertheless, thank you for suggesting that! 👍

[rdimitrov]

@networkop I'm curious to see whether this fixes that sporadic VETH fails we had seen before

[networkop]

I think it would. thanks @rdimitrov

[vparames86]

Thanks @rdimitrov and @networkop . I will take these changes in today and will test and let you know.

[rdimitrov]

@vparames86 Thank you for taking the time to dig up into it! Much appreciated! 👍

[vparames86]

@rdimitrov - This issue is fixed for VETH pairs, but I am seeing it now in VXLAN too.

time="2020-05-07T19:29:10Z" level=info msg="remote: connection type - remote source/local destination - incoming"
time="2020-05-07T19:29:10Z" level=info msg="remote: creating connection..."
time="2020-05-07T19:29:10Z" level=error msg="remote: failed to create VXLAN interface: file exists"
time="2020-05-07T19:29:10Z" level=error msg="remote: failed to create connection - failed to create VXLAN interface: file exists"
time="2020-05-07T19:29:10Z" level=warning msg="error while handling Request() connection:failed to create VXLAN interface: file exists"

Probably we need to apply the same fix for VXLAN too

[rdimitrov]

@vparames86 Hey, I think it's better to keep this one for VETH, so can you create a separate issue in which you describe the steps to reproduce it - number of nodes, client/endpoint request details? Thanks!